You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2017/08/17 01:00:18 UTC

Build failed in Jenkins: Mesos-Buildbot » autotools,clang,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #4118

See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=autotools,COMPILER=clang,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)/4118/display/redirect?page=changes>

Changes:

[anand] Fixed a bug around `kill()` not removing active containers.

------------------------------------------
[...truncated 21.31 MB...]
I0817 01:00:05.801321  6737 hierarchical.cpp:1943] No allocations performed
I0817 01:00:05.801424  6737 hierarchical.cpp:2033] No inverse offers to send out!
I0817 01:00:05.801476  6737 hierarchical.cpp:1486] Performed allocation for 1 agents in 303266ns
I0817 01:00:06.316730  6724 slave.cpp:4273] Cleaning up un-reregistered executors
I0817 01:00:06.316900  6724 slave.cpp:6210] Finished recovery
I0817 01:00:06.317662  6724 slave.cpp:6392] Querying resource estimator for oversubscribable resources
I0817 01:00:06.317929  6745 status_update_manager.cpp:177] Pausing sending status updates
I0817 01:00:06.317962  6725 slave.cpp:971] New master detected at master@172.17.0.8:40444
I0817 01:00:06.318066  6725 slave.cpp:1006] Detecting new master
I0817 01:00:06.318202  6725 slave.cpp:6406] Received oversubscribable resources {} from the resource estimator
I0817 01:00:06.324371  6723 slave.cpp:1033] Authenticating with master master@172.17.0.8:40444
I0817 01:00:06.324511  6723 slave.cpp:1044] Using default CRAM-MD5 authenticatee
I0817 01:00:06.324862  6740 authenticatee.cpp:121] Creating new client SASL connection
I0817 01:00:06.325322  6729 master.cpp:7837] Authenticating slave(478)@172.17.0.8:40444
I0817 01:00:06.325479  6730 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(993)@172.17.0.8:40444
I0817 01:00:06.325743  6722 authenticator.cpp:98] Creating new server SASL connection
I0817 01:00:06.326010  6739 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0817 01:00:06.326045  6739 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0817 01:00:06.326155  6739 authenticator.cpp:204] Received SASL authentication start
I0817 01:00:06.326222  6739 authenticator.cpp:326] Authentication requires more steps
I0817 01:00:06.326323  6728 authenticatee.cpp:259] Received SASL authentication step
I0817 01:00:06.326432  6727 authenticator.cpp:232] Received SASL authentication step
I0817 01:00:06.326464  6727 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '45197c1facb6' server FQDN: '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0817 01:00:06.326478  6727 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0817 01:00:06.326519  6727 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0817 01:00:06.326539  6727 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '45197c1facb6' server FQDN: '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0817 01:00:06.326550  6727 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0817 01:00:06.326558  6727 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0817 01:00:06.326575  6727 authenticator.cpp:318] Authentication success
I0817 01:00:06.326709  6726 authenticatee.cpp:299] Authentication success
I0817 01:00:06.326738  6742 master.cpp:7867] Successfully authenticated principal 'test-principal' at slave(478)@172.17.0.8:40444
I0817 01:00:06.326762  6734 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(993)@172.17.0.8:40444
I0817 01:00:06.326993  6737 slave.cpp:1128] Successfully authenticated with master master@172.17.0.8:40444
I0817 01:00:06.327518  6737 slave.cpp:1572] Will retry registration in 14.251184ms if necessary
I0817 01:00:06.328802  6736 master.cpp:6012] Received re-register agent message from agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444 (45197c1facb6)
I0817 01:00:06.328842  6736 master.cpp:3803] Authorizing agent with principal 'test-principal'
I0817 01:00:06.329376  6736 master.cpp:6081] Authorized re-registration of agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444 (45197c1facb6)
I0817 01:00:06.329483  6736 master.cpp:6146] Re-registering agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(477)@172.17.0.8:40444 (45197c1facb6)
I0817 01:00:06.329792  6730 slave.cpp:1275] Re-registered with master master@172.17.0.8:40444
I0817 01:00:06.329824  6722 hierarchical.cpp:678] Agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 reactivated
I0817 01:00:06.329856  6736 master.cpp:6586] Sending updated checkpointed resources {} to agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444 (45197c1facb6)
I0817 01:00:06.329866  6722 status_update_manager.cpp:184] Resuming sending status updates
I0817 01:00:06.329885  6730 slave.cpp:1312] Forwarding total oversubscribed resources {}
W0817 01:00:06.329907  6722 status_update_manager.cpp:191] Resending status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.329957  6722 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 to the agent
I0817 01:00:06.330029  6736 master.cpp:6688] Received update of agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444 (45197c1facb6) with total oversubscribed resources {}
I0817 01:00:06.330075  6730 slave.cpp:3330] Updating info for framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 with pid updated to scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
I0817 01:00:06.330152  6730 slave.cpp:7084] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556-5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000/framework.info'
I0817 01:00:06.330344  6728 hierarchical.cpp:660] Agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 (45197c1facb6) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0817 01:00:06.330607  6730 slave.cpp:7095] Checkpointing framework pid 'scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444' to '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556-5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000/framework.pid'
I0817 01:00:06.330912  6727 status_update_manager.cpp:184] Resuming sending status updates
W0817 01:00:06.330937  6727 status_update_manager.cpp:191] Resending status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.330953  6730 slave.cpp:3394] Ignoring new checkpointed resources identical to the current version: {}
I0817 01:00:06.330968  6727 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 to the agent
I0817 01:00:06.331070  6730 slave.cpp:4797] Forwarding the update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 to master@172.17.0.8:40444
I0817 01:00:06.331285  6730 slave.cpp:4797] Forwarding the update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 to master@172.17.0.8:40444
I0817 01:00:06.331362  6726 master.cpp:6846] Status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 from agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444 (45197c1facb6)
I0817 01:00:06.331408  6726 master.cpp:6908] Forwarding status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.331564  6726 master.cpp:8933] Updating the state of task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (latest state: TASK_FAILED, status update state: TASK_RUNNING)
I0817 01:00:06.331709  6744 sched.cpp:1041] Scheduler::statusUpdate took 41560ns
I0817 01:00:06.332159  6726 master.cpp:6846] Status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 from agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444 (45197c1facb6)
I0817 01:00:06.332201  6726 master.cpp:6908] Forwarding status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.332340  6726 master.cpp:8933] Updating the state of task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (latest state: TASK_FAILED, status update state: TASK_RUNNING)
I0817 01:00:06.332479  6733 sched.cpp:1041] Scheduler::statusUpdate took 23192ns
I0817 01:00:06.332495  6726 master.cpp:5477] Processing ACKNOWLEDGE call 6298f06a-4d56-49b0-ae14-12a4fd774566 for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444 on agent 56b17556-5965-44ca-be07-44edbcb8751c-S0
I0817 01:00:06.332500  6742 hierarchical.cpp:1161] 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 56b17556-5965-44ca-be07-44edbcb8751c-S0 from framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.332691  6726 master.cpp:5477] Processing ACKNOWLEDGE call 6298f06a-4d56-49b0-ae14-12a4fd774566 for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444 on agent 56b17556-5965-44ca-be07-44edbcb8751c-S0
I0817 01:00:06.332728  6734 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.332854  6734 status_update_manager.cpp:834] Checkpointing ACK for status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.332988  6734 status_update_manager.cpp:377] Forwarding update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 to the agent
I0817 01:00:06.333187  6724 slave.cpp:4797] Forwarding the update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 to master@172.17.0.8:40444
I0817 01:00:06.333245  6734 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
W0817 01:00:06.333329  6734 status_update_manager.cpp:763] Duplicate status update acknowledgment (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.333354  6724 slave.cpp:3609] Status update manager successfully handled status update acknowledgement (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
E0817 01:00:06.333447  6724 slave.cpp:3602] Failed to handle status update acknowledgement (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000: Duplicate acknowledgement
I0817 01:00:06.333453  6738 master.cpp:6846] Status update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 from agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444 (45197c1facb6)
I0817 01:00:06.333504  6738 master.cpp:6908] Forwarding status update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.333643  6738 master.cpp:8933] Updating the state of task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
I0817 01:00:06.333762  6732 sched.cpp:1041] Scheduler::statusUpdate took 39113ns
I0817 01:00:06.333951  6745 master.cpp:5477] Processing ACKNOWLEDGE call b29e6cb2-8461-43c6-b252-a7b4619bd9d4 for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444 on agent 56b17556-5965-44ca-be07-44edbcb8751c-S0
I0817 01:00:06.334004  6745 master.cpp:9027] Removing task 334ab1cb-44b2-4676-b2b5-0329c383ac33 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 on agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444 (45197c1facb6)
I0817 01:00:06.334609  6735 status_update_manager.cpp:395] Received status update acknowledgement (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.334683  6735 status_update_manager.cpp:834] Checkpointing ACK for status update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.334759  6735 status_update_manager.cpp:531] Cleaning up status update stream for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.335131  6723 slave.cpp:3609] Status update manager successfully handled status update acknowledgement (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.335178  6723 slave.cpp:7561] Completing task 334ab1cb-44b2-4676-b2b5-0329c383ac33
I0817 01:00:06.335224  6723 slave.cpp:5429] Cleaning up executor '334ab1cb-44b2-4676-b2b5-0329c383ac33' of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 at executor(1)@172.17.0.8:40576
I0817 01:00:06.335512  6740 gc.cpp:59] Scheduling '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/slaves/56b17556-5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-b2b5-0329c383ac33/runs/85315bbe-bb58-416d-853d-8c17b4a61361' for gc 6.99999611762667days in the future
I0817 01:00:06.335686  6729 gc.cpp:59] Scheduling '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/slaves/56b17556-5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-b2b5-0329c383ac33' for gc 6.99999611555556days in the future
I0817 01:00:06.335827  6729 gc.cpp:59] Scheduling '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556-5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-b2b5-0329c383ac33/runs/85315bbe-bb58-416d-853d-8c17b4a61361' for gc 6.99999611430519days in the future
I0817 01:00:06.335861  6723 slave.cpp:5525] Cleaning up framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.335929  6729 gc.cpp:59] Scheduling '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556-5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-b2b5-0329c383ac33' for gc 6.99999611335704days in the future
I0817 01:00:06.335980  6731 status_update_manager.cpp:285] Closing status update streams for framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.336024  6729 gc.cpp:59] Scheduling '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/slaves/56b17556-5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000' for gc 6.99999611171259days in the future
I0817 01:00:06.336120  6729 gc.cpp:59] Scheduling '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556-5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000' for gc 6.9999961109363days in the future
I0817 01:00:06.802976  6742 hierarchical.cpp:2033] No inverse offers to send out!
I0817 01:00:06.803063  6742 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.010273ms
I0817 01:00:06.803483  6733 master.cpp:7667] Sending 1 offers to framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
I0817 01:00:06.804096  6741 sched.cpp:933] Scheduler::resourceOffers took 135353ns
I0817 01:00:06.804899  6704 sched.cpp:2021] Asked to stop the driver
I0817 01:00:06.804999  6738 sched.cpp:1203] Stopping framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.805320  6745 master.cpp:8348] Processing TEARDOWN call for framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
I0817 01:00:06.805352  6745 master.cpp:8360] Removing framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
I0817 01:00:06.805367  6745 master.cpp:3264] Deactivating framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
I0817 01:00:06.805480  6740 hierarchical.cpp:412] Deactivated framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.805881  6745 master.cpp:9164] Removing offer 56b17556-5965-44ca-be07-44edbcb8751c-O1
I0817 01:00:06.806056  6739 slave.cpp:3159] Asked to shut down framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 by master@172.17.0.8:40444
I0817 01:00:06.806116  6739 slave.cpp:3174] Cannot shut down unknown framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.806344  6740 hierarchical.cpp:1161] 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 56b17556-5965-44ca-be07-44edbcb8751c-S0 from framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.809447  6740 hierarchical.cpp:355] Removed framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
I0817 01:00:06.809541  6730 slave.cpp:843] Agent terminating
I0817 01:00:06.814934  6704 master.cpp:1160] Master terminating
I0817 01:00:06.815558  6739 hierarchical.cpp:626] Removed agent 56b17556-5965-44ca-be07-44edbcb8751c-S0
[       OK ] SlaveRecoveryTest/0.Reboot (4030 ms)
[ RUN      ] SlaveRecoveryTest/0.RebootWithSlaveInfoMismatch
I0817 01:00:06.824440  6704 cluster.cpp:162] Creating default 'local' authorizer
I0817 01:00:06.827071  6734 master.cpp:442] Master 66249101-3204-4bec-9632-4a28a9d4b6e5 (45197c1facb6) started on 172.17.0.8:40444
I0817 01:00:06.827113  6734 master.cpp:444] 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/Z0ccUv/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="/mesos/mesos-1.4.0/_inst/share/mesos/webui" --work_dir="/tmp/Z0ccUv/master" --zk_session_timeout="10secs"
I0817 01:00:06.827448  6734 master.cpp:494] Master only allowing authenticated frameworks to register
I0817 01:00:06.827479  6734 master.cpp:508] Master only allowing authenticated agents to register
I0817 01:00:06.827493  6734 master.cpp:521] Master only allowing authenticated HTTP frameworks to register
I0817 01:00:06.827507  6734 credentials.hpp:37] Loading credentials for authentication from '/tmp/Z0ccUv/credentials'
I0817 01:00:06.827826  6734 master.cpp:566] Using default 'crammd5' authenticator
I0817 01:00:06.827980  6734 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0817 01:00:06.828145  6734 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0817 01:00:06.828272  6734 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0817 01:00:06.828392  6734 master.cpp:646] Authorization enabled
I0817 01:00:06.828569  6743 hierarchical.cpp:171] Initialized hierarchical allocator process
I0817 01:00:06.828590  6725 whitelist_watcher.cpp:77] No whitelist given
I0817 01:00:06.831037  6736 master.cpp:2163] Elected as the leading master!
I0817 01:00:06.831063  6736 master.cpp:1702] Recovering from registrar
I0817 01:00:06.831159  6728 registrar.cpp:347] Recovering registrar
I0817 01:00:06.831712  6728 registrar.cpp:391] Successfully fetched the registry (0B) in 515840ns
I0817 01:00:06.831832  6728 registrar.cpp:495] Applied 1 operations in 44686ns; attempting to update the registry
I0817 01:00:06.832372  6728 registrar.cpp:552] Successfully updated the registry in 482048ns
I0817 01:00:06.832489  6728 registrar.cpp:424] Successfully recovered registrar
I0817 01:00:06.832810  6738 master.cpp:1801] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
I0817 01:00:06.832854  6744 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
I0817 01:00:06.836031  6704 containerizer.cpp:246] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0817 01:00:06.836477  6704 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0817 01:00:06.836588  6704 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0817 01:00:06.836623  6704 provisioner.cpp:255] Using default backend 'copy'
I0817 01:00:06.840314  6704 process.cpp:3228] Attempting to spawn already spawned process files@172.17.0.8:40444
I0817 01:00:06.840575  6704 cluster.cpp:448] Creating default 'local' authorizer
I0817 01:00:06.842278  6725 slave.cpp:250] Mesos agent started on (479)@172.17.0.8:40444
I0817 01:00:06.842310  6725 slave.cpp:251] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/store/appc" --authenticate_http_executors="true" --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/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/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/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/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_secret_key="/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/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/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.4.0/_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:8;mem:4096;disk:2048" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV" --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/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_yF46Kd"
I0817 01:00:06.842685  6725 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/credential'
I0817 01:00:06.842784  6704 process.cpp:3228] Attempting to spawn already spawned process version@172.17.0.8:40444
I0817 01:00:06.842851  6725 slave.cpp:283] Agent using credential for: test-principal
I0817 01:00:06.842875  6725 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/http_credentials'
I0817 01:00:06.843179  6725 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0817 01:00:06.843313  6725 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0817 01:00:06.843533  6725 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 01:00:06.843629  6725 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 01:00:06.843639  6704 sched.cpp:232] Version: 1.4.0
I0817 01:00:06.843857  6725 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 01:00:06.843960  6725 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 01:00:06.844141  6731 sched.cpp:336] New master detected at master@172.17.0.8:40444
I0817 01:00:06.844230  6731 sched.cpp:407] Authenticating with master master@172.17.0.8:40444
I0817 01:00:06.844249  6731 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0817 01:00:06.844457  6738 authenticatee.cpp:121] Creating new client SASL connection
I0817 01:00:06.844712  6736 master.cpp:7837] Authenticating scheduler-db03a645-3ff8-4b33-b9cf-8617bdc60875@172.17.0.8:40444
I0817 01:00:06.844805  6739 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(994)@172.17.0.8:40444
I0817 01:00:06.845022  6742 authenticator.cpp:98] Creating new server SASL connection
I0817 01:00:06.845257  6729 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0817 01:00:06.845285  6729 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0817 01:00:06.845379  6730 authenticator.cpp:204] Received SASL authentication start
I0817 01:00:06.845227  6725 slave.cpp:565] Agent resources: [{"name":"cpus","scalar":{"value":8.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":4096.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":2048.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0817 01:00:06.845443  6730 authenticator.cpp:326] Authentication requires more steps
I0817 01:00:06.845474  6725 slave.cpp:573] Agent attributes: [  ]
I0817 01:00:06.845495  6725 slave.cpp:582] Agent hostname: 45197c1facb6
I0817 01:00:06.845587  6726 authenticatee.cpp:259] Received SASL authentication step
I0817 01:00:06.845631  6737 status_update_manager.cpp:177] Pausing sending status updates
I0817 01:00:06.845721  6727 authenticator.cpp:232] Received SASL authentication step
I0817 01:00:06.845752  6727 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '45197c1facb6' server FQDN: '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0817 01:00:06.845765  6727 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0817 01:00:06.845803  6727 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0817 01:00:06.845824  6727 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '45197c1facb6' server FQDN: '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0817 01:00:06.845834  6727 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0817 01:00:06.845840  6727 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0817 01:00:06.845859  6727 authenticator.cpp:318] Authentication success
I0817 01:00:06.845944  6722 authenticatee.cpp:299] Authentication success
I0817 01:00:06.846010  6733 master.cpp:7867] Successfully authenticated principal 'test-principal' at scheduler-db03a645-3ff8-4b33-b9cf-8617bdc60875@172.17.0.8:40444
I0817 01:00:06.846038  6732 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(994)@172.17.0.8:40444
I0817 01:00:06.846205  6724 sched.cpp:513] Successfully authenticated with master master@172.17.0.8:40444
I0817 01:00:06.846230  6724 sched.cpp:836] Sending SUBSCRIBE call to master@172.17.0.8:40444
I0817 01:00:06.846350  6724 sched.cpp:869] Will retry registration in 1.760433846secs if necessary
I0817 01:00:06.846515  6735 master.cpp:2894] Received SUBSCRIBE call for framework 'default' at scheduler-db03a645-3ff8-4b33-b9cf-8617bdc60875@172.17.0.8:40444
terminate called after throwing an instance of 'std::system_error'
  what():  Invalid argumentI0817 01:00:06.846544  6735 master.cpp:2228] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'

