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/10 20:54:19 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) #4443
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)/4443/display/redirect?page=changes>
Changes:
[yujie.jay] Used `Master::_apply` consistently for all offer operations.
[alexr] Added context to agent processing calls.
[yujie.jay] Made the maintainer doc up-to-date.
------------------------------------------
[...truncated 7.12 MB...]
3: I1110 20:54:12.620972 17336 slave.cpp:2071] Authorizing task '42575667-00b1-474c-ac15-567dfc64d029' for framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.621021 17336 slave.cpp:7030] Authorizing framework principal 'test-principal' to launch task 42575667-00b1-474c-ac15-567dfc64d029
3: I1110 20:54:12.621953 17322 hierarchical.cpp:1125] Recovered ports(allocated: *):[31000-32000]; mem(allocated: *):960; disk(allocated: *):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated: *):2; mem(allocated: *):64) on agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 from framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.622014 17322 hierarchical.cpp:1171] Framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 filtered agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 for 5secs
3: I1110 20:54:12.622030 17336 slave.cpp:1803] Got assigned task '93602a0b-d511-4d96-904c-3b44383255bd' for framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: E1110 20:54:12.622571 17336 slave.cpp:2212] Ignoring running task '42575667-00b1-474c-ac15-567dfc64d029' of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000: Task '42575667-00b1-474c-ac15-567dfc64d029' is not authorized to launch as user 'foo'
3: I1110 20:54:12.622651 17336 slave.cpp:4507] Handling status update TASK_ERROR (UUID: dacd7aee-47a8-42dc-afce-49ea6b414380) for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 from @0.0.0.0:0
3: W1110 20:54:12.622707 17336 slave.cpp:4622] Could not find the executor for status update TASK_ERROR (UUID: dacd7aee-47a8-42dc-afce-49ea6b414380) for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.622860 17325 status_update_manager.cpp:323] Received status update TASK_ERROR (UUID: dacd7aee-47a8-42dc-afce-49ea6b414380) for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.622898 17325 status_update_manager.cpp:500] Creating StatusUpdate stream for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.622931 17336 slave.cpp:2071] Authorizing task '93602a0b-d511-4d96-904c-3b44383255bd' for framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.622975 17336 slave.cpp:7030] Authorizing framework principal 'test-principal' to launch task 93602a0b-d511-4d96-904c-3b44383255bd
3: I1110 20:54:12.623378 17325 status_update_manager.cpp:377] Forwarding update TASK_ERROR (UUID: dacd7aee-47a8-42dc-afce-49ea6b414380) for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 to the agent
3: I1110 20:54:12.623520 17329 slave.cpp:4988] Forwarding the update TASK_ERROR (UUID: dacd7aee-47a8-42dc-afce-49ea6b414380) for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 to master@172.17.0.4:36855
3: I1110 20:54:12.623756 17329 slave.cpp:2239] Launching task '93602a0b-d511-4d96-904c-3b44383255bd' for framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.623831 17333 master.cpp:7248] Status update TASK_ERROR (UUID: dacd7aee-47a8-42dc-afce-49ea6b414380) for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 from agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 at slave(148)@172.17.0.4:36855 (4c4e601f62ba)
3: I1110 20:54:12.623886 17333 master.cpp:7310] Forwarding status update TASK_ERROR (UUID: dacd7aee-47a8-42dc-afce-49ea6b414380) for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.624048 17333 master.cpp:9503] Updating the state of task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 (latest state: TASK_ERROR, status update state: TASK_ERROR)
3: I1110 20:54:12.624191 17335 sched.cpp:1029] Scheduler::statusUpdate took 54588ns
3: I1110 20:54:12.624505 17329 paths.cpp:605] Trying to chown '/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0/slaves/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000/executors/93602a0b-d511-4d96-904c-3b44383255bd/runs/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae' to user 'mesos'
3: I1110 20:54:12.624549 17342 hierarchical.cpp:1125] Recovered cpus(allocated: *):1; mem(allocated: *):32 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated: *):1; mem(allocated: *):32) on agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 from framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.624774 17333 master.cpp:5792] Processing ACKNOWLEDGE call dacd7aee-47a8-42dc-afce-49ea6b414380 for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 (default) at scheduler-35934ca5-b620-455c-af92-065d93242bf1@172.17.0.4:36855 on agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0
3: I1110 20:54:12.624770 17329 slave.cpp:7504] Launching executor '93602a0b-d511-4d96-904c-3b44383255bd' of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-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/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0/slaves/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000/executors/93602a0b-d511-4d96-904c-3b44383255bd/runs/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae'
3: I1110 20:54:12.624825 17333 master.cpp:9597] Removing task 42575667-00b1-474c-ac15-567dfc64d029 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 on agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 at slave(148)@172.17.0.4:36855 (4c4e601f62ba)
3: I1110 20:54:12.625329 17329 slave.cpp:2930] Launching container 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae for executor '93602a0b-d511-4d96-904c-3b44383255bd' of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.625583 17327 containerizer.cpp:1136] Starting container 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae
3: I1110 20:54:12.625614 17329 slave.cpp:2467] Queued task '93602a0b-d511-4d96-904c-3b44383255bd' for executor '93602a0b-d511-4d96-904c-3b44383255bd' of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.625682 17329 slave.cpp:4882] Status update manager successfully handled status update TASK_ERROR (UUID: dacd7aee-47a8-42dc-afce-49ea6b414380) for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.625906 17339 status_update_manager.cpp:395] Received status update acknowledgement (UUID: dacd7aee-47a8-42dc-afce-49ea6b414380) for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.625921 17329 slave.cpp:958] Successfully attached '/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0/slaves/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000/executors/93602a0b-d511-4d96-904c-3b44383255bd/runs/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae' to virtual path '/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0/slaves/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000/executors/93602a0b-d511-4d96-904c-3b44383255bd/runs/latest'
3: I1110 20:54:12.625953 17329 slave.cpp:958] Successfully attached '/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0/slaves/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000/executors/93602a0b-d511-4d96-904c-3b44383255bd/runs/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae' to virtual path '/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000/executors/93602a0b-d511-4d96-904c-3b44383255bd/runs/latest'
3: I1110 20:54:12.625980 17329 slave.cpp:958] Successfully attached '/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0/slaves/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000/executors/93602a0b-d511-4d96-904c-3b44383255bd/runs/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae' to virtual path '/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0/slaves/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000/executors/93602a0b-d511-4d96-904c-3b44383255bd/runs/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae'
3: I1110 20:54:12.626025 17339 status_update_manager.cpp:531] Cleaning up status update stream for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.626071 17327 containerizer.cpp:2784] Transitioning the state of container 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae from PROVISIONING to PREPARING
3: I1110 20:54:12.626591 17339 slave.cpp:3791] Status update manager successfully handled status update acknowledgement (UUID: dacd7aee-47a8-42dc-afce-49ea6b414380) for task 42575667-00b1-474c-ac15-567dfc64d029 of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: E1110 20:54:12.626651 17339 slave.cpp:3815] Status update acknowledgement (UUID: dacd7aee-47a8-42dc-afce-49ea6b414380) for task 42575667-00b1-474c-ac15-567dfc64d029 of unknown executor
3: I1110 20:54:12.629554 17325 containerizer.cpp:1734] 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.4:36855"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0\/slaves\/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0\/frameworks\/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000\/executors\/93602a0b-d511-4d96-904c-3b44383255bd\/runs\/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"93602a0b-d511-4d96-904c-3b44383255bd"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(148)@172.17.0.4:36855"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0\/slaves\/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0\/frameworks\/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000\/executors\/93602a0b-d511-4d96-904c-3b44383255bd\/runs\/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0\/slaves\/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0\/frameworks\/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000\/executors\/93602a0b-d511-4d96-904c-3b44383255bd\/runs\/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae"}" --pipe_read="7" --pipe_write="8" --runtime_directory="/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_lBRM6f/containers/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae" --unshare_namespace_mnt="false"'
3: I1110 20:54:12.631547 17325 launcher.cpp:140] Forked child with pid '19492' for container '6be160f4-54f1-42bd-b5aa-cebd73c6d0ae'
3: I1110 20:54:12.632014 17325 containerizer.cpp:2784] Transitioning the state of container 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae from PREPARING to ISOLATING
3: I1110 20:54:12.633133 17329 containerizer.cpp:2784] Transitioning the state of container 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae from ISOLATING to FETCHING
3: I1110 20:54:12.633291 17339 fetcher.cpp:379] Starting to fetch URIs for container: 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae, directory: /tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0/slaves/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000/executors/93602a0b-d511-4d96-904c-3b44383255bd/runs/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae
3: I1110 20:54:12.634217 17341 containerizer.cpp:2784] Transitioning the state of container 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae from FETCHING to RUNNING
3: I1110 20:54:12.836196 19506 exec.cpp:162] Version: 1.5.0
3: I1110 20:54:12.845124 17334 slave.cpp:4053] Got registration for executor '93602a0b-d511-4d96-904c-3b44383255bd' of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 from executor(1)@172.17.0.4:43371
3: I1110 20:54:12.847162 17344 slave.cpp:2669] Sending queued task '93602a0b-d511-4d96-904c-3b44383255bd' to executor '93602a0b-d511-4d96-904c-3b44383255bd' of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 at executor(1)@172.17.0.4:43371
3: I1110 20:54:12.849400 19513 exec.cpp:237] Executor registered on agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0
3: I1110 20:54:12.852923 19495 executor.cpp:171] Received SUBSCRIBED event
3: I1110 20:54:12.854117 19495 executor.cpp:175] Subscribed executor on 4c4e601f62ba
3: I1110 20:54:12.854324 19495 executor.cpp:171] Received LAUNCH event
3: I1110 20:54:12.856055 19495 executor.cpp:637] Starting task 93602a0b-d511-4d96-904c-3b44383255bd
3: I1110 20:54:12.859118 17342 slave.cpp:4507] Handling status update TASK_STARTING (UUID: 6473f6da-75da-4519-b7f5-964a36567611) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 from executor(1)@172.17.0.4:43371
3: I1110 20:54:12.861191 17334 status_update_manager.cpp:323] Received status update TASK_STARTING (UUID: 6473f6da-75da-4519-b7f5-964a36567611) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.861240 17334 status_update_manager.cpp:500] Creating StatusUpdate stream for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.862030 17334 status_update_manager.cpp:377] Forwarding update TASK_STARTING (UUID: 6473f6da-75da-4519-b7f5-964a36567611) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 to the agent
3: I1110 20:54:12.862375 17330 slave.cpp:4988] Forwarding the update TASK_STARTING (UUID: 6473f6da-75da-4519-b7f5-964a36567611) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 to master@172.17.0.4:36855
3: I1110 20:54:12.862630 17330 slave.cpp:4882] Status update manager successfully handled status update TASK_STARTING (UUID: 6473f6da-75da-4519-b7f5-964a36567611) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.862676 17330 slave.cpp:4898] Sending acknowledgement for status update TASK_STARTING (UUID: 6473f6da-75da-4519-b7f5-964a36567611) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 to executor(1)@172.17.0.4:43371
3: I1110 20:54:12.862912 17343 master.cpp:7248] Status update TASK_STARTING (UUID: 6473f6da-75da-4519-b7f5-964a36567611) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 from agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 at slave(148)@172.17.0.4:36855 (4c4e601f62ba)
3: I1110 20:54:12.862967 17343 master.cpp:7310] Forwarding status update TASK_STARTING (UUID: 6473f6da-75da-4519-b7f5-964a36567611) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.863142 17343 master.cpp:9503] Updating the state of task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
3: I1110 20:54:12.863409 17333 sched.cpp:1029] Scheduler::statusUpdate took 122811ns
3: I1110 20:54:12.864121 17338 master.cpp:5792] Processing ACKNOWLEDGE call 6473f6da-75da-4519-b7f5-964a36567611 for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 (default) at scheduler-35934ca5-b620-455c-af92-065d93242bf1@172.17.0.4:36855 on agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0
3: I1110 20:54:12.864449 17342 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 6473f6da-75da-4519-b7f5-964a36567611) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.864809 17342 slave.cpp:3791] Status update manager successfully handled status update acknowledgement (UUID: 6473f6da-75da-4519-b7f5-964a36567611) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.869240 19495 executor.cpp:477] Running '/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
3: I1110 20:54:12.872007 19495 executor.cpp:650] Forked command at 19519
3: I1110 20:54:12.876292 17339 slave.cpp:4507] Handling status update TASK_RUNNING (UUID: 82784313-906a-48b0-8563-ef0ad41b1b24) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 from executor(1)@172.17.0.4:43371
3: I1110 20:54:12.877988 17326 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 82784313-906a-48b0-8563-ef0ad41b1b24) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.878157 17326 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 82784313-906a-48b0-8563-ef0ad41b1b24) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 to the agent
3: I1110 20:54:12.878439 17328 slave.cpp:4988] Forwarding the update TASK_RUNNING (UUID: 82784313-906a-48b0-8563-ef0ad41b1b24) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 to master@172.17.0.4:36855
3: I1110 20:54:12.878686 17328 slave.cpp:4882] Status update manager successfully handled status update TASK_RUNNING (UUID: 82784313-906a-48b0-8563-ef0ad41b1b24) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.878753 17328 slave.cpp:4898] Sending acknowledgement for status update TASK_RUNNING (UUID: 82784313-906a-48b0-8563-ef0ad41b1b24) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 to executor(1)@172.17.0.4:43371
3: I1110 20:54:12.879014 17335 master.cpp:7248] Status update TASK_RUNNING (UUID: 82784313-906a-48b0-8563-ef0ad41b1b24) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 from agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 at slave(148)@172.17.0.4:36855 (4c4e601f62ba)
3: I1110 20:54:12.879094 17335 master.cpp:7310] Forwarding status update TASK_RUNNING (UUID: 82784313-906a-48b0-8563-ef0ad41b1b24) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.879624 17340 sched.cpp:1029] Scheduler::statusUpdate took 148080ns
3: I1110 20:54:12.879931 17335 master.cpp:9503] Updating the state of task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: I1110 20:54:12.880028 17321 sched.cpp:2009] Asked to stop the driver
3: I1110 20:54:12.880123 17341 sched.cpp:1191] Stopping framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.880235 17335 master.cpp:5792] Processing ACKNOWLEDGE call 82784313-906a-48b0-8563-ef0ad41b1b24 for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 (default) at scheduler-35934ca5-b620-455c-af92-065d93242bf1@172.17.0.4:36855 on agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0
3: I1110 20:54:12.880511 17335 master.cpp:8793] Processing TEARDOWN call for framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 (default) at scheduler-35934ca5-b620-455c-af92-065d93242bf1@172.17.0.4:36855
3: I1110 20:54:12.880543 17335 master.cpp:8805] Removing framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 (default) at scheduler-35934ca5-b620-455c-af92-065d93242bf1@172.17.0.4:36855
3: I1110 20:54:12.880561 17335 master.cpp:3332] Deactivating framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 (default) at scheduler-35934ca5-b620-455c-af92-065d93242bf1@172.17.0.4:36855
3: I1110 20:54:12.880775 17341 hierarchical.cpp:412] Deactivated framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.880781 17339 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 82784313-906a-48b0-8563-ef0ad41b1b24) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.880769 17335 master.cpp:9503] Updating the state of task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
3: I1110 20:54:12.881405 17329 hierarchical.cpp:1125] Recovered cpus(allocated: *):1; mem(allocated: *):32 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 from framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.881320 17335 master.cpp:9597] Removing task 93602a0b-d511-4d96-904c-3b44383255bd with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 on agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 at slave(148)@172.17.0.4:36855 (4c4e601f62ba)
3: I1110 20:54:12.881384 17332 slave.cpp:3267] Asked to shut down framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 by master@172.17.0.4:36855
3: I1110 20:54:12.886478 17332 slave.cpp:3292] Shutting down framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.886553 17332 slave.cpp:5855] Shutting down executor '93602a0b-d511-4d96-904c-3b44383255bd' of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 at executor(1)@172.17.0.4:43371
3: I1110 20:54:12.886945 17332 slave.cpp:3791] Status update manager successfully handled status update acknowledgement (UUID: 82784313-906a-48b0-8563-ef0ad41b1b24) for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.887064 17323 hierarchical.cpp:355] Removed framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.887235 17338 containerizer.cpp:2220] Destroying container 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae in RUNNING state
3: I1110 20:54:12.887257 17338 containerizer.cpp:2784] Transitioning the state of container 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae from RUNNING to DESTROYING
3: I1110 20:54:12.887559 17338 launcher.cpp:156] Asked to destroy container 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae
3: I1110 20:54:12.888144 19505 exec.cpp:435] Executor asked to shutdown
3: I1110 20:54:12.888448 19502 executor.cpp:171] Received SHUTDOWN event
3: I1110 20:54:12.888483 19502 executor.cpp:747] Shutting down
3: I1110 20:54:12.888530 19502 executor.cpp:854] Sending SIGTERM to process tree at pid 19519
3: I1110 20:54:12.900771 17325 slave.cpp:5120] Got exited event for executor(1)@172.17.0.4:43371
3: I1110 20:54:12.909521 17324 containerizer.cpp:2671] Container 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae has exited
3: I1110 20:54:12.911810 17337 provisioner.cpp:490] Ignoring destroy request for unknown container 6be160f4-54f1-42bd-b5aa-cebd73c6d0ae
3: I1110 20:54:12.912600 17324 slave.cpp:5520] Executor '93602a0b-d511-4d96-904c-3b44383255bd' of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 terminated with signal Killed
3: I1110 20:54:12.912665 17324 slave.cpp:5624] Cleaning up executor '93602a0b-d511-4d96-904c-3b44383255bd' of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000 at executor(1)@172.17.0.4:43371
3: I1110 20:54:12.912897 17329 gc.cpp:90] Scheduling '/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0/slaves/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000/executors/93602a0b-d511-4d96-904c-3b44383255bd/runs/6be160f4-54f1-42bd-b5aa-cebd73c6d0ae' for gc 6.99998943509333days in the future
3: I1110 20:54:12.913069 17324 slave.cpp:5731] Cleaning up framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.913117 17329 gc.cpp:90] Scheduling '/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0/slaves/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000/executors/93602a0b-d511-4d96-904c-3b44383255bd' for gc 6.99998943289481days in the future
3: I1110 20:54:12.913166 17323 status_update_manager.cpp:285] Closing status update streams for framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.913223 17323 status_update_manager.cpp:531] Cleaning up status update stream for task 93602a0b-d511-4d96-904c-3b44383255bd of framework 6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000
3: I1110 20:54:12.913331 17329 gc.cpp:90] Scheduling '/tmp/SlaveAuthorizerTest_0_AuthorizeRunTaskOnAgent_31ayV0/slaves/6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0/frameworks/6a193c6b-c958-4cb2-9a2b-e55194aec38f-0000' for gc 6.99998943044148days in the future
3: I1110 20:54:12.913781 17321 slave.cpp:883] Agent terminating
3: I1110 20:54:12.913959 17335 master.cpp:1309] Agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 at slave(148)@172.17.0.4:36855 (4c4e601f62ba) disconnected
3: I1110 20:54:12.913980 17335 master.cpp:3369] Disconnecting agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 at slave(148)@172.17.0.4:36855 (4c4e601f62ba)
3: I1110 20:54:12.914026 17335 master.cpp:3388] Deactivating agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 at slave(148)@172.17.0.4:36855 (4c4e601f62ba)
3: I1110 20:54:12.914134 17330 hierarchical.cpp:690] Agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0 deactivated
3: I1110 20:54:12.919595 17321 master.cpp:1151] Master terminating
3: I1110 20:54:12.920312 17337 hierarchical.cpp:626] Removed agent 6a193c6b-c958-4cb2-9a2b-e55194aec38f-S0
3: [ OK ] SlaveAuthorizerTest/0.AuthorizeRunTaskOnAgent (344 ms)
3: [----------] 3 tests from SlaveAuthorizerTest/0 (498 ms total)
3:
3: [----------] 3 tests from SlaveAuthorizerTest/1, where TypeParam = mesos::internal::LocalAuthorizer
3: [ RUN ] SlaveAuthorizerTest/1.FilterStateEndpoint
3: I1110 20:54:12.930200 17334 master.cpp:448] Master 589f5f88-27e2-4c48-9f43-f8a672fe0e5d (4c4e601f62ba) started on 172.17.0.4:36855
3: I1110 20:54:12.930227 17334 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/FP9E5u/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/FP9E5u/master" --zk_session_timeout="10secs"
3: I1110 20:54:12.930536 17334 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1110 20:54:12.930542 17334 master.cpp:505] Master only allowing authenticated agents to register
3: I1110 20:54:12.930546 17334 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1110 20:54:12.930550 17334 credentials.hpp:37] Loading credentials for authentication from '/tmp/FP9E5u/credentials'
3: I1110 20:54:12.930814 17334 master.cpp:555] Using default 'crammd5' authenticator
3: I1110 20:54:12.930971 17334 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1110 20:54:12.931138 17334 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1110 20:54:12.931257 17334 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1110 20:54:12.931365 17334 master.cpp:634] Authorization enabled
3: I1110 20:54:12.931529 17339 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1110 20:54:12.931622 17329 whitelist_watcher.cpp:77] No whitelist given
3: I1110 20:54:12.934314 17345 master.cpp:2213] Elected as the leading master!
3: I1110 20:54:12.934336 17345 master.cpp:1693] Recovering from registrar
3: I1110 20:54:12.934517 17327 registrar.cpp:347] Recovering registrar
3: I1110 20:54:12.935093 17327 registrar.cpp:391] Successfully fetched the registry (0B) in 542976ns
3: I1110 20:54:12.935200 17327 registrar.cpp:495] Applied 1 operations in 31056ns; attempting to update the registry
3: I1110 20:54:12.935721 17327 registrar.cpp:552] Successfully updated the registry in 466688ns
3: I1110 20:54:12.935819 17327 registrar.cpp:424] Successfully recovered registrar
3: I1110 20:54:12.936149 17325 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1110 20:54:12.936161 17322 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1110 20:54:12.940984 17321 process.cpp:3178] Attempted to spawn already running process files@172.17.0.4:36855
3: I1110 20:54:12.943063 17338 slave.cpp:262] Mesos agent started on (149)@172.17.0.4:36855
3: W1110 20:54:12.943512 17321 process.cpp:3178] Attempted to spawn already running process version@172.17.0.4:36855
3: I1110 20:54:12.943085 17338 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveAuthorizerTest_1_FilterStateEndpoint_fGAD70/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SlaveAuthorizerTest_1_FilterStateEndpoint_fGAD70/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/SlaveAuthorizerTest_1_FilterStateEndpoint_fGAD70/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/SlaveAuthorizerTest_1_FilterStateEndpoint_fGAD70/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/SlaveAuthorizerTest_1_FilterStateEndpoint_fGAD70/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus(superhero):2;cpus(muggle):3;mem(superhero):512;mem(muggle):1024;" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/SlaveAuthorizerTest_1_FilterStateEndpoint_fGAD70" --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/SlaveAuthorizerTest_1_FilterStateEndpoint_TSGD6K" --zk_session_timeout="10secs"
3: I1110 20:54:12.943640 17338 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveAuthorizerTest_1_FilterStateEndpoint_fGAD70/credential'
3: I1110 20:54:12.943845 17338 slave.cpp:295] Agent using credential for: test-principal
3: I1110 20:54:12.943866 17338 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveAuthorizerTest_1_FilterStateEndpoint_fGAD70/http_credentials'
3: I1110 20:54:12.944115 17338 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1110 20:54:12.944280 17338 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1110 20:54:12.944463 17321 sched.cpp:232] Version: 1.5.0
3: I1110 20:54:12.945082 17329 sched.cpp:336] New master detected at master@172.17.0.4:36855
3: I1110 20:54:12.945186 17329 sched.cpp:396] Authenticating with master master@172.17.0.4:36855
3: I1110 20:54:12.945205 17329 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1110 20:54:12.945528 17342 authenticatee.cpp:121] Creating new client SASL connection
3: I1110 20:54:12.945976 17332 master.cpp:8286] Authenticating scheduler-2b5d251e-e797-4e00-9791-fbc26423887d@172.17.0.4:36855
3: I1110 20:54:12.946079 17339 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(349)@172.17.0.4:36855
3: I1110 20:54:12.946436 17334 authenticator.cpp:98] Creating new server SASL connection
3: I1110 20:54:12.946132 17338 slave.cpp:593] Agent resources: [{"name":"cpus","reservations":[{"role":"superhero","type":"STATIC"}],"scalar":{"value":2.0},"type":"SCALAR"},{"name":"cpus","reservations":[{"role":"muggle","type":"STATIC"}],"scalar":{"value":3.0},"type":"SCALAR"},{"name":"mem","reservations":[{"role":"superhero","type":"STATIC"}],"scalar":{"value":512.0},"type":"SCALAR"},{"name":"mem","reservations":[{"role":"muggle","type":"STATIC"}],"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: I1110 20:54:12.946524 17338 slave.cpp:601] Agent attributes: [ ]
3: I1110 20:54:12.946534 17338 slave.cpp:610] Agent hostname: 4c4e601f62ba
3: I1110 20:54:12.946692 17333 status_update_manager.cpp:177] Pausing sending status updates
3: I1110 20:54:12.946693 17323 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1110 20:54:12.946727 17323 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1110 20:54:12.946852 17344 authenticator.cpp:204] Received SASL authentication start
3: I1110 20:54:12.946904 17344 authenticator.cpp:326] Authentication requires more steps
3: I1110 20:54:12.947006 17345 authenticatee.cpp:259] Received SASL authentication step
3: I1110 20:54:12.947125 17341 authenticator.cpp:232] Received SASL authentication step
3: I1110 20:54:12.947157 17341 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c4e601f62ba' server FQDN: '4c4e601f62ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1110 20:54:12.947172 17341 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1110 20:54:12.947219 17341 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1110 20:54:12.947252 17341 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c4e601f62ba' server FQDN: '4c4e601f62ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1110 20:54:12.947263 17341 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1110 20:54:12.947271 17341 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1110 20:54:12.947290 17341 authenticator.cpp:318] Authentication success
3: I1110 20:54:12.947366 17330 authenticatee.cpp:299] Authentication success
3: I1110 20:54:12.947504 17336 master.cpp:8316] Successfully authenticated principal 'test-principal' at scheduler-2b5d251e-e797-4e00-9791-fbc26423887d@172.17.0.4:36855
3: I1110 20:54:12.947568 17341 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(349)@172.17.0.4:36855
3: I1110 20:54:12.947681 17343 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:36855
3: I1110 20:54:12.947702 17343 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:36855
3: I1110 20:54:12.947820 17343 sched.cpp:857] Will retry registration in 1.554164579secs if necessary
3: I1110 20:54:12.948016 17325 master.cpp:2962] Received SUBSCRIBE call for framework 'framework-superhero' at scheduler-2b5d251e-e797-4e00-9791-fbc26423887d@172.17.0.4:36855
3: I1110 20:54:12.948104 17325 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ superhero }'
3: I1110 20:54:12.948268 17335 state.cpp:64] Recovering state from '/tmp/SlaveAuthorizerTest_1_FilterStateEndpoint_TSGD6K/meta'
3: I1110 20:54:12.948530 17328 status_update_manager.cpp:203] Recovering status update manager
3: I1110 20:54:12.948696 17332 master.cpp:3042] Subscribing framework framework-superhero with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1110 20:54:12.948873 17334 slave.cpp:6422] Finished recovery
3: I1110 20:54:12.949378 17323 sched.cpp:751] Framework registered with 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-0000
3: I1110 20:54:12.949478 17323 sched.cpp:765] Scheduler::registered took 74730ns
3: I1110 20:54:12.949538 17333 hierarchical.cpp:303] Added framework 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-0000
3: I1110 20:54:12.949654 17343 status_update_manager.cpp:177] Pausing sending status updates
3: I1110 20:54:12.949686 17341 slave.cpp:1007] New master detected at master@172.17.0.4:36855
3: I1110 20:54:12.949810 17341 slave.cpp:1042] Detecting new master
3: I1110 20:54:12.949945 17333 hierarchical.cpp:1450] Performed allocation for 0 agents in 92484ns
3: I1110 20:54:12.951012 17329 slave.cpp:1069] Authenticating with master master@172.17.0.4:36855
3: I1110 20:54:12.951064 17329 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1110 20:54:12.951262 17322 authenticatee.cpp:121] Creating new client SASL connection
3: I1110 20:54:12.951490 17328 master.cpp:8286] Authenticating slave(149)@172.17.0.4:36855
3: I1110 20:54:12.951637 17324 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(350)@172.17.0.4:36855
3: I1110 20:54:12.951905 17342 authenticator.cpp:98] Creating new server SASL connection
3: I1110 20:54:12.952136 17339 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1110 20:54:12.952157 17339 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1110 20:54:12.952252 17344 authenticator.cpp:204] Received SASL authentication start
3: I1110 20:54:12.952299 17344 authenticator.cpp:326] Authentication requires more steps
3: I1110 20:54:12.952401 17332 authenticatee.cpp:259] Received SASL authentication step
3: I1110 20:54:12.952512 17345 authenticator.cpp:232] Received SASL authentication step
3: I1110 20:54:12.952536 17345 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c4e601f62ba' server FQDN: '4c4e601f62ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1110 20:54:12.952548 17345 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1110 20:54:12.952574 17345 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1110 20:54:12.952589 17345 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4c4e601f62ba' server FQDN: '4c4e601f62ba' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1110 20:54:12.952595 17345 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1110 20:54:12.952600 17345 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1110 20:54:12.952611 17345 authenticator.cpp:318] Authentication success
3: I1110 20:54:12.952677 17323 authenticatee.cpp:299] Authentication success
3: I1110 20:54:12.952736 17334 master.cpp:8316] Successfully authenticated principal 'test-principal' at slave(149)@172.17.0.4:36855
3: I1110 20:54:12.952759 17327 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(350)@172.17.0.4:36855
3: I1110 20:54:12.952916 17323 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:36855
3: I1110 20:54:12.953155 17323 slave.cpp:1682] Will retry registration in 9.942102ms if necessary
3: I1110 20:54:12.953367 17336 master.cpp:6033] Received register agent message from slave(149)@172.17.0.4:36855 (4c4e601f62ba)
3: I1110 20:54:12.953490 17336 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1110 20:54:12.953953 17331 master.cpp:6093] Authorized registration of agent at slave(149)@172.17.0.4:36855 (4c4e601f62ba)
3: I1110 20:54:12.954053 17331 master.cpp:6186] Registering agent at slave(149)@172.17.0.4:36855 (4c4e601f62ba) with id 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-S0
3: I1110 20:54:12.954476 17337 registrar.cpp:495] Applied 1 operations in 62843ns; attempting to update the registry
3: I1110 20:54:12.955050 17337 registrar.cpp:552] Successfully updated the registry in 523008ns
3: I1110 20:54:12.955257 17329 master.cpp:6233] Admitted agent 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-S0 at slave(149)@172.17.0.4:36855 (4c4e601f62ba)
3: I1110 20:54:12.956071 17328 slave.cpp:1207] Registered with master master@172.17.0.4:36855; given agent ID 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-S0
3: I1110 20:54:12.955945 17329 master.cpp:6264] Registered agent 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-S0 at slave(149)@172.17.0.4:36855 (4c4e601f62ba) with [{"name":"cpus","reservations":[{"role":"superhero","type":"STATIC"}],"scalar":{"value":2.0},"type":"SCALAR"},{"name":"cpus","reservations":[{"role":"muggle","type":"STATIC"}],"scalar":{"value":3.0},"type":"SCALAR"},{"name":"mem","reservations":[{"role":"superhero","type":"STATIC"}],"scalar":{"value":512.0},"type":"SCALAR"},{"name":"mem","reservations":[{"role":"muggle","type":"STATIC"}],"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: I1110 20:54:12.956343 17339 status_update_manager.cpp:184] Resuming sending status updates
3: I1110 20:54:12.956516 17328 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/SlaveAuthorizerTest_1_FilterStateEndpoint_TSGD6K/meta/slaves/589f5f88-27e2-4c48-9f43-f8a672fe0e5d-S0/slave.info'
3: I1110 20:54:12.956693 17324 hierarchical.cpp:593] Added agent 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-S0 (4c4e601f62ba) with cpus(reservations: [(STATIC,superhero)]):2; cpus(reservations: [(STATIC,muggle)]):3; mem(reservations: [(STATIC,superhero)]):512; mem(reservations: [(STATIC,muggle)]):1024; disk:367489; ports:[31000-32000] (allocated: {})
3: I1110 20:54:12.957109 17328 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1110 20:54:12.957307 17344 master.cpp:7065] Received update of agent 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-S0 at slave(149)@172.17.0.4:36855 (4c4e601f62ba) with total oversubscribed resources {}
3: I1110 20:54:12.957542 17344 master.cpp:7083] Ignoring update on agent 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-S0 at slave(149)@172.17.0.4:36855 (4c4e601f62ba) as it reports no changes
3: I1110 20:54:12.958158 17324 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.24732ms
3: I1110 20:54:12.958729 17332 master.cpp:8116] Sending 1 offers to framework 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-0000 (framework-superhero) at scheduler-2b5d251e-e797-4e00-9791-fbc26423887d@172.17.0.4:36855
3: I1110 20:54:12.959280 17345 sched.cpp:921] Scheduler::resourceOffers took 112786ns
3: I1110 20:54:12.961129 17336 master.cpp:10016] Removing offer 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-O0
3: I1110 20:54:12.961303 17336 master.cpp:4229] Processing ACCEPT call for offers: [ 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-O0 ] on agent 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-S0 at slave(149)@172.17.0.4:36855 (4c4e601f62ba) for framework 589f5f88-27e2-4c48-9f43-f8a672fe0e5d-0000 (framework-superhero) at scheduler-2b5d251e-e797-4e00-9791-fbc26423887d@172.17.0.4:36855
3: I1110 20:54:12.961417 17336 master.cpp:3598] Authorizing framework principal 'test-principal' to launch task 1
3: W1110 20:54:12.963526 17336 validation.cpp:1404] Executor 'test-executor-superhero' for task '1' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
3: W1110 20:54:12.963559 17336 validation.cpp:1416] Executor 'test-executor-superhero' for task '1' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1510344739-28916
Error response from daemon: conflict: unable to remove repository reference "mesos-1510344739-28916" (must force) - container 4c4e601f62ba is using its referenced image aa1d8aac4803
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,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4446
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)/4446/display/redirect>
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) #4445
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)/4445/display/redirect>
------------------------------------------
[...truncated 13.75 MB...]
3: I1111 06:54:43.950383 17262 slave.cpp:4053] Got registration for executor 'test-executor' of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 from executor(115)@172.17.0.2:46580
3: I1111 06:54:43.950856 17270 exec.cpp:237] Executor registered on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
3: I1111 06:54:43.950908 17270 exec.cpp:249] Executor::registered took 25170ns
3: I1111 06:54:43.951380 17262 slave.cpp:2669] Sending queued task '1' to executor 'test-executor' of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 at executor(115)@172.17.0.2:46580
3: I1111 06:54:43.951823 17262 exec.cpp:331] Executor asked to run task '1'
3: I1111 06:54:43.951958 17262 exec.cpp:340] Executor::launchTask took 110717ns
3: I1111 06:54:43.952069 17262 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.952383 17261 slave.cpp:4507] Handling status update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 from executor(115)@172.17.0.2:46580
3: I1111 06:54:43.953101 17266 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.953153 17266 status_update_manager.cpp:500] Creating StatusUpdate stream for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.953625 17266 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 to the agent
3: I1111 06:54:43.953838 17269 slave.cpp:4988] Forwarding the update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 to master@172.17.0.2:46580
3: I1111 06:54:43.954043 17269 slave.cpp:4882] Status update manager successfully handled status update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.954088 17269 slave.cpp:4898] Sending acknowledgement for status update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 to executor(115)@172.17.0.2:46580
3: I1111 06:54:43.954210 17258 master.cpp:7248] Status update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 from agent f087df97-96b4-4cc9-b99a-a36b74462017-S0 at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.954277 17259 exec.cpp:388] Executor received status update acknowledgement cda3c057-1ba3-47a7-8d61-4a8cef1c2171 for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.954274 17258 master.cpp:7310] Forwarding status update TASK_RUNNING (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.954500 17258 master.cpp:9503] Updating the state of task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: I1111 06:54:43.954803 17264 sched.cpp:1029] Scheduler::statusUpdate took 110672ns
3: I1111 06:54:43.955158 17271 master.cpp:5792] Processing ACKNOWLEDGE call cda3c057-1ba3-47a7-8d61-4a8cef1c2171 for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 (default) at scheduler-6bf08b38-c4f3-4b39-829d-206f49592ab0@172.17.0.2:46580 on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
3: I1111 06:54:43.955282 17257 sched.cpp:2009] Asked to stop the driver
3: I1111 06:54:43.955390 17267 sched.cpp:1191] Stopping framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.955544 17263 status_update_manager.cpp:395] Received status update acknowledgement (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.955682 17261 master.cpp:8793] Processing TEARDOWN call for framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 (default) at scheduler-6bf08b38-c4f3-4b39-829d-206f49592ab0@172.17.0.2:46580
3: I1111 06:54:43.955724 17261 master.cpp:8805] Removing framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 (default) at scheduler-6bf08b38-c4f3-4b39-829d-206f49592ab0@172.17.0.2:46580
3: I1111 06:54:43.955821 17261 master.cpp:3332] Deactivating framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 (default) at scheduler-6bf08b38-c4f3-4b39-829d-206f49592ab0@172.17.0.2:46580
3: I1111 06:54:43.955840 17266 slave.cpp:3791] Status update manager successfully handled status update acknowledgement (UUID: cda3c057-1ba3-47a7-8d61-4a8cef1c2171) for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.955972 17269 hierarchical.cpp:412] Deactivated framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.956069 17261 master.cpp:9503] Updating the state of task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
3: I1111 06:54:43.956070 17259 slave.cpp:3267] Asked to shut down framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 by master@172.17.0.2:46580
3: I1111 06:54:43.956120 17259 slave.cpp:3292] Shutting down framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.956161 17259 slave.cpp:5855] Shutting down executor 'test-executor' of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 at executor(115)@172.17.0.2:46580
3: I1111 06:54:43.956259 17258 exec.cpp:435] Executor asked to shutdown
3: I1111 06:54:43.956292 17258 exec.cpp:450] Executor::shutdown took 18445ns
3: I1111 06:54:43.956493 17271 slave.cpp:5120] Got exited event for executor(115)@172.17.0.2:46580
3: I1111 06:54:43.956903 17261 master.cpp:9597] Removing task 1 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0 at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.957639 17261 master.cpp:9626] Removing executor 'test-executor' with resources [] of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0 at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.957675 17260 slave.cpp:5520] Executor 'test-executor' of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 exited with status 0
3: I1111 06:54:43.957757 17260 slave.cpp:5624] Cleaning up executor 'test-executor' of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 at executor(115)@172.17.0.2:46580
3: I1111 06:54:43.957852 17265 hierarchical.cpp:1125] Recovered cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0 from framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.958060 17264 gc.cpp:90] Scheduling '/tmp/MasterAuthorizationTest_AuthorizedTask_FnQEhi/slaves/f087df97-96b4-4cc9-b99a-a36b74462017-S0/frameworks/f087df97-96b4-4cc9-b99a-a36b74462017-0000/executors/test-executor/runs/4525ebe0-68ad-40bc-b25a-99fde9fdb05c' for gc 6.99998891267259days in the future
3: I1111 06:54:43.958277 17260 slave.cpp:5731] Cleaning up framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.958276 17263 gc.cpp:90] Scheduling '/tmp/MasterAuthorizationTest_AuthorizedTask_FnQEhi/slaves/f087df97-96b4-4cc9-b99a-a36b74462017-S0/frameworks/f087df97-96b4-4cc9-b99a-a36b74462017-0000/executors/test-executor' for gc 6.99998891001185days in the future
3: I1111 06:54:43.958384 17269 status_update_manager.cpp:285] Closing status update streams for framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.958428 17269 status_update_manager.cpp:531] Cleaning up status update stream for task 1 of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.958480 17259 hierarchical.cpp:355] Removed framework f087df97-96b4-4cc9-b99a-a36b74462017-0000
3: I1111 06:54:43.958544 17263 gc.cpp:90] Scheduling '/tmp/MasterAuthorizationTest_AuthorizedTask_FnQEhi/slaves/f087df97-96b4-4cc9-b99a-a36b74462017-S0/frameworks/f087df97-96b4-4cc9-b99a-a36b74462017-0000' for gc 6.99998890715259days in the future
3: W1111 06:54:43.958709 17261 master.cpp:7454] Ignoring unknown exited executor 'test-executor' of framework f087df97-96b4-4cc9-b99a-a36b74462017-0000 on agent f087df97-96b4-4cc9-b99a-a36b74462017-S0 at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.959002 17265 slave.cpp:883] Agent terminating
3: I1111 06:54:43.959193 17264 master.cpp:1309] Agent f087df97-96b4-4cc9-b99a-a36b74462017-S0 at slave(299)@172.17.0.2:46580 (2782842d33d5) disconnected
3: I1111 06:54:43.959219 17264 master.cpp:3369] Disconnecting agent f087df97-96b4-4cc9-b99a-a36b74462017-S0 at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.959271 17264 master.cpp:3388] Deactivating agent f087df97-96b4-4cc9-b99a-a36b74462017-S0 at slave(299)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:43.959352 17267 hierarchical.cpp:690] Agent f087df97-96b4-4cc9-b99a-a36b74462017-S0 deactivated
3: I1111 06:54:43.963544 17257 master.cpp:1151] Master terminating
3: I1111 06:54:43.964382 17273 hierarchical.cpp:626] Removed agent f087df97-96b4-4cc9-b99a-a36b74462017-S0
3: [ OK ] MasterAuthorizationTest.AuthorizedTask (74 ms)
3: [ RUN ] MasterAuthorizationTest.UnauthorizedTask
3: I1111 06:54:43.973251 17257 cluster.cpp:162] Creating default 'local' authorizer
3: I1111 06:54:43.976135 17267 master.cpp:448] Master 2f7f580a-832b-4e20-9015-63576543d149 (2782842d33d5) started on 172.17.0.2:46580
3: I1111 06:54:43.976161 17267 master.cpp:450] Flags at startup: --acls="run_tasks {
3: principals {
3: type: NONE
3: }
3: users {
3: values: "foo"
3: }
3: }
3: " --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/NihwMS/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/NihwMS/master" --zk_session_timeout="10secs"
3: I1111 06:54:43.976595 17267 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1111 06:54:43.976605 17267 master.cpp:505] Master only allowing authenticated agents to register
3: I1111 06:54:43.976611 17267 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1111 06:54:43.976617 17267 credentials.hpp:37] Loading credentials for authentication from '/tmp/NihwMS/credentials'
3: I1111 06:54:43.976933 17267 master.cpp:555] Using default 'crammd5' authenticator
3: I1111 06:54:43.977088 17267 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1111 06:54:43.977284 17267 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1111 06:54:43.977460 17267 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1111 06:54:43.977596 17267 master.cpp:634] Authorization enabled
3: I1111 06:54:43.977825 17258 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1111 06:54:43.977869 17262 whitelist_watcher.cpp:77] No whitelist given
3: I1111 06:54:43.980875 17269 master.cpp:2213] Elected as the leading master!
3: I1111 06:54:43.980906 17269 master.cpp:1693] Recovering from registrar
3: I1111 06:54:43.981099 17272 registrar.cpp:347] Recovering registrar
3: I1111 06:54:43.981734 17272 registrar.cpp:391] Successfully fetched the registry (0B) in 591872ns
3: I1111 06:54:43.981842 17272 registrar.cpp:495] Applied 1 operations in 28515ns; attempting to update the registry
3: I1111 06:54:43.982393 17272 registrar.cpp:552] Successfully updated the registry in 495872ns
3: I1111 06:54:43.982520 17272 registrar.cpp:424] Successfully recovered registrar
3: I1111 06:54:43.982954 17258 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1111 06:54:43.983021 17260 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1111 06:54:43.988366 17257 process.cpp:3178] Attempted to spawn already running process files@172.17.0.2:46580
3: I1111 06:54:43.988705 17257 cluster.cpp:448] Creating default 'local' authorizer
3: I1111 06:54:43.991094 17272 slave.cpp:262] Mesos agent started on (300)@172.17.0.2:46580
3: I1111 06:54:43.991116 17272 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/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/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/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/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/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/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb" --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/MasterAuthorizationTest_UnauthorizedTask_MElU21" --zk_session_timeout="10secs"
3: I1111 06:54:43.991639 17272 credentials.hpp:86] Loading credential for authentication from '/tmp/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/credential'
3: W1111 06:54:43.991662 17257 process.cpp:3178] Attempted to spawn already running process version@172.17.0.2:46580
3: I1111 06:54:43.991834 17272 slave.cpp:295] Agent using credential for: test-principal
3: I1111 06:54:43.991853 17272 credentials.hpp:37] Loading credentials for authentication from '/tmp/MasterAuthorizationTest_UnauthorizedTask_ZtEjjb/http_credentials'
3: I1111 06:54:43.992193 17272 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1111 06:54:43.992338 17272 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1111 06:54:43.992594 17257 sched.cpp:232] Version: 1.5.0
3: I1111 06:54:43.993161 17261 sched.cpp:336] New master detected at master@172.17.0.2:46580
3: I1111 06:54:43.993278 17261 sched.cpp:396] Authenticating with master master@172.17.0.2:46580
3: I1111 06:54:43.993299 17261 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1111 06:54:43.993563 17262 authenticatee.cpp:121] Creating new client SASL connection
3: I1111 06:54:43.993873 17260 master.cpp:8286] Authenticating scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:43.994036 17268 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(628)@172.17.0.2:46580
3: I1111 06:54:43.993953 17272 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1111 06:54:43.994233 17272 slave.cpp:601] Agent attributes: [ ]
3: I1111 06:54:43.994246 17272 slave.cpp:610] Agent hostname: 2782842d33d5
3: I1111 06:54:43.994402 17269 authenticator.cpp:98] Creating new server SASL connection
3: I1111 06:54:43.994428 17267 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 06:54:43.994654 17271 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1111 06:54:43.994683 17271 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1111 06:54:43.994813 17273 authenticator.cpp:204] Received SASL authentication start
3: I1111 06:54:43.994879 17273 authenticator.cpp:326] Authentication requires more steps
3: I1111 06:54:43.995036 17266 authenticatee.cpp:259] Received SASL authentication step
3: I1111 06:54:43.995183 17266 authenticator.cpp:232] Received SASL authentication step
3: I1111 06:54:43.995213 17266 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2782842d33d5' server FQDN: '2782842d33d5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1111 06:54:43.995224 17266 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 06:54:43.995255 17266 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 06:54:43.995275 17266 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2782842d33d5' server FQDN: '2782842d33d5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1111 06:54:43.995287 17266 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:43.995296 17266 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:43.995311 17266 authenticator.cpp:318] Authentication success
3: I1111 06:54:43.995404 17264 authenticatee.cpp:299] Authentication success
3: I1111 06:54:43.995471 17265 master.cpp:8316] Successfully authenticated principal 'test-principal' at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:43.995527 17266 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(628)@172.17.0.2:46580
3: I1111 06:54:43.995712 17261 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:46580
3: I1111 06:54:43.995734 17261 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:46580
3: I1111 06:54:43.995849 17261 sched.cpp:857] Will retry registration in 1.571954047secs if necessary
3: I1111 06:54:43.996047 17267 master.cpp:2962] Received SUBSCRIBE call for framework 'default' at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:43.996129 17267 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1111 06:54:43.996428 17273 state.cpp:64] Recovering state from '/tmp/MasterAuthorizationTest_UnauthorizedTask_MElU21/meta'
3: I1111 06:54:43.996857 17273 master.cpp:3042] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1111 06:54:43.996896 17259 status_update_manager.cpp:203] Recovering status update manager
3: I1111 06:54:43.997335 17262 slave.cpp:6422] Finished recovery
3: I1111 06:54:43.997484 17273 sched.cpp:751] Framework registered with 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:43.997534 17273 sched.cpp:765] Scheduler::registered took 22365ns
3: I1111 06:54:43.997668 17266 hierarchical.cpp:303] Added framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:43.997913 17266 hierarchical.cpp:1450] Performed allocation for 0 agents in 98576ns
3: I1111 06:54:43.998292 17271 slave.cpp:1007] New master detected at master@172.17.0.2:46580
3: I1111 06:54:43.998329 17264 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 06:54:43.998397 17271 slave.cpp:1042] Detecting new master
3: I1111 06:54:44.004760 17270 slave.cpp:1069] Authenticating with master master@172.17.0.2:46580
3: I1111 06:54:44.004832 17270 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1111 06:54:44.005084 17258 authenticatee.cpp:121] Creating new client SASL connection
3: I1111 06:54:44.005373 17260 master.cpp:8286] Authenticating slave(300)@172.17.0.2:46580
3: I1111 06:54:44.005491 17259 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(629)@172.17.0.2:46580
3: I1111 06:54:44.005751 17268 authenticator.cpp:98] Creating new server SASL connection
3: I1111 06:54:44.006021 17267 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1111 06:54:44.006050 17267 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1111 06:54:44.006167 17261 authenticator.cpp:204] Received SASL authentication start
3: I1111 06:54:44.006222 17261 authenticator.cpp:326] Authentication requires more steps
3: I1111 06:54:44.006323 17261 authenticatee.cpp:259] Received SASL authentication step
3: I1111 06:54:44.006467 17269 authenticator.cpp:232] Received SASL authentication step
3: I1111 06:54:44.006498 17269 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2782842d33d5' server FQDN: '2782842d33d5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1111 06:54:44.006508 17269 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 06:54:44.006536 17269 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 06:54:44.006553 17269 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2782842d33d5' server FQDN: '2782842d33d5' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1111 06:54:44.006564 17269 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:44.006572 17269 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1111 06:54:44.006585 17269 authenticator.cpp:318] Authentication success
3: I1111 06:54:44.006680 17266 authenticatee.cpp:299] Authentication success
3: I1111 06:54:44.006731 17262 master.cpp:8316] Successfully authenticated principal 'test-principal' at slave(300)@172.17.0.2:46580
3: I1111 06:54:44.006762 17263 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(629)@172.17.0.2:46580
3: I1111 06:54:44.007067 17272 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:46580
3: I1111 06:54:44.007295 17272 slave.cpp:1682] Will retry registration in 12.984422ms if necessary
3: I1111 06:54:44.007504 17270 master.cpp:6033] Received register agent message from slave(300)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:44.007642 17270 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1111 06:54:44.008059 17260 master.cpp:6093] Authorized registration of agent at slave(300)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:44.008169 17260 master.cpp:6186] Registering agent at slave(300)@172.17.0.2:46580 (2782842d33d5) with id 2f7f580a-832b-4e20-9015-63576543d149-S0
3: I1111 06:54:44.008705 17259 registrar.cpp:495] Applied 1 operations in 64603ns; attempting to update the registry
3: I1111 06:54:44.009331 17259 registrar.cpp:552] Successfully updated the registry in 561152ns
3: I1111 06:54:44.009577 17269 master.cpp:6233] Admitted agent 2f7f580a-832b-4e20-9015-63576543d149-S0 at slave(300)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:44.010349 17262 slave.cpp:1207] Registered with master master@172.17.0.2:46580; given agent ID 2f7f580a-832b-4e20-9015-63576543d149-S0
3: I1111 06:54:44.010496 17265 status_update_manager.cpp:184] Resuming sending status updates
3: I1111 06:54:44.010257 17269 master.cpp:6264] Registered agent 2f7f580a-832b-4e20-9015-63576543d149-S0 at slave(300)@172.17.0.2:46580 (2782842d33d5) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1111 06:54:44.010663 17264 hierarchical.cpp:593] Added agent 2f7f580a-832b-4e20-9015-63576543d149-S0 (2782842d33d5) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1111 06:54:44.010701 17262 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/MasterAuthorizationTest_UnauthorizedTask_MElU21/meta/slaves/2f7f580a-832b-4e20-9015-63576543d149-S0/slave.info'
3: I1111 06:54:44.011144 17262 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1111 06:54:44.011348 17262 master.cpp:7065] Received update of agent 2f7f580a-832b-4e20-9015-63576543d149-S0 at slave(300)@172.17.0.2:46580 (2782842d33d5) with total oversubscribed resources {}
3: I1111 06:54:44.011538 17262 master.cpp:7083] Ignoring update on agent 2f7f580a-832b-4e20-9015-63576543d149-S0 at slave(300)@172.17.0.2:46580 (2782842d33d5) as it reports no changes
3: I1111 06:54:44.012274 17264 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.392507ms
3: I1111 06:54:44.012774 17272 master.cpp:8116] Sending 1 offers to framework 2f7f580a-832b-4e20-9015-63576543d149-0000 (default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.013392 17270 sched.cpp:921] Scheduler::resourceOffers took 124522ns
3: I1111 06:54:44.015431 17266 master.cpp:10016] Removing offer 2f7f580a-832b-4e20-9015-63576543d149-O0
3: I1111 06:54:44.015609 17266 master.cpp:4229] Processing ACCEPT call for offers: [ 2f7f580a-832b-4e20-9015-63576543d149-O0 ] on agent 2f7f580a-832b-4e20-9015-63576543d149-S0 at slave(300)@172.17.0.2:46580 (2782842d33d5) for framework 2f7f580a-832b-4e20-9015-63576543d149-0000 (default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.015755 17266 master.cpp:3598] Authorizing framework principal 'test-principal' to launch task 1
3: I1111 06:54:44.017117 17269 master.cpp:7305] Sending status update TASK_ERROR for task 1 of framework 2f7f580a-832b-4e20-9015-63576543d149-0000 'Not authorized to launch as user 'foo''
3: I1111 06:54:44.017491 17264 sched.cpp:1029] Scheduler::statusUpdate took 64801ns
3: I1111 06:54:44.018162 17268 master.cpp:7704] Performing implicit task state reconciliation for framework 2f7f580a-832b-4e20-9015-63576543d149-0000 (default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.018339 17272 hierarchical.cpp:1125] Recovered cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 2f7f580a-832b-4e20-9015-63576543d149-S0 from framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:44.018420 17272 hierarchical.cpp:1171] Framework 2f7f580a-832b-4e20-9015-63576543d149-0000 filtered agent 2f7f580a-832b-4e20-9015-63576543d149-S0 for 5secs
3: I1111 06:54:44.018632 17257 sched.cpp:2009] Asked to stop the driver
3: I1111 06:54:44.018735 17259 sched.cpp:1191] Stopping framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:44.019057 17271 master.cpp:8793] Processing TEARDOWN call for framework 2f7f580a-832b-4e20-9015-63576543d149-0000 (default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.019095 17271 master.cpp:8805] Removing framework 2f7f580a-832b-4e20-9015-63576543d149-0000 (default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.019111 17271 master.cpp:3332] Deactivating framework 2f7f580a-832b-4e20-9015-63576543d149-0000 (default) at scheduler-4ee42587-8bd8-4f22-ab48-ae8afc1fd796@172.17.0.2:46580
3: I1111 06:54:44.019245 17263 hierarchical.cpp:412] Deactivated framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:44.019358 17263 slave.cpp:3267] Asked to shut down framework 2f7f580a-832b-4e20-9015-63576543d149-0000 by master@172.17.0.2:46580
3: I1111 06:54:44.019395 17263 slave.cpp:3282] Cannot shut down unknown framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:44.019805 17267 hierarchical.cpp:355] Removed framework 2f7f580a-832b-4e20-9015-63576543d149-0000
3: I1111 06:54:44.020354 17257 slave.cpp:883] Agent terminating
3: I1111 06:54:44.020539 17262 master.cpp:1309] Agent 2f7f580a-832b-4e20-9015-63576543d149-S0 at slave(300)@172.17.0.2:46580 (2782842d33d5) disconnected
3: I1111 06:54:44.020570 17262 master.cpp:3369] Disconnecting agent 2f7f580a-832b-4e20-9015-63576543d149-S0 at slave(300)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:44.020643 17262 master.cpp:3388] Deactivating agent 2f7f580a-832b-4e20-9015-63576543d149-S0 at slave(300)@172.17.0.2:46580 (2782842d33d5)
3: I1111 06:54:44.020776 17260 hierarchical.cpp:690] Agent 2f7f580a-832b-4e20-9015-63576543d149-S0 deactivated
3: I1111 06:54:44.024834 17257 master.cpp:1151] Master terminating
3: I1111 06:54:44.025576 17268 hierarchical.cpp:626] Removed agent 2f7f580a-832b-4e20-9015-63576543d149-S0
3: [ OK ] MasterAuthorizationTest.UnauthorizedTask (59 ms)
3: [ RUN ] MasterAuthorizationTest.UnauthorizedTaskGroup
3: I1111 06:54:44.032232 17257 cluster.cpp:162] Creating default 'local' authorizer
3: I1111 06:54:44.035271 17259 master.cpp:448] Master fef770b0-29b9-4f39-95bd-71c650445e2e (2782842d33d5) started on 172.17.0.2:46580
3: I1111 06:54:44.035295 17259 master.cpp:450] Flags at startup: --acls="run_tasks {
3: principals {
3: type: NONE
3: }
3: users {
3: values: "foo"
3: }
3: }
3: " --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/MiBBjD/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/MiBBjD/master" --zk_session_timeout="10secs"
3: I1111 06:54:44.035706 17259 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1111 06:54:44.035715 17259 master.cpp:505] Master only allowing authenticated agents to register
3: I1111 06:54:44.035722 17259 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1111 06:54:44.035727 17259 credentials.hpp:37] Loading credentials for authentication from '/tmp/MiBBjD/credentials'
3: I1111 06:54:44.036115 17259 master.cpp:555] Using default 'crammd5' authenticator
3: I1111 06:54:44.036270 17259 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1111 06:54:44.036434 17259 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1111 06:54:44.036598 17259 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1111 06:54:44.036753 17259 master.cpp:634] Authorization enabled
3: I1111 06:54:44.036933 17271 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1111 06:54:44.036940 17264 whitelist_watcher.cpp:77] No whitelist given
3: I1111 06:54:44.039788 17259 master.cpp:2213] Elected as the leading master!
3: I1111 06:54:44.039820 17259 master.cpp:1693] Recovering from registrar
3: I1111 06:54:44.040092 17266 registrar.cpp:347] Recovering registrar
3: I1111 06:54:44.040659 17266 registrar.cpp:391] Successfully fetched the registry (0B) in 526848ns
3: I1111 06:54:44.040766 17266 registrar.cpp:495] Applied 1 operations in 26952ns; attempting to update the registry
3: I1111 06:54:44.041306 17266 registrar.cpp:552] Successfully updated the registry in 486144ns
3: I1111 06:54:44.041434 17266 registrar.cpp:424] Successfully recovered registrar
3: I1111 06:54:44.041854 17271 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1111 06:54:44.041905 17270 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1111 06:54:44.047060 17257 process.cpp:3178] Attempted to spawn already running process files@172.17.0.2:46580
3: I1111 06:54:44.048188 17257 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1111 06:54:44.048873 17257 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1111 06:54:44.049003 17257 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1111 06:54:44.049052 17257 provisioner.cpp:255] Using default backend 'copy'
write /dev/stdout: resource temporarily unavailable
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com
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) #4444
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)/4444/display/redirect?page=changes>
Changes:
[jpeach] Made Envp conversion operator consistent with Argv.
[jpeach] Deleted Argv copy constructor and assignment members.
------------------------------------------
[...truncated 24.27 MB...]
3: I1111 02:02:36.536967 17338 master.cpp:2213] Elected as the leading master!
3: I1111 02:02:36.536986 17338 master.cpp:1693] Recovering from registrar
3: I1111 02:02:36.537081 17340 registrar.cpp:347] Recovering registrar
3: I1111 02:02:36.537498 17340 registrar.cpp:391] Successfully fetched the registry (0B) in 390144ns
3: I1111 02:02:36.537575 17340 registrar.cpp:495] Applied 1 operations in 18495ns; attempting to update the registry
3: I1111 02:02:36.538005 17340 registrar.cpp:552] Successfully updated the registry in 387072ns
3: I1111 02:02:36.538105 17340 registrar.cpp:424] Successfully recovered registrar
3: I1111 02:02:36.538415 17339 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1111 02:02:36.538441 17330 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: I1111 02:02:36.541064 17329 process.cpp:3925] Handling HTTP event for process 'master' with path: '/master/api/v1'
3: I1111 02:02:36.542775 17347 http.cpp:1185] HTTP POST for /master/api/v1 from 172.17.0.5:49278
3: I1111 02:02:36.542876 17347 http.cpp:673] Processing call READ_FILE
3: I1111 02:02:36.544819 17323 master.cpp:1151] Master terminating
3: [ OK ] ContentType/MasterAPITest.ReadFileInvalidPath/0 (21 ms)
3: [ RUN ] ContentType/MasterAPITest.ReadFileInvalidPath/1
3: I1111 02:02:36.550580 17323 cluster.cpp:162] Creating default 'local' authorizer
3: I1111 02:02:36.553323 17332 master.cpp:448] Master 935b73af-ec12-4672-9b86-b09db6c84098 (d9cccd9998bb) started on 172.17.0.5:41640
3: I1111 02:02:36.553346 17332 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1000secs" --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/lPG0KX/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/lPG0KX/master" --zk_session_timeout="10secs"
3: I1111 02:02:36.553573 17332 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1111 02:02:36.553580 17332 master.cpp:505] Master only allowing authenticated agents to register
3: I1111 02:02:36.553586 17332 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1111 02:02:36.553589 17332 credentials.hpp:37] Loading credentials for authentication from '/tmp/lPG0KX/credentials'
3: I1111 02:02:36.553833 17332 master.cpp:555] Using default 'crammd5' authenticator
3: I1111 02:02:36.553952 17332 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1111 02:02:36.554080 17332 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1111 02:02:36.554200 17332 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1111 02:02:36.554342 17332 master.cpp:634] Authorization enabled
3: I1111 02:02:36.554519 17324 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1111 02:02:36.554519 17339 whitelist_watcher.cpp:77] No whitelist given
3: I1111 02:02:36.556893 17337 master.cpp:2213] Elected as the leading master!
3: I1111 02:02:36.556933 17337 master.cpp:1693] Recovering from registrar
3: I1111 02:02:36.557132 17346 registrar.cpp:347] Recovering registrar
3: I1111 02:02:36.557816 17346 registrar.cpp:391] Successfully fetched the registry (0B) in 637952ns
3: I1111 02:02:36.557940 17346 registrar.cpp:495] Applied 1 operations in 41544ns; attempting to update the registry
3: I1111 02:02:36.558576 17346 registrar.cpp:552] Successfully updated the registry in 585984ns
3: I1111 02:02:36.558698 17346 registrar.cpp:424] Successfully recovered registrar
3: I1111 02:02:36.559151 17345 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1111 02:02:36.559242 17325 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: I1111 02:02:36.561460 17332 process.cpp:3925] Handling HTTP event for process 'master' with path: '/master/api/v1'
3: I1111 02:02:36.563037 17331 http.cpp:1185] HTTP POST for /master/api/v1 from 172.17.0.5:49280
3: I1111 02:02:36.563201 17331 http.cpp:673] Processing call READ_FILE
3: I1111 02:02:36.564859 17323 master.cpp:1151] Master terminating
3: [ OK ] ContentType/MasterAPITest.ReadFileInvalidPath/1 (20 ms)
3: [ RUN ] ContentType/MasterAPITest.Teardown/0
3: I1111 02:02:36.574429 17329 master.cpp:448] Master 87d17586-17ad-4ff3-930a-847c2a72ad1c (d9cccd9998bb) started on 172.17.0.5:41640
3: I1111 02:02:36.574461 17329 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1000secs" --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/5XoHpU/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/5XoHpU/master" --zk_session_timeout="10secs"
3: I1111 02:02:36.574771 17329 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1111 02:02:36.574780 17329 master.cpp:505] Master only allowing authenticated agents to register
3: I1111 02:02:36.574785 17329 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1111 02:02:36.574791 17329 credentials.hpp:37] Loading credentials for authentication from '/tmp/5XoHpU/credentials'
3: I1111 02:02:36.575100 17329 master.cpp:555] Using default 'crammd5' authenticator
3: I1111 02:02:36.575254 17329 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1111 02:02:36.575462 17329 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1111 02:02:36.575630 17329 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1111 02:02:36.575762 17329 master.cpp:634] Authorization enabled
3: I1111 02:02:36.575958 17345 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1111 02:02:36.576007 17338 whitelist_watcher.cpp:77] No whitelist given
3: I1111 02:02:36.578660 17324 master.cpp:2213] Elected as the leading master!
3: I1111 02:02:36.578686 17324 master.cpp:1693] Recovering from registrar
3: I1111 02:02:36.578789 17332 registrar.cpp:347] Recovering registrar
3: I1111 02:02:36.579313 17332 registrar.cpp:391] Successfully fetched the registry (0B) in 472064ns
3: I1111 02:02:36.579453 17332 registrar.cpp:495] Applied 1 operations in 31373ns; attempting to update the registry
3: I1111 02:02:36.580189 17332 registrar.cpp:552] Successfully updated the registry in 663808ns
3: I1111 02:02:36.580364 17332 registrar.cpp:424] Successfully recovered registrar
3: I1111 02:02:36.580798 17347 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1111 02:02:36.580844 17346 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1111 02:02:36.586890 17323 process.cpp:3178] Attempted to spawn already running process files@172.17.0.5:41640
3: I1111 02:02:36.587196 17323 cluster.cpp:448] Creating default 'local' authorizer
3: I1111 02:02:36.589584 17344 slave.cpp:262] Mesos agent started on (640)@172.17.0.5:41640
3: I1111 02:02:36.589607 17344 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ContentType_MasterAPITest_Teardown_0_xtSMNN/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/ContentType_MasterAPITest_Teardown_0_xtSMNN/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/ContentType_MasterAPITest_Teardown_0_xtSMNN/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/ContentType_MasterAPITest_Teardown_0_xtSMNN/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/ContentType_MasterAPITest_Teardown_0_xtSMNN/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ContentType_MasterAPITest_Teardown_0_xtSMNN" --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/ContentType_MasterAPITest_Teardown_0_UPwJ6Q" --zk_session_timeout="10secs"
3: I1111 02:02:36.589998 17344 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_MasterAPITest_Teardown_0_xtSMNN/credential'
3: I1111 02:02:36.590137 17344 slave.cpp:295] Agent using credential for: test-principal
3: I1111 02:02:36.590167 17344 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_MasterAPITest_Teardown_0_xtSMNN/http_credentials'
3: I1111 02:02:36.590410 17344 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1111 02:02:36.590536 17344 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1111 02:02:36.592036 17344 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1111 02:02:36.592259 17344 slave.cpp:601] Agent attributes: [ ]
3: I1111 02:02:36.592283 17344 slave.cpp:610] Agent hostname: d9cccd9998bb
3: I1111 02:02:36.592408 17343 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 02:02:36.593780 17325 state.cpp:64] Recovering state from '/tmp/ContentType_MasterAPITest_Teardown_0_UPwJ6Q/meta'
3: I1111 02:02:36.594017 17345 status_update_manager.cpp:203] Recovering status update manager
3: I1111 02:02:36.594427 17329 slave.cpp:6422] Finished recovery
3: I1111 02:02:36.595072 17339 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 02:02:36.595090 17334 slave.cpp:1007] New master detected at master@172.17.0.5:41640
3: I1111 02:02:36.595173 17334 slave.cpp:1042] Detecting new master
3: I1111 02:02:36.602655 17327 slave.cpp:1069] Authenticating with master master@172.17.0.5:41640
3: I1111 02:02:36.602738 17327 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1111 02:02:36.603085 17324 authenticatee.cpp:121] Creating new client SASL connection
3: I1111 02:02:36.603585 17324 master.cpp:8286] Authenticating slave(640)@172.17.0.5:41640
3: I1111 02:02:36.603760 17331 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1264)@172.17.0.5:41640
3: I1111 02:02:36.604079 17337 authenticator.cpp:98] Creating new server SASL connection
3: I1111 02:02:36.604450 17341 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1111 02:02:36.604491 17341 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1111 02:02:36.604624 17332 authenticator.cpp:204] Received SASL authentication start
3: I1111 02:02:36.604701 17332 authenticator.cpp:326] Authentication requires more steps
3: I1111 02:02:36.604843 17336 authenticatee.cpp:259] Received SASL authentication step
3: I1111 02:02:36.605007 17343 authenticator.cpp:232] Received SASL authentication step
3: I1111 02:02:36.605046 17343 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd9cccd9998bb' server FQDN: 'd9cccd9998bb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1111 02:02:36.605067 17343 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 02:02:36.605118 17343 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 02:02:36.605136 17343 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd9cccd9998bb' server FQDN: 'd9cccd9998bb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1111 02:02:36.605144 17343 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1111 02:02:36.605150 17343 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1111 02:02:36.605180 17343 authenticator.cpp:318] Authentication success
3: I1111 02:02:36.605285 17340 authenticatee.cpp:299] Authentication success
3: I1111 02:02:36.605399 17344 master.cpp:8316] Successfully authenticated principal 'test-principal' at slave(640)@172.17.0.5:41640
3: I1111 02:02:36.605437 17325 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1264)@172.17.0.5:41640
3: I1111 02:02:36.605589 17347 slave.cpp:1161] Successfully authenticated with master master@172.17.0.5:41640
3: I1111 02:02:36.605923 17347 slave.cpp:1682] Will retry registration in 1.906661ms if necessary
3: I1111 02:02:36.606561 17326 master.cpp:6033] Received register agent message from slave(640)@172.17.0.5:41640 (d9cccd9998bb)
3: I1111 02:02:36.606675 17326 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1111 02:02:36.607101 17334 master.cpp:6093] Authorized registration of agent at slave(640)@172.17.0.5:41640 (d9cccd9998bb)
3: I1111 02:02:36.607170 17323 scheduler.cpp:190] Version: 1.5.0
3: I1111 02:02:36.607193 17334 master.cpp:6186] Registering agent at slave(640)@172.17.0.5:41640 (d9cccd9998bb) with id 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0
3: I1111 02:02:36.607436 17331 scheduler.cpp:313] Using default 'basic' HTTP authenticatee
3: I1111 02:02:36.607730 17324 registrar.cpp:495] Applied 1 operations in 75194ns; attempting to update the registry
3: I1111 02:02:36.607862 17340 scheduler.cpp:496] New master detected at master@172.17.0.5:41640
3: I1111 02:02:36.607888 17340 scheduler.cpp:505] Waiting for 0ns before initiating a re-(connection) attempt with the master
3: I1111 02:02:36.608444 17324 registrar.cpp:552] Successfully updated the registry in 648960ns
3: I1111 02:02:36.608572 17333 slave.cpp:1682] Will retry registration in 33.010751ms if necessary
3: I1111 02:02:36.608791 17347 master.cpp:6027] Ignoring register agent message from slave(640)@172.17.0.5:41640 (d9cccd9998bb) as registration is already in progress
3: I1111 02:02:36.608876 17347 master.cpp:6233] Admitted agent 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0 at slave(640)@172.17.0.5:41640 (d9cccd9998bb)
3: I1111 02:02:36.609719 17328 slave.cpp:1207] Registered with master master@172.17.0.5:41640; given agent ID 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0
3: I1111 02:02:36.609575 17347 master.cpp:6264] Registered agent 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0 at slave(640)@172.17.0.5:41640 (d9cccd9998bb) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1111 02:02:36.609820 17327 status_update_manager.cpp:184] Resuming sending status updates
3: I1111 02:02:36.609935 17339 hierarchical.cpp:593] Added agent 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0 (d9cccd9998bb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1111 02:02:36.610108 17328 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/ContentType_MasterAPITest_Teardown_0_UPwJ6Q/meta/slaves/87d17586-17ad-4ff3-930a-847c2a72ad1c-S0/slave.info'
3: I1111 02:02:36.610235 17339 hierarchical.cpp:1450] Performed allocation for 1 agents in 139397ns
3: I1111 02:02:36.610625 17328 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1111 02:02:36.610736 17332 scheduler.cpp:387] Connected with the master at http://172.17.0.5:41640/master/api/v1/scheduler
3: I1111 02:02:36.610878 17331 master.cpp:7065] Received update of agent 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0 at slave(640)@172.17.0.5:41640 (d9cccd9998bb) with total oversubscribed resources {}
3: I1111 02:02:36.611034 17331 master.cpp:7083] Ignoring update on agent 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0 at slave(640)@172.17.0.5:41640 (d9cccd9998bb) as it reports no changes
3: I1111 02:02:36.611985 17329 scheduler.cpp:249] Sending SUBSCRIBE call to http://172.17.0.5:41640/master/api/v1/scheduler
3: I1111 02:02:36.613484 17339 process.cpp:3925] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
3: I1111 02:02:36.614894 17338 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:49284
3: I1111 02:02:36.615114 17338 master.cpp:2613] Received subscription request for HTTP framework 'default'
3: I1111 02:02:36.615222 17338 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1111 02:02:36.615814 17343 master.cpp:2749] Subscribing framework 'default' with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1111 02:02:36.616637 17346 hierarchical.cpp:303] Added framework 87d17586-17ad-4ff3-930a-847c2a72ad1c-0000
3: I1111 02:02:36.617558 17342 scheduler.cpp:741] Enqueuing event SUBSCRIBED received from http://172.17.0.5:41640/master/api/v1/scheduler
3: I1111 02:02:36.618201 17346 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.397593ms
3: I1111 02:02:36.618258 17342 scheduler.cpp:741] Enqueuing event HEARTBEAT received from http://172.17.0.5:41640/master/api/v1/scheduler
3: I1111 02:02:36.618719 17341 master.cpp:8116] Sending 1 offers to framework 87d17586-17ad-4ff3-930a-847c2a72ad1c-0000 (default)
3: I1111 02:02:36.620863 17327 process.cpp:3925] Handling HTTP event for process 'master' with path: '/master/api/v1'
3: I1111 02:02:36.620972 17329 scheduler.cpp:741] Enqueuing event OFFERS received from http://172.17.0.5:41640/master/api/v1/scheduler
3: I1111 02:02:36.622086 17328 http.cpp:1185] HTTP POST for /master/api/v1 from 172.17.0.5:49286
3: I1111 02:02:36.622181 17328 http.cpp:673] Processing call GET_FRAMEWORKS
3: I1111 02:02:36.628281 17340 process.cpp:3925] Handling HTTP event for process 'master' with path: '/master/api/v1'
3: I1111 02:02:36.629799 17328 http.cpp:1185] HTTP POST for /master/api/v1 from 172.17.0.5:49288
3: I1111 02:02:36.629904 17328 http.cpp:673] Processing call TEARDOWN
3: I1111 02:02:36.633658 17346 process.cpp:3925] Handling HTTP event for process 'master' with path: '/master/api/v1'
3: I1111 02:02:36.634881 17344 http.cpp:1185] HTTP POST for /master/api/v1 from 172.17.0.5:49290
3: I1111 02:02:36.634943 17344 http.cpp:673] Processing call GET_FRAMEWORKS
3: I1111 02:02:36.639842 17327 process.cpp:3925] Handling HTTP event for process 'master' with path: '/master/api/v1'
3: I1111 02:02:36.641131 17339 http.cpp:1185] HTTP POST for /master/api/v1 from 172.17.0.5:49292
3: I1111 02:02:36.641216 17339 http.cpp:673] Processing call TEARDOWN
3: I1111 02:02:36.641682 17344 master.cpp:8805] Removing framework 87d17586-17ad-4ff3-930a-847c2a72ad1c-0000 (default)
3: I1111 02:02:36.641721 17344 master.cpp:3332] Deactivating framework 87d17586-17ad-4ff3-930a-847c2a72ad1c-0000 (default)
3: I1111 02:02:36.641867 17331 hierarchical.cpp:412] Deactivated framework 87d17586-17ad-4ff3-930a-847c2a72ad1c-0000
3: I1111 02:02:36.642263 17344 master.cpp:10016] Removing offer 87d17586-17ad-4ff3-930a-847c2a72ad1c-O0
3: I1111 02:02:36.642618 17328 slave.cpp:3267] Asked to shut down framework 87d17586-17ad-4ff3-930a-847c2a72ad1c-0000 by master@172.17.0.5:41640
3: I1111 02:02:36.642650 17328 slave.cpp:3282] Cannot shut down unknown framework 87d17586-17ad-4ff3-930a-847c2a72ad1c-0000
3: I1111 02:02:36.642812 17331 hierarchical.cpp:1125] Recovered cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0 from framework 87d17586-17ad-4ff3-930a-847c2a72ad1c-0000
3: I1111 02:02:36.643111 17331 hierarchical.cpp:355] Removed framework 87d17586-17ad-4ff3-930a-847c2a72ad1c-0000
3: E1111 02:02:36.643368 17324 scheduler.cpp:714] End-Of-File received from master. The master closed the event stream
3: I1111 02:02:36.643867 17343 scheduler.cpp:470] Re-detecting master
3: I1111 02:02:36.644487 17343 scheduler.cpp:421] Ignoring disconnection attempt from stale connection
3: I1111 02:02:36.644534 17343 scheduler.cpp:421] Ignoring disconnection attempt from stale connection
3: I1111 02:02:36.644678 17343 scheduler.cpp:496] New master detected at master@172.17.0.5:41640
3: I1111 02:02:36.644704 17343 scheduler.cpp:505] Waiting for 0ns before initiating a re-(connection) attempt with the master
3: I1111 02:02:36.646636 17344 scheduler.cpp:387] Connected with the master at http://172.17.0.5:41640/master/api/v1/scheduler
3: I1111 02:02:36.647810 17326 process.cpp:3925] Handling HTTP event for process 'master' with path: '/master/api/v1'
3: I1111 02:02:36.649041 17340 http.cpp:1185] HTTP POST for /master/api/v1 from 172.17.0.5:49294
3: I1111 02:02:36.649093 17340 http.cpp:673] Processing call GET_FRAMEWORKS
3: I1111 02:02:36.652910 17338 slave.cpp:883] Agent terminating
3: I1111 02:02:36.653087 17338 master.cpp:1309] Agent 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0 at slave(640)@172.17.0.5:41640 (d9cccd9998bb) disconnected
3: I1111 02:02:36.653105 17338 master.cpp:3369] Disconnecting agent 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0 at slave(640)@172.17.0.5:41640 (d9cccd9998bb)
3: I1111 02:02:36.653154 17338 master.cpp:3388] Deactivating agent 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0 at slave(640)@172.17.0.5:41640 (d9cccd9998bb)
3: I1111 02:02:36.653257 17336 hierarchical.cpp:690] Agent 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0 deactivated
3: I1111 02:02:36.656951 17323 master.cpp:1151] Master terminating
3: I1111 02:02:36.657511 17333 hierarchical.cpp:626] Removed agent 87d17586-17ad-4ff3-930a-847c2a72ad1c-S0
3: W1111 02:02:36.658566 17323 master.hpp:3079] Failed to close HTTP pipe for 87d17586-17ad-4ff3-930a-847c2a72ad1c-0000 (default)
3: [ OK ] ContentType/MasterAPITest.Teardown/0 (92 ms)
3: [ RUN ] ContentType/MasterAPITest.Teardown/1
3: I1111 02:02:36.665549 17324 master.cpp:448] Master 2989a614-b084-4f96-ae57-bbe292e726e9 (d9cccd9998bb) started on 172.17.0.5:41640
3: I1111 02:02:36.665565 17324 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1000secs" --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/Sg6C9D/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/Sg6C9D/master" --zk_session_timeout="10secs"
3: I1111 02:02:36.665827 17324 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1111 02:02:36.665834 17324 master.cpp:505] Master only allowing authenticated agents to register
3: I1111 02:02:36.665838 17324 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1111 02:02:36.665843 17324 credentials.hpp:37] Loading credentials for authentication from '/tmp/Sg6C9D/credentials'
3: I1111 02:02:36.666103 17324 master.cpp:555] Using default 'crammd5' authenticator
3: I1111 02:02:36.666246 17324 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1111 02:02:36.666399 17324 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1111 02:02:36.666517 17324 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1111 02:02:36.666625 17324 master.cpp:634] Authorization enabled
3: I1111 02:02:36.666777 17326 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1111 02:02:36.666784 17328 whitelist_watcher.cpp:77] No whitelist given
3: I1111 02:02:36.669121 17334 master.cpp:2213] Elected as the leading master!
3: I1111 02:02:36.669142 17334 master.cpp:1693] Recovering from registrar
3: I1111 02:02:36.669279 17344 registrar.cpp:347] Recovering registrar
3: I1111 02:02:36.669759 17344 registrar.cpp:391] Successfully fetched the registry (0B) in 444160ns
3: I1111 02:02:36.669857 17344 registrar.cpp:495] Applied 1 operations in 30760ns; attempting to update the registry
3: I1111 02:02:36.670327 17344 registrar.cpp:552] Successfully updated the registry in 427008ns
3: I1111 02:02:36.670444 17344 registrar.cpp:424] Successfully recovered registrar
3: I1111 02:02:36.670805 17331 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1111 02:02:36.670869 17338 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1111 02:02:36.675220 17323 process.cpp:3178] Attempted to spawn already running process files@172.17.0.5:41640
3: I1111 02:02:36.675493 17323 cluster.cpp:448] Creating default 'local' authorizer
3: I1111 02:02:36.677371 17330 slave.cpp:262] Mesos agent started on (641)@172.17.0.5:41640
3: I1111 02:02:36.677392 17330 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ContentType_MasterAPITest_Teardown_1_WJb9Xx/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/ContentType_MasterAPITest_Teardown_1_WJb9Xx/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/ContentType_MasterAPITest_Teardown_1_WJb9Xx/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/ContentType_MasterAPITest_Teardown_1_WJb9Xx/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/ContentType_MasterAPITest_Teardown_1_WJb9Xx/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ContentType_MasterAPITest_Teardown_1_WJb9Xx" --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/ContentType_MasterAPITest_Teardown_1_X7AS3A" --zk_session_timeout="10secs"
3: I1111 02:02:36.677711 17330 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_MasterAPITest_Teardown_1_WJb9Xx/credential'
3: I1111 02:02:36.677842 17330 slave.cpp:295] Agent using credential for: test-principal
3: I1111 02:02:36.677858 17330 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_MasterAPITest_Teardown_1_WJb9Xx/http_credentials'
3: I1111 02:02:36.678059 17330 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1111 02:02:36.678181 17330 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1111 02:02:36.679502 17330 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1111 02:02:36.679716 17330 slave.cpp:601] Agent attributes: [ ]
3: I1111 02:02:36.679728 17330 slave.cpp:610] Agent hostname: d9cccd9998bb
3: I1111 02:02:36.679836 17336 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 02:02:36.681354 17337 state.cpp:64] Recovering state from '/tmp/ContentType_MasterAPITest_Teardown_1_X7AS3A/meta'
3: I1111 02:02:36.681586 17324 status_update_manager.cpp:203] Recovering status update manager
3: I1111 02:02:36.681915 17329 slave.cpp:6422] Finished recovery
3: I1111 02:02:36.682546 17347 status_update_manager.cpp:177] Pausing sending status updates
3: I1111 02:02:36.682557 17333 slave.cpp:1007] New master detected at master@172.17.0.5:41640
3: I1111 02:02:36.682637 17333 slave.cpp:1042] Detecting new master
3: I1111 02:02:36.684931 17327 slave.cpp:1069] Authenticating with master master@172.17.0.5:41640
3: I1111 02:02:36.684990 17327 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1111 02:02:36.685220 17335 authenticatee.cpp:121] Creating new client SASL connection
3: I1111 02:02:36.685497 17325 master.cpp:8286] Authenticating slave(641)@172.17.0.5:41640
3: I1111 02:02:36.685598 17344 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1265)@172.17.0.5:41640
3: I1111 02:02:36.685852 17341 authenticator.cpp:98] Creating new server SASL connection
3: I1111 02:02:36.686072 17340 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1111 02:02:36.686095 17340 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1111 02:02:36.686197 17343 authenticator.cpp:204] Received SASL authentication start
3: I1111 02:02:36.686251 17343 authenticator.cpp:326] Authentication requires more steps
3: I1111 02:02:36.686337 17336 authenticatee.cpp:259] Received SASL authentication step
3: I1111 02:02:36.686477 17339 authenticator.cpp:232] Received SASL authentication step
3: I1111 02:02:36.686507 17339 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd9cccd9998bb' server FQDN: 'd9cccd9998bb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1111 02:02:36.686518 17339 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1111 02:02:36.686547 17339 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1111 02:02:36.686564 17339 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd9cccd9998bb' server FQDN: 'd9cccd9998bb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1111 02:02:36.686573 17339 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1111 02:02:36.686578 17339 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1111 02:02:36.686590 17339 authenticator.cpp:318] Authentication success
3: I1111 02:02:36.686681 17331 authenticatee.cpp:299] Authentication success
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1510362986-5423
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com