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/11/17 19:42:05 UTC

Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4469

See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4469/display/redirect?page=changes>

Changes:

[xujyan] Downgraded the logging level of socket shutdown failures.

------------------------------------------
[...truncated 5.51 MB...]
3: I1117 19:41:54.376359 17376 hierarchical.cpp:303] Added framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.376472 17367 provisioner.cpp:416] Provisioner recovery complete
3: I1117 19:41:54.376641 17376 hierarchical.cpp:1450] Performed allocation for 0 agents in 79114ns
3: I1117 19:41:54.376878 17365 slave.cpp:6441] Finished recovery
3: I1117 19:41:54.377921 17358 status_update_manager.cpp:177] Pausing sending status updates
3: I1117 19:41:54.377928 17374 slave.cpp:1007] New master detected at master@172.17.0.2:38153
3: I1117 19:41:54.378031 17374 slave.cpp:1042] Detecting new master
3: I1117 19:41:54.379304 17370 slave.cpp:1069] Authenticating with master master@172.17.0.2:38153
3: I1117 19:41:54.379386 17370 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1117 19:41:54.379660 17373 authenticatee.cpp:121] Creating new client SASL connection
3: I1117 19:41:54.380028 17357 master.cpp:8285] Authenticating slave(108)@172.17.0.2:38153
3: I1117 19:41:54.380203 17375 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(235)@172.17.0.2:38153
3: I1117 19:41:54.380589 17362 authenticator.cpp:98] Creating new server SASL connection
3: I1117 19:41:54.380873 17361 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1117 19:41:54.380901 17361 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1117 19:41:54.381080 17361 authenticator.cpp:204] Received SASL authentication start
3: I1117 19:41:54.381152 17361 authenticator.cpp:326] Authentication requires more steps
3: I1117 19:41:54.381268 17361 authenticatee.cpp:259] Received SASL authentication step
3: I1117 19:41:54.381423 17361 authenticator.cpp:232] Received SASL authentication step
3: I1117 19:41:54.381446 17361 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '82fd273382c8' server FQDN: '82fd273382c8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1117 19:41:54.381469 17361 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1117 19:41:54.381526 17361 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1117 19:41:54.381542 17361 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '82fd273382c8' server FQDN: '82fd273382c8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1117 19:41:54.381551 17361 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1117 19:41:54.381556 17361 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1117 19:41:54.381570 17361 authenticator.cpp:318] Authentication success
3: I1117 19:41:54.381716 17372 authenticatee.cpp:299] Authentication success
3: I1117 19:41:54.381778 17371 master.cpp:8315] Successfully authenticated principal 'test-principal' at slave(108)@172.17.0.2:38153
3: I1117 19:41:54.381831 17361 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(235)@172.17.0.2:38153
3: I1117 19:41:54.382146 17355 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:38153
3: I1117 19:41:54.382426 17355 slave.cpp:1682] Will retry registration in 11.613035ms if necessary
3: I1117 19:41:54.382722 17354 master.cpp:6032] Received register agent message from slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:54.382858 17354 master.cpp:3870] Authorizing agent with principal 'test-principal'
3: I1117 19:41:54.383386 17353 master.cpp:6092] Authorized registration of agent at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:54.383524 17353 master.cpp:6185] Registering agent at slave(108)@172.17.0.2:38153 (82fd273382c8) with id 8d0afc37-3375-41b4-946f-dee1ebff927d-S0
3: I1117 19:41:54.384008 17360 registrar.cpp:495] Applied 1 operations in 52589ns; attempting to update the registry
3: I1117 19:41:54.384498 17360 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1117 19:41:54.384682 17373 master.cpp:6232] Admitted agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:54.385596 17375 slave.cpp:1207] Registered with master master@172.17.0.2:38153; given agent ID 8d0afc37-3375-41b4-946f-dee1ebff927d-S0
3: I1117 19:41:54.385704 17369 status_update_manager.cpp:184] Resuming sending status updates
3: I1117 19:41:54.385462 17373 master.cpp:6263] Registered agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":367489.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1117 19:41:54.385800 17362 hierarchical.cpp:593] Added agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 (82fd273382c8) with cpus:2; mem:1024; disk:367489; ports:[31000-32000] (allocated: {})
3: I1117 19:41:54.385933 17375 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/meta/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/slave.info'
3: I1117 19:41:54.386338 17375 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1117 19:41:54.386533 17375 master.cpp:7064] Received update of agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8) with total oversubscribed resources {}
3: I1117 19:41:54.386704 17375 master.cpp:7082] Ignoring update on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8) as it reports no changes
3: I1117 19:41:54.387125 17362 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.124337ms
3: I1117 19:41:54.387723 17366 master.cpp:8115] Sending 1 offers to framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 (default) at scheduler-95f9873c-6bdb-4fe6-85cb-c2dde91b0e81@172.17.0.2:38153
3: I1117 19:41:54.388305 17372 sched.cpp:921] Scheduler::resourceOffers took 86287ns
3: I1117 19:41:54.390429 17368 master.cpp:10024] Removing offer 8d0afc37-3375-41b4-946f-dee1ebff927d-O0
3: I1117 19:41:54.390579 17368 master.cpp:4228] Processing ACCEPT call for offers: [ 8d0afc37-3375-41b4-946f-dee1ebff927d-O0 ] on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8) for framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 (default) at scheduler-95f9873c-6bdb-4fe6-85cb-c2dde91b0e81@172.17.0.2:38153
3: I1117 19:41:54.390686 17368 master.cpp:3597] Authorizing framework principal 'test-principal' to launch task b74c7b14-1461-47d5-8465-ca47de421b17
3: I1117 19:41:54.392354 17367 master.cpp:10770] Adding task b74c7b14-1461-47d5-8465-ca47de421b17 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 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:54.392688 17367 master.cpp:4976] Launching task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 (default) at scheduler-95f9873c-6bdb-4fe6-85cb-c2dde91b0e81@172.17.0.2:38153 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 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:54.393385 17355 slave.cpp:1803] Got assigned task 'b74c7b14-1461-47d5-8465-ca47de421b17' for framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.393829 17354 hierarchical.cpp:1125] Recovered cpus(allocated: *):1; mem(allocated: *):512; disk(allocated: *):367489; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:367489; ports:[31000-32000], allocated: cpus(allocated: *):1; mem(allocated: *):512) on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 from framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.393896 17354 hierarchical.cpp:1171] Framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 filtered agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 for 5secs
3: I1117 19:41:54.393926 17355 slave.cpp:2071] Authorizing task 'b74c7b14-1461-47d5-8465-ca47de421b17' for framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.393983 17355 slave.cpp:7262] Authorizing framework principal 'test-principal' to launch task b74c7b14-1461-47d5-8465-ca47de421b17
3: I1117 19:41:54.394779 17358 slave.cpp:2239] Launching task 'b74c7b14-1461-47d5-8465-ca47de421b17' for framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.395361 17358 paths.cpp:621] Trying to chown '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0000/executors/b74c7b14-1461-47d5-8465-ca47de421b17/runs/0421bfb5-c991-4886-b4fa-8080d839ec59' to user 'mesos'
3: I1117 19:41:54.395637 17358 slave.cpp:7736] Launching executor 'b74c7b14-1461-47d5-8465-ca47de421b17' of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] in work directory '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0000/executors/b74c7b14-1461-47d5-8465-ca47de421b17/runs/0421bfb5-c991-4886-b4fa-8080d839ec59'
3: I1117 19:41:54.396376 17358 slave.cpp:2930] Launching container 0421bfb5-c991-4886-b4fa-8080d839ec59 for executor 'b74c7b14-1461-47d5-8465-ca47de421b17' of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.396661 17360 containerizer.cpp:1149] Starting container 0421bfb5-c991-4886-b4fa-8080d839ec59
3: I1117 19:41:54.396735 17358 slave.cpp:2467] Queued task 'b74c7b14-1461-47d5-8465-ca47de421b17' for executor 'b74c7b14-1461-47d5-8465-ca47de421b17' of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.396827 17358 slave.cpp:958] Successfully attached '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0000/executors/b74c7b14-1461-47d5-8465-ca47de421b17/runs/0421bfb5-c991-4886-b4fa-8080d839ec59' to virtual path '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0000/executors/b74c7b14-1461-47d5-8465-ca47de421b17/runs/latest'
3: I1117 19:41:54.396879 17358 slave.cpp:958] Successfully attached '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0000/executors/b74c7b14-1461-47d5-8465-ca47de421b17/runs/0421bfb5-c991-4886-b4fa-8080d839ec59' to virtual path '/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0000/executors/b74c7b14-1461-47d5-8465-ca47de421b17/runs/latest'
3: I1117 19:41:54.396914 17358 slave.cpp:958] Successfully attached '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0000/executors/b74c7b14-1461-47d5-8465-ca47de421b17/runs/0421bfb5-c991-4886-b4fa-8080d839ec59' to virtual path '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0000/executors/b74c7b14-1461-47d5-8465-ca47de421b17/runs/0421bfb5-c991-4886-b4fa-8080d839ec59'
3: I1117 19:41:54.397131 17360 containerizer.cpp:2818] Transitioning the state of container 0421bfb5-c991-4886-b4fa-8080d839ec59 from PROVISIONING to PREPARING
3: I1117 19:41:54.400977 17372 containerizer.cpp:1768] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:38153"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl\/slaves\/8d0afc37-3375-41b4-946f-dee1ebff927d-S0\/frameworks\/8d0afc37-3375-41b4-946f-dee1ebff927d-0000\/executors\/b74c7b14-1461-47d5-8465-ca47de421b17\/runs\/0421bfb5-c991-4886-b4fa-8080d839ec59"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"b74c7b14-1461-47d5-8465-ca47de421b17"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"8d0afc37-3375-41b4-946f-dee1ebff927d-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"8d0afc37-3375-41b4-946f-dee1ebff927d-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(108)@172.17.0.2:38153"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl\/slaves\/8d0afc37-3375-41b4-946f-dee1ebff927d-S0\/frameworks\/8d0afc37-3375-41b4-946f-dee1ebff927d-0000\/executors\/b74c7b14-1461-47d5-8465-ca47de421b17\/runs\/0421bfb5-c991-4886-b4fa-8080d839ec59"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl\/slaves\/8d0afc37-3375-41b4-946f-dee1ebff927d-S0\/frameworks\/8d0afc37-3375-41b4-946f-dee1ebff927d-0000\/executors\/b74c7b14-1461-47d5-8465-ca47de421b17\/runs\/0421bfb5-c991-4886-b4fa-8080d839ec59"}" --pipe_read="7" --pipe_write="8" --runtime_directory="/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_kn2R9H/containers/0421bfb5-c991-4886-b4fa-8080d839ec59" --unshare_namespace_mnt="false"'
3: I1117 19:41:54.403668 17372 launcher.cpp:140] Forked child with pid '19320' for container '0421bfb5-c991-4886-b4fa-8080d839ec59'
3: I1117 19:41:54.404273 17372 containerizer.cpp:2818] Transitioning the state of container 0421bfb5-c991-4886-b4fa-8080d839ec59 from PREPARING to ISOLATING
3: I1117 19:41:54.405725 17357 containerizer.cpp:2818] Transitioning the state of container 0421bfb5-c991-4886-b4fa-8080d839ec59 from ISOLATING to FETCHING
3: I1117 19:41:54.405956 17359 fetcher.cpp:379] Starting to fetch URIs for container: 0421bfb5-c991-4886-b4fa-8080d839ec59, directory: /tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0000/executors/b74c7b14-1461-47d5-8465-ca47de421b17/runs/0421bfb5-c991-4886-b4fa-8080d839ec59
3: I1117 19:41:54.406867 17369 containerizer.cpp:2818] Transitioning the state of container 0421bfb5-c991-4886-b4fa-8080d839ec59 from FETCHING to RUNNING
3: I1117 19:41:54.657491 19333 exec.cpp:162] Version: 1.5.0
3: I1117 19:41:54.671267 17375 slave.cpp:4063] Got registration for executor 'b74c7b14-1461-47d5-8465-ca47de421b17' of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 from executor(1)@172.17.0.2:45240
3: I1117 19:41:54.674808 17376 slave.cpp:2669] Sending queued task 'b74c7b14-1461-47d5-8465-ca47de421b17' to executor 'b74c7b14-1461-47d5-8465-ca47de421b17' of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 at executor(1)@172.17.0.2:45240
3: I1117 19:41:54.677670 19340 exec.cpp:237] Executor registered on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0
3: I1117 19:41:54.682350 19345 executor.cpp:171] Received SUBSCRIBED event
3: I1117 19:41:54.683990 19345 executor.cpp:175] Subscribed executor on 82fd273382c8
3: I1117 19:41:54.684300 19345 executor.cpp:171] Received LAUNCH event
3: I1117 19:41:54.687120 19345 executor.cpp:637] Starting task b74c7b14-1461-47d5-8465-ca47de421b17
3: I1117 19:41:54.690747 17365 slave.cpp:4517] Handling status update TASK_STARTING (UUID: 41192968-3abf-4b17-b1d1-f87350967fde) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 from executor(1)@172.17.0.2:45240
3: I1117 19:41:54.693310 17375 status_update_manager.cpp:323] Received status update TASK_STARTING (UUID: 41192968-3abf-4b17-b1d1-f87350967fde) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.693378 17375 status_update_manager.cpp:500] Creating StatusUpdate stream for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.694015 17375 status_update_manager.cpp:377] Forwarding update TASK_STARTING (UUID: 41192968-3abf-4b17-b1d1-f87350967fde) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 to the agent
3: I1117 19:41:54.694278 17367 slave.cpp:4998] Forwarding the update TASK_STARTING (UUID: 41192968-3abf-4b17-b1d1-f87350967fde) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 to master@172.17.0.2:38153
3: I1117 19:41:54.694545 17367 slave.cpp:4892] Status update manager successfully handled status update TASK_STARTING (UUID: 41192968-3abf-4b17-b1d1-f87350967fde) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.694605 17367 slave.cpp:4908] Sending acknowledgement for status update TASK_STARTING (UUID: 41192968-3abf-4b17-b1d1-f87350967fde) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 to executor(1)@172.17.0.2:45240
3: I1117 19:41:54.694897 17356 master.cpp:7247] Status update TASK_STARTING (UUID: 41192968-3abf-4b17-b1d1-f87350967fde) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 from agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:54.694963 17356 master.cpp:7309] Forwarding status update TASK_STARTING (UUID: 41192968-3abf-4b17-b1d1-f87350967fde) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.695168 17356 master.cpp:9502] Updating the state of task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
3: I1117 19:41:54.695425 17368 sched.cpp:1029] Scheduler::statusUpdate took 80659ns
3: I1117 19:41:54.695751 17355 master.cpp:5791] Processing ACKNOWLEDGE call 41192968-3abf-4b17-b1d1-f87350967fde for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 (default) at scheduler-95f9873c-6bdb-4fe6-85cb-c2dde91b0e81@172.17.0.2:38153 on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0
3: I1117 19:41:54.696144 17361 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 41192968-3abf-4b17-b1d1-f87350967fde) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.696463 17371 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: 41192968-3abf-4b17-b1d1-f87350967fde) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.706847 19345 executor.cpp:477] Running '/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
3: I1117 19:41:54.710530 19345 executor.cpp:650] Forked command at 19347
3: I1117 19:41:54.714608 17354 slave.cpp:4517] Handling status update TASK_RUNNING (UUID: d21ad764-3bb6-4055-821e-32808ad6c85a) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 from executor(1)@172.17.0.2:45240
3: I1117 19:41:54.716156 17364 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: d21ad764-3bb6-4055-821e-32808ad6c85a) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.716310 17364 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: d21ad764-3bb6-4055-821e-32808ad6c85a) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 to the agent
3: I1117 19:41:54.716576 17362 slave.cpp:4998] Forwarding the update TASK_RUNNING (UUID: d21ad764-3bb6-4055-821e-32808ad6c85a) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 to master@172.17.0.2:38153
3: I1117 19:41:54.716799 17362 slave.cpp:4892] Status update manager successfully handled status update TASK_RUNNING (UUID: d21ad764-3bb6-4055-821e-32808ad6c85a) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.716843 17362 slave.cpp:4908] Sending acknowledgement for status update TASK_RUNNING (UUID: d21ad764-3bb6-4055-821e-32808ad6c85a) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 to executor(1)@172.17.0.2:45240
3: I1117 19:41:54.717137 17366 master.cpp:7247] Status update TASK_RUNNING (UUID: d21ad764-3bb6-4055-821e-32808ad6c85a) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 from agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:54.717195 17366 master.cpp:7309] Forwarding status update TASK_RUNNING (UUID: d21ad764-3bb6-4055-821e-32808ad6c85a) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.717391 17366 master.cpp:9502] Updating the state of task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: I1117 19:41:54.717610 17375 sched.cpp:1029] Scheduler::statusUpdate took 56120ns
3: I1117 19:41:54.717878 17367 master.cpp:5791] Processing ACKNOWLEDGE call d21ad764-3bb6-4055-821e-32808ad6c85a for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 (default) at scheduler-95f9873c-6bdb-4fe6-85cb-c2dde91b0e81@172.17.0.2:38153 on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0
3: I1117 19:41:54.718210 17368 status_update_manager.cpp:395] Received status update acknowledgement (UUID: d21ad764-3bb6-4055-821e-32808ad6c85a) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:54.718514 17355 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: d21ad764-3bb6-4055-821e-32808ad6c85a) for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: W1117 19:41:54.720518 17352 process.cpp:3185] Attempted to spawn already running process version@172.17.0.2:38153
3: I1117 19:41:54.721585 17352 sched.cpp:232] Version: 1.5.0
3: I1117 19:41:54.722427 17354 sched.cpp:336] New master detected at master@172.17.0.2:38153
3: I1117 19:41:54.722626 17354 sched.cpp:396] Authenticating with master master@172.17.0.2:38153
3: I1117 19:41:54.722647 17354 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1117 19:41:54.723134 17363 authenticatee.cpp:121] Creating new client SASL connection
3: I1117 19:41:54.723539 17369 master.cpp:8285] Authenticating scheduler-fd6568c2-7190-4dba-861d-58e493966638@172.17.0.2:38153
3: I1117 19:41:54.723866 17359 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(236)@172.17.0.2:38153
3: I1117 19:41:54.724270 17376 authenticator.cpp:98] Creating new server SASL connection
3: I1117 19:41:54.724643 17370 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1117 19:41:54.724668 17370 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1117 19:41:54.724869 17360 authenticator.cpp:204] Received SASL authentication start
3: I1117 19:41:54.724936 17360 authenticator.cpp:326] Authentication requires more steps
3: I1117 19:41:54.725108 17372 authenticatee.cpp:259] Received SASL authentication step
3: I1117 19:41:54.725257 17357 authenticator.cpp:232] Received SASL authentication step
3: I1117 19:41:54.725291 17357 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '82fd273382c8' server FQDN: '82fd273382c8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1117 19:41:54.725306 17357 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1117 19:41:54.725356 17357 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1117 19:41:54.725380 17357 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '82fd273382c8' server FQDN: '82fd273382c8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1117 19:41:54.725390 17357 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1117 19:41:54.725399 17357 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1117 19:41:54.725415 17357 authenticator.cpp:318] Authentication success
3: I1117 19:41:54.725527 17373 authenticatee.cpp:299] Authentication success
3: I1117 19:41:54.725595 17358 master.cpp:8315] Successfully authenticated principal 'test-principal' at scheduler-fd6568c2-7190-4dba-861d-58e493966638@172.17.0.2:38153
3: I1117 19:41:54.725666 17364 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(236)@172.17.0.2:38153
3: I1117 19:41:54.725883 17362 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:38153
3: I1117 19:41:54.725900 17362 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:38153
3: I1117 19:41:54.726014 17362 sched.cpp:857] Will retry registration in 602.867166ms if necessary
3: I1117 19:41:54.726213 17367 master.cpp:2961] Received SUBSCRIBE call for framework 'default' at scheduler-fd6568c2-7190-4dba-861d-58e493966638@172.17.0.2:38153
3: I1117 19:41:54.726306 17367 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1117 19:41:54.726832 17368 master.cpp:3041] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT, PARTITION_AWARE ]
3: I1117 19:41:54.727440 17355 hierarchical.cpp:303] Added framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:54.727475 17353 sched.cpp:751] Framework registered with 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:54.727517 17353 sched.cpp:765] Scheduler::registered took 21711ns
3: I1117 19:41:54.728832 17355 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.218687ms
3: I1117 19:41:54.729542 17371 master.cpp:8115] Sending 1 offers to framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 (default) at scheduler-fd6568c2-7190-4dba-861d-58e493966638@172.17.0.2:38153
3: I1117 19:41:54.730072 17374 sched.cpp:921] Scheduler::resourceOffers took 83962ns
3: I1117 19:41:54.731698 17365 master.cpp:10024] Removing offer 8d0afc37-3375-41b4-946f-dee1ebff927d-O1
3: I1117 19:41:54.731823 17365 master.cpp:4228] Processing ACCEPT call for offers: [ 8d0afc37-3375-41b4-946f-dee1ebff927d-O1 ] on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8) for framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 (default) at scheduler-fd6568c2-7190-4dba-861d-58e493966638@172.17.0.2:38153
3: I1117 19:41:54.731904 17365 master.cpp:3597] Authorizing framework principal 'test-principal' to launch task b1780bfc-2b75-4cd1-9e52-55ed44bd5199
3: I1117 19:41:54.733569 17369 master.cpp:10770] Adding task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 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 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:54.734025 17369 master.cpp:4976] Launching task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 (default) at scheduler-fd6568c2-7190-4dba-861d-58e493966638@172.17.0.2:38153 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 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:54.734815 17376 slave.cpp:1803] Got assigned task 'b1780bfc-2b75-4cd1-9e52-55ed44bd5199' for framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:54.734947 17370 hierarchical.cpp:1125] Recovered ports(allocated: *):[31000-32000]; disk(allocated: *):367489 (total: cpus:2; mem:1024; disk:367489; ports:[31000-32000], allocated: cpus(allocated: *):2; mem(allocated: *):1024) on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 from framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:54.735011 17370 hierarchical.cpp:1171] Framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 filtered agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 for 5secs
3: I1117 19:41:54.735473 17376 slave.cpp:2071] Authorizing task 'b1780bfc-2b75-4cd1-9e52-55ed44bd5199' for framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:54.735519 17376 slave.cpp:7262] Authorizing framework principal 'test-principal' to launch task b1780bfc-2b75-4cd1-9e52-55ed44bd5199
3: I1117 19:41:54.736258 17358 slave.cpp:2239] Launching task 'b1780bfc-2b75-4cd1-9e52-55ed44bd5199' for framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:54.736763 17358 paths.cpp:621] Trying to chown '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0001/executors/b1780bfc-2b75-4cd1-9e52-55ed44bd5199/runs/ee3ac891-d70b-4024-89b7-213e008e653c' to user 'mesos'
3: I1117 19:41:54.737012 17358 slave.cpp:7736] Launching executor 'b1780bfc-2b75-4cd1-9e52-55ed44bd5199' of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] in work directory '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0001/executors/b1780bfc-2b75-4cd1-9e52-55ed44bd5199/runs/ee3ac891-d70b-4024-89b7-213e008e653c'
3: I1117 19:41:54.737687 17358 slave.cpp:2930] Launching container ee3ac891-d70b-4024-89b7-213e008e653c for executor 'b1780bfc-2b75-4cd1-9e52-55ed44bd5199' of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:54.737954 17366 containerizer.cpp:1149] Starting container ee3ac891-d70b-4024-89b7-213e008e653c
3: I1117 19:41:54.737993 17358 slave.cpp:2467] Queued task 'b1780bfc-2b75-4cd1-9e52-55ed44bd5199' for executor 'b1780bfc-2b75-4cd1-9e52-55ed44bd5199' of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:54.738067 17358 slave.cpp:958] Successfully attached '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0001/executors/b1780bfc-2b75-4cd1-9e52-55ed44bd5199/runs/ee3ac891-d70b-4024-89b7-213e008e653c' to virtual path '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0001/executors/b1780bfc-2b75-4cd1-9e52-55ed44bd5199/runs/latest'
3: I1117 19:41:54.738107 17358 slave.cpp:958] Successfully attached '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0001/executors/b1780bfc-2b75-4cd1-9e52-55ed44bd5199/runs/ee3ac891-d70b-4024-89b7-213e008e653c' to virtual path '/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0001/executors/b1780bfc-2b75-4cd1-9e52-55ed44bd5199/runs/latest'
3: I1117 19:41:54.738138 17358 slave.cpp:958] Successfully attached '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0001/executors/b1780bfc-2b75-4cd1-9e52-55ed44bd5199/runs/ee3ac891-d70b-4024-89b7-213e008e653c' to virtual path '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0001/executors/b1780bfc-2b75-4cd1-9e52-55ed44bd5199/runs/ee3ac891-d70b-4024-89b7-213e008e653c'
3: I1117 19:41:54.738371 17366 containerizer.cpp:2818] Transitioning the state of container ee3ac891-d70b-4024-89b7-213e008e653c from PROVISIONING to PREPARING
3: I1117 19:41:54.742199 17374 containerizer.cpp:1768] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:38153"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl\/slaves\/8d0afc37-3375-41b4-946f-dee1ebff927d-S0\/frameworks\/8d0afc37-3375-41b4-946f-dee1ebff927d-0001\/executors\/b1780bfc-2b75-4cd1-9e52-55ed44bd5199\/runs\/ee3ac891-d70b-4024-89b7-213e008e653c"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"b1780bfc-2b75-4cd1-9e52-55ed44bd5199"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"8d0afc37-3375-41b4-946f-dee1ebff927d-0001"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"8d0afc37-3375-41b4-946f-dee1ebff927d-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(108)@172.17.0.2:38153"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl\/slaves\/8d0afc37-3375-41b4-946f-dee1ebff927d-S0\/frameworks\/8d0afc37-3375-41b4-946f-dee1ebff927d-0001\/executors\/b1780bfc-2b75-4cd1-9e52-55ed44bd5199\/runs\/ee3ac891-d70b-4024-89b7-213e008e653c"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl\/slaves\/8d0afc37-3375-41b4-946f-dee1ebff927d-S0\/frameworks\/8d0afc37-3375-41b4-946f-dee1ebff927d-0001\/executors\/b1780bfc-2b75-4cd1-9e52-55ed44bd5199\/runs\/ee3ac891-d70b-4024-89b7-213e008e653c"}" --pipe_read="9" --pipe_write="10" --runtime_directory="/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_kn2R9H/containers/ee3ac891-d70b-4024-89b7-213e008e653c" --unshare_namespace_mnt="false"'
3: I1117 19:41:54.744596 17374 launcher.cpp:140] Forked child with pid '19348' for container 'ee3ac891-d70b-4024-89b7-213e008e653c'
3: I1117 19:41:54.745199 17374 containerizer.cpp:2818] Transitioning the state of container ee3ac891-d70b-4024-89b7-213e008e653c from PREPARING to ISOLATING
3: I1117 19:41:54.746592 17364 containerizer.cpp:2818] Transitioning the state of container ee3ac891-d70b-4024-89b7-213e008e653c from ISOLATING to FETCHING
3: I1117 19:41:54.746894 17366 fetcher.cpp:379] Starting to fetch URIs for container: ee3ac891-d70b-4024-89b7-213e008e653c, directory: /tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_hXMrHl/slaves/8d0afc37-3375-41b4-946f-dee1ebff927d-S0/frameworks/8d0afc37-3375-41b4-946f-dee1ebff927d-0001/executors/b1780bfc-2b75-4cd1-9e52-55ed44bd5199/runs/ee3ac891-d70b-4024-89b7-213e008e653c
3: I1117 19:41:54.747766 17367 containerizer.cpp:2818] Transitioning the state of container ee3ac891-d70b-4024-89b7-213e008e653c from FETCHING to RUNNING
3: I1117 19:41:54.988828 19350 exec.cpp:162] Version: 1.5.0
3: I1117 19:41:55.002707 17353 slave.cpp:4063] Got registration for executor 'b1780bfc-2b75-4cd1-9e52-55ed44bd5199' of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 from executor(1)@172.17.0.2:45415
3: I1117 19:41:55.005733 17357 slave.cpp:2669] Sending queued task 'b1780bfc-2b75-4cd1-9e52-55ed44bd5199' to executor 'b1780bfc-2b75-4cd1-9e52-55ed44bd5199' of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 at executor(1)@172.17.0.2:45415
3: I1117 19:41:55.009320 19370 exec.cpp:237] Executor registered on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0
3: I1117 19:41:55.014705 19352 executor.cpp:171] Received SUBSCRIBED event
3: I1117 19:41:55.016487 19352 executor.cpp:175] Subscribed executor on 82fd273382c8
3: I1117 19:41:55.016861 19352 executor.cpp:171] Received LAUNCH event
3: I1117 19:41:55.020067 19352 executor.cpp:637] Starting task b1780bfc-2b75-4cd1-9e52-55ed44bd5199
3: I1117 19:41:55.025575 17375 slave.cpp:4517] Handling status update TASK_STARTING (UUID: 331432c2-d8de-495e-8591-95e3f7ad09b5) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 from executor(1)@172.17.0.2:45415
3: I1117 19:41:55.028148 17353 status_update_manager.cpp:323] Received status update TASK_STARTING (UUID: 331432c2-d8de-495e-8591-95e3f7ad09b5) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.028249 17353 status_update_manager.cpp:500] Creating StatusUpdate stream for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.029197 17353 status_update_manager.cpp:377] Forwarding update TASK_STARTING (UUID: 331432c2-d8de-495e-8591-95e3f7ad09b5) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 to the agent
3: I1117 19:41:55.029520 17372 slave.cpp:4998] Forwarding the update TASK_STARTING (UUID: 331432c2-d8de-495e-8591-95e3f7ad09b5) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 to master@172.17.0.2:38153
3: I1117 19:41:55.029762 17372 slave.cpp:4892] Status update manager successfully handled status update TASK_STARTING (UUID: 331432c2-d8de-495e-8591-95e3f7ad09b5) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.029814 17372 slave.cpp:4908] Sending acknowledgement for status update TASK_STARTING (UUID: 331432c2-d8de-495e-8591-95e3f7ad09b5) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 to executor(1)@172.17.0.2:45415
3: I1117 19:41:55.030014 17363 master.cpp:7247] Status update TASK_STARTING (UUID: 331432c2-d8de-495e-8591-95e3f7ad09b5) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 from agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:55.030117 17363 master.cpp:7309] Forwarding status update TASK_STARTING (UUID: 331432c2-d8de-495e-8591-95e3f7ad09b5) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.030422 17363 master.cpp:9502] Updating the state of task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 (latest state: TASK_STARTING, status update state: TASK_STARTING)
3: I1117 19:41:55.030753 17354 sched.cpp:1029] Scheduler::statusUpdate took 115371ns
3: I1117 19:41:55.031170 17354 master.cpp:5791] Processing ACKNOWLEDGE call 331432c2-d8de-495e-8591-95e3f7ad09b5 for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 (default) at scheduler-fd6568c2-7190-4dba-861d-58e493966638@172.17.0.2:38153 on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0
3: I1117 19:41:55.031610 17370 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 331432c2-d8de-495e-8591-95e3f7ad09b5) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.032013 17361 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: 331432c2-d8de-495e-8591-95e3f7ad09b5) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.042269 19352 executor.cpp:477] Running '/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
3: I1117 19:41:55.046082 19352 executor.cpp:650] Forked command at 19376
3: I1117 19:41:55.050297 17359 slave.cpp:4517] Handling status update TASK_RUNNING (UUID: 4abdb3b2-811d-45fd-b224-cc2f95f1a66b) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 from executor(1)@172.17.0.2:45415
3: I1117 19:41:55.052150 17368 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 4abdb3b2-811d-45fd-b224-cc2f95f1a66b) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.052377 17368 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 4abdb3b2-811d-45fd-b224-cc2f95f1a66b) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 to the agent
3: I1117 19:41:55.052713 17355 slave.cpp:4998] Forwarding the update TASK_RUNNING (UUID: 4abdb3b2-811d-45fd-b224-cc2f95f1a66b) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 to master@172.17.0.2:38153
3: I1117 19:41:55.052989 17355 slave.cpp:4892] Status update manager successfully handled status update TASK_RUNNING (UUID: 4abdb3b2-811d-45fd-b224-cc2f95f1a66b) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.053031 17355 slave.cpp:4908] Sending acknowledgement for status update TASK_RUNNING (UUID: 4abdb3b2-811d-45fd-b224-cc2f95f1a66b) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 to executor(1)@172.17.0.2:45415
3: I1117 19:41:55.053314 17371 master.cpp:7247] Status update TASK_RUNNING (UUID: 4abdb3b2-811d-45fd-b224-cc2f95f1a66b) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 from agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:55.053367 17371 master.cpp:7309] Forwarding status update TASK_RUNNING (UUID: 4abdb3b2-811d-45fd-b224-cc2f95f1a66b) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.053567 17371 master.cpp:9502] Updating the state of task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: I1117 19:41:55.053831 17353 sched.cpp:1029] Scheduler::statusUpdate took 67472ns
3: I1117 19:41:55.054138 17372 master.cpp:5791] Processing ACKNOWLEDGE call 4abdb3b2-811d-45fd-b224-cc2f95f1a66b for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 (default) at scheduler-fd6568c2-7190-4dba-861d-58e493966638@172.17.0.2:38153 on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0
3: I1117 19:41:55.054430 17363 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 4abdb3b2-811d-45fd-b224-cc2f95f1a66b) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.054646 17354 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: 4abdb3b2-811d-45fd-b224-cc2f95f1a66b) for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.063205 17369 hierarchical.cpp:1450] Performed allocation for 1 agents in 232969ns
3: I1117 19:41:55.066377 17368 hierarchical.cpp:1450] Performed allocation for 1 agents in 206367ns
3: I1117 19:41:55.068681 17363 hierarchical.cpp:1450] Performed allocation for 1 agents in 261137ns
3: I1117 19:41:55.070848 17359 hierarchical.cpp:1450] Performed allocation for 1 agents in 124508ns
3: I1117 19:41:55.070942 17362 slave.cpp:6058] Current disk usage 68.80%. Max allowed age: 1.484052335493357days
3: I1117 19:41:55.073501 17358 master.cpp:7571] Marking agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8) unreachable: health check timed out
3: I1117 19:41:55.073560 17369 hierarchical.cpp:1450] Performed allocation for 1 agents in 274420ns
3: I1117 19:41:55.074162 17353 registrar.cpp:495] Applied 1 operations in 124828ns; attempting to update the registry
3: I1117 19:41:55.074939 17353 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1117 19:41:55.075177 17354 master.cpp:7619] Marked agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8) unreachable: health check timed out
3: I1117 19:41:55.075481 17354 master.cpp:9502] Updating the state of task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 (latest state: TASK_UNREACHABLE, status update state: TASK_UNREACHABLE)
3: I1117 19:41:55.076010 17361 hierarchical.cpp:626] Removed agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0
3: I1117 19:41:55.076117 17354 master.cpp:9596] Removing task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:55.076679 17354 master.cpp:7304] Sending status update TASK_UNREACHABLE for task b1780bfc-2b75-4cd1-9e52-55ed44bd5199 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 'health check timed out'
3: I1117 19:41:55.076916 17354 master.cpp:9502] Updating the state of task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 (latest state: TASK_LOST, status update state: TASK_LOST)
3: I1117 19:41:55.077157 17373 sched.cpp:1029] Scheduler::statusUpdate took 64340ns
3: I1117 19:41:55.077546 17354 master.cpp:9596] Removing task b74c7b14-1461-47d5-8465-ca47de421b17 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 on agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 at slave(108)@172.17.0.2:38153 (82fd273382c8)
3: I1117 19:41:55.077917 17354 master.cpp:7304] Sending status update TASK_LOST for task b74c7b14-1461-47d5-8465-ca47de421b17 of framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 'health check timed out'
3: I1117 19:41:55.078435 17354 master.cpp:2130] Notifying framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001 (default) at scheduler-fd6568c2-7190-4dba-861d-58e493966638@172.17.0.2:38153 of lost agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 (82fd273382c8)
3: I1117 19:41:55.078527 17375 sched.cpp:1029] Scheduler::statusUpdate took 66297ns
3: I1117 19:41:55.078527 17354 master.cpp:2130] Notifying framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000 (default) at scheduler-95f9873c-6bdb-4fe6-85cb-c2dde91b0e81@172.17.0.2:38153 of lost agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0 (82fd273382c8)
3: I1117 19:41:55.078667 17367 sched.cpp:1091] Lost agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0
3: I1117 19:41:55.078742 17367 sched.cpp:1102] Scheduler::slaveLost took 32833ns
3: I1117 19:41:55.078862 17360 sched.cpp:1091] Lost agent 8d0afc37-3375-41b4-946f-dee1ebff927d-S0
3: I1117 19:41:55.078927 17360 sched.cpp:1102] Scheduler::slaveLost took 30360ns
3: I1117 19:41:55.080580 17352 master.cpp:1151] Master terminating
3: I1117 19:41:55.080874 17376 hierarchical.cpp:355] Removed framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0001
3: I1117 19:41:55.081231 17376 hierarchical.cpp:355] Removed framework 8d0afc37-3375-41b4-946f-dee1ebff927d-0000
3: I1117 19:41:55.081576 17373 slave.cpp:5130] Got exited event for master@172.17.0.2:38153
3: W1117 19:41:55.081609 17373 slave.cpp:5135] Master disconnected! Waiting for a new master to be elected
3: I1117 19:41:55.087525 17352 cluster.cpp:162] Creating default 'local' authorizer
3: I1117 19:41:55.090716 17359 master.cpp:448] Master 9f43e62b-4581-4c95-816e-930c13056d57 (82fd273382c8) started on 172.17.0.2:38153
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1510945729-17009
Error response from daemon: conflict: unable to remove repository reference "mesos-1510945729-17009" (must force) - container 82fd273382c8 is using its referenced image 56816d96c5cd
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user xujyan@apple.com

Jenkins build is back to normal : Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4470

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4470/display/redirect?page=changes>