Bug #14938: [crunch-dispatch-cloud] flaky test in lib/dispatchcloud/worker - Arvados

Actions

Copy link

Bug #14938

closed

[crunch-dispatch-cloud] flaky test in lib/dispatchcloud/worker

Added by Peter Amstutz over 5 years ago. Updated over 5 years ago.

Status:

Resolved

Priority:

Normal

Assigned To:

Category:

Target version:

2019-03-13 Sprint

Story points:

Release:

Arvados v1.4 - Q1/Q2 2019

Release relationship:

Auto

Description

https://ci.curoverse.com/job/run-tests-remainder/2587/console

16:00:45 FAIL: pool_test.go:36: PoolSuite.TestResumeAfterRestart
16:00:45 
16:00:45 time="2019-03-08T16:00:45.815900956Z" level=info msg="instance appeared in cloud" Address= IdleBehavior=run Instance=stub-providertype1-1b6cffa2ba517936 InstanceType=type1 State=booting
16:00:45 time="2019-03-08T16:00:45.816070136Z" level=info msg="instance appeared in cloud" Address= IdleBehavior=run Instance=stub-providertype1-30b95ff183c471d4 InstanceType=type1 State=booting
16:00:45 time="2019-03-08T16:00:45.816215985Z" level=info msg="instance appeared in cloud" Address= IdleBehavior=run Instance=stub-providertype2-28b621587cb3ad0b InstanceType=type2 State=booting
16:00:45 time="2019-03-08T16:00:45.816328691Z" level=info msg="loaded initial instance list" N=3
16:00:45 time="2019-03-08T16:00:45.826227235Z" level=info msg="boot probe succeeded" Address= Command=true Instance=stub-providertype1-30b95ff183c471d4 InstanceType=type1 stderr= stdout=
16:00:45 time="2019-03-08T16:00:45.826285401Z" level=info msg="instance booted; will try probeRunning" Address= Instance=stub-providertype1-30b95ff183c471d4 InstanceType=type1 ProbeStart="2019-03-08 16:00:45.826213414 +0000 UTC m=+0.015954157" 
16:00:45 time="2019-03-08T16:00:45.826315732Z" level=info msg="probes succeeded, instance is in service" Address= Instance=stub-providertype1-30b95ff183c471d4 InstanceType=type1 ProbeStart="2019-03-08 16:00:45.826213414 +0000 UTC m=+0.015954157" RunningContainers=0 State=idle
16:00:45 time="2019-03-08T16:00:45.826277432Z" level=info msg="boot probe succeeded" Address= Command=true Instance=stub-providertype1-1b6cffa2ba517936 InstanceType=type1 stderr= stdout=
16:00:45 time="2019-03-08T16:00:45.826486798Z" level=info msg="instance booted; will try probeRunning" Address= Instance=stub-providertype1-1b6cffa2ba517936 InstanceType=type1 ProbeStart="2019-03-08 16:00:45.826272138 +0000 UTC m=+0.016012917" 
16:00:45 time="2019-03-08T16:00:45.826503012Z" level=info msg="probes succeeded, instance is in service" Address= Instance=stub-providertype1-1b6cffa2ba517936 InstanceType=type1 ProbeStart="2019-03-08 16:00:45.826272138 +0000 UTC m=+0.016012917" RunningContainers=0 State=idle
16:00:45 time="2019-03-08T16:00:45.827171420Z" level=info msg="boot probe succeeded" Address= Command=true Instance=stub-providertype2-28b621587cb3ad0b InstanceType=type2 stderr= stdout=
16:00:45 time="2019-03-08T16:00:45.827198060Z" level=info msg="instance booted; will try probeRunning" Address= Instance=stub-providertype2-28b621587cb3ad0b InstanceType=type2 ProbeStart="2019-03-08 16:00:45.827159989 +0000 UTC m=+0.016900757" 
16:00:45 time="2019-03-08T16:00:45.827225798Z" level=info msg="probes succeeded, instance is in service" Address= Instance=stub-providertype2-28b621587cb3ad0b InstanceType=type2 ProbeStart="2019-03-08 16:00:45.827159989 +0000 UTC m=+0.016900757" RunningContainers=0 State=idle
16:00:45 ------- starting new pool, waiting to recover state
16:00:45 time="2019-03-08T16:00:45.827400731Z" level=info msg="instance appeared in cloud" Address="127.0.0.1:45101" IdleBehavior=run Instance=stub-providertype2-28b621587cb3ad0b InstanceType=type2 State=unknown
16:00:45 time="2019-03-08T16:00:45.827465574Z" level=info msg="instance appeared in cloud" Address="127.0.0.1:35695" IdleBehavior=run Instance=stub-providertype1-1b6cffa2ba517936 InstanceType=type1 State=unknown
16:00:45 time="2019-03-08T16:00:45.827511006Z" level=info msg="instance appeared in cloud" Address="127.0.0.1:40529" IdleBehavior=run Instance=stub-providertype1-30b95ff183c471d4 InstanceType=type1 State=unknown
16:00:45 time="2019-03-08T16:00:45.827537085Z" level=info msg="loaded initial instance list" N=3
16:00:45 time="2019-03-08T16:00:45.837509289Z" level=info msg="boot probe succeeded" Address="127.0.0.1:45101" Command=true Instance=stub-providertype2-28b621587cb3ad0b InstanceType=type2 stderr= stdout=
16:00:45 time="2019-03-08T16:00:45.837595567Z" level=info msg="instance booted; will try probeRunning" Address="127.0.0.1:45101" Instance=stub-providertype2-28b621587cb3ad0b InstanceType=type2 ProbeStart="2019-03-08 16:00:45.837490567 +0000 UTC m=+0.027231362" 
16:00:45 time="2019-03-08T16:00:45.837622982Z" level=info msg="probes succeeded, instance is in service" Address="127.0.0.1:45101" Instance=stub-providertype2-28b621587cb3ad0b InstanceType=type2 ProbeStart="2019-03-08 16:00:45.837490567 +0000 UTC m=+0.027231362" RunningContainers=0 State=idle
16:00:45 time="2019-03-08T16:00:45.837509701Z" level=info msg="boot probe succeeded" Address="127.0.0.1:40529" Command=true Instance=stub-providertype1-30b95ff183c471d4 InstanceType=type1 stderr= stdout=
16:00:45 time="2019-03-08T16:00:45.837664046Z" level=info msg="instance booted; will try probeRunning" Address="127.0.0.1:40529" Instance=stub-providertype1-30b95ff183c471d4 InstanceType=type1 ProbeStart="2019-03-08 16:00:45.83749274 +0000 UTC m=+0.027233502" 
16:00:45 time="2019-03-08T16:00:45.837685252Z" level=info msg="probes succeeded, instance is in service" Address="127.0.0.1:40529" Instance=stub-providertype1-30b95ff183c471d4 InstanceType=type1 ProbeStart="2019-03-08 16:00:45.83749274 +0000 UTC m=+0.027233502" RunningContainers=0 State=idle
16:00:45 time="2019-03-08T16:00:45.838470935Z" level=info msg="boot probe succeeded" Address="127.0.0.1:35695" Command=true Instance=stub-providertype1-1b6cffa2ba517936 InstanceType=type1 stderr= stdout=
16:00:45 time="2019-03-08T16:00:45.838496576Z" level=info msg="instance booted; will try probeRunning" Address="127.0.0.1:35695" Instance=stub-providertype1-1b6cffa2ba517936 InstanceType=type1 ProbeStart="2019-03-08 16:00:45.838462635 +0000 UTC m=+0.028203403" 
16:00:45 time="2019-03-08T16:00:45.838508320Z" level=info msg="probes succeeded, instance is in service" Address="127.0.0.1:35695" Instance=stub-providertype1-1b6cffa2ba517936 InstanceType=type1 ProbeStart="2019-03-08 16:00:45.838462635 +0000 UTC m=+0.028203403" RunningContainers=0 State=idle
16:00:45 pool_test.go:119:
16:00:45     c.Check(inst.IdleBehavior, check.Equals, IdleBehaviorHold)
16:00:45 ... obtained worker.IdleBehavior = "run" 
16:00:45 ... expected worker.IdleBehavior = "hold"