See <https://builds.apache.org/job/Mesos-Reviewbot/21522/display/redirect>

------------------------------------------
[...truncated 17.66 MB...]
I0204 21:07:35.085636  6607 authenticator.cpp:232] Received SASL authentication 
step
I0204 21:07:35.085667  6607 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: '2e50cf33c8bc' server FQDN: '2e50cf33c8bc' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: false 
I0204 21:07:35.085685  6607 auxprop.cpp:181] Looking up auxiliary property 
'*userPassword'
I0204 21:07:35.085721  6607 auxprop.cpp:181] Looking up auxiliary property 
'*cmusaslsecretCRAM-MD5'
I0204 21:07:35.085743  6607 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: '2e50cf33c8bc' server FQDN: '2e50cf33c8bc' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: true 
I0204 21:07:35.085759  6607 auxprop.cpp:131] Skipping auxiliary property 
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0204 21:07:35.085772  6607 auxprop.cpp:131] Skipping auxiliary property 
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0204 21:07:35.085793  6607 authenticator.cpp:318] Authentication success
I0204 21:07:35.085886  6594 authenticatee.cpp:299] Authentication success
I0204 21:07:35.085959  6605 master.cpp:9008] Successfully authenticated 
principal 'test-principal' at slave(397)@172.17.0.2:42561
I0204 21:07:35.086019  6607 authenticator.cpp:432] Authentication session 
cleanup for crammd5-authenticatee(828)@172.17.0.2:42561
I0204 21:07:35.086205  6594 slave.cpp:1320] Successfully authenticated with 
master master@172.17.0.2:42561
I0204 21:07:35.086576  6594 slave.cpp:1766] Will retry registration in 
17.832597ms if necessary
I0204 21:07:35.086740  6610 master.cpp:6013] Received register agent message 
from slave(397)@172.17.0.2:42561 (2e50cf33c8bc)
I0204 21:07:35.087061  6610 master.cpp:3793] Authorizing agent providing 
resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 
'test-principal'
I0204 21:07:35.087630  6611 master.cpp:6084] Authorized registration of agent 
at slave(397)@172.17.0.2:42561 (2e50cf33c8bc)
I0204 21:07:35.087731  6611 master.cpp:6195] Registering agent at 
slave(397)@172.17.0.2:42561 (2e50cf33c8bc) with id 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0
I0204 21:07:35.088281  6596 registrar.cpp:495] Applied 1 operations in 
151698ns; attempting to update the registry
I0204 21:07:35.088984  6596 registrar.cpp:552] Successfully updated the 
registry in 0ns
I0204 21:07:35.089196  6597 master.cpp:6243] Admitted agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc)
I0204 21:07:35.089928  6595 slave.cpp:1367] Registered with master 
master@172.17.0.2:42561; given agent ID 3d1962e4-db12-47b9-9254-dcc55c23e392-S0
I0204 21:07:35.089964  6597 master.cpp:6292] Registered agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0204 21:07:35.090042  6592 task_status_update_manager.cpp:188] Resuming 
sending task status updates
I0204 21:07:35.090294  6595 slave.cpp:1387] Checkpointing SlaveInfo to 
'/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_483rrf/meta/slaves/3d1962e4-db12-47b9-9254-dcc55c23e392-S0/slave.info'
I0204 21:07:35.090294  6609 hierarchical.cpp:574] Added agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 (2e50cf33c8bc) with cpus:2; mem:1024; 
disk:1024; ports:[31000-32000] (allocated: {})
I0204 21:07:35.090826  6595 slave.cpp:1434] Forwarding agent update 
{"operations":{},"resource_version_uuid":{"value":"1Zh17XSQRkicdvPgMWpFqg=="},"slave_id":{"value":"3d1962e4-db12-47b9-9254-dcc55c23e392-S0"},"update_oversubscribed_resources":true}
I0204 21:07:35.091364  6598 master.cpp:7235] Received update of agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc) with total oversubscribed resources {}
I0204 21:07:35.091647  6598 master.cpp:7329] Ignoring update on agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc) as it reports no changes
I0204 21:07:35.091995  6609 hierarchical.cpp:1517] Performed allocation for 1 
agents in 1.530165ms
I0204 21:07:35.092552  6606 master.cpp:8808] Sending 1 offers to framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 (default) at 
scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561
I0204 21:07:35.094022  6608 sched.cpp:921] Scheduler::resourceOffers took 
989894ns
I0204 21:07:35.095422  6606 master.cpp:10716] Removing offer 
3d1962e4-db12-47b9-9254-dcc55c23e392-O0
I0204 21:07:35.095868  6606 master.cpp:4220] Processing ACCEPT call for offers: 
[ 3d1962e4-db12-47b9-9254-dcc55c23e392-O0 ] on agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc) for framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 
(default) at scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561
I0204 21:07:35.095980  6606 master.cpp:3505] Authorizing framework principal 
'test-principal' to launch task 0
W0204 21:07:35.098048  6607 validation.cpp:1386] 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.
W0204 21:07:35.098085  6607 validation.cpp:1398] 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.
I0204 21:07:35.098511  6607 master.cpp:11518] Adding task 0 with resources 
cpus(allocated: *):2; mem(allocated: *):1024 on agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc)
I0204 21:07:35.098783  6607 master.cpp:4964] Launching task 0 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 (default) at 
scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561 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 3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at 
slave(397)@172.17.0.2:42561 (2e50cf33c8bc)
I0204 21:07:35.099591  6603 slave.cpp:1879] Got assigned task '0' for framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.099951  6610 hierarchical.cpp:1192] 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 3d1962e4-db12-47b9-9254-dcc55c23e392-S0 from framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.100028  6610 hierarchical.cpp:1238] Framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 filtered agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 for 5secs
I0204 21:07:35.100337  6603 slave.cpp:2149] Authorizing task '0' for framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.100400  6603 slave.cpp:7955] Authorizing framework principal 
'test-principal' to launch task 0
I0204 21:07:35.101253  6590 slave.cpp:2542] Launching task '0' for framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.101332  6590 paths.cpp:727] Creating sandbox 
'/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_483rrf/slaves/3d1962e4-db12-47b9-9254-dcc55c23e392-S0/frameworks/3d1962e4-db12-47b9-9254-dcc55c23e392-0000/executors/default/runs/f935a391-cb5c-40c5-9819-b5c80d9238bc'
 for user 'mesos'