*** Aborted at 1502931606 (unix time) try "date -d @1502931606" if you are using GNU date ***
PC: @     0x2b5638257c37 (unknown)
*** SIGABRT (@0x3e800001a30) received by PID 6704 (TID 0x2b56419b3700) from PID 6704; stack trace: ***
I0817 01:00:06.847018  6744 master.cpp:2974] Subscribing framework default with checkpointing enabled and capabilities [ RESERVATION_REFINEMENT ]
    @     0x2b5638013330 (unknown)
I0817 01:00:06.847276  6723 state.cpp:64] Recovering state from '/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_yF46Kd/meta'
    @     0x2b5638257c37 (unknown)
    @     0x2b563825b028 (unknown)
    @     0x2b5637843535 (unknown)
I0817 01:00:06.847627  6730 status_update_manager.cpp:203] Recovering status update manager
I0817 01:00:06.847650  6742 sched.cpp:759] Framework registered with 66249101-3204-4bec-9632-4a28a9d4b6e5-0000
    @     0x2b56378416d6 (unknown)
I0817 01:00:06.847724  6742 sched.cpp:773] Scheduler::registered took 38692ns
    @     0x2b5637841703 (unknown)
I0817 01:00:06.847841  6728 containerizer.cpp:609] Recovering containerizer
I0817 01:00:06.847849  6736 hierarchical.cpp:303] Added framework 66249101-3204-4bec-9632-4a28a9d4b6e5-0000
    @     0x2b5637894af5 (unknown)
I0817 01:00:06.848007  6736 hierarchical.cpp:1943] No allocations performed
I0817 01:00:06.848045  6736 hierarchical.cpp:2033] No inverse offers to send out!
I0817 01:00:06.848076  6736 hierarchical.cpp:1486] Performed allocation for 0 agents in 112255ns
    @     0x2b563800b184 start_thread
    @     0x2b563831effd (unknown)
make[4]: *** [check-local] Aborted (core dumped)
make[4]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.4.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1502928841-11353
Untagged: mesos-1502928841-11353:latest
Deleted: sha256:b357f94c675052121faba6fe659e4eb7ae3e1561b4a9437f6f1fa9372bd553f0
Deleted: sha256:a96273e4fde97cd27620621e0595131961cc9d52b7596f71f0f5227fe8fc13ca
Deleted: sha256:ce40dc29c56558c1c6bc6de09555cf72ac0ed0e123528596b9f00366d0a5d9cb
Deleted: sha256:07c588a98d87917d607d4bfc5ed8e2aa505ca3ef14b805f03d6e2da329eb1bf8
Deleted: sha256:db572215bdd853fdae5e743968629a440977c43ce9b85e7dd367a64703bca758
Deleted: sha256:c53b35da4b823af8922b02331a25daa3929de567db25a5b768a9fd878f9a6bdd
Deleted: sha256:a5e5c1c3346f346f44235f537f35bf5cd17ec098e7ff02ebc24a5c638ea1bfc8
Deleted: sha256:926e91e72e8e57be634ea00e9ddff4e4cabbc11335a3fb219cd131b2ed9ab392
Deleted: sha256:f4649fa91e399abcaff7e3ae53ff38d5e76fa41598cd59c2ad8ade0ab6733e4d
Deleted: sha256:743e6ebb05fbd1e05c86275466c6188b9fd4e45b8d50d3a1bd7bd72f3da6cf5c
Deleted: sha256:0692e3b9d64f5aa3b030779e4f9a76224e412d59a542ccbfd09e25fa6affb46f
Deleted: sha256:f28c43c772395095e3d7cbcb1f8e03e019c81e9180460f9d6e87bc8c4222002a
Deleted: sha256:c885dcb5d6d14a85d75c216e122bea52342e8db9e83c8725d23a4c0a7c07c2b6
Deleted: sha256:66500f988c2ab193d11a154febd6bd8cb1a13f9e270ea6cf0dc80bbfe1114bc6
Deleted: sha256:f9a400d8c7f70691776f92bec8c4a15b3ed3e3beb5fdf2c77fa39d53d6ff4ce6
Deleted: sha256:6b9a61dcfa10915fa155e3596d04544a0263a294f74d5720698fa3ce14cc89fa
Deleted: sha256:6c31420e1acbb33ca3a6a1a8fad9ee67ccdf4c51420ad66bb167cfb879bf18d2
Deleted: sha256:457d8b02047822f8e50c72c0f0077ae09497b3f30506b0ac2d6b8e8207d0f6bd
Deleted: sha256:1045dd5e6093bfae7f668960f2473b540a3c7e57305beb8613e97e74ea1786b7
Deleted: sha256:b06f149fef2d09a542a4708153903f753990e4c608434a65d6b599ee4fed4bd9
Deleted: sha256:0d51e647adbe81d4cb44a35a96734c9cd4ecff41a57ef91eac8f4348fd546a12
Deleted: sha256:63e2e1e2bf046565d1723dfbd4754867ed745e1feca4ceef5ba5b4c3d2d0b747
Deleted: sha256:c2be339c2a2099eab71b3adf3c70c9b0e8ef5a615229504dfdcfaa68bd6a92cf
Deleted: sha256:0e0dd36544fec166584cffc3867896fd04b9b733e55e7e7a30084a35d0ca5fd5
Build step 'Execute shell' marked build as failure

Jenkins build is back to normal : Mesos-Buildbot » autotools,clang,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #4121

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=autotools,COMPILER=clang,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)/4121/display/redirect?page=changes>


Build failed in Jenkins: Mesos-Buildbot » autotools,clang,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #4120

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=autotools,COMPILER=clang,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)/4120/display/redirect?page=changes>

Changes:

[songzihao1990] Fixed mesos containerizer to support docker image WORKDIR missing.

[songzihao1990] Added MESOS-7652 to 1.3.2 CHANGELOG.

[songzihao1990] Added MESOS-7652 to 1.2.3 CHANGELOG.

[songzihao1990] Added MESOS-7652 to 1.1.3 CHANGELOG.

[mpark] Updated website for 1.3.1 release.

------------------------------------------
[...truncated 32.12 MB...]
W0817 15:02:04.451107  5873 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0817 15:02:04.451236  5873 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0817 15:02:04.451287  5873 provisioner.cpp:255] Using default backend 'copy'
I0817 15:02:04.455104 24549 slave.cpp:250] Mesos agent started on (806)@172.17.0.2:50704
I0817 15:02:04.455149 24549 slave.cpp:251] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_0_EerM8Z/store/appc" --authenticate_http_executors="true" --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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_0_EerM8Z/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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_0_EerM8Z/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_secret_key="/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_0_EerM8Z/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_0_EerM8Z/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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_0_EerM8Z/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.4.0/_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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_0_EerM8Z" --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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_0_FZEgft"
I0817 15:02:04.455638 24549 credentials.hpp:86] Loading credential for authentication from '/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_0_EerM8Z/credential'
I0817 15:02:04.455838 24549 slave.cpp:283] Agent using credential for: test-principal
I0817 15:02:04.455873 24549 credentials.hpp:37] Loading credentials for authentication from '/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_0_EerM8Z/http_credentials'
I0817 15:02:04.456295 24549 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.456442 24549 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.456728 24549 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.456854 24549 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.457124 24549 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.457257 24549 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.459019 24549 slave.cpp:565] 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"}]
I0817 15:02:04.459308 24549 slave.cpp:573] Agent attributes: [  ]
I0817 15:02:04.459327 24549 slave.cpp:582] Agent hostname: 3f3e797b79af
I0817 15:02:04.459486 24539 status_update_manager.cpp:177] Pausing sending status updates
I0817 15:02:04.461230 24554 state.cpp:64] Recovering state from '/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_0_FZEgft/meta'
I0817 15:02:04.461616 24544 status_update_manager.cpp:203] Recovering status update manager
I0817 15:02:04.461864 24552 containerizer.cpp:609] Recovering containerizer
I0817 15:02:04.463554 24553 provisioner.cpp:416] Provisioner recovery complete
I0817 15:02:04.463979 24545 slave.cpp:6210] Finished recovery
I0817 15:02:04.464599 24545 slave.cpp:6392] Querying resource estimator for oversubscribable resources
I0817 15:02:04.464896 24541 slave.cpp:6406] Received oversubscribable resources {} from the resource estimator
I0817 15:02:04.467171 24540 process.cpp:3933] Handling HTTP event for process 'slave(806)' with path: '/slave(806)/monitor/statistics'
I0817 15:02:04.469182 24554 http.cpp:1166] HTTP GET for /slave(806)/monitor/statistics from 172.17.0.2:47788
I0817 15:02:04.469285 24554 http.cpp:957] Authorizing principal 'test-principal' to GET the '/monitor/statistics' endpoint
I0817 15:02:04.471469 24545 slave.cpp:843] Agent terminating
[       OK ] Endpoint/SlaveEndpointTest.UnauthorizedRequest/0 (32 ms)
[ RUN      ] Endpoint/SlaveEndpointTest.UnauthorizedRequest/1
I0817 15:02:04.483466  5873 containerizer.cpp:246] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0817 15:02:04.483932  5873 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0817 15:02:04.484045  5873 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0817 15:02:04.484093  5873 provisioner.cpp:255] Using default backend 'copy'
I0817 15:02:04.487327 24544 slave.cpp:250] Mesos agent started on (807)@172.17.0.2:50704
I0817 15:02:04.487365 24544 slave.cpp:251] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_1_sNLr17/store/appc" --authenticate_http_executors="true" --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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_1_sNLr17/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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_1_sNLr17/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_secret_key="/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_1_sNLr17/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_1_sNLr17/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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_1_sNLr17/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.4.0/_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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_1_sNLr17" --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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_1_vSMv2A"
I0817 15:02:04.487918 24544 credentials.hpp:86] Loading credential for authentication from '/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_1_sNLr17/credential'
I0817 15:02:04.488117 24544 slave.cpp:283] Agent using credential for: test-principal
I0817 15:02:04.488147 24544 credentials.hpp:37] Loading credentials for authentication from '/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_1_sNLr17/http_credentials'
I0817 15:02:04.488504 24544 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.488636 24544 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.488857 24544 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.488952 24544 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.489127 24544 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.489226 24544 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.490520 24544 slave.cpp:565] 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"}]
I0817 15:02:04.490731 24544 slave.cpp:573] Agent attributes: [  ]
I0817 15:02:04.490746 24544 slave.cpp:582] Agent hostname: 3f3e797b79af
I0817 15:02:04.490900 24549 status_update_manager.cpp:177] Pausing sending status updates
I0817 15:02:04.492616 24552 state.cpp:64] Recovering state from '/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_1_vSMv2A/meta'
I0817 15:02:04.492962 24542 status_update_manager.cpp:203] Recovering status update manager
I0817 15:02:04.493181 24541 containerizer.cpp:609] Recovering containerizer
I0817 15:02:04.494765 24542 provisioner.cpp:416] Provisioner recovery complete
I0817 15:02:04.495182 24551 slave.cpp:6210] Finished recovery
I0817 15:02:04.495609 24551 slave.cpp:6392] Querying resource estimator for oversubscribable resources
I0817 15:02:04.495820 24546 slave.cpp:6406] Received oversubscribable resources {} from the resource estimator
I0817 15:02:04.497817 24553 process.cpp:3933] Handling HTTP event for process 'slave(807)' with path: '/slave(807)/monitor/statistics.json'
I0817 15:02:04.499567 24552 http.cpp:1166] HTTP GET for /slave(807)/monitor/statistics.json from 172.17.0.2:47789
I0817 15:02:04.499641 24552 http.cpp:957] Authorizing principal 'test-principal' to GET the '/monitor/statistics.json' endpoint
I0817 15:02:04.501381 24541 slave.cpp:843] Agent terminating
[       OK ] Endpoint/SlaveEndpointTest.UnauthorizedRequest/1 (31 ms)
[ RUN      ] Endpoint/SlaveEndpointTest.UnauthorizedRequest/2
I0817 15:02:04.516350  5873 containerizer.cpp:246] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0817 15:02:04.516813  5873 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0817 15:02:04.516916  5873 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0817 15:02:04.516957  5873 provisioner.cpp:255] Using default backend 'copy'
I0817 15:02:04.520179 24540 slave.cpp:250] Mesos agent started on (808)@172.17.0.2:50704
I0817 15:02:04.520216 24540 slave.cpp:251] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_2_qJUIeg/store/appc" --authenticate_http_executors="true" --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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_2_qJUIeg/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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_2_qJUIeg/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_secret_key="/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_2_qJUIeg/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_2_qJUIeg/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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_2_qJUIeg/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.4.0/_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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_2_qJUIeg" --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/Endpoint_SlaveEndpointTest_UnauthorizedRequest_2_NmpAaJ"
I0817 15:02:04.520891 24540 credentials.hpp:86] Loading credential for authentication from '/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_2_qJUIeg/credential'
I0817 15:02:04.521117 24540 slave.cpp:283] Agent using credential for: test-principal
I0817 15:02:04.521152 24540 credentials.hpp:37] Loading credentials for authentication from '/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_2_qJUIeg/http_credentials'
I0817 15:02:04.521623 24540 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.521792 24540 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.522065 24540 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.522176 24540 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.522353 24540 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.522451 24540 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.523766 24540 slave.cpp:565] 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"}]
I0817 15:02:04.523982 24540 slave.cpp:573] Agent attributes: [  ]
I0817 15:02:04.524003 24540 slave.cpp:582] Agent hostname: 3f3e797b79af
I0817 15:02:04.524147 24543 status_update_manager.cpp:177] Pausing sending status updates
I0817 15:02:04.526065 24549 state.cpp:64] Recovering state from '/tmp/Endpoint_SlaveEndpointTest_UnauthorizedRequest_2_NmpAaJ/meta'
I0817 15:02:04.526355 24550 status_update_manager.cpp:203] Recovering status update manager
I0817 15:02:04.526592 24546 containerizer.cpp:609] Recovering containerizer
I0817 15:02:04.527927 24550 provisioner.cpp:416] Provisioner recovery complete
I0817 15:02:04.528334 24547 slave.cpp:6210] Finished recovery
I0817 15:02:04.528908 24547 slave.cpp:6392] Querying resource estimator for oversubscribable resources
I0817 15:02:04.529213 24544 slave.cpp:6406] Received oversubscribable resources {} from the resource estimator
I0817 15:02:04.531692 24546 process.cpp:3933] Handling HTTP event for process 'slave(808)' with path: '/slave(808)/containers'
I0817 15:02:04.533763 24545 http.cpp:1166] HTTP GET for /slave(808)/containers from 172.17.0.2:47790
I0817 15:02:04.533854 24545 http.cpp:957] Authorizing principal 'test-principal' to GET the '/containers' endpoint
I0817 15:02:04.535878 24554 slave.cpp:843] Agent terminating
[       OK ] Endpoint/SlaveEndpointTest.UnauthorizedRequest/2 (32 ms)
[ RUN      ] Endpoint/SlaveEndpointTest.NoAuthorizer/0
I0817 15:02:04.550019  5873 containerizer.cpp:246] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0817 15:02:04.550621  5873 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0817 15:02:04.550755  5873 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0817 15:02:04.550797  5873 provisioner.cpp:255] Using default backend 'copy'
I0817 15:02:04.552826  5873 cluster.cpp:448] Creating default 'local' authorizer
I0817 15:02:04.554456 24548 slave.cpp:250] Mesos agent started on (809)@172.17.0.2:50704
I0817 15:02:04.554494 24548 slave.cpp:251] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_0_MHbBNo/store/appc" --authenticate_http_executors="true" --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/Endpoint_SlaveEndpointTest_NoAuthorizer_0_MHbBNo/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/Endpoint_SlaveEndpointTest_NoAuthorizer_0_MHbBNo/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_secret_key="/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_0_MHbBNo/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_0_MHbBNo/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/Endpoint_SlaveEndpointTest_NoAuthorizer_0_MHbBNo/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.4.0/_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/Endpoint_SlaveEndpointTest_NoAuthorizer_0_MHbBNo" --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/Endpoint_SlaveEndpointTest_NoAuthorizer_0_1k03DR"
I0817 15:02:04.555040 24548 credentials.hpp:86] Loading credential for authentication from '/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_0_MHbBNo/credential'
I0817 15:02:04.555238 24548 slave.cpp:283] Agent using credential for: test-principal
I0817 15:02:04.555270 24548 credentials.hpp:37] Loading credentials for authentication from '/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_0_MHbBNo/http_credentials'
I0817 15:02:04.555716 24548 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.555866 24548 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.556165 24548 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.556295 24548 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.556529 24548 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.556658 24548 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.558351 24548 slave.cpp:565] 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"}]
I0817 15:02:04.558639 24548 slave.cpp:573] Agent attributes: [  ]
I0817 15:02:04.558655 24548 slave.cpp:582] Agent hostname: 3f3e797b79af
I0817 15:02:04.558814 24541 status_update_manager.cpp:177] Pausing sending status updates
I0817 15:02:04.560559 24551 state.cpp:64] Recovering state from '/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_0_1k03DR/meta'
I0817 15:02:04.560899 24543 status_update_manager.cpp:203] Recovering status update manager
I0817 15:02:04.561131 24545 containerizer.cpp:609] Recovering containerizer
I0817 15:02:04.562778 24543 provisioner.cpp:416] Provisioner recovery complete
I0817 15:02:04.563220 24539 slave.cpp:6210] Finished recovery
I0817 15:02:04.563743 24539 slave.cpp:6392] Querying resource estimator for oversubscribable resources
I0817 15:02:04.563964 24549 slave.cpp:6406] Received oversubscribable resources {} from the resource estimator
I0817 15:02:04.566449 24545 process.cpp:3933] Handling HTTP event for process 'slave(809)' with path: '/slave(809)/monitor/statistics'
I0817 15:02:04.568414 24544 http.cpp:1166] HTTP GET for /slave(809)/monitor/statistics from 172.17.0.2:47791
I0817 15:02:04.568507 24544 http.cpp:957] Authorizing principal 'test-principal' to GET the '/monitor/statistics' endpoint
I0817 15:02:04.572162  5873 slave.cpp:843] Agent terminating
[       OK ] Endpoint/SlaveEndpointTest.NoAuthorizer/0 (36 ms)
[ RUN      ] Endpoint/SlaveEndpointTest.NoAuthorizer/1
I0817 15:02:04.586354  5873 containerizer.cpp:246] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0817 15:02:04.586937  5873 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0817 15:02:04.587072  5873 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0817 15:02:04.587113  5873 provisioner.cpp:255] Using default backend 'copy'
I0817 15:02:04.589049  5873 cluster.cpp:448] Creating default 'local' authorizer
I0817 15:02:04.590653 24539 slave.cpp:250] Mesos agent started on (810)@172.17.0.2:50704
I0817 15:02:04.590688 24539 slave.cpp:251] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_1_QC1NJx/store/appc" --authenticate_http_executors="true" --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/Endpoint_SlaveEndpointTest_NoAuthorizer_1_QC1NJx/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/Endpoint_SlaveEndpointTest_NoAuthorizer_1_QC1NJx/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_secret_key="/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_1_QC1NJx/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_1_QC1NJx/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/Endpoint_SlaveEndpointTest_NoAuthorizer_1_QC1NJx/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.4.0/_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/Endpoint_SlaveEndpointTest_NoAuthorizer_1_QC1NJx" --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/Endpoint_SlaveEndpointTest_NoAuthorizer_1_buqnu0"
I0817 15:02:04.591068 24539 credentials.hpp:86] Loading credential for authentication from '/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_1_QC1NJx/credential'
I0817 15:02:04.591289 24539 slave.cpp:283] Agent using credential for: test-principal
I0817 15:02:04.591320 24539 credentials.hpp:37] Loading credentials for authentication from '/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_1_QC1NJx/http_credentials'
I0817 15:02:04.591719 24539 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.591879 24539 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.592152 24539 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.592303 24539 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.592561 24539 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.592700 24539 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.594445 24539 slave.cpp:565] 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"}]
I0817 15:02:04.594733 24539 slave.cpp:573] Agent attributes: [  ]
I0817 15:02:04.594750 24539 slave.cpp:582] Agent hostname: 3f3e797b79af
I0817 15:02:04.594964 24548 status_update_manager.cpp:177] Pausing sending status updates
I0817 15:02:04.596611 24543 state.cpp:64] Recovering state from '/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_1_buqnu0/meta'
I0817 15:02:04.596930 24546 status_update_manager.cpp:203] Recovering status update manager
I0817 15:02:04.597163 24553 containerizer.cpp:609] Recovering containerizer
I0817 15:02:04.598628 24546 provisioner.cpp:416] Provisioner recovery complete
I0817 15:02:04.599054 24551 slave.cpp:6210] Finished recovery
I0817 15:02:04.599556 24551 slave.cpp:6392] Querying resource estimator for oversubscribable resources
I0817 15:02:04.599751 24542 slave.cpp:6406] Received oversubscribable resources {} from the resource estimator
I0817 15:02:04.601984 24548 process.cpp:3933] Handling HTTP event for process 'slave(810)' with path: '/slave(810)/monitor/statistics.json'
I0817 15:02:04.603965 24543 http.cpp:1166] HTTP GET for /slave(810)/monitor/statistics.json from 172.17.0.2:47792
I0817 15:02:04.604079 24543 http.cpp:957] Authorizing principal 'test-principal' to GET the '/monitor/statistics.json' endpoint
I0817 15:02:04.607300 24552 slave.cpp:843] Agent terminating
[       OK ] Endpoint/SlaveEndpointTest.NoAuthorizer/1 (35 ms)
[ RUN      ] Endpoint/SlaveEndpointTest.NoAuthorizer/2
I0817 15:02:04.621315  5873 containerizer.cpp:246] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0817 15:02:04.621923  5873 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0817 15:02:04.622056  5873 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0817 15:02:04.622099  5873 provisioner.cpp:255] Using default backend 'copy'
I0817 15:02:04.624315  5873 cluster.cpp:448] Creating default 'local' authorizer
I0817 15:02:04.625922 24543 slave.cpp:250] Mesos agent started on (811)@172.17.0.2:50704
I0817 15:02:04.625957 24543 slave.cpp:251] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_2_MVHU2G/store/appc" --authenticate_http_executors="true" --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/Endpoint_SlaveEndpointTest_NoAuthorizer_2_MVHU2G/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/Endpoint_SlaveEndpointTest_NoAuthorizer_2_MVHU2G/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_secret_key="/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_2_MVHU2G/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_2_MVHU2G/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/Endpoint_SlaveEndpointTest_NoAuthorizer_2_MVHU2G/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.4.0/_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/Endpoint_SlaveEndpointTest_NoAuthorizer_2_MVHU2G" --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/Endpoint_SlaveEndpointTest_NoAuthorizer_2_lArNH9"
I0817 15:02:04.626302 24543 credentials.hpp:86] Loading credential for authentication from '/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_2_MVHU2G/credential'
I0817 15:02:04.626489 24543 slave.cpp:283] Agent using credential for: test-principal
I0817 15:02:04.626519 24543 credentials.hpp:37] Loading credentials for authentication from '/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_2_MVHU2G/http_credentials'
I0817 15:02:04.626876 24543 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.627038 24543 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0817 15:02:04.627241 24543 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.627355 24543 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 15:02:04.627619 24543 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.627763 24543 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 15:02:04.629520 24543 slave.cpp:565] 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"}]
I0817 15:02:04.629817 24543 slave.cpp:573] Agent attributes: [  ]
I0817 15:02:04.629843 24543 slave.cpp:582] Agent hostname: 3f3e797b79af
I0817 15:02:04.630028 24539 status_update_manager.cpp:177] Pausing sending status updates
I0817 15:02:04.631382 24552 state.cpp:64] Recovering state from '/tmp/Endpoint_SlaveEndpointTest_NoAuthorizer_2_lArNH9/meta'
I0817 15:02:04.631800 24540 status_update_manager.cpp:203] Recovering status update manager
I0817 15:02:04.632058 24554 containerizer.cpp:609] Recovering containerizer
I0817 15:02:04.633426 24548 provisioner.cpp:416] Provisioner recovery complete
I0817 15:02:04.633808 24539 slave.cpp:6210] Finished recovery
I0817 15:02:04.634230 24539 slave.cpp:6392] Querying resource estimator for oversubscribable resources
I0817 15:02:04.634459 24543 slave.cpp:6406] Received oversubscribable resources {} from the resource estimator
I0817 15:02:04.636564 24549 process.cpp:3933] Handling HTTP event for process 'slave(811)' with path: '/slave(811)/containers'
I0817 15:02:04.638165 24540 http.cpp:1166] HTTP GET for /slave(811)/containers from 172.17.0.2:47793
I0817 15:02:04.638240 24540 http.cpp:957] Authorizing principal 'test-principal' to GET the '/containers' endpoint
I0817 15:02:04.641517 24550 slave.cpp:843] Agent terminating
[       OK ] Endpoint/SlaveEndpointTest.NoAuthorizer/2 (34 ms)
[----------] 9 tests from Endpoint/SlaveEndpointTest (310 ms total)

