See
<https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4468/display/redirect?page=changes>
Changes:
[Kapil Arya] Removed WIP from 1.4.1 changelog.
[Kapil Arya] Update website for 1.4.1 relsease.
------------------------------------------
[...truncated 3.70 MB...]
3: I1116 21:16:59.505553 17366 master.cpp:7064] Received update of agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06) with total oversubscribed resources {}
3: I1116 21:16:59.505759 17366 master.cpp:7082] Ignoring update on agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06) as it reports no changes
3: I1116 21:16:59.507048 17351 sched.cpp:232] Version: 1.5.0
3: I1116 21:16:59.507699 17370 sched.cpp:336] New master detected at
master@172.17.0.4:41888
3: I1116 21:16:59.507819 17370 sched.cpp:396] Authenticating with master
master@172.17.0.4:41888
3: I1116 21:16:59.507839 17370 sched.cpp:403] Using default CRAM-MD5
authenticatee
3: I1116 21:16:59.508163 17362 authenticatee.cpp:121] Creating new client SASL
connection
3: I1116 21:16:59.508514 17375 master.cpp:8285] Authenticating
scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888
3: I1116 21:16:59.508697 17364 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(145)@172.17.0.4:41888
3: I1116 21:16:59.509091 17368 authenticator.cpp:98] Creating new server SASL
connection
3: I1116 21:16:59.509477 17355 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1116 21:16:59.509516 17355 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1116 21:16:59.509692 17358 authenticator.cpp:204] Received SASL
authentication start
3: I1116 21:16:59.509769 17358 authenticator.cpp:326] Authentication requires
more steps
3: I1116 21:16:59.509927 17358 authenticatee.cpp:259] Received SASL
authentication step
3: I1116 21:16:59.510119 17374 authenticator.cpp:232] Received SASL
authentication step
3: I1116 21:16:59.510162 17374 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'da3e8d96ac06' server FQDN: 'da3e8d96ac06'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I1116 21:16:59.510179 17374 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I1116 21:16:59.510221 17374 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I1116 21:16:59.510263 17374 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'da3e8d96ac06' server FQDN: 'da3e8d96ac06'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I1116 21:16:59.510282 17374 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1116 21:16:59.510298 17374 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1116 21:16:59.510334 17374 authenticator.cpp:318] Authentication success
3: I1116 21:16:59.510486 17367 authenticatee.cpp:299] Authentication success
3: I1116 21:16:59.510565 17363 master.cpp:8315] Successfully authenticated
principal 'test-principal' at
scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888
3: I1116 21:16:59.510701 17360 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(145)@172.17.0.4:41888
3: I1116 21:16:59.510931 17365 sched.cpp:502] Successfully authenticated with
master master@172.17.0.4:41888
3: I1116 21:16:59.510964 17365 sched.cpp:824] Sending SUBSCRIBE call to
master@172.17.0.4:41888
3: I1116 21:16:59.511162 17365 sched.cpp:857] Will retry registration in
433.284988ms if necessary
3: I1116 21:16:59.511407 17361 master.cpp:2961] Received SUBSCRIBE call for
framework 'default' at
scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888
3: I1116 21:16:59.511534 17361 master.cpp:2278] Authorizing framework principal
'test-principal' to receive offers for roles '{ * }'
3: I1116 21:16:59.512249 17352 master.cpp:3041] Subscribing framework default
with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1116 21:16:59.513212 17352 sched.cpp:751] Framework registered with
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.513355 17352 sched.cpp:765] Scheduler::registered took
103311ns
3: I1116 21:16:59.513424 17371 hierarchical.cpp:303] Added framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.514945 17371 hierarchical.cpp:1450] Performed allocation for
1 agents in 1.238529ms
3: I1116 21:16:59.515501 17358 master.cpp:8115] Sending 1 offers to framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 (default) at
scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888
3: I1116 21:16:59.517475 17367 sched.cpp:921] Scheduler::resourceOffers took
1.31575ms
3: I1116 21:16:59.519420 17374 master.cpp:10024] Removing offer
e387905e-1a84-40d0-ae3b-003f45078c11-O0
3: I1116 21:16:59.519649 17374 master.cpp:4228] Processing ACCEPT call for
offers: [ e387905e-1a84-40d0-ae3b-003f45078c11-O0 ] on agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06) for framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
(default) at scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888
3: I1116 21:16:59.519853 17374 master.cpp:3597] Authorizing framework principal
'test-principal' to launch task 0
3: W1116 21:16:59.522399 17356 validation.cpp:1391] Executor 'default' for task
'0' uses less CPUs (None) than the minimum required (0.01). Please update your
executor, as this will be mandatory in future releases.
3: W1116 21:16:59.522454 17356 validation.cpp:1403] Executor 'default' for task
'0' uses less memory (None) than the minimum required (32MB). Please update
your executor, as this will be mandatory in future releases.
3: I1116 21:16:59.523049 17356 master.cpp:10770] Adding task 0 with resources
[{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}]
on agent e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06)
3: I1116 21:16:59.523650 17356 master.cpp:4976] Launching task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 (default) at
scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888 with resources
[{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}]
on agent e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06)
3: I1116 21:16:59.524459 17366 slave.cpp:1803] Got assigned task '0' for
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.525207 17360 hierarchical.cpp:1125] Recovered
ports(allocated: *):[31000-32000]; disk(allocated: *):1024 (total: cpus:2;
mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated: *):2;
mem(allocated: *):1024) on agent e387905e-1a84-40d0-ae3b-003f45078c11-S0 from
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.525306 17360 hierarchical.cpp:1171] Framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 filtered agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 for 5secs
3: I1116 21:16:59.525426 17366 slave.cpp:2071] Authorizing task '0' for
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.525539 17366 slave.cpp:7262] Authorizing framework principal
'test-principal' to launch task 0
3: I1116 21:16:59.526525 17373 slave.cpp:2239] Launching task '0' for framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.527184 17373 paths.cpp:621] Trying to chown
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/aa1aad18-dbdc-4eba-9ced-36fa684617b9'
to user 'mesos'
3: I1116 21:16:59.527447 17373 slave.cpp:7736] Launching executor 'default' of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 with resources [] in work
directory
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/aa1aad18-dbdc-4eba-9ced-36fa684617b9'
3: I1116 21:16:59.528005 17373 slave.cpp:2930] Launching container
aa1aad18-dbdc-4eba-9ced-36fa684617b9 for executor 'default' of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.528452 17373 slave.cpp:2467] Queued task '0' for executor
'default' of framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.528551 17373 slave.cpp:958] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/aa1aad18-dbdc-4eba-9ced-36fa684617b9'
to virtual path
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/latest'
3: I1116 21:16:59.528597 17373 slave.cpp:958] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/aa1aad18-dbdc-4eba-9ced-36fa684617b9'
to virtual path
'/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/latest'
3: I1116 21:16:59.528635 17373 slave.cpp:958] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/aa1aad18-dbdc-4eba-9ced-36fa684617b9'
to virtual path
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/aa1aad18-dbdc-4eba-9ced-36fa684617b9'
3: W1116 21:16:59.530865 17352 process.cpp:3178] Attempted to spawn already
running process version@172.17.0.4:41888
3: I1116 21:16:59.531062 17352 exec.cpp:162] Version: 1.5.0
3: I1116 21:16:59.531337 17362 exec.cpp:212] Executor started at:
executor(14)@172.17.0.4:41888 with pid 17351
3: I1116 21:16:59.531558 17364 slave.cpp:4063] Got registration for executor
'default' of framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 from
executor(14)@172.17.0.4:41888
3: I1116 21:16:59.531961 17368 exec.cpp:237] Executor registered on agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0
3: I1116 21:16:59.532012 17368 exec.cpp:249] Executor::registered took 26870ns
3: I1116 21:16:59.532421 17364 slave.cpp:2669] Sending queued task '0' to
executor 'default' of framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 at
executor(14)@172.17.0.4:41888
3: I1116 21:16:59.532801 17357 exec.cpp:331] Executor asked to run task '0'
3: I1116 21:16:59.532901 17357 exec.cpp:340] Executor::launchTask took 72633ns
3: I1116 21:16:59.533005 17357 exec.cpp:571] Executor sending status update
TASK_RUNNING (UUID: f0fc0028-1976-46b8-ae32-0c5e04be8aae) for task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.533429 17371 slave.cpp:4517] Handling status update
TASK_RUNNING (UUID: f0fc0028-1976-46b8-ae32-0c5e04be8aae) for task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 from
executor(14)@172.17.0.4:41888
3: I1116 21:16:59.534375 17372 status_update_manager.cpp:323] Received status
update TASK_RUNNING (UUID: f0fc0028-1976-46b8-ae32-0c5e04be8aae) for task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.534449 17372 status_update_manager.cpp:500] Creating
StatusUpdate stream for task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.535117 17372 status_update_manager.cpp:377] Forwarding update
TASK_RUNNING (UUID: f0fc0028-1976-46b8-ae32-0c5e04be8aae) for task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 to the agent
3: I1116 21:16:59.535403 17374 slave.cpp:4998] Forwarding the update
TASK_RUNNING (UUID: f0fc0028-1976-46b8-ae32-0c5e04be8aae) for task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 to master@172.17.0.4:41888
3: I1116 21:16:59.535717 17374 slave.cpp:4892] Status update manager
successfully handled status update TASK_RUNNING (UUID:
f0fc0028-1976-46b8-ae32-0c5e04be8aae) for task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.535789 17374 slave.cpp:4908] Sending acknowledgement for
status update TASK_RUNNING (UUID: f0fc0028-1976-46b8-ae32-0c5e04be8aae) for
task 0 of framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 to
executor(14)@172.17.0.4:41888
3: I1116 21:16:59.535969 17363 master.cpp:7247] Status update TASK_RUNNING
(UUID: f0fc0028-1976-46b8-ae32-0c5e04be8aae) for task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 from agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06)
3: I1116 21:16:59.536032 17369 exec.cpp:388] Executor received status update
acknowledgement f0fc0028-1976-46b8-ae32-0c5e04be8aae for task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.536064 17363 master.cpp:7309] Forwarding status update
TASK_RUNNING (UUID: f0fc0028-1976-46b8-ae32-0c5e04be8aae) for task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.536367 17363 master.cpp:9502] Updating the state of task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 (latest state:
TASK_RUNNING, status update state: TASK_RUNNING)
3: I1116 21:16:59.536669 17356 sched.cpp:1029] Scheduler::statusUpdate took
120791ns
3: I1116 21:16:59.537238 17354 master.cpp:5791] Processing ACKNOWLEDGE call
f0fc0028-1976-46b8-ae32-0c5e04be8aae for task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 (default) at
scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888 on agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0
3: I1116 21:16:59.537753 17370 status_update_manager.cpp:395] Received status
update acknowledgement (UUID: f0fc0028-1976-46b8-ae32-0c5e04be8aae) for task 0
of framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.538143 17375 slave.cpp:3801] Status update manager
successfully handled status update acknowledgement (UUID:
f0fc0028-1976-46b8-ae32-0c5e04be8aae) for task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.541024 17368 process.cpp:3925] Handling HTTP event for
process 'files' with path: '/files/browse'
3: I1116 21:16:59.542989 17374 http.cpp:1185] HTTP GET for
/files/browse?path=%2Ftmp%2FGarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng%2Fslaves%2Fe387905e-1a84-40d0-ae3b-003f45078c11-S0%2Fframeworks%2Fe387905e-1a84-40d0-ae3b-003f45078c11-0000%2Fexecutors%2Fdefault%2Fruns%2Flatest
from 172.17.0.4:54110
3: I1116 21:16:59.547031 17352 slave.cpp:5130] Got exited event for
executor(14)@172.17.0.4:41888
3: I1116 21:16:59.547368 17357 slave.cpp:5539] Executor 'default' of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 exited with status 0
3: I1116 21:16:59.547524 17357 slave.cpp:4517] Handling status update
TASK_FAILED (UUID: 571ea9f8-3fcd-441f-8a11-669d8ef69af2) for task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 from @0.0.0.0:0
3: I1116 21:16:59.548112 17357 master.cpp:7459] Executor 'default' of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 on agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06): exited with status 0
3: I1116 21:16:59.548200 17357 master.cpp:9625] Removing executor 'default'
with resources [] of framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 on
agent e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06)
3: I1116 21:16:59.548701 17369 sched.cpp:1131] Executor default on agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 exited with status 0
3: I1116 21:16:59.548765 17369 sched.cpp:1142] Scheduler::executorLost took
34485ns
3: I1116 21:16:59.548907 17361 status_update_manager.cpp:323] Received status
update TASK_FAILED (UUID: 571ea9f8-3fcd-441f-8a11-669d8ef69af2) for task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.549118 17361 status_update_manager.cpp:377] Forwarding update
TASK_FAILED (UUID: 571ea9f8-3fcd-441f-8a11-669d8ef69af2) for task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 to the agent
3: I1116 21:16:59.549489 17360 slave.cpp:4998] Forwarding the update
TASK_FAILED (UUID: 571ea9f8-3fcd-441f-8a11-669d8ef69af2) for task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 to master@172.17.0.4:41888
3: I1116 21:16:59.549849 17360 slave.cpp:4892] Status update manager
successfully handled status update TASK_FAILED (UUID:
571ea9f8-3fcd-441f-8a11-669d8ef69af2) for task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.550104 17366 master.cpp:7247] Status update TASK_FAILED
(UUID: 571ea9f8-3fcd-441f-8a11-669d8ef69af2) for task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 from agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06)
3: I1116 21:16:59.550192 17366 master.cpp:7309] Forwarding status update
TASK_FAILED (UUID: 571ea9f8-3fcd-441f-8a11-669d8ef69af2) for task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.550504 17366 master.cpp:9502] Updating the state of task 0 of
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 (latest state: TASK_FAILED,
status update state: TASK_FAILED)
3: I1116 21:16:59.550753 17356 sched.cpp:1029] Scheduler::statusUpdate took
28726ns
3: I1116 21:16:59.551491 17365 hierarchical.cpp:1125] Recovered cpus(allocated:
*):2; mem(allocated: *):1024 (total: cpus:2; mem:1024; disk:1024;
ports:[31000-32000], allocated: {}) on agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 from framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.551617 17366 master.cpp:5791] Processing ACKNOWLEDGE call
571ea9f8-3fcd-441f-8a11-669d8ef69af2 for task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 (default) at
scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888 on agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0
3: I1116 21:16:59.551726 17366 master.cpp:9596] Removing task 0 with resources
[{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}]
of framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 on agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06)
3: I1116 21:16:59.552682 17373 status_update_manager.cpp:395] Received status
update acknowledgement (UUID: 571ea9f8-3fcd-441f-8a11-669d8ef69af2) for task 0
of framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.552873 17373 status_update_manager.cpp:531] Cleaning up
status update stream for task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.553458 17375 slave.cpp:3801] Status update manager
successfully handled status update acknowledgement (UUID:
571ea9f8-3fcd-441f-8a11-669d8ef69af2) for task 0 of framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.553531 17375 slave.cpp:8341] Completing task 0
3: I1116 21:16:59.553573 17375 slave.cpp:5643] Cleaning up executor 'default'
of framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 at
executor(14)@172.17.0.4:41888
3: I1116 21:16:59.553949 17354 gc.cpp:90] Scheduling
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/aa1aad18-dbdc-4eba-9ced-36fa684617b9'
for gc 6.99999367657481days in the future
3: I1116 21:16:59.554217 17375 slave.cpp:5750] Cleaning up framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.554210 17354 gc.cpp:90] Scheduling
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default'
for gc 6.99999367657481days in the future
3: I1116 21:16:59.554391 17362 status_update_manager.cpp:285] Closing status
update streams for framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.554548 17355 gc.cpp:90] Scheduling
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000'
for gc 6.99999367657481days in the future
3: I1116 21:16:59.557364 17367 slave.cpp:5966] Framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 seems to have exited. Ignoring
registration timeout for executor 'default'
3: I1116 21:16:59.557368 17369 master.cpp:1881] Skipping periodic registry
garbage collection: no agents qualify for removal
3: I1116 21:16:59.557490 17361 gc.cpp:208] Deleting
/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/aa1aad18-dbdc-4eba-9ced-36fa684617b9
3: I1116 21:16:59.557730 17361 gc.cpp:218] Deleted
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/aa1aad18-dbdc-4eba-9ced-36fa684617b9'
3: I1116 21:16:59.557734 17367 slave.cpp:6058] Current disk usage 18.64%. Max
allowed age: 4.995333734425208days
3: I1116 21:16:59.557847 17361 gc.cpp:208] Deleting
/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default
3: I1116 21:16:59.558066 17356 gc.cpp:263] Pruning directories with remaining
removal time 0ns
3: I1116 21:16:59.558187 17361 gc.cpp:218] Deleted
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default'
3: I1116 21:16:59.558254 17368 hierarchical.cpp:1450] Performed allocation for
1 agents in 1.483905ms
3: I1116 21:16:59.558296 17356 gc.cpp:183] Skipping deletion of
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default/runs/aa1aad18-dbdc-4eba-9ced-36fa684617b9'
as it is already in progress
3: I1116 21:16:59.558296 17361 gc.cpp:208] Deleting
/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.558338 17356 gc.cpp:183] Skipping deletion of
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000/executors/default'
as it is already in progress
3: I1116 21:16:59.558359 17356 gc.cpp:183] Skipping deletion of
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000'
as it is already in progress
3: I1116 21:16:59.558820 17361 gc.cpp:218] Deleted
'/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng/slaves/e387905e-1a84-40d0-ae3b-003f45078c11-S0/frameworks/e387905e-1a84-40d0-ae3b-003f45078c11-0000'
3: I1116 21:16:59.558936 17365 master.cpp:8115] Sending 1 offers to framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 (default) at
scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888
3: I1116 21:16:59.559521 17354 sched.cpp:921] Scheduler::resourceOffers took
27520ns
3: I1116 21:16:59.562525 17364 process.cpp:3925] Handling HTTP event for
process 'files' with path: '/files/browse'
3: I1116 21:16:59.564162 17374 http.cpp:1185] HTTP GET for
/files/browse?path=%2Ftmp%2FGarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng%2Fslaves%2Fe387905e-1a84-40d0-ae3b-003f45078c11-S0%2Fframeworks%2Fe387905e-1a84-40d0-ae3b-003f45078c11-0000%2Fexecutors%2Fdefault
from 172.17.0.4:54112
3: I1116 21:16:59.573230 17368 process.cpp:3925] Handling HTTP event for
process 'files' with path: '/files/browse'
3: I1116 21:16:59.574874 17354 http.cpp:1185] HTTP GET for
/files/browse?path=%2Ftmp%2FGarbageCollectorIntegrationTest_ExitedExecutor_JrX3ng%2Fslaves%2Fe387905e-1a84-40d0-ae3b-003f45078c11-S0%2Fframeworks%2Fe387905e-1a84-40d0-ae3b-003f45078c11-0000%2Fexecutors%2Fdefault%2Fruns%2Flatest
from 172.17.0.4:54114
3: I1116 21:16:59.580902 17351 sched.cpp:2009] Asked to stop the driver
3: I1116 21:16:59.581050 17353 sched.cpp:1191] Stopping framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.581413 17358 master.cpp:8792] Processing TEARDOWN call for
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000 (default) at
scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888
3: I1116 21:16:59.581456 17358 master.cpp:8804] Removing framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 (default) at
scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888
3: I1116 21:16:59.581472 17358 master.cpp:3331] Deactivating framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 (default) at
scheduler-92f33f13-25e7-48a6-84f5-0877bfcf4b9f@172.17.0.4:41888
3: I1116 21:16:59.581619 17369 hierarchical.cpp:412] Deactivated framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.582151 17358 master.cpp:10024] Removing offer
e387905e-1a84-40d0-ae3b-003f45078c11-O1
3: I1116 21:16:59.582478 17354 slave.cpp:3267] Asked to shut down framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000 by master@172.17.0.4:41888
3: I1116 21:16:59.582535 17354 slave.cpp:3282] Cannot shut down unknown
framework e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.582826 17374 slave.cpp:883] Agent terminating
3: I1116 21:16:59.582815 17360 hierarchical.cpp:1125] Recovered cpus(allocated:
*):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated:
*):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000],
allocated: {}) on agent e387905e-1a84-40d0-ae3b-003f45078c11-S0 from framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.583057 17363 master.cpp:1309] Agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06) disconnected
3: I1116 21:16:59.583094 17363 master.cpp:3368] Disconnecting agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06)
3: I1116 21:16:59.583166 17360 hierarchical.cpp:355] Removed framework
e387905e-1a84-40d0-ae3b-003f45078c11-0000
3: I1116 21:16:59.583171 17363 master.cpp:3387] Deactivating agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 at slave(63)@172.17.0.4:41888
(da3e8d96ac06)
3: I1116 21:16:59.583407 17361 hierarchical.cpp:690] Agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0 deactivated
3: I1116 21:16:59.587754 17351 master.cpp:1151] Master terminating
3: I1116 21:16:59.588555 17371 hierarchical.cpp:626] Removed agent
e387905e-1a84-40d0-ae3b-003f45078c11-S0
3: [ OK ] GarbageCollectorIntegrationTest.ExitedExecutor (130 ms)
3: [ RUN ] GarbageCollectorIntegrationTest.DiskUsage
3: I1116 21:16:59.595396 17351 cluster.cpp:162] Creating default 'local'
authorizer
3: I1116 21:16:59.599254 17367 master.cpp:448] Master
edecb9e1-882a-4825-abc1-5a36dbcbfd41 (da3e8d96ac06) started on 172.17.0.4:41888
3: I1116 21:16:59.599285 17367 master.cpp:450] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1secs" --allocator="HierarchicalDRF"
--authenticate_agents="true" --authenticate_frameworks="true"
--authenticate_http_frameworks="true" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authenticators="crammd5"
--authorizers="local" --credentials="/tmp/2gJGxh/credentials"
--filter_gpu_resources="true" --framework_sorter="drf" --help="false"
--hostname_lookup="true" --http_authenticators="basic"
--http_framework_authenticators="basic" --initialize_driver_logging="true"
--log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
--max_agent_ping_timeouts="5" --max_completed_frameworks="50"
--max_completed_tasks_per_framework="1000"
--max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false"
--recovery_agent_removal_limit="100%" --registry="in_memory"
--registry_fetch_timeout="1mins" --registry_gc_interval="15mins"
--registry_max_agent_age="2weeks" --registry_max_agent_count="102400"
--registry_store_timeout="100secs" --registry_strict="false"
--root_submissions="true" --user_sorter="drf" --version="false"
--webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/2gJGxh/master"
--zk_session_timeout="10secs"
3: I1116 21:16:59.599627 17367 master.cpp:499] Master only allowing
authenticated frameworks to register
3: I1116 21:16:59.599635 17367 master.cpp:505] Master only allowing
authenticated agents to register
3: I1116 21:16:59.599640 17367 master.cpp:511] Master only allowing
authenticated HTTP frameworks to register
3: I1116 21:16:59.599648 17367 credentials.hpp:37] Loading credentials for
authentication from '/tmp/2gJGxh/credentials'
3: I1116 21:16:59.599993 17367 master.cpp:555] Using default 'crammd5'
authenticator
3: I1116 21:16:59.600168 17367 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
3: I1116 21:16:59.600338 17367 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
3: I1116 21:16:59.600489 17367 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
3: I1116 21:16:59.600634 17367 master.cpp:634] Authorization enabled
3: I1116 21:16:59.600800 17361 hierarchical.cpp:171] Initialized hierarchical
allocator process
3: I1116 21:16:59.600818 17355 whitelist_watcher.cpp:77] No whitelist given
3: I1116 21:16:59.604279 17370 master.cpp:2213] Elected as the leading master!
3: I1116 21:16:59.604326 17370 master.cpp:1693] Recovering from registrar
3: I1116 21:16:59.604562 17364 registrar.cpp:347] Recovering registrar
3: I1116 21:16:59.605453 17364 registrar.cpp:391] Successfully fetched the
registry (0B) in 829184ns
3: I1116 21:16:59.605599 17364 registrar.cpp:495] Applied 1 operations in
40275ns; attempting to update the registry
3: I1116 21:16:59.606434 17364 registrar.cpp:552] Successfully updated the
registry in 751104ns
3: I1116 21:16:59.606611 17364 registrar.cpp:424] Successfully recovered
registrar
3: I1116 21:16:59.607169 17360 master.cpp:1806] Recovered 0 agents from the
registry (129B); allowing 10mins for agents to re-register
3: I1116 21:16:59.607234 17366 hierarchical.cpp:209] Skipping recovery of
hierarchical allocator: nothing to recover
3: W1116 21:16:59.614634 17351 process.cpp:3178] Attempted to spawn already
running process files@172.17.0.4:41888
3: I1116 21:16:59.615097 17351 cluster.cpp:448] Creating default 'local'
authorizer
3: I1116 21:16:59.618593 17371 slave.cpp:262] Mesos agent started on
(64)@172.17.0.4:41888
3: I1116 21:16:59.618629 17371 slave.cpp:263] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/GarbageCollectorIntegrationTest_DiskUsage_pRNQxi/store/appc"
--authenticate_http_readonly="true" --authenticate_http_readwrite="true"
--authenticatee="crammd5" --authentication_backoff_factor="1secs"
--authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false"
--cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup"
--cgroups_limit_swap="false" --cgroups_root="mesos"
--container_disk_watch_interval="15secs" --containerizers="mesos"
--credential="/tmp/GarbageCollectorIntegrationTest_DiskUsage_pRNQxi/credential"
--default_role="*" --disallow_sharing_agent_pid_namespace="false"
--disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true"
--docker_registry="https://registry-1.docker.io"; --docker_remove_delay="6hrs"
--docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns"
--docker_store_dir="/tmp/GarbageCollectorIntegrationTest_DiskUsage_pRNQxi/store/docker"
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
--enforce_container_disk_quota="false" --executor_registration_timeout="1mins"
--executor_reregistration_timeout="2secs"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/GarbageCollectorIntegrationTest_DiskUsage_pRNQxi/fetch"
--fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks"
--gc_disk_headroom="0.1" --hadoop_home="" --help="false"
--hostname_lookup="true" --http_command_executor="false"
--http_credentials="/tmp/GarbageCollectorIntegrationTest_DiskUsage_pRNQxi/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="posix"
--launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150"
--oversubscribed_resources_interval="15secs" --perf_duration="10secs"
--perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns"
--quiet="false" --recover="reconnect" --recovery_timeout="15mins"
--registration_backoff_factor="10ms"
--resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]"
--revocable_cpu_low_priority="true"
--runtime_dir="/tmp/GarbageCollectorIntegrationTest_DiskUsage_pRNQxi"
--sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true"
--systemd_enable_support="true"
--systemd_runtime_directory="/run/systemd/system" --version="false"
--work_dir="/tmp/GarbageCollectorIntegrationTest_DiskUsage_T1UK2h"
--zk_session_timeout="10secs"
3: I1116 21:16:59.619374 17371 credentials.hpp:86] Loading credential for
authentication from
'/tmp/GarbageCollectorIntegrationTest_DiskUsage_pRNQxi/credential'
3: I1116 21:16:59.619638 17371 slave.cpp:295] Agent using credential for:
test-principal
3: I1116 21:16:59.619680 17371 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/GarbageCollectorIntegrationTest_DiskUsage_pRNQxi/http_credentials'
3: I1116 21:16:59.620105 17371 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I1116 21:16:59.620340 17371 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
3: I1116 21:16:59.622659 17371 slave.cpp:593] Agent resources:
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1116 21:16:59.623005 17371 slave.cpp:601] Agent attributes: [ ]
3: I1116 21:16:59.623019 17371 slave.cpp:610] Agent hostname: da3e8d96ac06
3: I1116 21:16:59.623292 17365 status_update_manager.cpp:177] Pausing sending
status updates
3: I1116 21:16:59.625458 17361 state.cpp:64] Recovering state from
'/tmp/GarbageCollectorIntegrationTest_DiskUsage_T1UK2h/meta'
3: I1116 21:16:59.625948 17361 status_update_manager.cpp:203] Recovering status
update manager
3: I1116 21:16:59.626466 17370 slave.cpp:6441] Finished recovery
3: I1116 21:16:59.627553 17357 slave.cpp:1007] New master detected at
master@172.17.0.4:41888
3: I1116 21:16:59.627580 17356 status_update_manager.cpp:177] Pausing sending
status updates
3: I1116 21:16:59.627698 17357 slave.cpp:1042] Detecting new master
3: I1116 21:16:59.634260 17374 slave.cpp:1069] Authenticating with master
master@172.17.0.4:41888
3: I1116 21:16:59.634374 17374 slave.cpp:1078] Using default CRAM-MD5
authenticatee
3: I1116 21:16:59.634683 17362 authenticatee.cpp:121] Creating new client SASL
connection
3: I1116 21:16:59.635119 17368 master.cpp:8285] Authenticating
slave(64)@172.17.0.4:41888
3: I1116 21:16:59.635295 17364 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(146)@172.17.0.4:41888
3: I1116 21:16:59.635725 17373 authenticator.cpp:98] Creating new server SASL
connection
3: I1116 21:16:59.636106 17359 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1116 21:16:59.636150 17359 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1116 21:16:59.636310 17369 authenticator.cpp:204] Received SASL
authentication start
3: I1116 21:16:59.636391 17369 authenticator.cpp:326] Authentication requires
more steps
3: I1116 21:16:59.636533 17369 authenticatee.cpp:259] Received SASL
authentication step
3: I1116 21:16:59.636689 17369 authenticator.cpp:232] Received SASL
authentication step
3: I1116 21:16:59.636726 17369 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'da3e8d96ac06' server FQDN: 'da3e8d96ac06'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I1116 21:16:59.636744 17369 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I1116 21:16:59.636786 17369 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I1116 21:16:59.636813 17369 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'da3e8d96ac06' server FQDN: 'da3e8d96ac06'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I1116 21:16:59.636827 17369 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1116 21:16:59.636835 17369 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1116 21:16:59.636854 17369 authenticator.cpp:318] Authentication success
3: I1116 21:16:59.637001 17366 authenticatee.cpp:299] Authentication success
3: I1116 21:16:59.637074 17371 master.cpp:8315] Successfully authenticated
principal 'test-principal' at slave(64)@172.17.0.4:41888
3: I1116 21:16:59.637125 17360 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(146)@172.17.0.4:41888
3: I1116 21:16:59.637408 17369 slave.cpp:1161] Successfully authenticated with
master master@172.17.0.4:41888
3: I1116 21:16:59.637701 17369 slave.cpp:1682] Will retry registration in
17.131645ms if necessary
3: I1116 21:16:59.637959 17352 master.cpp:6032] Received register agent message
from slave(64)@172.17.0.4:41888 (da3e8d96ac06)
3: I1116 21:16:59.638113 17352 master.cpp:3870] Authorizing agent with
principal 'test-principal'
3: I1116 21:16:59.638716 17372 master.cpp:6092] Authorized registration of
agent at slave(64)@172.17.0.4:41888 (da3e8d96ac06)
3: I1116 21:16:59.638876 17372 master.cpp:6185] Registering agent at
slave(64)@172.17.0.4:41888 (da3e8d96ac06) with id
edecb9e1-882a-4825-abc1-5a36dbcbfd41-S0
3: I1116 21:16:59.639500 17353 registrar.cpp:495] Applied 1 operations in
80716ns; attempting to update the registry
3: I1116 21:16:59.640197 17357 registrar.cpp:552] Successfully updated the
registry in 612096ns
3: I1116 21:16:59.640512 17368 master.cpp:6232] Admitted agent
edecb9e1-882a-4825-abc1-5a36dbcbfd41-S0 at slave(64)@172.17.0.4:41888
(da3e8d96ac06)
3: I1116 21:16:59.641383 17368 master.cpp:6263] Registered agent
edecb9e1-882a-4825-abc1-5a36dbcbfd41-S0 at slave(64)@172.17.0.4:41888
(da3e8d96ac06) with
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1116 21:16:59.641690 17373 slave.cpp:1207] Registered with master
master@172.17.0.4:41888; given agent ID edecb9e1-882a-4825-abc1-5a36dbcbfd41-S0
3: I1116 21:16:59.641855 17371 status_update_manager.cpp:184] Resuming sending
status updates
3: I1116 21:16:59.641896 17359 hierarchical.cpp:593] Added agent
edecb9e1-882a-4825-abc1-5a36dbcbfd41-S0 (da3e8d96ac06) with cpus:2; mem:1024;
disk:1024; ports:[31000-32000] (allocated: {})
3: I1116 21:16:59.642124 17373 slave.cpp:1227] Checkpointing SlaveInfo to
'/tmp/GarbageCollectorIntegrationTest_DiskUsage_T1UK2h/meta/slaves/edecb9e1-882a-4825-abc1-5a36dbcbfd41-S0/slave.info'
3: I1116 21:16:59.642343 17359 hierarchical.cpp:1450] Performed allocation for
1 agents in 190339ns
3: W1116 21:16:59.642658 17351 process.cpp:3178] Attempted to spawn already
running process version@172.17.0.4:41888
3: I1116 21:16:59.642688 17373 slave.cpp:1295] Forwarding total oversubscribed
resources {}
3: I1116 21:16:59.642966 17361 master.cpp:7064] Received update of agent
edecb9e1-882a-4825-abc1-5a36dbcbfd41-S0 at slave(64)@172.17.0.4:41888
(da3e8d96ac06) with total oversubscribed resources {}
3: I1116 21:16:59.643208 17361 master.cpp:7082] Ignoring update on agent
edecb9e1-882a-4825-abc1-5a36dbcbfd41-S0 at slave(64)@172.17.0.4:41888
(da3e8d96ac06) as it reports no changes
3: I1116 21:16:59.644685 17351 sched.cpp:232] Version: 1.5.0
3: I1116 21:16:59.645480 17358 sched.cpp:336] New master detected at
master@172.17.0.4:41888
3: I1116 21:16:59.645612 17358 sched.cpp:396] Authenticating with master
master@172.17.0.4:41888
3: I1116 21:16:59.645638 17358 sched.cpp:403] Using default CRAM-MD5
authenticatee
3: I1116 21:16:59.645947 17353 authenticatee.cpp:121] Creating new client SASL
connection
3: I1116 21:16:59.646323 17374 master.cpp:8285] Authenticating
scheduler-ccb9bf6f-13b1-4e6a-9be6-9cfd45da96b9@172.17.0.4:41888
3: I1116 21:16:59.646446 17356 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(147)@172.17.0.4:41888
3: I1116 21:16:59.646771 17357 authenticator.cpp:98] Creating new server SASL
connection
3: I1116 21:16:59.647074 17364 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1116 21:16:59.647105 17364 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1116 21:16:59.647254 17365 authenticator.cpp:204] Received SASL
authentication start
write /dev/stdout: resource temporarily unavailable
Build step 'Execute shell' marked build as failure