I0204 21:07:35.101976  6590 slave.cpp:8429] Launching executor 'default' of 
framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 with resources [] in work 
directory 
'/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_483rrf/slaves/3d1962e4-db12-47b9-9254-dcc55c23e392-S0/frameworks/3d1962e4-db12-47b9-9254-dcc55c23e392-0000/executors/default/runs/f935a391-cb5c-40c5-9819-b5c80d9238bc'
I0204 21:07:35.102545  6590 slave.cpp:3102] Launching container 
f935a391-cb5c-40c5-9819-b5c80d9238bc for executor 'default' of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.103103  6590 slave.cpp:2628] Queued task '0' for executor 
'default' of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.103206  6590 slave.cpp:1006] Successfully attached 
'/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_483rrf/slaves/3d1962e4-db12-47b9-9254-dcc55c23e392-S0/frameworks/3d1962e4-db12-47b9-9254-dcc55c23e392-0000/executors/default/runs/f935a391-cb5c-40c5-9819-b5c80d9238bc'
 to virtual path 
'/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_483rrf/slaves/3d1962e4-db12-47b9-9254-dcc55c23e392-S0/frameworks/3d1962e4-db12-47b9-9254-dcc55c23e392-0000/executors/default/runs/latest'
I0204 21:07:35.103255  6590 slave.cpp:1006] Successfully attached 
'/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_483rrf/slaves/3d1962e4-db12-47b9-9254-dcc55c23e392-S0/frameworks/3d1962e4-db12-47b9-9254-dcc55c23e392-0000/executors/default/runs/f935a391-cb5c-40c5-9819-b5c80d9238bc'
 to virtual path 
