Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4617

[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%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4617/display/redirect?page=changes>

Changes:

[yujie.jay] Updated GET_CONTAINERS API allowing nested/standalone containers.

[yujie.jay] Added VIEW_STANDALONE_CONTAINER ACL.

[yujie.jay] Supported getting all containers in the agent API.

[yujie.jay] Added doc for new fields in GET_CONTAINERS operator API.

[yujie.jay] Updated CHANGELOG about the change to GET_CONTAINERS API.

[yujie.jay] Updated upgrades.md about the GET_CONTAINERS API change.

[yujie.jay] Added validation for VIEW_STANDALONE_CONTAINER ACL.

[yujie.jay] Added tests for VIEW_STANDALONE_CONTAINER ACL.

------------------------------------------
[...truncated 8.17 MB...]
3: I1215 22:59:58.038117 18357 authenticator.cpp:98] Creating new server SASL connection
3: I1215 22:59:58.038319 18367 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1215 22:59:58.038342 18367 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1215 22:59:58.038450 18367 authenticator.cpp:204] Received SASL authentication start
3: I1215 22:59:58.038502 18367 authenticator.cpp:326] Authentication requires more steps
3: I1215 22:59:58.038614 18361 authenticatee.cpp:259] Received SASL authentication step
3: I1215 22:59:58.038735 18362 authenticator.cpp:232] Received SASL authentication step
3: I1215 22:59:58.038763 18362 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2d3135d1bddb' server FQDN: '2d3135d1bddb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1215 22:59:58.038775 18362 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1215 22:59:58.038800 18362 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1215 22:59:58.038815 18362 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2d3135d1bddb' server FQDN: '2d3135d1bddb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1215 22:59:58.038825 18362 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1215 22:59:58.038831 18362 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1215 22:59:58.038843 18362 authenticator.cpp:318] Authentication success
3: I1215 22:59:58.038915 18373 authenticatee.cpp:299] Authentication success
3: I1215 22:59:58.038980 18365 master.cpp:8962] Successfully authenticated principal 'test-principal' at slave(184)@172.17.0.2:33179
3: I1215 22:59:58.039039 18376 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(390)@172.17.0.2:33179
3: I1215 22:59:58.039284 18366 slave.cpp:1207] Successfully authenticated with master master@172.17.0.2:33179
3: I1215 22:59:58.039494 18366 slave.cpp:1686] Will retry registration in 9.48233ms if necessary
3: I1215 22:59:58.039623 18374 master.cpp:6077] Received register agent message from slave(184)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.039695 18374 master.cpp:3866] Authorizing agent with principal 'test-principal'
3: I1215 22:59:58.040052 18368 master.cpp:6147] Authorized registration of agent at slave(184)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.040132 18368 master.cpp:6240] Registering agent at slave(184)@172.17.0.2:33179 (2d3135d1bddb) with id 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0
3: I1215 22:59:58.040594 18372 registrar.cpp:495] Applied 1 operations in 85764ns; attempting to update the registry
3: I1215 22:59:58.041205 18372 registrar.cpp:552] Successfully updated the registry in 558080ns
3: I1215 22:59:58.041366 18359 master.cpp:6288] Admitted agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.042014 18359 master.cpp:6337] Registered agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I1215 22:59:58.042069 18357 slave.cpp:1253] Registered with master master@172.17.0.2:33179; given agent ID 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0
3: I1215 22:59:58.042170 18361 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1215 22:59:58.042347 18357 slave.cpp:1273] Checkpointing SlaveInfo to '/tmp/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn/meta/slaves/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0/slave.info'
3: I1215 22:59:58.042383 18360 hierarchical.cpp:574] Added agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 (2d3135d1bddb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1215 22:59:58.042800 18357 slave.cpp:1330] Forwarding agent update {"offer_operations":{},"resource_version_uuid":{"value":"i0\/Z7sQ1QzGZhdi2bHiZgg=="},"slave_id":{"value":"7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0"},"update_oversubscribed_resources":true}
3: I1215 22:59:58.042976 18373 master.cpp:7266] Received update of agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb) with total oversubscribed resources {}
3: I1215 22:59:58.043334 18373 master.cpp:7362] Ignoring update on agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb) as it reports no changes
3: I1215 22:59:58.043767 18360 hierarchical.cpp:1517] Performed allocation for 1 agents in 1.226519ms
3: I1215 22:59:58.044239 18365 master.cpp:8762] Sending 1 offers to framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 (default) at scheduler-43aeb3e0-a4bb-4aae-bbfc-1e13cc305698@172.17.0.2:33179
3: I1215 22:59:58.044734 18377 sched.cpp:921] Scheduler::resourceOffers took 106916ns
3: I1215 22:59:58.046352 18356 master.cpp:10678] Removing offer 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-O0
3: I1215 22:59:58.046481 18356 master.cpp:4273] Processing ACCEPT call for offers: [ 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-O0 ] on agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb) for framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 (default) at scheduler-43aeb3e0-a4bb-4aae-bbfc-1e13cc305698@172.17.0.2:33179
3: I1215 22:59:58.046576 18356 master.cpp:3593] Authorizing framework principal 'test-principal' to launch task 0d4eb5b4-733a-483e-93ba-4da823b0906b
3: I1215 22:59:58.048209 18358 master.cpp:11433] Adding task 0d4eb5b4-733a-483e-93ba-4da823b0906b with resources cpus(allocated: *):1; mem(allocated: *):32 on agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.048447 18358 master.cpp:5024] Launching task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 (default) at scheduler-43aeb3e0-a4bb-4aae-bbfc-1e13cc305698@172.17.0.2:33179 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] on agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.049181 18363 slave.cpp:1809] Got assigned task '0d4eb5b4-733a-483e-93ba-4da823b0906b' for framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.049662 18372 hierarchical.cpp:1192] Recovered cpus(allocated: *):1; mem(allocated: *):992; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated: *):1; mem(allocated: *):32) on agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 from framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.049728 18372 hierarchical.cpp:1238] Framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 filtered agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 for 5secs
3: I1215 22:59:58.049806 18363 slave.cpp:2079] Authorizing task '0d4eb5b4-733a-483e-93ba-4da823b0906b' for framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.049865 18363 slave.cpp:7865] Authorizing framework principal 'test-principal' to launch task 0d4eb5b4-733a-483e-93ba-4da823b0906b
3: I1215 22:59:58.050745 18361 slave.cpp:2472] Launching task '0d4eb5b4-733a-483e-93ba-4da823b0906b' for framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.051374 18361 paths.cpp:756] Trying to chown '/tmp/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn/slaves/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0/frameworks/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000/executors/0d4eb5b4-733a-483e-93ba-4da823b0906b/runs/e8f78afb-805f-4afe-9826-c2649a8ffec8' to user 'mesos'
3: I1215 22:59:58.051646 18361 slave.cpp:8339] Launching executor '0d4eb5b4-733a-483e-93ba-4da823b0906b' of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-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/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn/slaves/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0/frameworks/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000/executors/0d4eb5b4-733a-483e-93ba-4da823b0906b/runs/e8f78afb-805f-4afe-9826-c2649a8ffec8'
3: I1215 22:59:58.052860 18361 slave.cpp:2558] Queued task '0d4eb5b4-733a-483e-93ba-4da823b0906b' for executor '0d4eb5b4-733a-483e-93ba-4da823b0906b' of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.052959 18361 slave.cpp:984] Successfully attached '/tmp/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn/slaves/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0/frameworks/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000/executors/0d4eb5b4-733a-483e-93ba-4da823b0906b/runs/e8f78afb-805f-4afe-9826-c2649a8ffec8' to virtual path '/tmp/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn/slaves/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0/frameworks/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000/executors/0d4eb5b4-733a-483e-93ba-4da823b0906b/runs/latest'
3: I1215 22:59:58.053010 18361 slave.cpp:984] Successfully attached '/tmp/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn/slaves/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0/frameworks/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000/executors/0d4eb5b4-733a-483e-93ba-4da823b0906b/runs/e8f78afb-805f-4afe-9826-c2649a8ffec8' to virtual path '/frameworks/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000/executors/0d4eb5b4-733a-483e-93ba-4da823b0906b/runs/latest'
3: I1215 22:59:58.053055 18361 slave.cpp:984] Successfully attached '/tmp/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn/slaves/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0/frameworks/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000/executors/0d4eb5b4-733a-483e-93ba-4da823b0906b/runs/e8f78afb-805f-4afe-9826-c2649a8ffec8' to virtual path '/tmp/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn/slaves/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0/frameworks/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000/executors/0d4eb5b4-733a-483e-93ba-4da823b0906b/runs/e8f78afb-805f-4afe-9826-c2649a8ffec8'
3: I1215 22:59:58.053411 18361 slave.cpp:3024] Launching container e8f78afb-805f-4afe-9826-c2649a8ffec8 for executor '0d4eb5b4-733a-483e-93ba-4da823b0906b' of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.054231 18365 containerizer.cpp:1206] Starting container e8f78afb-805f-4afe-9826-c2649a8ffec8
3: I1215 22:59:58.054960 18365 containerizer.cpp:1378] Checkpointed ContainerConfig at '/tmp/SlaveTest_StatisticsEndpointRunningExecutor_j41lHm/containers/e8f78afb-805f-4afe-9826-c2649a8ffec8/config'
3: I1215 22:59:58.054987 18365 containerizer.cpp:2955] Transitioning the state of container e8f78afb-805f-4afe-9826-c2649a8ffec8 from PROVISIONING to PREPARING
3: I1215 22:59:58.059026 18370 containerizer.cpp:1857] 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:33179"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn\/slaves\/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0\/frameworks\/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000\/executors\/0d4eb5b4-733a-483e-93ba-4da823b0906b\/runs\/e8f78afb-805f-4afe-9826-c2649a8ffec8"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiJlOGY3OGFmYi04MDVmLTRhZmUtOTgyNi1jMjY0OWE4ZmZlYzgiLCJlaWQiOiIwZDRlYjViNC03MzNhLTQ4M2UtOTNiYS00ZGE4MjNiMDkwNmIiLCJmaWQiOiI3YmExOWEzMS02MzkwLTRjODItYmRmNS1mM2Y3NWFlMGRjMmMtMDAwMCJ9.gG38r0UCMfQHDVtdDJNeA-ZF-v7A3RnfN1zlcse90F4"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"0d4eb5b4-733a-483e-93ba-4da823b0906b"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(184)@172.17.0.2:33179"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn\/slaves\/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0\/frameworks\/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000\/executors\/0d4eb5b4-733a-483e-93ba-4da823b0906b\/runs\/e8f78afb-805f-4afe-9826-c2649a8ffec8"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn\/slaves\/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0\/frameworks\/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000\/executors\/0d4eb5b4-733a-483e-93ba-4da823b0906b\/runs\/e8f78afb-805f-4afe-9826-c2649a8ffec8"}" --pipe_read="8" --pipe_write="9" --runtime_directory="/tmp/SlaveTest_StatisticsEndpointRunningExecutor_j41lHm/containers/e8f78afb-805f-4afe-9826-c2649a8ffec8" --unshare_namespace_mnt="false"'
3: I1215 22:59:58.061298 18370 launcher.cpp:140] Forked child with pid '20669' for container 'e8f78afb-805f-4afe-9826-c2649a8ffec8'
3: I1215 22:59:58.061823 18370 containerizer.cpp:2955] Transitioning the state of container e8f78afb-805f-4afe-9826-c2649a8ffec8 from PREPARING to ISOLATING
3: I1215 22:59:58.063566 18375 containerizer.cpp:2955] Transitioning the state of container e8f78afb-805f-4afe-9826-c2649a8ffec8 from ISOLATING to FETCHING
3: I1215 22:59:58.063766 18369 fetcher.cpp:369] Starting to fetch URIs for container: e8f78afb-805f-4afe-9826-c2649a8ffec8, directory: /tmp/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn/slaves/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0/frameworks/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000/executors/0d4eb5b4-733a-483e-93ba-4da823b0906b/runs/e8f78afb-805f-4afe-9826-c2649a8ffec8
3: I1215 22:59:58.064800 18379 containerizer.cpp:2955] Transitioning the state of container e8f78afb-805f-4afe-9826-c2649a8ffec8 from FETCHING to RUNNING
3: I1215 22:59:58.354346 20681 exec.cpp:162] Version: 1.5.0
3: I1215 22:59:58.370399 18358 slave.cpp:4293] Got registration for executor '0d4eb5b4-733a-483e-93ba-4da823b0906b' of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 from executor(1)@172.17.0.2:43639
3: I1215 22:59:58.374639 18377 slave.cpp:2763] Sending queued task '0d4eb5b4-733a-483e-93ba-4da823b0906b' to executor '0d4eb5b4-733a-483e-93ba-4da823b0906b' of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 at executor(1)@172.17.0.2:43639
3: I1215 22:59:58.379591 20687 exec.cpp:237] Executor registered on agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0
3: I1215 22:59:58.383632 20692 executor.cpp:171] Received SUBSCRIBED event
3: I1215 22:59:58.385022 20692 executor.cpp:175] Subscribed executor on 2d3135d1bddb
3: I1215 22:59:58.385233 20692 executor.cpp:171] Received LAUNCH event
3: I1215 22:59:58.387274 20692 executor.cpp:638] Starting task 0d4eb5b4-733a-483e-93ba-4da823b0906b
3: I1215 22:59:58.390306 18375 slave.cpp:4750] Handling status update TASK_STARTING (Status UUID: aacea68e-8215-42f7-84c4-97aefc4f884c) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 from executor(1)@172.17.0.2:43639
3: I1215 22:59:58.392848 18363 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: aacea68e-8215-42f7-84c4-97aefc4f884c) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.392930 18363 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.394001 18363 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: aacea68e-8215-42f7-84c4-97aefc4f884c) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 to the agent
3: I1215 22:59:58.394367 18361 slave.cpp:5233] Forwarding the update TASK_STARTING (Status UUID: aacea68e-8215-42f7-84c4-97aefc4f884c) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 to master@172.17.0.2:33179
3: I1215 22:59:58.394814 18361 slave.cpp:5126] Task status update manager successfully handled status update TASK_STARTING (Status UUID: aacea68e-8215-42f7-84c4-97aefc4f884c) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.394907 18361 slave.cpp:5142] Sending acknowledgement for status update TASK_STARTING (Status UUID: aacea68e-8215-42f7-84c4-97aefc4f884c) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 to executor(1)@172.17.0.2:43639
3: I1215 22:59:58.395171 18359 master.cpp:7854] Status update TASK_STARTING (Status UUID: aacea68e-8215-42f7-84c4-97aefc4f884c) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 from agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.395280 18359 master.cpp:7910] Forwarding status update TASK_STARTING (Status UUID: aacea68e-8215-42f7-84c4-97aefc4f884c) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.395612 18359 master.cpp:10158] Updating the state of task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
3: I1215 22:59:58.396047 18371 sched.cpp:1029] Scheduler::statusUpdate took 166591ns
3: I1215 22:59:58.396798 18370 master.cpp:5842] Processing ACKNOWLEDGE call aacea68e-8215-42f7-84c4-97aefc4f884c for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 (default) at scheduler-43aeb3e0-a4bb-4aae-bbfc-1e13cc305698@172.17.0.2:33179 on agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0
3: I1215 22:59:58.397369 18375 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: aacea68e-8215-42f7-84c4-97aefc4f884c) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.397841 18364 slave.cpp:4028] Task status update manager successfully handled status update acknowledgement (UUID: aacea68e-8215-42f7-84c4-97aefc4f884c) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.408601 20692 executor.cpp:478] Running '/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
3: I1215 22:59:58.412959 20692 executor.cpp:651] Forked command at 20696
3: I1215 22:59:58.417402 18376 slave.cpp:4750] Handling status update TASK_RUNNING (Status UUID: 45f3319c-7037-4d2a-9800-da7f7207ad43) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 from executor(1)@172.17.0.2:43639
3: I1215 22:59:58.420104 18373 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 45f3319c-7037-4d2a-9800-da7f7207ad43) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.420310 18373 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: 45f3319c-7037-4d2a-9800-da7f7207ad43) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 to the agent
3: I1215 22:59:58.420608 18365 slave.cpp:5233] Forwarding the update TASK_RUNNING (Status UUID: 45f3319c-7037-4d2a-9800-da7f7207ad43) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 to master@172.17.0.2:33179
3: I1215 22:59:58.420917 18365 slave.cpp:5126] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 45f3319c-7037-4d2a-9800-da7f7207ad43) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.420982 18365 slave.cpp:5142] Sending acknowledgement for status update TASK_RUNNING (Status UUID: 45f3319c-7037-4d2a-9800-da7f7207ad43) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 to executor(1)@172.17.0.2:43639
3: I1215 22:59:58.421154 18371 master.cpp:7854] Status update TASK_RUNNING (Status UUID: 45f3319c-7037-4d2a-9800-da7f7207ad43) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 from agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.421244 18371 master.cpp:7910] Forwarding status update TASK_RUNNING (Status UUID: 45f3319c-7037-4d2a-9800-da7f7207ad43) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.421548 18371 master.cpp:10158] Updating the state of task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: I1215 22:59:58.421918 18357 sched.cpp:1029] Scheduler::statusUpdate took 135176ns
3: I1215 22:59:58.422423 18375 master.cpp:5842] Processing ACKNOWLEDGE call 45f3319c-7037-4d2a-9800-da7f7207ad43 for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 (default) at scheduler-43aeb3e0-a4bb-4aae-bbfc-1e13cc305698@172.17.0.2:33179 on agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0
3: I1215 22:59:58.422883 18366 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 45f3319c-7037-4d2a-9800-da7f7207ad43) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.423321 18372 slave.cpp:4028] Task status update manager successfully handled status update acknowledgement (UUID: 45f3319c-7037-4d2a-9800-da7f7207ad43) for task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.425808 18367 process.cpp:3503] Handling HTTP event for process 'slave(184)' with path: '/slave(184)/monitor/statistics'
3: I1215 22:59:58.429636 18371 http.cpp:1185] HTTP GET for /slave(184)/monitor/statistics from 172.17.0.2:36668
3: I1215 22:59:58.429778 18371 http.cpp:976] Authorizing principal 'test-principal' to GET the '/monitor/statistics' endpoint
3: I1215 22:59:58.440577 18355 sched.cpp:2009] Asked to stop the driver
3: I1215 22:59:58.440798 18369 sched.cpp:1191] Stopping framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.441234 18360 master.cpp:9442] Processing TEARDOWN call for framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 (default) at scheduler-43aeb3e0-a4bb-4aae-bbfc-1e13cc305698@172.17.0.2:33179
3: I1215 22:59:58.441289 18360 master.cpp:9454] Removing framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 (default) at scheduler-43aeb3e0-a4bb-4aae-bbfc-1e13cc305698@172.17.0.2:33179
3: I1215 22:59:58.441311 18360 master.cpp:3327] Deactivating framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 (default) at scheduler-43aeb3e0-a4bb-4aae-bbfc-1e13cc305698@172.17.0.2:33179
3: I1215 22:59:58.441603 18366 hierarchical.cpp:405] Deactivated framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.441604 18360 master.cpp:10158] Updating the state of task 0d4eb5b4-733a-483e-93ba-4da823b0906b of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
3: I1215 22:59:58.441608 18372 slave.cpp:3376] Asked to shut down framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 by master@172.17.0.2:33179
3: I1215 22:59:58.441704 18372 slave.cpp:3401] Shutting down framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.441794 18372 slave.cpp:6109] Shutting down executor '0d4eb5b4-733a-483e-93ba-4da823b0906b' of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 at executor(1)@172.17.0.2:43639
3: I1215 22:59:58.442651 18355 slave.cpp:909] Agent terminating
3: I1215 22:59:58.442628 18360 master.cpp:10264] Removing task 0d4eb5b4-733a-483e-93ba-4da823b0906b with resources cpus(allocated: *):1; mem(allocated: *):32 of framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 on agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.442749 18355 slave.cpp:3376] Asked to shut down framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 by @0.0.0.0:0
3: W1215 22:59:58.442821 18355 slave.cpp:3397] Ignoring shutdown framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000 because it is terminating
3: I1215 22:59:58.443306 18357 hierarchical.cpp:1192] Recovered cpus(allocated: *):1; mem(allocated: *):32 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 from framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.443629 20680 exec.cpp:435] Executor asked to shutdown
3: I1215 22:59:58.444200 18370 hierarchical.cpp:344] Removed framework 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000
3: I1215 22:59:58.444514 20683 executor.cpp:171] Received SHUTDOWN event
3: I1215 22:59:58.444558 20683 executor.cpp:748] Shutting down
3: I1215 22:59:58.444643 20683 executor.cpp:855] Sending SIGTERM to process tree at pid 20696
3: I1215 22:59:58.444639 18360 master.cpp:1305] Agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb) disconnected
3: I1215 22:59:58.444675 18360 master.cpp:3364] Disconnecting agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.444787 18360 master.cpp:3383] Deactivating agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 at slave(184)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.444979 18373 hierarchical.cpp:766] Agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0 deactivated
3: I1215 22:59:58.445392 18372 containerizer.cpp:2352] Destroying container e8f78afb-805f-4afe-9826-c2649a8ffec8 in RUNNING state
3: I1215 22:59:58.445447 18372 containerizer.cpp:2955] Transitioning the state of container e8f78afb-805f-4afe-9826-c2649a8ffec8 from RUNNING to DESTROYING
3: I1215 22:59:58.446175 18372 launcher.cpp:156] Asked to destroy container e8f78afb-805f-4afe-9826-c2649a8ffec8
3: I1215 22:59:58.453845 20683 executor.cpp:868] Sent SIGTERM to the following process trees:
3: [ 
3: --- 20696 mesos-containerizer launch --help=false --launch_info={"command":{"shell":true,"value":"sleep 1000"},"environment":{"variables":[{"name":"PATH","type":"VALUE","value":"\/usr\/local\/sbin:\/usr\/local\/bin:\/usr\/sbin:\/usr\/bin:\/sbin:\/bin"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(184)@172.17.0.2:33179"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:33179"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn\/slaves\/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0\/frameworks\/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000\/executors\/0d4eb5b4-733a-483e-93ba-4da823b0906b\/runs\/e8f78afb-805f-4afe-9826-c2649a8ffec8"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiJlOGY3OGFmYi04MDVmLTRhZmUtOTgyNi1jMjY0OWE4ZmZlYzgiLCJlaWQiOiIwZDRlYjViNC03MzNhLTQ4M2UtOTNiYS00ZGE4MjNiMDkwNmIiLCJmaWQiOiI3YmExOWEzMS02MzkwLTRjODItYmRmNS1mM2Y3NWFlMGRjMmMtMDAwMCJ9.gG38r0UCMfQHDVtdDJNeA-ZF-v7A3RnfN1zlcse90F4"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"0d4eb5b4-733a-483e-93ba-4da823b0906b"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000"},{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/SlaveTest_StatisticsEndpointRunningExecutor_nzKhmn\/slaves\/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0\/frameworks\/7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-0000\/executors\/0d4eb5b4-733a-483e-93ba-4da823b0906b\/runs\/e8f78afb-805f-4afe-9826-c2649a8ffec8"}]}} --unshare_namespace_mnt=false 
3: ]
3: I1215 22:59:58.453876 20683 executor.cpp:872] Scheduling escalation to SIGKILL in 3secs from now
3: I1215 22:59:58.521041 18365 containerizer.cpp:2803] Container e8f78afb-805f-4afe-9826-c2649a8ffec8 has exited
3: I1215 22:59:58.523977 18378 provisioner.cpp:598] Ignoring destroy request for unknown container e8f78afb-805f-4afe-9826-c2649a8ffec8
3: I1215 22:59:58.536695 18368 master.cpp:1147] Master terminating
3: I1215 22:59:58.537695 18379 hierarchical.cpp:609] Removed agent 7ba19a31-6390-4c82-bdf5-f3f75ae0dc2c-S0
3: [       OK ] SlaveTest.StatisticsEndpointRunningExecutor (545 ms)
3: [ RUN      ] SlaveTest.StatisticsEndpointAuthentication
3: I1215 22:59:58.547016 18355 cluster.cpp:172] Creating default 'local' authorizer
3: I1215 22:59:58.550797 18367 master.cpp:456] Master fa07435a-0261-4934-9f70-4cc69b605ff0 (2d3135d1bddb) started on 172.17.0.2:33179
3: I1215 22:59:58.550825 18367 master.cpp:458] 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/BQ9knk/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/BQ9knk/master" --zk_session_timeout="10secs"
3: I1215 22:59:58.551246 18367 master.cpp:507] Master only allowing authenticated frameworks to register
3: I1215 22:59:58.551256 18367 master.cpp:513] Master only allowing authenticated agents to register
3: I1215 22:59:58.551261 18367 master.cpp:519] Master only allowing authenticated HTTP frameworks to register
3: I1215 22:59:58.551268 18367 credentials.hpp:37] Loading credentials for authentication from '/tmp/BQ9knk/credentials'
3: I1215 22:59:58.551612 18367 master.cpp:563] Using default 'crammd5' authenticator
3: I1215 22:59:58.551787 18367 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1215 22:59:58.551972 18367 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1215 22:59:58.552130 18367 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1215 22:59:58.552314 18367 master.cpp:642] Authorization enabled
3: I1215 22:59:58.552505 18377 hierarchical.cpp:175] Initialized hierarchical allocator process
3: I1215 22:59:58.552534 18363 whitelist_watcher.cpp:77] No whitelist given
3: I1215 22:59:58.556064 18376 master.cpp:2209] Elected as the leading master!
3: I1215 22:59:58.556100 18376 master.cpp:1689] Recovering from registrar
3: I1215 22:59:58.556291 18375 registrar.cpp:347] Recovering registrar
3: I1215 22:59:58.557072 18375 registrar.cpp:391] Successfully fetched the registry (0B) in 737024ns
3: I1215 22:59:58.557204 18375 registrar.cpp:495] Applied 1 operations in 39441ns; attempting to update the registry
3: I1215 22:59:58.557930 18375 registrar.cpp:552] Successfully updated the registry in 664064ns
3: I1215 22:59:58.558085 18375 registrar.cpp:424] Successfully recovered registrar
3: I1215 22:59:58.558583 18369 master.cpp:1802] Recovered 0 agents from the registry (135B); allowing 10mins for agents to re-register
3: I1215 22:59:58.558630 18363 hierarchical.cpp:213] Skipping recovery of hierarchical allocator: nothing to recover
3: W1215 22:59:58.564066 18355 process.cpp:2756] Attempted to spawn already running process files@172.17.0.2:33179
3: I1215 22:59:58.565253 18355 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1215 22:59:58.565832 18355 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1215 22:59:58.565974 18355 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1215 22:59:58.566017 18355 provisioner.cpp:299] Using default backend 'copy'
3: I1215 22:59:58.568302 18355 cluster.cpp:460] Creating default 'local' authorizer
3: I1215 22:59:58.571038 18363 slave.cpp:258] Mesos agent started on (185)@172.17.0.2:33179
3: I1215 22:59:58.571060 18363 slave.cpp:259] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveTest_StatisticsEndpointAuthentication_ZYntzl/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_StatisticsEndpointAuthentication_ZYntzl/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_StatisticsEndpointAuthentication_ZYntzl/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveTest_StatisticsEndpointAuthentication_ZYntzl/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_StatisticsEndpointAuthentication_ZYntzl/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/SlaveTest_StatisticsEndpointAuthentication_ZYntzl/jwt_secret_key" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --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_StatisticsEndpointAuthentication_ZYntzl" --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_StatisticsEndpointAuthentication_TpKoYk" --zk_session_timeout="10secs"
3: I1215 22:59:58.571535 18363 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveTest_StatisticsEndpointAuthentication_ZYntzl/credential'
3: I1215 22:59:58.571709 18363 slave.cpp:291] Agent using credential for: test-principal
3: I1215 22:59:58.571729 18363 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveTest_StatisticsEndpointAuthentication_ZYntzl/http_credentials'
3: I1215 22:59:58.572021 18363 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1215 22:59:58.572150 18363 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1215 22:59:58.572392 18363 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1215 22:59:58.572504 18363 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1215 22:59:58.572718 18363 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1215 22:59:58.572835 18363 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1215 22:59:58.574661 18363 slave.cpp:590] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1215 22:59:58.574937 18363 slave.cpp:598] Agent attributes: [  ]
3: I1215 22:59:58.574949 18363 slave.cpp:607] Agent hostname: 2d3135d1bddb
3: I1215 22:59:58.575196 18378 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1215 22:59:58.577162 18362 state.cpp:66] Recovering state from '/tmp/SlaveTest_StatisticsEndpointAuthentication_TpKoYk/meta'
3: I1215 22:59:58.577275 18363 process.cpp:3503] Handling HTTP event for process 'slave(185)' with path: '/slave(185)/monitor/statistics'
3: I1215 22:59:58.578161 18376 task_status_update_manager.cpp:207] Recovering task status update manager
3: I1215 22:59:58.578601 18373 containerizer.cpp:674] Recovering containerizer
3: I1215 22:59:58.580564 18371 provisioner.cpp:495] Provisioner recovery complete
3: I1215 22:59:58.580965 18379 slave.cpp:6742] Finished recovery
3: I1215 22:59:58.581976 18358 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1215 22:59:58.581987 18372 slave.cpp:1033] New master detected at master@172.17.0.2:33179
3: I1215 22:59:58.582072 18372 slave.cpp:1088] Detecting new master
3: I1215 22:59:58.583811 18356 process.cpp:3503] Handling HTTP event for process 'slave(185)' with path: '/slave(185)/monitor/statistics'
3: I1215 22:59:58.589530 18373 process.cpp:3503] Handling HTTP event for process 'slave(185)' with path: '/slave(185)/monitor/statistics'
3: I1215 22:59:58.591799 18371 http.cpp:1185] HTTP GET for /slave(185)/monitor/statistics from 172.17.0.2:36674
3: I1215 22:59:58.591897 18371 http.cpp:976] Authorizing principal 'test-principal' to GET the '/monitor/statistics' endpoint
3: I1215 22:59:58.592141 18371 slave.cpp:1115] Authenticating with master master@172.17.0.2:33179
3: I1215 22:59:58.592219 18371 slave.cpp:1124] Using default CRAM-MD5 authenticatee
3: I1215 22:59:58.592520 18370 authenticatee.cpp:121] Creating new client SASL connection
3: I1215 22:59:58.592890 18379 master.cpp:8932] Authenticating slave(185)@172.17.0.2:33179
3: I1215 22:59:58.593053 18361 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(391)@172.17.0.2:33179
3: I1215 22:59:58.593364 18368 authenticator.cpp:98] Creating new server SASL connection
3: I1215 22:59:58.593642 18359 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1215 22:59:58.593667 18359 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1215 22:59:58.593848 18360 authenticator.cpp:204] Received SASL authentication start
3: I1215 22:59:58.593927 18360 authenticator.cpp:326] Authentication requires more steps
3: I1215 22:59:58.594076 18367 authenticatee.cpp:259] Received SASL authentication step
3: I1215 22:59:58.594240 18357 authenticator.cpp:232] Received SASL authentication step
3: I1215 22:59:58.594281 18357 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2d3135d1bddb' server FQDN: '2d3135d1bddb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1215 22:59:58.594298 18357 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1215 22:59:58.594344 18357 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1215 22:59:58.594369 18357 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2d3135d1bddb' server FQDN: '2d3135d1bddb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1215 22:59:58.594388 18357 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1215 22:59:58.594398 18357 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1215 22:59:58.594424 18357 authenticator.cpp:318] Authentication success
3: I1215 22:59:58.594573 18365 authenticatee.cpp:299] Authentication success
3: I1215 22:59:58.594650 18373 master.cpp:8962] Successfully authenticated principal 'test-principal' at slave(185)@172.17.0.2:33179
3: I1215 22:59:58.594790 18378 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(391)@172.17.0.2:33179
3: I1215 22:59:58.594997 18375 slave.cpp:1207] Successfully authenticated with master master@172.17.0.2:33179
3: I1215 22:59:58.595286 18375 slave.cpp:1686] Will retry registration in 3.819808ms if necessary
3: I1215 22:59:58.595470 18370 master.cpp:6077] Received register agent message from slave(185)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.595579 18370 master.cpp:3866] Authorizing agent with principal 'test-principal'
3: I1215 22:59:58.595990 18368 master.cpp:6147] Authorized registration of agent at slave(185)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.596086 18368 master.cpp:6240] Registering agent at slave(185)@172.17.0.2:33179 (2d3135d1bddb) with id fa07435a-0261-4934-9f70-4cc69b605ff0-S0
3: I1215 22:59:58.596796 18371 registrar.cpp:495] Applied 1 operations in 141471ns; attempting to update the registry
3: I1215 22:59:58.597141 18372 process.cpp:3503] Handling HTTP event for process 'slave(185)' with path: '/slave(185)/monitor/statistics.json'
3: I1215 22:59:58.597661 18371 registrar.cpp:552] Successfully updated the registry in 785152ns
3: I1215 22:59:58.597884 18374 master.cpp:6288] Admitted agent fa07435a-0261-4934-9f70-4cc69b605ff0-S0 at slave(185)@172.17.0.2:33179 (2d3135d1bddb)
3: I1215 22:59:58.598682 18374 master.cpp:6337] Registered agent fa07435a-0261-4934-9f70-4cc69b605ff0-S0 at slave(185)@172.17.0.2:33179 (2d3135d1bddb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I1215 22:59:58.598778 18369 slave.cpp:1253] Registered with master master@172.17.0.2:33179; given agent ID fa07435a-0261-4934-9f70-4cc69b605ff0-S0
3: I1215 22:59:58.598925 18361 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1215 22:59:58.599189 18378 hierarchical.cpp:574] Added agent fa07435a-0261-4934-9f70-4cc69b605ff0-S0 (2d3135d1bddb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1215 22:59:58.599261 18369 slave.cpp:1273] Checkpointing SlaveInfo to '/tmp/SlaveTest_StatisticsEndpointAuthentication_TpKoYk/meta/slaves/fa07435a-0261-4934-9f70-4cc69b605ff0-S0/slave.info'
3: I1215 22:59:58.599745 18378 hierarchical.cpp:1517] Performed allocation for 1 agents in 253410ns
3: I1215 22:59:58.600128 18369 slave.cpp:1330] Forwarding agent update {"offer_operations":{},"resource_version_uuid":{"value":"ikfcROgYTGu0UpD1z9nIcw=="},"slave_id":{"value":"fa07435a-0261-4934-9f70-4cc69b605ff0-S0"},"update_oversubscribed_resources":true}
3: I1215 22:59:58.600476 18368 master.cpp:7266] Received update of agent fa07435a-0261-4934-9f70-4cc69b605ff0-S0 at slave(185)@172.17.0.2:33179 (2d3135d1bddb) with total oversubscribed resources {}
3: I1215 22:59:58.600946 18368 master.cpp:7362] Ignoring update on agent fa07435a-0261-4934-9f70-4cc69b605ff0-S0 at slave(185)@172.17.0.2:33179 (2d3135d1bddb) as it reports no changes
3: I1215 22:59:58.604385 18366 process.cpp:3503] Handling HTTP event for process 'slave(185)' with path: '/slave(185)/monitor/statistics.json'
3: I1215 22:59:58.610709 18371 process.cpp:3503] Handling HTTP event for process 'slave(185)' with path: '/slave(185)/monitor/statistics.json'
3: I1215 22:59:58.613368 18362 http.cpp:1185] HTTP GET for /slave(185)/monitor/statistics.json from 172.17.0.2:36680
3: I1215 22:59:58.613466 18362 http.cpp:976] Authorizing principal 'test-principal' to GET the '/monitor/statistics.json' endpoint
3: I1215 22:59:59.098258 18355 slave.cpp:909] Agent terminating
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1513376124-13630
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com

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

[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%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4618/display/redirect>