[----------] 2 tests from ContainerizerType/DefaultContainerDNSFlagTest
[ RUN      ] ContainerizerType/DefaultContainerDNSFlagTest.ValidateFlag/0
[       OK ] ContainerizerType/DefaultContainerDNSFlagTest.ValidateFlag/0 (11 ms)
[ RUN      ] ContainerizerType/DefaultContainerDNSFlagTest.ValidateFlag/1
[       OK ] ContainerizerType/DefaultContainerDNSFlagTest.ValidateFlag/1 (9 ms)
[----------] 2 tests from ContainerizerType/DefaultContainerDNSFlagTest (20 ms total)

[----------] Global test environment tear-down
[==========] 1663 tests from 184 test cases ran. (487964 ms total)
[  PASSED  ] 1662 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] ExamplesTest.NoExecutorFramework

 1 FAILED TEST
  YOU HAVE 20 DISABLED TESTS

I0817 15:02:04.726908 24555 process.cpp:1072] Failed to accept socket: future discarded
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.4.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1502978685-4151
Untagged: mesos-1502978685-4151:latest
Deleted: sha256:95582701f2287a0a722ed109e2d27cbf06201cf22cd641fe3ce33ade0fcf90a5
Deleted: sha256:8314e561294227a5edffb51c64c07324acf6077e7f97555b522efdcb0f5ab6d2
Deleted: sha256:f1101abfae14c216c3e43e1b51440c8595916f6886f1ce6992234bd32e050499
Deleted: sha256:947d4f5ca9c72d9893ad18e09496acb69e04fbe7b79bc3ddf777ec1a90dab448
Deleted: sha256:27e9254e9c88e7b58e53005c260f6b4e8e43fab42dc049dafca8a285ede8d210
Deleted: sha256:d00451c4f8fefd24c66499a280240f6cb9b9b46b9d645fffd40c06ed9fa3d868
Deleted: sha256:233d2e8f4deda1d1227d55f7fc88b900c7ded46d5b0d12fea465a6b5635f37eb
Deleted: sha256:71810afee11c6232edda61d618bc66366f458277a4619589b4ca85c64f659b4b
Deleted: sha256:6eb9b0e1330e0f5c6f58a7ecbb269e75284a2e6c34d9211a2029e8f4c60ff858
Deleted: sha256:69be67d54a1ecbe35a55007093e2e8f028a9c50f2dae0c7e626510b300b6dab8
Deleted: sha256:9e44c17a28a70fc40bc21924f5c23612e71ce614e5679bb6b36d7f03445fe4af
Deleted: sha256:5517be1bf410b6f10f3d447059ca69f7860bfbd32df0381ce22e08815a0d8f26
Deleted: sha256:f8d4d318eb955a3c029d260c6e42e0dca5b6fc03fa8318bbc5d3299a69b561a8
Deleted: sha256:db225bc9a2aa4804e7928b1e5044d6385043e28a8c01219f225c975f36c6f680
Deleted: sha256:167b255a464155c53816aff04a894fc533e1661a489c95577ad9e8200495d1fb
Deleted: sha256:68aa97fb84a82f48c937e4ab90cde9dd4b59ebcb67634d55ffe752b511dcdf8e
Deleted: sha256:ccc12b90adba92cee5725cba81ddacbfa61ad7779c1ec5e60cb0112423cbf896
Deleted: sha256:292a8ad42bda7841caa3190368dea99581b641b81be7bf4cf34281ee803c64d5
Deleted: sha256:a814c9c9bd9b6e4a8a6af915a2d68dbcc6b143a215126ad378059cd59871056d
Deleted: sha256:2e1d3c0574adeaf2b5b56f504cffb060dd2a470bb661da06a9235ac70ff45161
Deleted: sha256:46d2bd374777ed9d90c4e0c7c31b522d1b920fa46e3a1d633018898a32ea366a
Deleted: sha256:be9c7b1b534d1c0d539b769ae1a93aae5bb57db7e410284d2e06d64d4c94d9ae
Deleted: sha256:0c04801f94e04c6bebc14bd2e7ffd50d33bcffe43a40972b3bf0fce1759568b0
Deleted: sha256:db004bb57d46ad63aee992830331a845f07878cce41c87ca67df030d87d7bf01
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user songzihao1990@gmail.com

Build failed in Jenkins: Mesos-Buildbot » autotools,clang,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #4119

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=autotools,COMPILER=clang,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)/4119/display/redirect?page=changes>

Changes:

[anand] Fixed a bug around `kill()` not removing active containers.

[songzihao1990] Fixed mesos containerizer to support docker image WORKDIR missing.

[songzihao1990] Added MESOS-7652 to 1.3.2 CHANGELOG.

[songzihao1990] Added MESOS-7652 to 1.2.3 CHANGELOG.

[songzihao1990] Added MESOS-7652 to 1.1.3 CHANGELOG.