'/frameworks/3d1962e4-db12-47b9-9254-dcc55c23e392-0000/executors/default/runs/latest'
I0204 21:07:35.103312  6590 slave.cpp:1006] Successfully attached 
'/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_483rrf/slaves/3d1962e4-db12-47b9-9254-dcc55c23e392-S0/frameworks/3d1962e4-db12-47b9-9254-dcc55c23e392-0000/executors/default/runs/f935a391-cb5c-40c5-9819-b5c80d9238bc'
 to virtual path 
'/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_483rrf/slaves/3d1962e4-db12-47b9-9254-dcc55c23e392-S0/frameworks/3d1962e4-db12-47b9-9254-dcc55c23e392-0000/executors/default/runs/f935a391-cb5c-40c5-9819-b5c80d9238bc'
W0204 21:07:35.105600  6596 process.cpp:2795] Attempted to spawn already 
running process version@172.17.0.2:42561
I0204 21:07:35.105814  6596 exec.cpp:162] Version: 1.6.0
I0204 21:07:35.106097  6602 exec.cpp:212] Executor started at: 
executor(118)@172.17.0.2:42561 with pid 6588
I0204 21:07:35.106407  6602 slave.cpp:4352] Got registration for executor 
'default' of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 from 
executor(118)@172.17.0.2:42561
I0204 21:07:35.106825  6592 exec.cpp:236] Executor registered on agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0
I0204 21:07:35.106956  6592 exec.cpp:248] Executor::registered took 30854ns
I0204 21:07:35.107820  6608 slave.cpp:2833] Sending queued task '0' to executor 
'default' of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 at 
executor(118)@172.17.0.2:42561
I0204 21:07:35.108217  6608 exec.cpp:330] Executor asked to run task '0'
I0204 21:07:35.108314  6608 exec.cpp:339] Executor::launchTask took 71712ns
I0204 21:07:35.108422  6608 exec.cpp:581] Executor sending status update 
TASK_RUNNING (Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) for task 0 of 
framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.108727  6608 slave.cpp:4809] Handling status update TASK_RUNNING 
(Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) for task 0 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 from executor(118)@172.17.0.2:42561
I0204 21:07:35.109323  6607 task_status_update_manager.cpp:328] Received task 
status update TASK_RUNNING (Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) 
for task 0 of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.109375  6607 task_status_update_manager.cpp:507] Creating 
StatusUpdate stream for task 0 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.109903  6607 task_status_update_manager.cpp:383] Forwarding task 
status update TASK_RUNNING (Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) 
for task 0 of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 to the agent
I0204 21:07:35.110093  6610 slave.cpp:5291] Forwarding the update TASK_RUNNING 
(Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) for task 0 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 to master@172.17.0.2:42561
I0204 21:07:35.110302  6610 slave.cpp:5184] Task status update manager 
successfully handled status update TASK_RUNNING (Status UUID: 
f01a3d08-4f48-4603-8772-4d3648ead670) for task 0 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.110384  6610 slave.cpp:5200] Sending acknowledgement for status 
update TASK_RUNNING (Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) for 
task 0 of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 to 
executor(118)@172.17.0.2:42561
I0204 21:07:35.110656  6610 exec.cpp:398] Executor received status update 
acknowledgement f01a3d08-4f48-4603-8772-4d3648ead670 for task 0 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.110986  6604 exec.cpp:581] Executor sending status update 
TASK_FINISHED (Status UUID: f9ae7bf9-f7e2-4bb6-b41a-1f46df68b7d0) for task 0 of 
framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.111325  6593 slave.cpp:4809] Handling status update 
TASK_FINISHED (Status UUID: f9ae7bf9-f7e2-4bb6-b41a-1f46df68b7d0) for task 0 of 
framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 from 
executor(118)@172.17.0.2:42561
I0204 21:07:35.112139  6591 task_status_update_manager.cpp:328] Received task 
status update TASK_FINISHED (Status UUID: f9ae7bf9-f7e2-4bb6-b41a-1f46df68b7d0) 
for task 0 of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.112383  6596 slave.cpp:5184] Task status update manager 
successfully handled status update TASK_FINISHED (Status UUID: 
f9ae7bf9-f7e2-4bb6-b41a-1f46df68b7d0) for task 0 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.112435  6596 slave.cpp:5200] Sending acknowledgement for status 
update TASK_FINISHED (Status UUID: f9ae7bf9-f7e2-4bb6-b41a-1f46df68b7d0) for 
task 0 of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 to 
executor(118)@172.17.0.2:42561
I0204 21:07:35.112643  6592 exec.cpp:398] Executor received status update 
acknowledgement f9ae7bf9-f7e2-4bb6-b41a-1f46df68b7d0 for task 0 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.112948  6602 master.cpp:1149] Master terminating
W0204 21:07:35.113111  6602 master.cpp:10289] Removing task 0 with resources 
cpus(allocated: *):2; mem(allocated: *):1024 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 on agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc) in non-terminal state TASK_STAGING
I0204 21:07:35.113617  6602 master.cpp:10332] Removing executor 'default' with 
resources [] of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 on agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc)
I0204 21:07:35.113770  6598 hierarchical.cpp:609] Removed agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0
I0204 21:07:35.114670  6610 slave.cpp:5423] Got exited event for 
master@172.17.0.2:42561
W0204 21:07:35.114697  6610 slave.cpp:5428] Master disconnected! Waiting for a 
new master to be elected
I0204 21:07:35.115712  6598 hierarchical.cpp:344] Removed framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.120733  6588 cluster.cpp:172] Creating default 'local' authorizer
I0204 21:07:35.124601  6598 master.cpp:458] Master 
a05e67da-13f5-46d0-9738-dee10381c5fa (2e50cf33c8bc) started on 172.17.0.2:42561
I0204 21:07:35.124627  6598 master.cpp:460] 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/p7WLTD/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" 
--require_agent_domain="false" --root_submissions="true" --user_sorter="drf" 
--version="false" --webui_dir="/mesos/mesos-1.6.0/_inst/share/mesos/webui" 
--work_dir="/tmp/p7WLTD/master" --zk_session_timeout="10secs"
I0204 21:07:35.124989  6598 master.cpp:509] Master only allowing authenticated 
frameworks to register
I0204 21:07:35.125010  6598 master.cpp:515] Master only allowing authenticated 
agents to register
I0204 21:07:35.125020  6598 master.cpp:521] Master only allowing authenticated 
HTTP frameworks to register
I0204 21:07:35.125030  6598 credentials.hpp:37] Loading credentials for 
authentication from '/tmp/p7WLTD/credentials'
I0204 21:07:35.125320  6598 master.cpp:565] Using default 'crammd5' 
authenticator
I0204 21:07:35.125514  6598 http.cpp:1045] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-readonly'
I0204 21:07:35.125836  6598 http.cpp:1045] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-readwrite'
I0204 21:07:35.126003  6598 http.cpp:1045] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-scheduler'
I0204 21:07:35.126160  6598 master.cpp:644] Authorization enabled
I0204 21:07:35.126313  6595 hierarchical.cpp:175] Initialized hierarchical 
allocator process
I0204 21:07:35.126456  6610 whitelist_watcher.cpp:77] No whitelist given
I0204 21:07:35.130048  6598 master.cpp:2133] Elected as the leading master!
I0204 21:07:35.130156  6598 master.cpp:1692] Recovering from registrar
I0204 21:07:35.130479  6606 registrar.cpp:347] Recovering registrar
I0204 21:07:35.131335  6606 registrar.cpp:391] Successfully fetched the 
registry (0B) in 0ns
I0204 21:07:35.131577  6606 registrar.cpp:495] Applied 1 operations in 41720ns; 
attempting to update the registry
I0204 21:07:35.132522  6606 registrar.cpp:552] Successfully updated the 
registry in 0ns
I0204 21:07:35.132771  6606 registrar.cpp:424] Successfully recovered registrar
I0204 21:07:35.133323  6589 hierarchical.cpp:213] Skipping recovery of 
hierarchical allocator: nothing to recover
I0204 21:07:35.133404  6612 master.cpp:1806] Recovered 0 agents from the 
registry (135B); allowing 10mins for agents to re-register
I0204 21:07:35.134275  6608 sched.cpp:330] Scheduler::disconnected took 22843ns
I0204 21:07:35.134302  6608 sched.cpp:336] New master detected at 
master@172.17.0.2:42561
I0204 21:07:35.134425  6608 sched.cpp:396] Authenticating with master 
master@172.17.0.2:42561
I0204 21:07:35.134449  6608 sched.cpp:403] Using default CRAM-MD5 authenticatee
I0204 21:07:35.134770  6610 authenticatee.cpp:121] Creating new client SASL 
connection
I0204 21:07:35.135269  6609 master.cpp:8978] Authenticating 
scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561
I0204 21:07:35.135411  6591 authenticator.cpp:414] Starting authentication 
session for crammd5-authenticatee(829)@172.17.0.2:42561
I0204 21:07:35.135671  6601 authenticator.cpp:98] Creating new server SASL 
connection
I0204 21:07:35.135896  6599 authenticatee.cpp:213] Received SASL authentication 
mechanisms: CRAM-MD5
I0204 21:07:35.135927  6599 authenticatee.cpp:239] Attempting to authenticate 
with mechanism 'CRAM-MD5'
I0204 21:07:35.136054  6597 authenticator.cpp:204] Received SASL authentication 
start
I0204 21:07:35.136111  6597 authenticator.cpp:326] Authentication requires more 
steps
I0204 21:07:35.136221  6594 authenticatee.cpp:259] Received SASL authentication 
step
I0204 21:07:35.136339  6594 authenticator.cpp:232] Received SASL authentication 
step
I0204 21:07:35.136374  6594 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: '2e50cf33c8bc' server FQDN: '2e50cf33c8bc' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: false 
I0204 21:07:35.136394  6594 auxprop.cpp:181] Looking up auxiliary property 
'*userPassword'
I0204 21:07:35.136438  6594 auxprop.cpp:181] Looking up auxiliary property 
'*cmusaslsecretCRAM-MD5'
I0204 21:07:35.136464  6594 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: '2e50cf33c8bc' server FQDN: '2e50cf33c8bc' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: true 
I0204 21:07:35.136508  6594 auxprop.cpp:131] Skipping auxiliary property 
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0204 21:07:35.136523  6594 auxprop.cpp:131] Skipping auxiliary property 
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0204 21:07:35.136545  6594 authenticator.cpp:318] Authentication success
I0204 21:07:35.136706  6600 authenticatee.cpp:299] Authentication success
I0204 21:07:35.136775  6594 authenticator.cpp:432] Authentication session 
cleanup for crammd5-authenticatee(829)@172.17.0.2:42561
I0204 21:07:35.136771  6603 master.cpp:9008] Successfully authenticated 
principal 'test-principal' at 
scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561
I0204 21:07:35.137019  6600 sched.cpp:502] Successfully authenticated with 
master master@172.17.0.2:42561
I0204 21:07:35.137045  6600 sched.cpp:824] Sending SUBSCRIBE call to 
master@172.17.0.2:42561
I0204 21:07:35.137184  6600 sched.cpp:857] Will retry registration in 
725.839229ms if necessary
I0204 21:07:35.137394  6589 master.cpp:2869] Received SUBSCRIBE call for 
framework 'default' at 
scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561
I0204 21:07:35.137481  6589 master.cpp:2198] Authorizing framework principal 
'test-principal' to receive offers for roles '{ * }'
I0204 21:07:35.137979  6612 master.cpp:2949] Subscribing framework default with 
checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0204 21:07:35.138160  6612 master.cpp:9199] Adding framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 (default) with roles {  } suppressed
I0204 21:07:35.138365  6612 master.cpp:7165] Updating framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 (default) with roles {  } suppressed
I0204 21:07:35.138720  6595 hierarchical.cpp:297] Added framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.138766  6595 hierarchical.cpp:405] Deactivated framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.138778  6612 sched.cpp:751] Framework registered with 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.138878  6612 sched.cpp:765] Scheduler::registered took 63809ns
I0204 21:07:35.138933  6595 hierarchical.cpp:371] Activated framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.139168  6595 hierarchical.cpp:1517] Performed allocation for 0 
agents in 80821ns
I0204 21:07:35.139655  6599 task_status_update_manager.cpp:181] Pausing sending 
task status updates
I0204 21:07:35.139668  6597 slave.cpp:1146] New master detected at 
master@172.17.0.2:42561
I0204 21:07:35.139873  6597 slave.cpp:1201] Detecting new master
I0204 21:07:35.145205  6611 slave.cpp:1228] Authenticating with master 
master@172.17.0.2:42561
I0204 21:07:35.145284  6611 slave.cpp:1237] Using default CRAM-MD5 authenticatee
I0204 21:07:35.145550  6598 authenticatee.cpp:121] Creating new client SASL 
connection
I0204 21:07:35.145875  6598 master.cpp:8978] Authenticating 
slave(397)@172.17.0.2:42561
I0204 21:07:35.146020  6590 authenticator.cpp:414] Starting authentication 
session for crammd5-authenticatee(830)@172.17.0.2:42561
I0204 21:07:35.146280  6593 authenticator.cpp:98] Creating new server SASL 
connection
I0204 21:07:35.146492  6606 authenticatee.cpp:213] Received SASL authentication 
mechanisms: CRAM-MD5
I0204 21:07:35.146525  6606 authenticatee.cpp:239] Attempting to authenticate 
with mechanism 'CRAM-MD5'
I0204 21:07:35.146653  6594 authenticator.cpp:204] Received SASL authentication 
start
I0204 21:07:35.146713  6594 authenticator.cpp:326] Authentication requires more 
steps
I0204 21:07:35.146821  6600 authenticatee.cpp:259] Received SASL authentication 
step
I0204 21:07:35.146950  6589 authenticator.cpp:232] Received SASL authentication 
step
I0204 21:07:35.146989  6589 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: '2e50cf33c8bc' server FQDN: '2e50cf33c8bc' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: false 
I0204 21:07:35.147009  6589 auxprop.cpp:181] Looking up auxiliary property 
'*userPassword'
I0204 21:07:35.147047  6589 auxprop.cpp:181] Looking up auxiliary property 
'*cmusaslsecretCRAM-MD5'
I0204 21:07:35.147073  6589 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: '2e50cf33c8bc' server FQDN: '2e50cf33c8bc' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: true 
I0204 21:07:35.147090  6589 auxprop.cpp:131] Skipping auxiliary property 
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0204 21:07:35.147102  6589 auxprop.cpp:131] Skipping auxiliary property 
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0204 21:07:35.147120  6589 authenticator.cpp:318] Authentication success
I0204 21:07:35.147208  6592 authenticatee.cpp:299] Authentication success
I0204 21:07:35.147339  6592 authenticator.cpp:432] Authentication session 
cleanup for crammd5-authenticatee(830)@172.17.0.2:42561
I0204 21:07:35.147502  6604 master.cpp:9008] Successfully authenticated 
principal 'test-principal' at slave(397)@172.17.0.2:42561
I0204 21:07:35.147676  6589 slave.cpp:1320] Successfully authenticated with 
master master@172.17.0.2:42561
I0204 21:07:35.148530  6589 slave.cpp:1766] Will retry registration in 
8.29998ms if necessary
I0204 21:07:35.148934  6609 master.cpp:6371] Received re-register agent message 
from agent 3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at 
slave(397)@172.17.0.2:42561 (2e50cf33c8bc)
I0204 21:07:35.149340  6609 master.cpp:3793] Authorizing agent providing 
resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 
'test-principal'
I0204 21:07:35.149950  6607 master.cpp:6467] Authorized re-registration of 
agent 3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc)
I0204 21:07:35.150053  6607 master.cpp:6620] Consulting registry about agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at 
slave(397)@172.17.0.2:42561(2e50cf33c8bc)
W0204 21:07:35.150512  6607 registry_operations.cpp:182] Allowing UNKNOWN agent 
to reregister: hostname: "2e50cf33c8bc"
resources {
  name: "cpus"
  type: SCALAR
  scalar {
    value: 2
  }
}
resources {
  name: "mem"
  type: SCALAR
  scalar {
    value: 1024
  }
}
resources {
  name: "disk"
  type: SCALAR
  scalar {
    value: 1024
  }
}
resources {
  name: "ports"
  type: RANGES
  ranges {
    range {
      begin: 31000
      end: 32000
    }
  }
}
id {
  value: "3d1962e4-db12-47b9-9254-dcc55c23e392-S0"
}
checkpoint: true
port: 42561
I0204 21:07:35.150918  6607 registrar.cpp:495] Applied 1 operations in 
439638ns; attempting to update the registry
I0204 21:07:35.151602  6607 registrar.cpp:552] Successfully updated the 
registry in 615168ns
I0204 21:07:35.151773  6590 master.cpp:6676] Re-admitted agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc)
I0204 21:07:35.151968  6590 master.cpp:7901] Sending status update 
TASK_FINISHED for task 0 of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 
'Unknown agent re-registered'