------------------------------------------
[...truncated 23.15 MB...]
I0817 09:55:16.889528  5893 http.cpp:1166] HTTP GET for /slave(531)/containers from 172.17.0.5:59429
I0817 09:55:16.889650  5893 http.cpp:957] Authorizing principal 'test-principal' to GET the '/containers' endpoint
I0817 09:55:16.889894  5896 provisioner.cpp:416] Provisioner recovery complete
I0817 09:55:16.891185  5903 slave.cpp:6210] Finished recovery
I0817 09:55:16.891693  5903 slave.cpp:6392] Querying resource estimator for oversubscribable resources
I0817 09:55:16.892068  5899 status_update_manager.cpp:177] Pausing sending status updates
I0817 09:55:16.892071  5903 slave.cpp:971] New master detected at master@172.17.0.5:38332
I0817 09:55:16.892278  5903 slave.cpp:1006] Detecting new master
I0817 09:55:16.892402  5903 slave.cpp:6406] Received oversubscribable resources {} from the resource estimator
I0817 09:55:16.893635  5894 slave.cpp:1033] Authenticating with master master@172.17.0.5:38332
I0817 09:55:16.893718  5894 slave.cpp:1044] Using default CRAM-MD5 authenticatee
I0817 09:55:16.893998  5903 authenticatee.cpp:121] Creating new client SASL connection
I0817 09:55:16.894238  5897 slave.cpp:843] Agent terminating
I0817 09:55:16.894470  5903 master.cpp:7837] Authenticating slave(531)@172.17.0.5:38332
I0817 09:55:16.894628  5895 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1066)@172.17.0.5:38332
I0817 09:55:16.894850  5901 authenticator.cpp:98] Creating new server SASL connection
W0817 09:55:16.895129  5894 master.cpp:7864] Failed to authenticate slave(531)@172.17.0.5:38332: Failed to communicate with authenticatee
I0817 09:55:16.895225  5902 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1066)@172.17.0.5:38332
I0817 09:55:16.900957  5873 master.cpp:1160] Master terminating
[       OK ] SlaveTest.ContainersEndpointNoExecutor (45 ms)
[ RUN      ] SlaveTest.ContainersEndpoint
I0817 09:55:16.906898  5873 cluster.cpp:162] Creating default 'local' authorizer
I0817 09:55:16.910744  5904 master.cpp:442] Master 1a831787-1931-495d-bf08-13faa009fdad (38b2174bc306) started on 172.17.0.5:38332
I0817 09:55:16.910784  5904 master.cpp:444] 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/Z4w2F7/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="/mesos/mesos-1.4.0/_inst/share/mesos/webui" --work_dir="/tmp/Z4w2F7/master" --zk_session_timeout="10secs"
I0817 09:55:16.911093  5904 master.cpp:494] Master only allowing authenticated frameworks to register
I0817 09:55:16.911105  5904 master.cpp:508] Master only allowing authenticated agents to register
I0817 09:55:16.911111  5904 master.cpp:521] Master only allowing authenticated HTTP frameworks to register
I0817 09:55:16.911118  5904 credentials.hpp:37] Loading credentials for authentication from '/tmp/Z4w2F7/credentials'
I0817 09:55:16.911433  5904 master.cpp:566] Using default 'crammd5' authenticator
I0817 09:55:16.911592  5904 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0817 09:55:16.911778  5904 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0817 09:55:16.911975  5904 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0817 09:55:16.912120  5904 master.cpp:646] Authorization enabled
I0817 09:55:16.912308  5892 whitelist_watcher.cpp:77] No whitelist given
I0817 09:55:16.912340  5906 hierarchical.cpp:171] Initialized hierarchical allocator process
I0817 09:55:16.914775  5903 master.cpp:2163] Elected as the leading master!
I0817 09:55:16.914798  5903 master.cpp:1702] Recovering from registrar
I0817 09:55:16.914906  5895 registrar.cpp:347] Recovering registrar
I0817 09:55:16.915464  5895 registrar.cpp:391] Successfully fetched the registry (0B) in 523008ns
I0817 09:55:16.915580  5895 registrar.cpp:495] Applied 1 operations in 42550ns; attempting to update the registry
I0817 09:55:16.916141  5895 registrar.cpp:552] Successfully updated the registry in 502016ns
I0817 09:55:16.916250  5895 registrar.cpp:424] Successfully recovered registrar
I0817 09:55:16.916613  5897 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
I0817 09:55:16.916612  5894 master.cpp:1801] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
I0817 09:55:16.921147  5873 process.cpp:3228] Attempting to spawn already spawned process files@172.17.0.5:38332
I0817 09:55:16.921466  5873 cluster.cpp:448] Creating default 'local' authorizer
I0817 09:55:16.923383  5898 slave.cpp:250] Mesos agent started on (532)@172.17.0.5:38332
I0817 09:55:16.923422  5898 slave.cpp:251] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveTest_ContainersEndpoint_hZoO9z/store/appc" --authenticate_http_executors="true" --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/SlaveTest_ContainersEndpoint_hZoO9z/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/SlaveTest_ContainersEndpoint_hZoO9z/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_secret_key="/tmp/SlaveTest_ContainersEndpoint_hZoO9z/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveTest_ContainersEndpoint_hZoO9z/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/SlaveTest_ContainersEndpoint_hZoO9z/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.4.0/_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/SlaveTest_ContainersEndpoint_hZoO9z" --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/SlaveTest_ContainersEndpoint_0uRUUQ"
I0817 09:55:16.923981  5898 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveTest_ContainersEndpoint_hZoO9z/credential'
I0817 09:55:16.924005  5873 process.cpp:3228] Attempting to spawn already spawned process version@172.17.0.5:38332
I0817 09:55:16.924197  5898 slave.cpp:283] Agent using credential for: test-principal
I0817 09:55:16.924227  5898 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveTest_ContainersEndpoint_hZoO9z/http_credentials'
I0817 09:55:16.924583  5898 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0817 09:55:16.924756  5898 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0817 09:55:16.925014  5898 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 09:55:16.925103  5873 sched.cpp:232] Version: 1.4.0
I0817 09:55:16.925186  5898 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0817 09:55:16.925693  5898 http.cpp:1026] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 09:55:16.925794  5903 sched.cpp:336] New master detected at master@172.17.0.5:38332
I0817 09:55:16.925827  5898 http.cpp:1047] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0817 09:55:16.925889  5903 sched.cpp:407] Authenticating with master master@172.17.0.5:38332
I0817 09:55:16.925911  5903 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0817 09:55:16.926147  5893 authenticatee.cpp:121] Creating new client SASL connection
I0817 09:55:16.926414  5906 master.cpp:7837] Authenticating scheduler-eff6bff9-ad3f-44e7-8b3e-9062b1c0cd32@172.17.0.5:38332
I0817 09:55:16.926529  5900 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1067)@172.17.0.5:38332
I0817 09:55:16.926753  5895 authenticator.cpp:98] Creating new server SASL connection
I0817 09:55:16.926939  5901 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0817 09:55:16.926976  5901 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0817 09:55:16.927094  5901 authenticator.cpp:204] Received SASL authentication start
I0817 09:55:16.927170  5901 authenticator.cpp:326] Authentication requires more steps
I0817 09:55:16.927284  5891 authenticatee.cpp:259] Received SASL authentication step
I0817 09:55:16.927395  5897 authenticator.cpp:232] Received SASL authentication step
I0817 09:55:16.927430  5897 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '38b2174bc306' server FQDN: '38b2174bc306' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0817 09:55:16.927445  5897 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0817 09:55:16.927487  5897 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0817 09:55:16.927508  5897 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '38b2174bc306' server FQDN: '38b2174bc306' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0817 09:55:16.927520  5897 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0817 09:55:16.927527  5897 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0817 09:55:16.927544  5897 authenticator.cpp:318] Authentication success
I0817 09:55:16.927615  5894 authenticatee.cpp:299] Authentication success
I0817 09:55:16.927491  5898 slave.cpp:565] 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"}]
I0817 09:55:16.927691  5899 master.cpp:7867] Successfully authenticated principal 'test-principal' at scheduler-eff6bff9-ad3f-44e7-8b3e-9062b1c0cd32@172.17.0.5:38332
I0817 09:55:16.927711  5894 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1067)@172.17.0.5:38332
I0817 09:55:16.927716  5898 slave.cpp:573] Agent attributes: [  ]
I0817 09:55:16.927757  5898 slave.cpp:582] Agent hostname: 38b2174bc306
I0817 09:55:16.927884  5893 status_update_manager.cpp:177] Pausing sending status updates
I0817 09:55:16.927909  5897 sched.cpp:513] Successfully authenticated with master master@172.17.0.5:38332
I0817 09:55:16.927978  5897 sched.cpp:836] Sending SUBSCRIBE call to master@172.17.0.5:38332
I0817 09:55:16.928113  5897 sched.cpp:869] Will retry registration in 1.76541175secs if necessary
I0817 09:55:16.928268  5900 master.cpp:2894] Received SUBSCRIBE call for framework 'default' at scheduler-eff6bff9-ad3f-44e7-8b3e-9062b1c0cd32@172.17.0.5:38332
I0817 09:55:16.928292  5900 master.cpp:2228] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
I0817 09:55:16.928771  5902 master.cpp:2974] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
I0817 09:55:16.929203  5892 state.cpp:64] Recovering state from '/tmp/SlaveTest_ContainersEndpoint_0uRUUQ/meta'
I0817 09:55:16.929486  5905 hierarchical.cpp:303] Added framework 1a831787-1931-495d-bf08-13faa009fdad-0000
I0817 09:55:16.929497  5893 status_update_manager.cpp:203] Recovering status update manager
I0817 09:55:16.929621  5899 sched.cpp:759] Framework registered with 1a831787-1931-495d-bf08-13faa009fdad-0000
I0817 09:55:16.929673  5905 hierarchical.cpp:1925] No allocations performed
I0817 09:55:16.929719  5905 hierarchical.cpp:2015] No inverse offers to send out!
I0817 09:55:16.929733  5899 sched.cpp:773] Scheduler::registered took 86155ns
I0817 09:55:16.929761  5905 hierarchical.cpp:1468] Performed allocation for 0 agents in 145491ns
I0817 09:55:16.929945  5897 slave.cpp:6210] Finished recovery
I0817 09:55:16.930393  5897 slave.cpp:6392] Querying resource estimator for oversubscribable resources
I0817 09:55:16.930601  5897 slave.cpp:971] New master detected at master@172.17.0.5:38332
I0817 09:55:16.930613  5891 status_update_manager.cpp:177] Pausing sending status updates
I0817 09:55:16.930696  5897 slave.cpp:1006] Detecting new master
I0817 09:55:16.930826  5897 slave.cpp:6406] Received oversubscribable resources {} from the resource estimator
I0817 09:55:16.933969  5902 slave.cpp:1033] Authenticating with master master@172.17.0.5:38332
I0817 09:55:16.934051  5902 slave.cpp:1044] Using default CRAM-MD5 authenticatee
I0817 09:55:16.934293  5906 authenticatee.cpp:121] Creating new client SASL connection
I0817 09:55:16.934597  5904 master.cpp:7837] Authenticating slave(532)@172.17.0.5:38332
I0817 09:55:16.934746  5893 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1068)@172.17.0.5:38332
I0817 09:55:16.935016  5895 authenticator.cpp:98] Creating new server SASL connection
I0817 09:55:16.935262  5892 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0817 09:55:16.935302  5892 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0817 09:55:16.935417  5892 authenticator.cpp:204] Received SASL authentication start
I0817 09:55:16.935489  5892 authenticator.cpp:326] Authentication requires more steps
I0817 09:55:16.935606  5894 authenticatee.cpp:259] Received SASL authentication step
I0817 09:55:16.935806  5894 authenticator.cpp:232] Received SASL authentication step
I0817 09:55:16.935847  5894 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '38b2174bc306' server FQDN: '38b2174bc306' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0817 09:55:16.935869  5894 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0817 09:55:16.935927  5894 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0817 09:55:16.935982  5894 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '38b2174bc306' server FQDN: '38b2174bc306' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0817 09:55:16.936034  5894 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0817 09:55:16.936051  5894 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0817 09:55:16.936074  5894 authenticator.cpp:318] Authentication success
I0817 09:55:16.936266  5900 authenticatee.cpp:299] Authentication success
I0817 09:55:16.936286  5905 master.cpp:7867] Successfully authenticated principal 'test-principal' at slave(532)@172.17.0.5:38332
I0817 09:55:16.936342  5894 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1068)@172.17.0.5:38332
I0817 09:55:16.936578  5900 slave.cpp:1128] Successfully authenticated with master master@172.17.0.5:38332
I0817 09:55:16.936811  5900 slave.cpp:1572] Will retry registration in 13.99687ms if necessary
I0817 09:55:16.937021  5906 master.cpp:5712] Received register agent message from slave(532)@172.17.0.5:38332 (38b2174bc306)
I0817 09:55:16.937072  5906 master.cpp:3803] Authorizing agent with principal 'test-principal'
I0817 09:55:16.937479  5904 master.cpp:5772] Authorized registration of agent at slave(532)@172.17.0.5:38332 (38b2174bc306)
I0817 09:55:16.937592  5904 master.cpp:5865] Registering agent at slave(532)@172.17.0.5:38332 (38b2174bc306) with id 1a831787-1931-495d-bf08-13faa009fdad-S0
I0817 09:55:16.938019  5895 registrar.cpp:495] Applied 1 operations in 96351ns; attempting to update the registry
I0817 09:55:16.938684  5895 registrar.cpp:552] Successfully updated the registry in 598016ns
I0817 09:55:16.938895  5891 master.cpp:5912] Admitted agent 1a831787-1931-495d-bf08-13faa009fdad-S0 at slave(532)@172.17.0.5:38332 (38b2174bc306)
I0817 09:55:16.939540  5902 slave.cpp:4887] Received ping from slave-observer(505)@172.17.0.5:38332
I0817 09:55:16.939486  5891 master.cpp:5943] Registered agent 1a831787-1931-495d-bf08-13faa009fdad-S0 at slave(532)@172.17.0.5:38332 (38b2174bc306) 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"}]
I0817 09:55:16.939725  5902 slave.cpp:1174] Registered with master master@172.17.0.5:38332; given agent ID 1a831787-1931-495d-bf08-13faa009fdad-S0
I0817 09:55:16.939843  5891 status_update_manager.cpp:184] Resuming sending status updates
I0817 09:55:16.940168  5898 hierarchical.cpp:593] Added agent 1a831787-1931-495d-bf08-13faa009fdad-S0 (38b2174bc306) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I0817 09:55:16.940285  5902 slave.cpp:1194] Checkpointing SlaveInfo to '/tmp/SlaveTest_ContainersEndpoint_0uRUUQ/meta/slaves/1a831787-1931-495d-bf08-13faa009fdad-S0/slave.info'
I0817 09:55:16.940639  5902 slave.cpp:1232] Forwarding total oversubscribed resources {}
I0817 09:55:16.940822  5906 master.cpp:6688] Received update of agent 1a831787-1931-495d-bf08-13faa009fdad-S0 at slave(532)@172.17.0.5:38332 (38b2174bc306) with total oversubscribed resources {}
I0817 09:55:16.941542  5898 hierarchical.cpp:2015] No inverse offers to send out!
I0817 09:55:16.941606  5898 hierarchical.cpp:1468] Performed allocation for 1 agents in 1.220877ms
I0817 09:55:16.941799  5898 hierarchical.cpp:660] Agent 1a831787-1931-495d-bf08-13faa009fdad-S0 (38b2174bc306) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0817 09:55:16.942047  5893 master.cpp:7667] Sending 1 offers to framework 1a831787-1931-495d-bf08-13faa009fdad-0000 (default) at scheduler-eff6bff9-ad3f-44e7-8b3e-9062b1c0cd32@172.17.0.5:38332
I0817 09:55:16.942556  5893 sched.cpp:933] Scheduler::resourceOffers took 109484ns
I0817 09:55:16.944998  5900 master.cpp:9164] Removing offer 1a831787-1931-495d-bf08-13faa009fdad-O0
I0817 09:55:16.945185  5900 master.cpp:4153] Processing ACCEPT call for offers: [ 1a831787-1931-495d-bf08-13faa009fdad-O0 ] on agent 1a831787-1931-495d-bf08-13faa009fdad-S0 at slave(532)@172.17.0.5:38332 (38b2174bc306) for framework 1a831787-1931-495d-bf08-13faa009fdad-0000 (default) at scheduler-eff6bff9-ad3f-44e7-8b3e-9062b1c0cd32@172.17.0.5:38332
I0817 09:55:16.945307  5900 master.cpp:3530] Authorizing framework principal 'test-principal' to launch task 1
I0817 09:55:16.945588  5900 master.cpp:3530] Authorizing framework principal 'test-principal' to launch task 2
W0817 09:55:16.947470  5900 validation.cpp:1294] Executor 'executor-1' for task '1' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0817 09:55:16.947515  5900 validation.cpp:1306] Executor 'executor-1' for task '1' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0817 09:55:16.947938  5900 master.cpp:9724] Adding task 1 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 1a831787-1931-495d-bf08-13faa009fdad-S0 at slave(532)@172.17.0.5:38332 (38b2174bc306)
I0817 09:55:16.948374  5900 master.cpp:4816] Launching task 1 of framework 1a831787-1931-495d-bf08-13faa009fdad-0000 (default) at scheduler-eff6bff9-ad3f-44e7-8b3e-9062b1c0cd32@172.17.0.5:38332 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 1a831787-1931-495d-bf08-13faa009fdad-S0 at slave(532)@172.17.0.5:38332 (38b2174bc306)
I0817 09:55:16.949018  5899 slave.cpp:1701] Got assigned task '1' for framework 1a831787-1931-495d-bf08-13faa009fdad-0000
W0817 09:55:16.949630  5900 validation.cpp:1294] Executor 'executor-2' for task '2' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0817 09:55:16.949672  5900 validation.cpp:1306] Executor 'executor-2' for task '2' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0817 09:55:16.949746  5899 slave.cpp:1982] Authorizing task '1' for framework 1a831787-1931-495d-bf08-13faa009fdad-0000
I0817 09:55:16.949836  5899 slave.cpp:6709] Authorizing framework principal 'test-principal' to launch task 1
I0817 09:55:16.950191  5900 master.cpp:9724] Adding task 2 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 1a831787-1931-495d-bf08-13faa009fdad-S0 at slave(532)@172.17.0.5:38332 (38b2174bc306)
I0817 09:55:16.950729  5901 slave.cpp:2169] Launching task '1' for framework 1a831787-1931-495d-bf08-13faa009fdad-0000
I0817 09:55:16.950592  5900 master.cpp:4816] Launching task 2 of framework 1a831787-1931-495d-bf08-13faa009fdad-0000 (default) at scheduler-eff6bff9-ad3f-44e7-8b3e-9062b1c0cd32@172.17.0.5:38332 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 1a831787-1931-495d-bf08-13faa009fdad-S0 at slave(532)@172.17.0.5:38332 (38b2174bc306)
I0817 09:55:16.951341  5901 paths.cpp:578] Trying to chown '/tmp/SlaveTest_ContainersEndpoint_0uRUUQ/slaves/1a831787-1931-495d-bf08-13faa009fdad-S0/frameworks/1a831787-1931-495d-bf08-13faa009fdad-0000/executors/executor-1/runs/b7e26b37-d308-4a75-86b6-b19484a29933' to user 'mesos'
I0817 09:55:16.951601  5901 slave.cpp:7165] Launching executor 'executor-1' of framework 1a831787-1931-495d-bf08-13faa009fdad-0000 with resources [] in work directory '/tmp/SlaveTest_ContainersEndpoint_0uRUUQ/slaves/1a831787-1931-495d-bf08-13faa009fdad-S0/frameworks/1a831787-1931-495d-bf08-13faa009fdad-0000/executors/executor-1/runs/b7e26b37-d308-4a75-86b6-b19484a29933'
I0817 09:55:16.952388  5901 slave.cpp:2398] Queued task '1' for executor 'executor-1' of framework 1a831787-1931-495d-bf08-13faa009fdad-0000
I0817 09:55:16.952608  5895 hierarchical.cpp:887] Updated allocation of framework 1a831787-1931-495d-bf08-13faa009fdad-0000 on agent 1a831787-1931-495d-bf08-13faa009fdad-S0 from cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] to cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000]
I0817 09:55:16.952673  5901 slave.cpp:1701] Got assigned task '2' for framework 1a831787-1931-495d-bf08-13faa009fdad-0000
I0817 09:55:16.953059  5901 slave.cpp:924] Successfully attached file '/tmp/SlaveTest_ContainersEndpoint_0uRUUQ/slaves/1a831787-1931-495d-bf08-13faa009fdad-S0/frameworks/1a831787-1931-495d-bf08-13faa009fdad-0000/executors/executor-1/runs/b7e26b37-d308-4a75-86b6-b19484a29933'
I0817 09:55:16.953100  5901 slave.cpp:924] Successfully attached file '/tmp/SlaveTest_ContainersEndpoint_0uRUUQ/slaves/1a831787-1931-495d-bf08-13faa009fdad-S0/frameworks/1a831787-1931-495d-bf08-13faa009fdad-0000/executors/executor-1/runs/b7e26b37-d308-4a75-86b6-b19484a29933'
I0817 09:55:16.953306  5901 slave.cpp:2856] Launching container b7e26b37-d308-4a75-86b6-b19484a29933 for executor 'executor-1' of framework 1a831787-1931-495d-bf08-13faa009fdad-0000
I0817 09:55:16.953356  5895 hierarchical.cpp:1152] 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 1a831787-1931-495d-bf08-13faa009fdad-S0 from framework 1a831787-1931-495d-bf08-13faa009fdad-0000
I0817 09:55:16.953413  5895 hierarchical.cpp:1189] Framework 1a831787-1931-495d-bf08-13faa009fdad-0000 filtered agent 1a831787-1931-495d-bf08-13faa009fdad-S0 for 5secs
I0817 09:55:16.953589  5901 slave.cpp:1982] Authorizing task '2' for framework 1a831787-1931-495d-bf08-13faa009fdad-0000
I0817 09:55:16.953645  5901 slave.cpp:6709] Authorizing framework principal 'test-principal' to launch task 2
I0817 09:55:16.954429  5893 slave.cpp:2169] Launching task '2' for framework 1a831787-1931-495d-bf08-13faa009fdad-0000
I0817 09:55:16.954814  5893 paths.cpp:578] Trying to chown '/tmp/SlaveTest_ContainersEndpoint_0uRUUQ/slaves/1a831787-1931-495d-bf08-13faa009fdad-S0/frameworks/1a831787-1931-495d-bf08-13faa009fdad-0000/executors/executor-2/runs/aaa3418c-fa1e-494c-a237-247264acbbdd' to user 'mesos'
I0817 09:55:16.955008  5893 slave.cpp:7165] Launching executor 'executor-2' of framework 1a831787-1931-495d-bf08-13faa009fdad-0000 with resources [] in work directory '/tmp/SlaveTest_ContainersEndpoint_0uRUUQ/slaves/1a831787-1931-495d-bf08-13faa009fdad-S0/frameworks/1a831787-1931-495d-bf08-13faa009fdad-0000/executors/executor-2/runs/aaa3418c-fa1e-494c-a237-247264acbbdd'
I0817 09:55:16.955554  5893 slave.cpp:2398] Queued task '2' for executor 'executor-2' of framework 1a831787-1931-495d-bf08-13faa009fdad-0000
I0817 09:55:16.955637  5893 slave.cpp:924] Successfully attached file '/tmp/SlaveTest_ContainersEndpoint_0uRUUQ/slaves/1a831787-1931-495d-bf08-13faa009fdad-S0/frameworks/1a831787-1931-495d-bf08-13faa009fdad-0000/executors/executor-2/runs/aaa3418c-fa1e-494c-a237-247264acbbdd'
*** Aborted at 1502963716 (unix time) try "date -d @1502963716" if you are using GNU date ***
PC: @     0x2b1e8e81482d (unknown)
I0817 09:55:16.956212  5891 process.cpp:3228] Attempting to spawn already spawned process version@172.17.0.5:38332
I0817 09:55:16.956398  5891 exec.cpp:162] Version: 1.4.0
I0817 09:55:16.956671  5894 exec.cpp:212] Executor started at: executor(136)@172.17.0.5:38332 with pid 5873
*** SIGSEGV (@0x31) received by PID 5873 (TID 0x2b1e97968700) from PID 49; stack trace: ***
    @     0x2b1ee47d9417 (unknown)
    @     0x2b1ee47dd6f9 (unknown)
    @     0x2b1e8e5cb330 (unknown)
    @     0x2b1e8e81482d (unknown)
    @     0x2b1e82d07ea8 os::getenv()
    @     0x2b1e8a55f35b mesos::internal::slave::executorEnvironment()
    @     0x2b1e8a55b699 mesos::internal::slave::Slave::launchExecutor()
    @     0x2b1e8a618b98 _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERK6OptionINS_6FutureINS1_6SecretEEEERKNS1_11FrameworkIDERKNS1_10ExecutorIDERKS5_INS1_8TaskInfoEESB_SE_SH_SL_EEvRKNS_3PIDIT_EEMSN_FvT0_T1_T2_T3_EOT4_OT5_OT6_OT7_ENKUlRS9_RSC_RSF_RSJ_PNS_11ProcessBaseEE_clES15_S16_S17_S18_S1A_
    @     0x2b1e8a618a0b _ZNSt5_BindIFZN7process8dispatchIN5mesos8internal5slave5SlaveERK6OptionINS0_6FutureINS2_6SecretEEEERKNS2_11FrameworkIDERKNS2_10ExecutorIDERKS6_INS2_8TaskInfoEESC_SF_SI_SM_EEvRKNS0_3PIDIT_EEMSO_FvT0_T1_T2_T3_EOT4_OT5_OT6_OT7_EUlRSA_RSD_RSG_RSK_PNS0_11ProcessBaseEE_SA_SD_SG_SK_St12_PlaceholderILi1EEEE6__callIvJOS1B_EJLm0ELm1ELm2ELm3ELm4EEEESO_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE
    @     0x2b1e8a618906 _ZNSt5_BindIFZN7process8dispatchIN5mesos8internal5slave5SlaveERK6OptionINS0_6FutureINS2_6SecretEEEERKNS2_11FrameworkIDERKNS2_10ExecutorIDERKS6_INS2_8TaskInfoEESC_SF_SI_SM_EEvRKNS0_3PIDIT_EEMSO_FvT0_T1_T2_T3_EOT4_OT5_OT6_OT7_EUlRSA_RSD_RSG_RSK_PNS0_11ProcessBaseEE_SA_SD_SG_SK_St12_PlaceholderILi1EEEEclIJS1B_EvEESS_DpOT_
    @     0x2b1e8a6183bf _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEESt5_BindIFZNS0_8dispatchIN5mesos8internal5slave5SlaveERK6OptionINS0_6FutureINS6_6SecretEEEERKNS6_11FrameworkIDERKNS6_10ExecutorIDERKSA_INS6_8TaskInfoEESG_SJ_SM_SQ_EEvRKNS0_3PIDIT_EEMSS_FvT0_T1_T2_T3_EOT4_OT5_OT6_OT7_EUlRSE_RSH_RSK_RSO_S2_E_SE_SH_SK_SO_St12_PlaceholderILi1EEEEE9_M_invokeERKSt9_Any_dataS2_
    @     0x2b1e8b8ee8c4 std::function<>::operator()()
    @     0x2b1e8b8d27b4 process::ProcessBase::visit()
    @     0x2b1e8b95dbbe process::DispatchEvent::visit()
    @     0x2b1e82ced4b1 process::ProcessBase::serve()
    @     0x2b1e8b8d0143 process::ProcessManager::resume()
    @     0x2b1e8b8dfcf1 process::ProcessManager::init_threads()::$_9::operator()()
    @     0x2b1e8b8dfc35 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvE3$_9vEE9_M_invokeIJEEEvSt12_Index_tupleIJXspT_EEE
    @     0x2b1e8b8dfc05 std::_Bind_simple<>::operator()()
    @     0x2b1e8b8dfbdc std::thread::_Impl<>::_M_run()
    @     0x2b1e8de4ca60 (unknown)
    @     0x2b1e8e5c3184 start_thread
    @     0x2b1e8e8d6ffd (unknown)
make[4]: *** [check-local] Segmentation fault
make[4]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.4.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1502960416-8874
Untagged: mesos-1502960416-8874:latest
Deleted: sha256:9390819a664d330a99266df3b51430a49ede966d3d1638c28d4b39391d915c49
Deleted: sha256:b842f26962b807b898a91bdffeb3a7da4361ed158aa4e303e9e2a51fed37641d
Deleted: sha256:9fd579257c31edb0791a1f91d05465aea1ddf790b11f9d35ba02fcdc78750a19
Deleted: sha256:92b126d50065c6fa0e61ab75678178b44bd3396e3db534c71b74c45c2d87be7d
Deleted: sha256:6510fd612711a2d9c50812b4dd6543a9e25c3a9ea427c317cd38ae7ecf559e76
Deleted: sha256:3a4924e6c3cf2ead9880448a5374b5e91227e2269551f89852fbb8877927b58e
Deleted: sha256:e6c1b01f84eb42872c3a8c2fae739cb69f355c73584fdc1d9f893e4ffab11c8a
Deleted: sha256:83648a1d4585f8ea8c262b69b4c23d5f3d3d5e1a58377f0b347151b781264b1e
Deleted: sha256:96cb107a0d660ad94729a58c00b6120d8f31228ae45fcbd37f2506a6a6bc0584
Deleted: sha256:f762c94d19e4c2c385ab023ac48144b8481decbc51cca944530c314adc6fc1b5
Deleted: sha256:8fa2a93b27c8b7975f83c56227cd7d19b5ff8387f114657af99552facfef8882
Deleted: sha256:8a183a8465e1a3b05d187420d7f79054165450fd322c38b805220fa4a5af3362
Deleted: sha256:2012a77a2a322275b901a12e3e51e24875153cbd4315bfc6e9679fe247a4c2d3
Deleted: sha256:f085c36a1a5530538ce77ce3613b0b09626b44a8034b32442e4adb75ccb54759
Deleted: sha256:0a085d72f29f970016b071407bfe614b1bd6c0e552ccaf1124f5854f2c11c9b2
Deleted: sha256:ee7604875800e0dfd2c938a150cec43801e62e30e9094851cf8bd4fd4c98f383
Deleted: sha256:f8457fdd81efadd6b6503d56ae99756b46292f963e6482ea047dc9768b1bfca0
Deleted: sha256:c4690948400bcaefa1eff2cb36d1160cfdcc27f728ce4ef40a0f517ee83a6c56
Deleted: sha256:77adef2e878cd745ad9f27d4ff17bd58aba371cc55ca2decac949ed7bd7f827a
Deleted: sha256:a677dc5a99833469652831581be21a9a3f67bdc1e3996c6e317f2e06f4aef0b7
Deleted: sha256:a44f654b15a4b9e1ded0ec187e92c504472a9cb59a307856ac87584933992f24
Deleted: sha256:3f69815d637d12fc2ca9bf1bde4a436f1f5140b301f7bc65a645ea68e9d301f7
Deleted: sha256:edb8a5cbd3ff7c701be152f4b5820e7887c3eadb0ada786a66d5f18cb35567bc
Deleted: sha256:1ca782bd3f5731f3aebbef3ae21699159d97724b95e743d881aac55f5c0d9459
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user songzihao1990@gmail.com

Re: Build failed in Jenkins: Mesos-Buildbot » autotools,clang,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #4118

Posted by Benjamin Mahler <bm...@apache.org>.
+benh

Ah I just realized the bottom of the trace has 'start_thread'.

Also, looking around I seem to see thread related examples:
https://stackoverflow.com/a/43684739 (mutex is destroyed when trying to
lock it)
https://stackoverflow.com/a/24169262 (calling join too many times)
https://stackoverflow.com/a/21084585 (join non-running thread)
https://stackoverflow.com/a/37891781 (joining default constructed thread)

I wonder if this is related to the EventQueue crash in CI.

On Fri, Oct 20, 2017 at 4:36 PM, Benjamin Mahler <bm...@apache.org> wrote:

> Anyone know what std::system_error with 'Invalid argument' might mean? Or
> why we're getting a stack trace entirely of '(Unknown)'?
>
> I've actually seen the same crash in a scale test cluster, would be great
> if anyone has any ideas here.
>
>
> On Wed, Aug 16, 2017 at 6:00 PM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
>> See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=auto
>> tools,COMPILER=clang,CONFIGURATION=--verbose%20--enable-libe
>> vent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,
>> OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!
>> ubuntu-eu2)/4118/display/redirect?page=changes>
>>
>> Changes:
>>
>> [anand] Fixed a bug around `kill()` not removing active containers.
>>
>> ------------------------------------------
>> [...truncated 21.31 MB...]
>> I0817 01:00:05.801321 6737 hierarchical.cpp:1943] No allocations
>> performed
>> I0817 01:00:05.801424  6737 hierarchical.cpp:2033] No inverse offers to
>> send out!
>> I0817 01:00:05.801476  6737 hierarchical.cpp:1486] Performed allocation
>> for 1 agents in 303266ns
>> I0817 01:00:06.316730  6724 slave.cpp:4273] Cleaning up un-reregistered
>> executors
>> I0817 01:00:06.316900  6724 slave.cpp:6210] Finished recovery
>> I0817 01:00:06.317662  6724 slave.cpp:6392] Querying resource estimator
>> for oversubscribable resources
>> I0817 01:00:06.317929  6745 status_update_manager.cpp:177] Pausing
>> sending status updates
>> I0817 01:00:06.317962  6725 slave.cpp:971] New master detected at
>> master@172.17.0.8:40444
>> I0817 01:00:06.318066  6725 slave.cpp:1006] Detecting new master
>> I0817 01:00:06.318202  6725 slave.cpp:6406] Received oversubscribable
>> resources {} from the resource estimator
>> I0817 01:00:06.324371  6723 slave.cpp:1033] Authenticating with master
>> master@172.17.0.8:40444
>> I0817 01:00:06.324511  6723 slave.cpp:1044] Using default CRAM-MD5
>> authenticatee
>> I0817 01:00:06.324862  6740 authenticatee.cpp:121] Creating new client
>> SASL connection
>> I0817 01:00:06.325322  6729 master.cpp:7837] Authenticating slave(478)@
>> 172.17.0.8:40444
>> I0817 01:00:06.325479 6730 authenticator.cpp:414] Starting
>> authentication session for crammd5-authenticatee(993)@172.17.0.8:40444
>> I0817 01:00:06.325743 6722 authenticator.cpp:98] Creating new server
>> SASL connection
>> I0817 01:00:06.326010  6739 authenticatee.cpp:213] Received SASL
>> authentication mechanisms: CRAM-MD5
>> I0817 01:00:06.326045  6739 authenticatee.cpp:239] Attempting to
>> authenticate with mechanism 'CRAM-MD5'
>> I0817 01:00:06.326155  6739 authenticator.cpp:204] Received SASL
>> authentication start
>> I0817 01:00:06.326222  6739 authenticator.cpp:326] Authentication
>> requires more steps
>> I0817 01:00:06.326323  6728 authenticatee.cpp:259] Received SASL
>> authentication step
>> I0817 01:00:06.326432  6727 authenticator.cpp:232] Received SASL
>> authentication step
>> I0817 01:00:06.326464  6727 auxprop.cpp:109] Request to lookup properties
>> for user: 'test-principal' realm: '45197c1facb6' server FQDN:
>> '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
>> I0817 01:00:06.326478  6727 auxprop.cpp:181] Looking up auxiliary
>> property '*userPassword'
>> I0817 01:00:06.326519  6727 auxprop.cpp:181] Looking up auxiliary
>> property '*cmusaslsecretCRAM-MD5'
>> I0817 01:00:06.326539  6727 auxprop.cpp:109] Request to lookup properties
>> for user: 'test-principal' realm: '45197c1facb6' server FQDN:
>> '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
>> I0817 01:00:06.326550  6727 auxprop.cpp:131] Skipping auxiliary property
>> '*userPassword' since SASL_AUXPROP_AUTHZID == true
>> I0817 01:00:06.326558  6727 auxprop.cpp:131] Skipping auxiliary property
>> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
>> I0817 01:00:06.326575  6727 authenticator.cpp:318] Authentication success
>> I0817 01:00:06.326709  6726 authenticatee.cpp:299] Authentication success
>> I0817 01:00:06.326738  6742 master.cpp:7867] Successfully authenticated
>> principal 'test-principal' at slave(478)@172.17.0.8:40444
>> I0817 01:00:06.326762  6734 authenticator.cpp:432] Authentication session
>> cleanup for crammd5-authenticatee(993)@172.17.0.8:40444
>> I0817 01:00:06.326993  6737 slave.cpp:1128] Successfully authenticated
>> with master master@172.17.0.8:40444
>> I0817 01:00:06.327518  6737 slave.cpp:1572] Will retry registration in
>> 14.251184ms if necessary
>> I0817 01:00:06.328802  6736 master.cpp:6012] Received re-register agent
>> message from agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@
>> 172.17.0.8:40444 (45197c1facb6)
>> I0817 01:00:06.328842  6736 master.cpp:3803] Authorizing agent with
>> principal 'test-principal'
>> I0817 01:00:06.329376  6736 master.cpp:6081] Authorized re-registration
>> of agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@
>> 172.17.0.8:40444 (45197c1facb6)
>> I0817 01:00:06.329483  6736 master.cpp:6146] Re-registering agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(477)@172.17.0.8:40444
>> (45197c1facb6)
>> I0817 01:00:06.329792  6730 slave.cpp:1275] Re-registered with master
>> master@172.17.0.8:40444
>> I0817 01:00:06.329824  6722 hierarchical.cpp:678] Agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0 reactivated
>> I0817 01:00:06.329856  6736 master.cpp:6586] Sending updated checkpointed
>> resources {} to agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at
>> slave(478)@172.17.0.8:40444 (45197c1facb6)
>> I0817 01:00:06.329866  6722 status_update_manager.cpp:184] Resuming
>> sending status updates
>> I0817 01:00:06.329885  6730 slave.cpp:1312] Forwarding total
>> oversubscribed resources {}
>> W0817 01:00:06.329907  6722 status_update_manager.cpp:191] Resending
>> status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566)
>> for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.329957  6722 status_update_manager.cpp:377] Forwarding
>> update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for
>> task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to the agent
>> I0817 01:00:06.330029  6736 master.cpp:6688] Received update of agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444
>> (45197c1facb6) with total oversubscribed resources {}
>> I0817 01:00:06.330075  6730 slave.cpp:3330] Updating info for framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 with pid updated to
>> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
>> I0817 01:00:06.330152  6730 slave.cpp:7084] Checkpointing FrameworkInfo
>> to '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556
>> -5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44c
>> a-be07-44edbcb8751c-0000/framework.info'
>> I0817 01:00:06.330344 6728 hierarchical.cpp:660] Agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0 (45197c1facb6) updated with
>> total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
>> I0817 01:00:06.330607  6730 slave.cpp:7095] Checkpointing framework pid '
>> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444' to
>> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556
>> -5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44c
>> a-be07-44edbcb8751c-0000/framework.pid'
>> I0817 01:00:06.330912  6727 status_update_manager.cpp:184] Resuming
>> sending status updates
>> W0817 01:00:06.330937  6727 status_update_manager.cpp:191] Resending
>> status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566)
>> for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.330953  6730 slave.cpp:3394] Ignoring new checkpointed
>> resources identical to the current version: {}
>> I0817 01:00:06.330968  6727 status_update_manager.cpp:377] Forwarding
>> update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for
>> task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to the agent
>> I0817 01:00:06.331070  6730 slave.cpp:4797] Forwarding the update
>> TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to master@172.17.0.8:40444
>> I0817 01:00:06.331285 6730 slave.cpp:4797] Forwarding the update
>> TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to master@172.17.0.8:40444
>> I0817 01:00:06.331362 6726 master.cpp:6846] Status update TASK_RUNNING
>> (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 from agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444
>> (45197c1facb6)
>> I0817 01:00:06.331408 6726 master.cpp:6908] Forwarding status update
>> TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.331564  6726 master.cpp:8933] Updating the state of task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (latest state: TASK_FAILED,
>> status update state: TASK_RUNNING)
>> I0817 01:00:06.331709  6744 sched.cpp:1041] Scheduler::statusUpdate took
>> 41560ns
>> I0817 01:00:06.332159  6726 master.cpp:6846] Status update TASK_RUNNING
>> (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 from agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444
>> (45197c1facb6)
>> I0817 01:00:06.332201 6726 master.cpp:6908] Forwarding status update
>> TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.332340  6726 master.cpp:8933] Updating the state of task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (latest state: TASK_FAILED,
>> status update state: TASK_RUNNING)
>> I0817 01:00:06.332479  6733 sched.cpp:1041] Scheduler::statusUpdate took
>> 23192ns
>> I0817 01:00:06.332495  6726 master.cpp:5477] Processing ACKNOWLEDGE call
>> 6298f06a-4d56-49b0-ae14-12a4fd774566 for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
>> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444 on agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0
>> I0817 01:00:06.332500 6742 hierarchical.cpp:1161] 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 56b17556-5965-44ca-be07-44edbcb8751c-S0
>> from framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.332691  6726 master.cpp:5477] Processing ACKNOWLEDGE call
>> 6298f06a-4d56-49b0-ae14-12a4fd774566 for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
>> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444 on agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0
>> I0817 01:00:06.332728 6734 status_update_manager.cpp:395] Received
>> status update acknowledgement (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566)
>> for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.332854  6734 status_update_manager.cpp:834] Checkpointing
>> ACK for status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566)
>> for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.332988  6734 status_update_manager.cpp:377] Forwarding
>> update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to the agent
>> I0817 01:00:06.333187  6724 slave.cpp:4797] Forwarding the update
>> TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to master@172.17.0.8:40444
>> I0817 01:00:06.333245  6734 status_update_manager.cpp:395] Received
>> status update acknowledgement (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566)
>> for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> W0817 01:00:06.333329  6734 status_update_manager.cpp:763] Duplicate
>> status update acknowledgment (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566)
>> for update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for
>> task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.333354  6724 slave.cpp:3609] Status update manager
>> successfully handled status update acknowledgement (UUID:
>> 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> E0817 01:00:06.333447  6724 slave.cpp:3602] Failed to handle status
>> update acknowledgement (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for
>> task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000: Duplicate acknowledgement
>> I0817 01:00:06.333453  6738 master.cpp:6846] Status update TASK_FAILED
>> (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 from agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444
>> (45197c1facb6)
>> I0817 01:00:06.333504  6738 master.cpp:6908] Forwarding status update
>> TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.333643  6738 master.cpp:8933] Updating the state of task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (latest state: TASK_FAILED,
>> status update state: TASK_FAILED)
>> I0817 01:00:06.333762  6732 sched.cpp:1041] Scheduler::statusUpdate took
>> 39113ns
>> I0817 01:00:06.333951  6745 master.cpp:5477] Processing ACKNOWLEDGE call
>> b29e6cb2-8461-43c6-b252-a7b4619bd9d4 for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
>> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444 on agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0
>> I0817 01:00:06.334004  6745 master.cpp:9027] Removing task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 with resources
>> [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"va
>> lue":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"
>> name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"all
>> ocation_info":{"role":"*"},"name":"disk","scalar":{"value"
>> :1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"
>> name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
>> of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 on agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444
>> (45197c1facb6)
>> I0817 01:00:06.334609 6735 status_update_manager.cpp:395] Received
>> status update acknowledgement (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4)
>> for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.334683  6735 status_update_manager.cpp:834] Checkpointing
>> ACK for status update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4)
>> for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.334759  6735 status_update_manager.cpp:531] Cleaning up
>> status update stream for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of
>> framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.335131  6723 slave.cpp:3609] Status update manager
>> successfully handled status update acknowledgement (UUID:
>> b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.335178  6723 slave.cpp:7561] Completing task
>> 334ab1cb-44b2-4676-b2b5-0329c383ac33
>> I0817 01:00:06.335224  6723 slave.cpp:5429] Cleaning up executor
>> '334ab1cb-44b2-4676-b2b5-0329c383ac33' of framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 at executor(1)@172.17.0.8:40576
>> I0817 01:00:06.335512  6740 gc.cpp:59] Scheduling
>> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/slaves/56b17556-5965
>> -44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be0
>> 7-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-b2b5-0329c3
>> 83ac33/runs/85315bbe-bb58-416d-853d-8c17b4a61361' for gc
>> 6.99999611762667days in the future
>> I0817 01:00:06.335686  6729 gc.cpp:59] Scheduling
>> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/slaves/56b17556-5965
>> -44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be0
>> 7-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-b2b5-0329c383ac33' for
>> gc 6.99999611555556days in the future
>> I0817 01:00:06.335827  6729 gc.cpp:59] Scheduling
>> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556
>> -5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44c
>> a-be07-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-b2b5-
>> 0329c383ac33/runs/85315bbe-bb58-416d-853d-8c17b4a61361' for gc
>> 6.99999611430519days in the future
>> I0817 01:00:06.335861  6723 slave.cpp:5525] Cleaning up framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.335929  6729 gc.cpp:59] Scheduling
>> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556
>> -5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44c
>> a-be07-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-b2b5-0329c383ac33'
>> for gc 6.99999611335704days in the future
>> I0817 01:00:06.335980  6731 status_update_manager.cpp:285] Closing status
>> update streams for framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.336024  6729 gc.cpp:59] Scheduling
>> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/slaves/56b17556-5965
>> -44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000'
>> for gc 6.99999611171259days in the future
>> I0817 01:00:06.336120  6729 gc.cpp:59] Scheduling
>> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556
>> -5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000'
>> for gc 6.9999961109363days in the future
>> I0817 01:00:06.802976  6742 hierarchical.cpp:2033] No inverse offers to
>> send out!
>> I0817 01:00:06.803063  6742 hierarchical.cpp:1486] Performed allocation
>> for 1 agents in 1.010273ms
>> I0817 01:00:06.803483  6733 master.cpp:7667] Sending 1 offers to
>> framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
>> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
>> I0817 01:00:06.804096  6741 sched.cpp:933] Scheduler::resourceOffers took
>> 135353ns
>> I0817 01:00:06.804899  6704 sched.cpp:2021] Asked to stop the driver
>> I0817 01:00:06.804999  6738 sched.cpp:1203] Stopping framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.805320  6745 master.cpp:8348] Processing TEARDOWN call for
>> framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
>> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
>> I0817 01:00:06.805352 6745 master.cpp:8360] Removing framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
>> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
>> I0817 01:00:06.805367  6745 master.cpp:3264] Deactivating framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
>> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
>> I0817 01:00:06.805480  6740 hierarchical.cpp:412] Deactivated framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.805881  6745 master.cpp:9164] Removing offer
>> 56b17556-5965-44ca-be07-44edbcb8751c-O1
>> I0817 01:00:06.806056  6739 slave.cpp:3159] Asked to shut down framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000 by master@172.17.0.8:40444
>> I0817 01:00:06.806116  6739 slave.cpp:3174] Cannot shut down unknown
>> framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.806344  6740 hierarchical.cpp:1161] 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 56b17556-5965-44ca-be07-44edbcb8751c-S0
>> from framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.809447  6740 hierarchical.cpp:355] Removed framework
>> 56b17556-5965-44ca-be07-44edbcb8751c-0000
>> I0817 01:00:06.809541  6730 slave.cpp:843] Agent terminating
>> I0817 01:00:06.814934  6704 master.cpp:1160] Master terminating
>> I0817 01:00:06.815558  6739 hierarchical.cpp:626] Removed agent
>> 56b17556-5965-44ca-be07-44edbcb8751c-S0
>> [       OK ] SlaveRecoveryTest/0.Reboot (4030 ms)
>> [ RUN      ] SlaveRecoveryTest/0.RebootWithSlaveInfoMismatch
>> I0817 01:00:06.824440  6704 cluster.cpp:162] Creating default 'local'
>> authorizer
>> I0817 01:00:06.827071  6734 master.cpp:442] Master
>> 66249101-3204-4bec-9632-4a28a9d4b6e5 (45197c1facb6) started on
>> 172.17.0.8:40444
>> I0817 01:00:06.827113  6734 master.cpp:444] 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/Z0ccUv/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="/mesos/mesos-1.4.0/_inst/share/mesos/webui"
>> --work_dir="/tmp/Z0ccUv/master" --zk_session_timeout="10secs"
>> I0817 01:00:06.827448  6734 master.cpp:494] Master only allowing
>> authenticated frameworks to register
>> I0817 01:00:06.827479  6734 master.cpp:508] Master only allowing
>> authenticated agents to register
>> I0817 01:00:06.827493  6734 master.cpp:521] Master only allowing
>> authenticated HTTP frameworks to register
>> I0817 01:00:06.827507  6734 credentials.hpp:37] Loading credentials for
>> authentication from '/tmp/Z0ccUv/credentials'
>> I0817 01:00:06.827826  6734 master.cpp:566] Using default 'crammd5'
>> authenticator
>> I0817 01:00:06.827980  6734 http.cpp:1026] Creating default 'basic' HTTP
>> authenticator for realm 'mesos-master-readonly'
>> I0817 01:00:06.828145  6734 http.cpp:1026] Creating default 'basic' HTTP
>> authenticator for realm 'mesos-master-readwrite'
>> I0817 01:00:06.828272  6734 http.cpp:1026] Creating default 'basic' HTTP
>> authenticator for realm 'mesos-master-scheduler'
>> I0817 01:00:06.828392  6734 master.cpp:646] Authorization enabled
>> I0817 01:00:06.828569  6743 hierarchical.cpp:171] Initialized
>> hierarchical allocator process
>> I0817 01:00:06.828590  6725 whitelist_watcher.cpp:77] No whitelist given
>> I0817 01:00:06.831037  6736 master.cpp:2163] Elected as the leading
>> master!
>> I0817 01:00:06.831063  6736 master.cpp:1702] Recovering from registrar
>> I0817 01:00:06.831159  6728 registrar.cpp:347] Recovering registrar
>> I0817 01:00:06.831712  6728 registrar.cpp:391] Successfully fetched the
>> registry (0B) in 515840ns
>> I0817 01:00:06.831832  6728 registrar.cpp:495] Applied 1 operations in
>> 44686ns; attempting to update the registry
>> I0817 01:00:06.832372  6728 registrar.cpp:552] Successfully updated the
>> registry in 482048ns
>> I0817 01:00:06.832489  6728 registrar.cpp:424] Successfully recovered
>> registrar
>> I0817 01:00:06.832810  6738 master.cpp:1801] Recovered 0 agents from the
>> registry (129B); allowing 10mins for agents to re-register
>> I0817 01:00:06.832854  6744 hierarchical.cpp:209] Skipping recovery of
>> hierarchical allocator: nothing to recover
>> I0817 01:00:06.836031  6704 containerizer.cpp:246] Using isolation:
>> posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
>> W0817 01:00:06.836477  6704 backend.cpp:76] Failed to create 'aufs'
>> backend: AufsBackend requires root privileges
>> W0817 01:00:06.836588  6704 backend.cpp:76] Failed to create 'bind'
>> backend: BindBackend requires root privileges
>> I0817 01:00:06.836623  6704 provisioner.cpp:255] Using default backend
>> 'copy'
>> I0817 01:00:06.840314  6704 process.cpp:3228] Attempting to spawn already
>> spawned process files@172.17.0.8:40444
>> I0817 01:00:06.840575  6704 cluster.cpp:448] Creating default 'local'
>> authorizer
>> I0817 01:00:06.842278  6725 slave.cpp:250] Mesos agent started on (479)@
>> 172.17.0.8:40444
>> I0817 01:00:06.842310  6725 slave.cpp:251] Flags at startup: --acls=""
>> --appc_simple_discovery_uri_prefix="http://"
>> --appc_store_dir="/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/store/appc"
>> --authenticate_http_executors="true" --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/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/credential"
>> --default_role="*" --disallow_sharing_agent_pid_namespace="false"
>> --disk_watch_interval="1mins" --docker="docker"
>> --docker_kill_orphans="true" --docker_registry="https://reg
>> istry-1.docker.io" --docker_remove_delay="6hrs"
>> --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns"
>> --docker_store_dir="/tmp/SlaveRecoveryTest_0_RebootWithSlave
>> InfoMismatch_SEk3BV/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_secret_key="/tmp/SlaveRecoveryTest_0_RebootWithSl
>> aveInfoMismatch_SEk3BV/executor_secret_key"
>> --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/Slav
>> eRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/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/SlaveRecoveryTest_0_RebootWithSlave
>> InfoMismatch_SEk3BV/http_credentials" --http_heartbeat_interval="30secs"
>> --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem"
>> --launcher="posix" --launcher_dir="/mesos/mesos-1.4.0/_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:8;mem:4096;disk:2048"
>> --revocable_cpu_low_priority="true" --runtime_dir="/tmp/SlaveRecov
>> eryTest_0_RebootWithSlaveInfoMismatch_SEk3BV"
>> --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/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_yF46Kd"
>> I0817 01:00:06.842685  6725 credentials.hpp:86] Loading credential for
>> authentication from '/tmp/SlaveRecoveryTest_0_Rebo
>> otWithSlaveInfoMismatch_SEk3BV/credential'
>> I0817 01:00:06.842784  6704 process.cpp:3228] Attempting to spawn already
>> spawned process version@172.17.0.8:40444
>> I0817 01:00:06.842851  6725 slave.cpp:283] Agent using credential for:
>> test-principal
>> I0817 01:00:06.842875  6725 credentials.hpp:37] Loading credentials for
>> authentication from '/tmp/SlaveRecoveryTest_0_Rebo
>> otWithSlaveInfoMismatch_SEk3BV/http_credentials'
>> I0817 01:00:06.843179  6725 http.cpp:1026] Creating default 'basic' HTTP
>> authenticator for realm 'mesos-agent-executor'
>> I0817 01:00:06.843313  6725 http.cpp:1047] Creating default 'jwt' HTTP
>> authenticator for realm 'mesos-agent-executor'
>> I0817 01:00:06.843533  6725 http.cpp:1026] Creating default 'basic' HTTP
>> authenticator for realm 'mesos-agent-readonly'
>> I0817 01:00:06.843629  6725 http.cpp:1047] Creating default 'jwt' HTTP
>> authenticator for realm 'mesos-agent-readonly'
>> I0817 01:00:06.843639  6704 sched.cpp:232] Version: 1.4.0
>> I0817 01:00:06.843857  6725 http.cpp:1026] Creating default 'basic' HTTP
>> authenticator for realm 'mesos-agent-readwrite'
>> I0817 01:00:06.843960  6725 http.cpp:1047] Creating default 'jwt' HTTP
>> authenticator for realm 'mesos-agent-readwrite'
>> I0817 01:00:06.844141  6731 sched.cpp:336] New master detected at
>> master@172.17.0.8:40444
>> I0817 01:00:06.844230  6731 sched.cpp:407] Authenticating with master
>> master@172.17.0.8:40444
>> I0817 01:00:06.844249  6731 sched.cpp:414] Using default CRAM-MD5
>> authenticatee
>> I0817 01:00:06.844457  6738 authenticatee.cpp:121] Creating new client
>> SASL connection
>> I0817 01:00:06.844712  6736 master.cpp:7837] Authenticating
>> scheduler-db03a645-3ff8-4b33-b9cf-8617bdc60875@172.17.0.8:40444
>> I0817 01:00:06.844805  6739 authenticator.cpp:414] Starting
>> authentication session for crammd5-authenticatee(994)@172.17.0.8:40444
>> I0817 01:00:06.845022  6742 authenticator.cpp:98] Creating new server
>> SASL connection
>> I0817 01:00:06.845257  6729 authenticatee.cpp:213] Received SASL
>> authentication mechanisms: CRAM-MD5
>> I0817 01:00:06.845285  6729 authenticatee.cpp:239] Attempting to
>> authenticate with mechanism 'CRAM-MD5'
>> I0817 01:00:06.845379  6730 authenticator.cpp:204] Received SASL
>> authentication start
>> I0817 01:00:06.845227  6725 slave.cpp:565] Agent resources:
>> [{"name":"cpus","scalar":{"value":8.0},"type":"SCALAR"},{"na
>> me":"mem","scalar":{"value":4096.0},"type":"SCALAR"},{"name"
>> :"disk","scalar":{"value":2048.0},"type":"SCALAR"},{"name":"
>> ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
>> I0817 01:00:06.845443  6730 authenticator.cpp:326] Authentication
>> requires more steps
>> I0817 01:00:06.845474  6725 slave.cpp:573] Agent attributes: [  ]
>> I0817 01:00:06.845495  6725 slave.cpp:582] Agent hostname: 45197c1facb6
>> I0817 01:00:06.845587  6726 authenticatee.cpp:259] Received SASL
>> authentication step
>> I0817 01:00:06.845631  6737 status_update_manager.cpp:177] Pausing
>> sending status updates
>> I0817 01:00:06.845721  6727 authenticator.cpp:232] Received SASL
>> authentication step
>> I0817 01:00:06.845752  6727 auxprop.cpp:109] Request to lookup properties
>> for user: 'test-principal' realm: '45197c1facb6' server FQDN:
>> '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
>> I0817 01:00:06.845765  6727 auxprop.cpp:181] Looking up auxiliary
>> property '*userPassword'
>> I0817 01:00:06.845803  6727 auxprop.cpp:181] Looking up auxiliary
>> property '*cmusaslsecretCRAM-MD5'
>> I0817 01:00:06.845824  6727 auxprop.cpp:109] Request to lookup properties
>> for user: 'test-principal' realm: '45197c1facb6' server FQDN:
>> '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
>> I0817 01:00:06.845834  6727 auxprop.cpp:131] Skipping auxiliary property
>> '*userPassword' since SASL_AUXPROP_AUTHZID == true
>> I0817 01:00:06.845840  6727 auxprop.cpp:131] Skipping auxiliary property
>> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
>> I0817 01:00:06.845859  6727 authenticator.cpp:318] Authentication success
>> I0817 01:00:06.845944  6722 authenticatee.cpp:299] Authentication success
>> I0817 01:00:06.846010  6733 master.cpp:7867] Successfully authenticated
>> principal 'test-principal' at scheduler-db03a645-3ff8-4b33-b
>> 9cf-8617bdc60875@172.17.0.8:40444
>> I0817 01:00:06.846038  6732 authenticator.cpp:432] Authentication session
>> cleanup for crammd5-authenticatee(994)@172.17.0.8:40444
>> I0817 01:00:06.846205  6724 sched.cpp:513] Successfully authenticated
>> with master master@172.17.0.8:40444
>> I0817 01:00:06.846230  6724 sched.cpp:836] Sending SUBSCRIBE call to
>> master@172.17.0.8:40444
>> I0817 01:00:06.846350  6724 sched.cpp:869] Will retry registration in
>> 1.760433846secs if necessary
>> I0817 01:00:06.846515  6735 master.cpp:2894] Received SUBSCRIBE call for
>> framework 'default' at scheduler-db03a645-3ff8-4b33-b
>> 9cf-8617bdc60875@172.17.0.8:40444
>> terminate called after throwing an instance of 'std::system_error'
>>   what():  Invalid argumentI0817 01:00:06.846544  6735 master.cpp:2228]
>> Authorizing framework principal 'test-principal' to receive offers for
>> roles '{ * }'
>>
>> *** Aborted at 1502931606 (unix time) try "date -d @1502931606" if you
>> are using GNU date ***
>> PC: @     0x2b5638257c37 (unknown)
>> *** SIGABRT (@0x3e800001a30) received by PID 6704 (TID 0x2b56419b3700)
>> from PID 6704; stack trace: ***
>> I0817 01:00:06.847018  6744 master.cpp:2974] Subscribing framework
>> default with checkpointing enabled and capabilities [
>> RESERVATION_REFINEMENT ]
>>     @     0x2b5638013330 (unknown)
>> I0817 01:00:06.847276  6723 state.cpp:64] Recovering state from
>> '/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_yF46Kd/meta'
>>     @     0x2b5638257c37 (unknown)
>>     @     0x2b563825b028 (unknown)
>>     @     0x2b5637843535 (unknown)
>> I0817 01:00:06.847627  6730 status_update_manager.cpp:203] Recovering
>> status update manager
>> I0817 01:00:06.847650  6742 sched.cpp:759] Framework registered with
>> 66249101-3204-4bec-9632-4a28a9d4b6e5-0000
>>     @     0x2b56378416d6 (unknown)
>> I0817 01:00:06.847724  6742 sched.cpp:773] Scheduler::registered took
>> 38692ns
>>     @     0x2b5637841703 (unknown)
>> I0817 01:00:06.847841  6728 containerizer.cpp:609] Recovering
>> containerizer
>> I0817 01:00:06.847849  6736 hierarchical.cpp:303] Added framework
>> 66249101-3204-4bec-9632-4a28a9d4b6e5-0000
>>     @     0x2b5637894af5 (unknown)
>> I0817 01:00:06.848007  6736 hierarchical.cpp:1943] No allocations
>> performed
>> I0817 01:00:06.848045  6736 hierarchical.cpp:2033] No inverse offers to
>> send out!
>> I0817 01:00:06.848076  6736 hierarchical.cpp:1486] Performed allocation
>> for 0 agents in 112255ns
>>     @     0x2b563800b184 start_thread
>>     @     0x2b563831effd (unknown)
>> make[4]: *** [check-local] Aborted (core dumped)
>> make[4]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
>> make[3]: *** [check-am] Error 2
>> make[3]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
>> make[2]: *** [check] Error 2
>> make[2]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
>> make[1]: *** [check-recursive] Error 1
>> make[1]: Leaving directory `/mesos/mesos-1.4.0/_build'
>> make: *** [distcheck] Error 1
>> + docker rmi mesos-1502928841-11353
>> Untagged: mesos-1502928841-11353:latest
>> Deleted: sha256:b357f94c675052121faba6fe659e4eb7ae3e1561b4a9437f6f1fa
>> 9372bd553f0
>> Deleted: sha256:a96273e4fde97cd27620621e0595131961cc9d52b7596f71f0f52
>> 27fe8fc13ca
>> Deleted: sha256:ce40dc29c56558c1c6bc6de09555cf72ac0ed0e123528596b9f00
>> 366d0a5d9cb
>> Deleted: sha256:07c588a98d87917d607d4bfc5ed8e2aa505ca3ef14b805f03d6e2
>> da329eb1bf8
>> Deleted: sha256:db572215bdd853fdae5e743968629a440977c43ce9b85e7dd367a
>> 64703bca758
>> Deleted: sha256:c53b35da4b823af8922b02331a25daa3929de567db25a5b768a9f
>> d878f9a6bdd
>> Deleted: sha256:a5e5c1c3346f346f44235f537f35bf5cd17ec098e7ff02ebc24a5
>> c638ea1bfc8
>> Deleted: sha256:926e91e72e8e57be634ea00e9ddff4e4cabbc11335a3fb219cd13
>> 1b2ed9ab392
>> Deleted: sha256:f4649fa91e399abcaff7e3ae53ff38d5e76fa41598cd59c2ad8ad
>> e0ab6733e4d
>> Deleted: sha256:743e6ebb05fbd1e05c86275466c6188b9fd4e45b8d50d3a1bd7bd
>> 72f3da6cf5c
>> Deleted: sha256:0692e3b9d64f5aa3b030779e4f9a76224e412d59a542ccbfd09e2
>> 5fa6affb46f
>> Deleted: sha256:f28c43c772395095e3d7cbcb1f8e03e019c81e9180460f9d6e87b
>> c8c4222002a
>> Deleted: sha256:c885dcb5d6d14a85d75c216e122bea52342e8db9e83c8725d23a4
>> c0a7c07c2b6
>> Deleted: sha256:66500f988c2ab193d11a154febd6bd8cb1a13f9e270ea6cf0dc80
>> bbfe1114bc6
>> Deleted: sha256:f9a400d8c7f70691776f92bec8c4a15b3ed3e3beb5fdf2c77fa39
>> d53d6ff4ce6
>> Deleted: sha256:6b9a61dcfa10915fa155e3596d04544a0263a294f74d5720698fa
>> 3ce14cc89fa
>> Deleted: sha256:6c31420e1acbb33ca3a6a1a8fad9ee67ccdf4c51420ad66bb167c
>> fb879bf18d2
>> Deleted: sha256:457d8b02047822f8e50c72c0f0077ae09497b3f30506b0ac2d6b8
>> e8207d0f6bd
>> Deleted: sha256:1045dd5e6093bfae7f668960f2473b540a3c7e57305beb8613e97
>> e74ea1786b7
>> Deleted: sha256:b06f149fef2d09a542a4708153903f753990e4c608434a65d6b59
>> 9ee4fed4bd9
>> Deleted: sha256:0d51e647adbe81d4cb44a35a96734c9cd4ecff41a57ef91eac8f4
>> 348fd546a12
>> Deleted: sha256:63e2e1e2bf046565d1723dfbd4754867ed745e1feca4ceef5ba5b
>> 4c3d2d0b747
>> Deleted: sha256:c2be339c2a2099eab71b3adf3c70c9b0e8ef5a615229504dfdcfa
>> a68bd6a92cf
>> Deleted: sha256:0e0dd36544fec166584cffc3867896fd04b9b733e55e7e7a30084
>> a35d0ca5fd5
>> Build step 'Execute shell' marked build as failure
>>
>
>

Re: Build failed in Jenkins: Mesos-Buildbot » autotools,clang,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #4118

Posted by Benjamin Mahler <bm...@apache.org>.
Anyone know what std::system_error with 'Invalid argument' might mean? Or
why we're getting a stack trace entirely of '(Unknown)'?

I've actually seen the same crash in a scale test cluster, would be great
if anyone has any ideas here.

On Wed, Aug 16, 2017 at 6:00 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:

> See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=auto
> tools,COMPILER=clang,CONFIGURATION=--verbose%20--enable-
> libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_
> VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-
> us1)&&(!ubuntu-eu2)/4118/display/redirect?page=changes>
>
> Changes:
>
> [anand] Fixed a bug around `kill()` not removing active containers.
>
> ------------------------------------------
> [...truncated 21.31 MB...]
> I0817 01:00:05.801321 6737 hierarchical.cpp:1943] No allocations performed
> I0817 01:00:05.801424  6737 hierarchical.cpp:2033] No inverse offers to
> send out!
> I0817 01:00:05.801476  6737 hierarchical.cpp:1486] Performed allocation
> for 1 agents in 303266ns
> I0817 01:00:06.316730  6724 slave.cpp:4273] Cleaning up un-reregistered
> executors
> I0817 01:00:06.316900  6724 slave.cpp:6210] Finished recovery
> I0817 01:00:06.317662  6724 slave.cpp:6392] Querying resource estimator
> for oversubscribable resources
> I0817 01:00:06.317929  6745 status_update_manager.cpp:177] Pausing sending
> status updates
> I0817 01:00:06.317962  6725 slave.cpp:971] New master detected at
> master@172.17.0.8:40444
> I0817 01:00:06.318066  6725 slave.cpp:1006] Detecting new master
> I0817 01:00:06.318202  6725 slave.cpp:6406] Received oversubscribable
> resources {} from the resource estimator
> I0817 01:00:06.324371  6723 slave.cpp:1033] Authenticating with master
> master@172.17.0.8:40444
> I0817 01:00:06.324511  6723 slave.cpp:1044] Using default CRAM-MD5
> authenticatee
> I0817 01:00:06.324862  6740 authenticatee.cpp:121] Creating new client
> SASL connection
> I0817 01:00:06.325322  6729 master.cpp:7837] Authenticating slave(478)@
> 172.17.0.8:40444
> I0817 01:00:06.325479 6730 authenticator.cpp:414] Starting authentication
> session for crammd5-authenticatee(993)@172.17.0.8:40444
> I0817 01:00:06.325743 6722 authenticator.cpp:98] Creating new server SASL
> connection
> I0817 01:00:06.326010  6739 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0817 01:00:06.326045  6739 authenticatee.cpp:239] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> I0817 01:00:06.326155  6739 authenticator.cpp:204] Received SASL
> authentication start
> I0817 01:00:06.326222  6739 authenticator.cpp:326] Authentication requires
> more steps
> I0817 01:00:06.326323  6728 authenticatee.cpp:259] Received SASL
> authentication step
> I0817 01:00:06.326432  6727 authenticator.cpp:232] Received SASL
> authentication step
> I0817 01:00:06.326464  6727 auxprop.cpp:109] Request to lookup properties
> for user: 'test-principal' realm: '45197c1facb6' server FQDN:
> '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0817 01:00:06.326478  6727 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0817 01:00:06.326519  6727 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0817 01:00:06.326539  6727 auxprop.cpp:109] Request to lookup properties
> for user: 'test-principal' realm: '45197c1facb6' server FQDN:
> '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0817 01:00:06.326550  6727 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0817 01:00:06.326558  6727 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0817 01:00:06.326575  6727 authenticator.cpp:318] Authentication success
> I0817 01:00:06.326709  6726 authenticatee.cpp:299] Authentication success
> I0817 01:00:06.326738  6742 master.cpp:7867] Successfully authenticated
> principal 'test-principal' at slave(478)@172.17.0.8:40444
> I0817 01:00:06.326762  6734 authenticator.cpp:432] Authentication session
> cleanup for crammd5-authenticatee(993)@172.17.0.8:40444
> I0817 01:00:06.326993  6737 slave.cpp:1128] Successfully authenticated
> with master master@172.17.0.8:40444
> I0817 01:00:06.327518  6737 slave.cpp:1572] Will retry registration in
> 14.251184ms if necessary
> I0817 01:00:06.328802  6736 master.cpp:6012] Received re-register agent
> message from agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@
> 172.17.0.8:40444 (45197c1facb6)
> I0817 01:00:06.328842  6736 master.cpp:3803] Authorizing agent with
> principal 'test-principal'
> I0817 01:00:06.329376  6736 master.cpp:6081] Authorized re-registration of
> agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@
> 172.17.0.8:40444 (45197c1facb6)
> I0817 01:00:06.329483  6736 master.cpp:6146] Re-registering agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(477)@172.17.0.8:40444
> (45197c1facb6)
> I0817 01:00:06.329792  6730 slave.cpp:1275] Re-registered with master
> master@172.17.0.8:40444
> I0817 01:00:06.329824  6722 hierarchical.cpp:678] Agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0 reactivated
> I0817 01:00:06.329856  6736 master.cpp:6586] Sending updated checkpointed
> resources {} to agent 56b17556-5965-44ca-be07-44edbcb8751c-S0 at
> slave(478)@172.17.0.8:40444 (45197c1facb6)
> I0817 01:00:06.329866  6722 status_update_manager.cpp:184] Resuming
> sending status updates
> I0817 01:00:06.329885  6730 slave.cpp:1312] Forwarding total
> oversubscribed resources {}
> W0817 01:00:06.329907  6722 status_update_manager.cpp:191] Resending
> status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566)
> for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.329957  6722 status_update_manager.cpp:377] Forwarding
> update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to the agent
> I0817 01:00:06.330029  6736 master.cpp:6688] Received update of agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444
> (45197c1facb6) with total oversubscribed resources {}
> I0817 01:00:06.330075  6730 slave.cpp:3330] Updating info for framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 with pid updated to
> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
> I0817 01:00:06.330152  6730 slave.cpp:7084] Checkpointing FrameworkInfo to
> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556
> -5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-
> 44ca-be07-44edbcb8751c-0000/framework.info'
> I0817 01:00:06.330344 6728 hierarchical.cpp:660] Agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0 (45197c1facb6) updated with total
> resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
> I0817 01:00:06.330607  6730 slave.cpp:7095] Checkpointing framework pid '
> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444' to
> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556
> -5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-
> 44ca-be07-44edbcb8751c-0000/framework.pid'
> I0817 01:00:06.330912  6727 status_update_manager.cpp:184] Resuming
> sending status updates
> W0817 01:00:06.330937  6727 status_update_manager.cpp:191] Resending
> status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566)
> for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.330953  6730 slave.cpp:3394] Ignoring new checkpointed
> resources identical to the current version: {}
> I0817 01:00:06.330968  6727 status_update_manager.cpp:377] Forwarding
> update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to the agent
> I0817 01:00:06.331070  6730 slave.cpp:4797] Forwarding the update
> TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to master@172.17.0.8:40444
> I0817 01:00:06.331285 6730 slave.cpp:4797] Forwarding the update
> TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to master@172.17.0.8:40444
> I0817 01:00:06.331362 6726 master.cpp:6846] Status update TASK_RUNNING
> (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 from agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444
> (45197c1facb6)
> I0817 01:00:06.331408 6726 master.cpp:6908] Forwarding status update
> TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.331564  6726 master.cpp:8933] Updating the state of task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (latest state: TASK_FAILED,
> status update state: TASK_RUNNING)
> I0817 01:00:06.331709  6744 sched.cpp:1041] Scheduler::statusUpdate took
> 41560ns
> I0817 01:00:06.332159  6726 master.cpp:6846] Status update TASK_RUNNING
> (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 from agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444
> (45197c1facb6)
> I0817 01:00:06.332201 6726 master.cpp:6908] Forwarding status update
> TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.332340  6726 master.cpp:8933] Updating the state of task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (latest state: TASK_FAILED,
> status update state: TASK_RUNNING)
> I0817 01:00:06.332479  6733 sched.cpp:1041] Scheduler::statusUpdate took
> 23192ns
> I0817 01:00:06.332495  6726 master.cpp:5477] Processing ACKNOWLEDGE call
> 6298f06a-4d56-49b0-ae14-12a4fd774566 for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444 on agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0
> I0817 01:00:06.332500 6742 hierarchical.cpp:1161] 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 56b17556-5965-44ca-be07-44edbcb8751c-S0
> from framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.332691  6726 master.cpp:5477] Processing ACKNOWLEDGE call
> 6298f06a-4d56-49b0-ae14-12a4fd774566 for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444 on agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0
> I0817 01:00:06.332728 6734 status_update_manager.cpp:395] Received status
> update acknowledgement (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for
> task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.332854  6734 status_update_manager.cpp:834] Checkpointing
> ACK for status update TASK_RUNNING (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566)
> for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.332988  6734 status_update_manager.cpp:377] Forwarding
> update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to the agent
> I0817 01:00:06.333187  6724 slave.cpp:4797] Forwarding the update
> TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 to master@172.17.0.8:40444
> I0817 01:00:06.333245  6734 status_update_manager.cpp:395] Received status
> update acknowledgement (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for
> task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> W0817 01:00:06.333329  6734 status_update_manager.cpp:763] Duplicate
> status update acknowledgment (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566)
> for update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for
> task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.333354  6724 slave.cpp:3609] Status update manager
> successfully handled status update acknowledgement (UUID:
> 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> E0817 01:00:06.333447  6724 slave.cpp:3602] Failed to handle status update
> acknowledgement (UUID: 6298f06a-4d56-49b0-ae14-12a4fd774566) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000: Duplicate acknowledgement
> I0817 01:00:06.333453  6738 master.cpp:6846] Status update TASK_FAILED
> (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 from agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444
> (45197c1facb6)
> I0817 01:00:06.333504  6738 master.cpp:6908] Forwarding status update
> TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.333643  6738 master.cpp:8933] Updating the state of task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (latest state: TASK_FAILED,
> status update state: TASK_FAILED)
> I0817 01:00:06.333762  6732 sched.cpp:1041] Scheduler::statusUpdate took
> 39113ns
> I0817 01:00:06.333951  6745 master.cpp:5477] Processing ACKNOWLEDGE call
> b29e6cb2-8461-43c6-b252-a7b4619bd9d4 for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444 on agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0
> I0817 01:00:06.334004  6745 master.cpp:9027] Removing task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 with resources
> [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"va
> lue":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},
> "name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"
> allocation_info":{"role":"*"},"name":"disk","scalar":{"value
> ":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},
> "name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
> of framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 on agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0 at slave(478)@172.17.0.8:40444
> (45197c1facb6)
> I0817 01:00:06.334609 6735 status_update_manager.cpp:395] Received status
> update acknowledgement (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for
> task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.334683  6735 status_update_manager.cpp:834] Checkpointing
> ACK for status update TASK_FAILED (UUID: b29e6cb2-8461-43c6-b252-a7b4619bd9d4)
> for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.334759  6735 status_update_manager.cpp:531] Cleaning up
> status update stream for task 334ab1cb-44b2-4676-b2b5-0329c383ac33 of
> framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.335131  6723 slave.cpp:3609] Status update manager
> successfully handled status update acknowledgement (UUID:
> b29e6cb2-8461-43c6-b252-a7b4619bd9d4) for task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33 of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.335178  6723 slave.cpp:7561] Completing task
> 334ab1cb-44b2-4676-b2b5-0329c383ac33
> I0817 01:00:06.335224  6723 slave.cpp:5429] Cleaning up executor
> '334ab1cb-44b2-4676-b2b5-0329c383ac33' of framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 at executor(1)@172.17.0.8:40576
> I0817 01:00:06.335512  6740 gc.cpp:59] Scheduling
> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/slaves/56b17556-5965
> -44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-
> be07-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-b2b5-
> 0329c383ac33/runs/85315bbe-bb58-416d-853d-8c17b4a61361' for gc
> 6.99999611762667days in the future
> I0817 01:00:06.335686  6729 gc.cpp:59] Scheduling
> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/slaves/56b17556-5965
> -44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-
> be07-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-b2b5-0329c383ac33'
> for gc 6.99999611555556days in the future
> I0817 01:00:06.335827  6729 gc.cpp:59] Scheduling
> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556
> -5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-
> 44ca-be07-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-
> b2b5-0329c383ac33/runs/85315bbe-bb58-416d-853d-8c17b4a61361' for gc
> 6.99999611430519days in the future
> I0817 01:00:06.335861  6723 slave.cpp:5525] Cleaning up framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.335929  6729 gc.cpp:59] Scheduling
> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556
> -5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-
> 44ca-be07-44edbcb8751c-0000/executors/334ab1cb-44b2-4676-b2b5-0329c383ac33'
> for gc 6.99999611335704days in the future
> I0817 01:00:06.335980  6731 status_update_manager.cpp:285] Closing status
> update streams for framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.336024  6729 gc.cpp:59] Scheduling
> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/slaves/56b17556-5965
> -44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000'
> for gc 6.99999611171259days in the future
> I0817 01:00:06.336120  6729 gc.cpp:59] Scheduling
> '/tmp/SlaveRecoveryTest_0_Reboot_kqojFE/meta/slaves/56b17556
> -5965-44ca-be07-44edbcb8751c-S0/frameworks/56b17556-5965-44ca-be07-44edbcb8751c-0000'
> for gc 6.9999961109363days in the future
> I0817 01:00:06.802976  6742 hierarchical.cpp:2033] No inverse offers to
> send out!
> I0817 01:00:06.803063  6742 hierarchical.cpp:1486] Performed allocation
> for 1 agents in 1.010273ms
> I0817 01:00:06.803483  6733 master.cpp:7667] Sending 1 offers to framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
> I0817 01:00:06.804096  6741 sched.cpp:933] Scheduler::resourceOffers took
> 135353ns
> I0817 01:00:06.804899  6704 sched.cpp:2021] Asked to stop the driver
> I0817 01:00:06.804999  6738 sched.cpp:1203] Stopping framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.805320  6745 master.cpp:8348] Processing TEARDOWN call for
> framework 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
> I0817 01:00:06.805352 6745 master.cpp:8360] Removing framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
> I0817 01:00:06.805367  6745 master.cpp:3264] Deactivating framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 (default) at
> scheduler-01d4e1d6-01e5-43cf-9fb4-ca558d87d299@172.17.0.8:40444
> I0817 01:00:06.805480  6740 hierarchical.cpp:412] Deactivated framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.805881  6745 master.cpp:9164] Removing offer
> 56b17556-5965-44ca-be07-44edbcb8751c-O1
> I0817 01:00:06.806056  6739 slave.cpp:3159] Asked to shut down framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000 by master@172.17.0.8:40444
> I0817 01:00:06.806116  6739 slave.cpp:3174] Cannot shut down unknown
> framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.806344  6740 hierarchical.cpp:1161] 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 56b17556-5965-44ca-be07-44edbcb8751c-S0
> from framework 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.809447  6740 hierarchical.cpp:355] Removed framework
> 56b17556-5965-44ca-be07-44edbcb8751c-0000
> I0817 01:00:06.809541  6730 slave.cpp:843] Agent terminating
> I0817 01:00:06.814934  6704 master.cpp:1160] Master terminating
> I0817 01:00:06.815558  6739 hierarchical.cpp:626] Removed agent
> 56b17556-5965-44ca-be07-44edbcb8751c-S0
> [       OK ] SlaveRecoveryTest/0.Reboot (4030 ms)
> [ RUN      ] SlaveRecoveryTest/0.RebootWithSlaveInfoMismatch
> I0817 01:00:06.824440  6704 cluster.cpp:162] Creating default 'local'
> authorizer
> I0817 01:00:06.827071  6734 master.cpp:442] Master
> 66249101-3204-4bec-9632-4a28a9d4b6e5 (45197c1facb6) started on
> 172.17.0.8:40444
> I0817 01:00:06.827113  6734 master.cpp:444] 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/Z0ccUv/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="/mesos/mesos-1.4.0/_inst/share/mesos/webui"
> --work_dir="/tmp/Z0ccUv/master" --zk_session_timeout="10secs"
> I0817 01:00:06.827448  6734 master.cpp:494] Master only allowing
> authenticated frameworks to register
> I0817 01:00:06.827479  6734 master.cpp:508] Master only allowing
> authenticated agents to register
> I0817 01:00:06.827493  6734 master.cpp:521] Master only allowing
> authenticated HTTP frameworks to register
> I0817 01:00:06.827507  6734 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/Z0ccUv/credentials'
> I0817 01:00:06.827826  6734 master.cpp:566] Using default 'crammd5'
> authenticator
> I0817 01:00:06.827980  6734 http.cpp:1026] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-readonly'
> I0817 01:00:06.828145  6734 http.cpp:1026] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-readwrite'
> I0817 01:00:06.828272  6734 http.cpp:1026] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-scheduler'
> I0817 01:00:06.828392  6734 master.cpp:646] Authorization enabled
> I0817 01:00:06.828569  6743 hierarchical.cpp:171] Initialized hierarchical
> allocator process
> I0817 01:00:06.828590  6725 whitelist_watcher.cpp:77] No whitelist given
> I0817 01:00:06.831037  6736 master.cpp:2163] Elected as the leading master!
> I0817 01:00:06.831063  6736 master.cpp:1702] Recovering from registrar
> I0817 01:00:06.831159  6728 registrar.cpp:347] Recovering registrar
> I0817 01:00:06.831712  6728 registrar.cpp:391] Successfully fetched the
> registry (0B) in 515840ns
> I0817 01:00:06.831832  6728 registrar.cpp:495] Applied 1 operations in
> 44686ns; attempting to update the registry
> I0817 01:00:06.832372  6728 registrar.cpp:552] Successfully updated the
> registry in 482048ns
> I0817 01:00:06.832489  6728 registrar.cpp:424] Successfully recovered
> registrar
> I0817 01:00:06.832810  6738 master.cpp:1801] Recovered 0 agents from the
> registry (129B); allowing 10mins for agents to re-register
> I0817 01:00:06.832854  6744 hierarchical.cpp:209] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0817 01:00:06.836031  6704 containerizer.cpp:246] Using isolation:
> posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
> W0817 01:00:06.836477  6704 backend.cpp:76] Failed to create 'aufs'
> backend: AufsBackend requires root privileges
> W0817 01:00:06.836588  6704 backend.cpp:76] Failed to create 'bind'
> backend: BindBackend requires root privileges
> I0817 01:00:06.836623  6704 provisioner.cpp:255] Using default backend
> 'copy'
> I0817 01:00:06.840314  6704 process.cpp:3228] Attempting to spawn already
> spawned process files@172.17.0.8:40444
> I0817 01:00:06.840575  6704 cluster.cpp:448] Creating default 'local'
> authorizer
> I0817 01:00:06.842278  6725 slave.cpp:250] Mesos agent started on (479)@
> 172.17.0.8:40444
> I0817 01:00:06.842310  6725 slave.cpp:251] Flags at startup: --acls=""
> --appc_simple_discovery_uri_prefix="http://"
> --appc_store_dir="/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/store/appc"
> --authenticate_http_executors="true" --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/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/credential"
> --default_role="*" --disallow_sharing_agent_pid_namespace="false"
> --disk_watch_interval="1mins" --docker="docker"
> --docker_kill_orphans="true" --docker_registry="https://reg
> istry-1.docker.io" --docker_remove_delay="6hrs"
> --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns"
> --docker_store_dir="/tmp/SlaveRecoveryTest_0_RebootWithSlave
> InfoMismatch_SEk3BV/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_secret_key="/tmp/SlaveRecoveryTest_0_RebootWithSl
> aveInfoMismatch_SEk3BV/executor_secret_key" --executor_shutdown_grace_period="5secs"
> --fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_SEk3BV/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/SlaveRecoveryTest_0_RebootWithSlave
> InfoMismatch_SEk3BV/http_credentials" --http_heartbeat_interval="30secs"
> --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem"
> --launcher="posix" --launcher_dir="/mesos/mesos-1.4.0/_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:8;mem:4096;disk:2048"
> --revocable_cpu_low_priority="true" --runtime_dir="/tmp/SlaveRecov
> eryTest_0_RebootWithSlaveInfoMismatch_SEk3BV"
> --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/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_yF46Kd"
> I0817 01:00:06.842685  6725 credentials.hpp:86] Loading credential for
> authentication from '/tmp/SlaveRecoveryTest_0_Rebo
> otWithSlaveInfoMismatch_SEk3BV/credential'
> I0817 01:00:06.842784  6704 process.cpp:3228] Attempting to spawn already
> spawned process version@172.17.0.8:40444
> I0817 01:00:06.842851  6725 slave.cpp:283] Agent using credential for:
> test-principal
> I0817 01:00:06.842875  6725 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/SlaveRecoveryTest_0_Rebo
> otWithSlaveInfoMismatch_SEk3BV/http_credentials'
> I0817 01:00:06.843179  6725 http.cpp:1026] Creating default 'basic' HTTP
> authenticator for realm 'mesos-agent-executor'
> I0817 01:00:06.843313  6725 http.cpp:1047] Creating default 'jwt' HTTP
> authenticator for realm 'mesos-agent-executor'
> I0817 01:00:06.843533  6725 http.cpp:1026] Creating default 'basic' HTTP
> authenticator for realm 'mesos-agent-readonly'
> I0817 01:00:06.843629  6725 http.cpp:1047] Creating default 'jwt' HTTP
> authenticator for realm 'mesos-agent-readonly'
> I0817 01:00:06.843639  6704 sched.cpp:232] Version: 1.4.0
> I0817 01:00:06.843857  6725 http.cpp:1026] Creating default 'basic' HTTP
> authenticator for realm 'mesos-agent-readwrite'
> I0817 01:00:06.843960  6725 http.cpp:1047] Creating default 'jwt' HTTP
> authenticator for realm 'mesos-agent-readwrite'
> I0817 01:00:06.844141  6731 sched.cpp:336] New master detected at
> master@172.17.0.8:40444
> I0817 01:00:06.844230  6731 sched.cpp:407] Authenticating with master
> master@172.17.0.8:40444
> I0817 01:00:06.844249  6731 sched.cpp:414] Using default CRAM-MD5
> authenticatee
> I0817 01:00:06.844457  6738 authenticatee.cpp:121] Creating new client
> SASL connection
> I0817 01:00:06.844712  6736 master.cpp:7837] Authenticating
> scheduler-db03a645-3ff8-4b33-b9cf-8617bdc60875@172.17.0.8:40444
> I0817 01:00:06.844805  6739 authenticator.cpp:414] Starting authentication
> session for crammd5-authenticatee(994)@172.17.0.8:40444
> I0817 01:00:06.845022  6742 authenticator.cpp:98] Creating new server SASL
> connection
> I0817 01:00:06.845257  6729 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0817 01:00:06.845285  6729 authenticatee.cpp:239] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> I0817 01:00:06.845379  6730 authenticator.cpp:204] Received SASL
> authentication start
> I0817 01:00:06.845227  6725 slave.cpp:565] Agent resources:
> [{"name":"cpus","scalar":{"value":8.0},"type":"SCALAR"},{"
> name":"mem","scalar":{"value":4096.0},"type":"SCALAR"},{"nam
> e":"disk","scalar":{"value":2048.0},"type":"SCALAR"},{"nam
> e":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},
> "type":"RANGES"}]
> I0817 01:00:06.845443  6730 authenticator.cpp:326] Authentication requires
> more steps
> I0817 01:00:06.845474  6725 slave.cpp:573] Agent attributes: [  ]
> I0817 01:00:06.845495  6725 slave.cpp:582] Agent hostname: 45197c1facb6
> I0817 01:00:06.845587  6726 authenticatee.cpp:259] Received SASL
> authentication step
> I0817 01:00:06.845631  6737 status_update_manager.cpp:177] Pausing sending
> status updates
> I0817 01:00:06.845721  6727 authenticator.cpp:232] Received SASL
> authentication step
> I0817 01:00:06.845752  6727 auxprop.cpp:109] Request to lookup properties
> for user: 'test-principal' realm: '45197c1facb6' server FQDN:
> '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0817 01:00:06.845765  6727 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0817 01:00:06.845803  6727 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0817 01:00:06.845824  6727 auxprop.cpp:109] Request to lookup properties
> for user: 'test-principal' realm: '45197c1facb6' server FQDN:
> '45197c1facb6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0817 01:00:06.845834  6727 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0817 01:00:06.845840  6727 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0817 01:00:06.845859  6727 authenticator.cpp:318] Authentication success
> I0817 01:00:06.845944  6722 authenticatee.cpp:299] Authentication success
> I0817 01:00:06.846010  6733 master.cpp:7867] Successfully authenticated
> principal 'test-principal' at scheduler-db03a645-3ff8-4b33-b
> 9cf-8617bdc60875@172.17.0.8:40444
> I0817 01:00:06.846038  6732 authenticator.cpp:432] Authentication session
> cleanup for crammd5-authenticatee(994)@172.17.0.8:40444
> I0817 01:00:06.846205  6724 sched.cpp:513] Successfully authenticated with
> master master@172.17.0.8:40444
> I0817 01:00:06.846230  6724 sched.cpp:836] Sending SUBSCRIBE call to
> master@172.17.0.8:40444
> I0817 01:00:06.846350  6724 sched.cpp:869] Will retry registration in
> 1.760433846secs if necessary
> I0817 01:00:06.846515  6735 master.cpp:2894] Received SUBSCRIBE call for
> framework 'default' at scheduler-db03a645-3ff8-4b33-b
> 9cf-8617bdc60875@172.17.0.8:40444
> terminate called after throwing an instance of 'std::system_error'
>   what():  Invalid argumentI0817 01:00:06.846544  6735 master.cpp:2228]
> Authorizing framework principal 'test-principal' to receive offers for
> roles '{ * }'
>
> *** Aborted at 1502931606 (unix time) try "date -d @1502931606" if you are
> using GNU date ***
> PC: @     0x2b5638257c37 (unknown)
> *** SIGABRT (@0x3e800001a30) received by PID 6704 (TID 0x2b56419b3700)
> from PID 6704; stack trace: ***
> I0817 01:00:06.847018  6744 master.cpp:2974] Subscribing framework default
> with checkpointing enabled and capabilities [ RESERVATION_REFINEMENT ]
>     @     0x2b5638013330 (unknown)
> I0817 01:00:06.847276  6723 state.cpp:64] Recovering state from
> '/tmp/SlaveRecoveryTest_0_RebootWithSlaveInfoMismatch_yF46Kd/meta'
>     @     0x2b5638257c37 (unknown)
>     @     0x2b563825b028 (unknown)
>     @     0x2b5637843535 (unknown)
> I0817 01:00:06.847627  6730 status_update_manager.cpp:203] Recovering
> status update manager
> I0817 01:00:06.847650  6742 sched.cpp:759] Framework registered with
> 66249101-3204-4bec-9632-4a28a9d4b6e5-0000
>     @     0x2b56378416d6 (unknown)
> I0817 01:00:06.847724  6742 sched.cpp:773] Scheduler::registered took
> 38692ns
>     @     0x2b5637841703 (unknown)
> I0817 01:00:06.847841  6728 containerizer.cpp:609] Recovering containerizer
> I0817 01:00:06.847849  6736 hierarchical.cpp:303] Added framework
> 66249101-3204-4bec-9632-4a28a9d4b6e5-0000
>     @     0x2b5637894af5 (unknown)
> I0817 01:00:06.848007  6736 hierarchical.cpp:1943] No allocations performed
> I0817 01:00:06.848045  6736 hierarchical.cpp:2033] No inverse offers to
> send out!
> I0817 01:00:06.848076  6736 hierarchical.cpp:1486] Performed allocation
> for 0 agents in 112255ns
>     @     0x2b563800b184 start_thread
>     @     0x2b563831effd (unknown)
> make[4]: *** [check-local] Aborted (core dumped)
> make[4]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-1.4.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1502928841-11353
> Untagged: mesos-1502928841-11353:latest
> Deleted: sha256:b357f94c675052121faba6fe659e4eb7ae3e1561b4a9437f6f1fa
> 9372bd553f0
> Deleted: sha256:a96273e4fde97cd27620621e0595131961cc9d52b7596f71f0f52
> 27fe8fc13ca
> Deleted: sha256:ce40dc29c56558c1c6bc6de09555cf72ac0ed0e123528596b9f00
> 366d0a5d9cb
> Deleted: sha256:07c588a98d87917d607d4bfc5ed8e2aa505ca3ef14b805f03d6e2
> da329eb1bf8
> Deleted: sha256:db572215bdd853fdae5e743968629a440977c43ce9b85e7dd367a
> 64703bca758
> Deleted: sha256:c53b35da4b823af8922b02331a25daa3929de567db25a5b768a9f
> d878f9a6bdd
> Deleted: sha256:a5e5c1c3346f346f44235f537f35bf5cd17ec098e7ff02ebc24a5
> c638ea1bfc8
> Deleted: sha256:926e91e72e8e57be634ea00e9ddff4e4cabbc11335a3fb219cd13
> 1b2ed9ab392
> Deleted: sha256:f4649fa91e399abcaff7e3ae53ff38d5e76fa41598cd59c2ad8ad
> e0ab6733e4d
> Deleted: sha256:743e6ebb05fbd1e05c86275466c6188b9fd4e45b8d50d3a1bd7bd
> 72f3da6cf5c
> Deleted: sha256:0692e3b9d64f5aa3b030779e4f9a76224e412d59a542ccbfd09e2
> 5fa6affb46f
> Deleted: sha256:f28c43c772395095e3d7cbcb1f8e03e019c81e9180460f9d6e87b
> c8c4222002a
> Deleted: sha256:c885dcb5d6d14a85d75c216e122bea52342e8db9e83c8725d23a4
> c0a7c07c2b6
> Deleted: sha256:66500f988c2ab193d11a154febd6bd8cb1a13f9e270ea6cf0dc80
> bbfe1114bc6
> Deleted: sha256:f9a400d8c7f70691776f92bec8c4a15b3ed3e3beb5fdf2c77fa39
> d53d6ff4ce6
> Deleted: sha256:6b9a61dcfa10915fa155e3596d04544a0263a294f74d5720698fa
> 3ce14cc89fa
> Deleted: sha256:6c31420e1acbb33ca3a6a1a8fad9ee67ccdf4c51420ad66bb167c
> fb879bf18d2
> Deleted: sha256:457d8b02047822f8e50c72c0f0077ae09497b3f30506b0ac2d6b8
> e8207d0f6bd
> Deleted: sha256:1045dd5e6093bfae7f668960f2473b540a3c7e57305beb8613e97
> e74ea1786b7
> Deleted: sha256:b06f149fef2d09a542a4708153903f753990e4c608434a65d6b59
> 9ee4fed4bd9
> Deleted: sha256:0d51e647adbe81d4cb44a35a96734c9cd4ecff41a57ef91eac8f4
> 348fd546a12
> Deleted: sha256:63e2e1e2bf046565d1723dfbd4754867ed745e1feca4ceef5ba5b
> 4c3d2d0b747
> Deleted: sha256:c2be339c2a2099eab71b3adf3c70c9b0e8ef5a615229504dfdcfa
> a68bd6a92cf
> Deleted: sha256:0e0dd36544fec166584cffc3867896fd04b9b733e55e7e7a30084
> a35d0ca5fd5
> Build step 'Execute shell' marked build as failure
>