GMOCK WARNING:
Uninteresting mock function call - returning directly.
    Function call: statusUpdate(0x7fff8db64210, @0x2b69864ab350 136-byte object 
<D0-31 68-7C 69-2B 00-00 00-00 00-00 00-00 00-00 9A-E8 00-00 00-00 00-00 58-A0 
9C-7C 69-2B 00-00 B0-78 00-9C 69-2B 00-00 58-A0 9C-7C 69-2B 00-00 D0-AD 00-9C 
69-2B 00-00 D0-56 02-9C 69-2B 00-00 ... 00-00 00-00 00-00 00-00 70-57 02-9C 
69-2B 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 
00-00 C4-5A D7-F7 73-A9 D6-41 00-00 00-00 00-00 00-00 20-00 00-00 02-00 00-00>)
NOTE: You can safely ignore the above warning unless this call should not 
happen.  Do not suppress it by blindly adding an EXPECT_CALL() if you don't 
mean to enforce the call.  See 
https://github.com/google/googletest/blob/master/googlemock/docs/CookBook.md#knowing-when-to-expect
 for details.
I0204 21:07:35.152364  6593 sched.cpp:1029] Scheduler::statusUpdate took 70504ns
I0204 21:07:35.152529  6590 master.cpp:11518] Adding task 0 with resources 
cpus(allocated: *):2; mem(allocated: *):1024 on agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc)
I0204 21:07:35.153167  6590 master.cpp:6860] Re-registered agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0204 21:07:35.153365  6596 slave.cpp:1471] Re-registered with master 
master@172.17.0.2:42561
I0204 21:07:35.153560  6592 task_status_update_manager.cpp:188] Resuming 
sending task status updates
I0204 21:07:35.153574  6596 slave.cpp:1516] Forwarding agent update 
{"operations":{},"resource_version_uuid":{"value":"1Zh17XSQRkicdvPgMWpFqg=="},"slave_id":{"value":"3d1962e4-db12-47b9-9254-dcc55c23e392-S0"},"update_oversubscribed_resources":true}
I0204 21:07:35.153703  6600 hierarchical.cpp:574] Added agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 (2e50cf33c8bc) with cpus:2; mem:1024; 
disk:1024; ports:[31000-32000] (allocated: {})
W0204 21:07:35.153759  6592 task_status_update_manager.cpp:195] Resending task 
status update TASK_RUNNING (Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) 
for task 0 of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.153842  6592 task_status_update_manager.cpp:383] Forwarding task 
status update TASK_RUNNING (Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) 
for task 0 of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 to the agent
I0204 21:07:35.153985  6589 master.cpp:8367] Performing implicit task state 
reconciliation for framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 
(default) at scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561
I0204 21:07:35.154079  6589 master.cpp:8417] Sending implicit reconciliation 
state TASK_RUNNING for task 0 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 (default) at 
scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561
I0204 21:07:35.154440  6599 sched.cpp:1029] Scheduler::statusUpdate took 81833ns
I0204 21:07:35.154706  6611 master.cpp:7235] Received update of agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc) with total oversubscribed resources {}
I0204 21:07:35.154799  6588 sched.cpp:2009] Asked to stop the driver
I0204 21:07:35.154892  6596 slave.cpp:3625] Updating info for framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 with pid updated to 
scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561
I0204 21:07:35.155040  6611 master.cpp:7329] Ignoring update on agent 
3d1962e4-db12-47b9-9254-dcc55c23e392-S0 at slave(397)@172.17.0.2:42561 
(2e50cf33c8bc) as it reports no changes
I0204 21:07:35.155042  6596 slave.cpp:5291] Forwarding the update TASK_RUNNING 
(Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) for task 0 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 to master@172.17.0.2:42561
I0204 21:07:35.155133  6611 sched.cpp:1191] Stopping framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.155268  6596 task_status_update_manager.cpp:188] Resuming 
sending task status updates
W0204 21:07:35.155360  6596 task_status_update_manager.cpp:195] Resending task 
status update TASK_RUNNING (Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) 
for task 0 of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000
I0204 21:07:35.155447  6596 task_status_update_manager.cpp:383] Forwarding task 
status update TASK_RUNNING (Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) 
for task 0 of framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 to the agent
I0204 21:07:35.155489  6605 master.cpp:9488] Processing TEARDOWN call for 
framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 (default) at 
scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561
I0204 21:07:35.155539  6605 master.cpp:9500] Removing framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 (default) at 
scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561
I0204 21:07:35.155560  6605 master.cpp:3239] Deactivating framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 (default) at 
scheduler-2d3c3375-6768-4f96-9879-fe7e70132dbd@172.17.0.2:42561
I0204 21:07:35.155649  6600 hierarchical.cpp:1517] Performed allocation for 1 
agents in 1.754144ms
I0204 21:07:35.155709  6605 master.cpp:10204] Updating the state of task 0 of 
framework 3d1962e4-db12-47b9-9254-dcc55c23e392-0000 (latest state: 
TASK_FINISHED, status update state: TASK_KILLED)
I0204 21:07:35.155731  6590 slave.cpp:5291] Forwarding the update TASK_RUNNING 
(Status UUID: f01a3d08-4f48-4603-8772-4d3648ead670) for task 0 of framework 
3d1962e4-db12-47b9-9254-dcc55c23e392-0000 to master@172.17.0.2:42561
Process leaked file descriptors. See 
https://jenkins.io/redirect/troubleshooting/process-leaked-file-descriptors for 
more information
Build step 'Execute shell' marked build as failure

Reply via email to