See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4575/display/redirect?page=changes>
Changes: [bmahler] Added a performance working group December 2017 blog post. ------------------------------------------ [...truncated 25.23 MB...] 3: I1211 20:45:37.496598 20118 slave.cpp:1686] Will retry registration in 16.711898ms if necessary 3: I1211 20:45:37.496843 20120 master.cpp:6090] Received register agent message from slave(680)@172.17.0.2:34623 (7480d98e41ff) 3: I1211 20:45:37.496997 20120 master.cpp:3871] Authorizing agent with principal 'test-principal' 3: I1211 20:45:37.497562 20107 master.cpp:6166] Authorized registration of agent at slave(680)@172.17.0.2:34623 (7480d98e41ff) 3: I1211 20:45:37.497681 20107 master.cpp:6259] Registering agent at slave(680)@172.17.0.2:34623 (7480d98e41ff) with id 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 3: I1211 20:45:37.498247 20126 registrar.cpp:495] Applied 1 operations in 95495ns; attempting to update the registry 3: I1211 20:45:37.498929 20126 registrar.cpp:552] Successfully updated the registry in 627968ns 3: I1211 20:45:37.499164 20119 master.cpp:6308] Admitted agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) 3: I1211 20:45:37.499863 20119 master.cpp:6344] Registered agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] 3: I1211 20:45:37.499929 20115 slave.cpp:1253] Registered with master [email protected]:34623; given agent ID 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 3: I1211 20:45:37.500057 20110 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I1211 20:45:37.500277 20129 hierarchical.cpp:572] Added agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 (7480d98e41ff) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) 3: I1211 20:45:37.500309 20115 slave.cpp:1273] Checkpointing SlaveInfo to '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/meta/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/slave.info' 3: I1211 20:45:37.500911 20115 slave.cpp:1330] Forwarding agent update {"offer_operations":{},"resource_categories":{"oversubscribed":true},"resource_version_uuid":"YN9d176BR4WAqTHA+q01RQ==","slave_id":{"value":"461dffc4-a0e0-4d23-b228-1382a605e95f-S0"}} 3: I1211 20:45:37.501150 20115 master.cpp:7227] Received update of agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) with total oversubscribed resources {} 3: I1211 20:45:37.501397 20115 master.cpp:7325] Ignoring update on agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) as it reports no changes 3: I1211 20:45:37.501745 20129 hierarchical.cpp:1513] Performed allocation for 1 agents in 1.299075ms 3: I1211 20:45:37.502319 20124 master.cpp:8707] Sending 1 offers to framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 (default) at [email protected]:34623 3: I1211 20:45:37.502856 20116 sched.cpp:921] Scheduler::resourceOffers took 115347ns 3: I1211 20:45:37.504995 20112 master.cpp:10627] Removing offer 461dffc4-a0e0-4d23-b228-1382a605e95f-O0 3: I1211 20:45:37.505224 20112 master.cpp:4278] Processing ACCEPT call for offers: [ 461dffc4-a0e0-4d23-b228-1382a605e95f-O0 ] on agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) for framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 (default) at [email protected]:34623 3: I1211 20:45:37.505354 20112 master.cpp:3598] Authorizing framework principal 'test-principal' to launch task 98860645-b714-4a13-b90c-a66e9d470c03 3: I1211 20:45:37.507571 20113 master.cpp:11379] Adding task 98860645-b714-4a13-b90c-a66e9d470c03 with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] on agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) 3: I1211 20:45:37.507952 20113 master.cpp:5029] Launching task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 (default) at [email protected]:34623 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"}] on agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) 3: I1211 20:45:37.508975 20123 slave.cpp:1809] Got assigned task '98860645-b714-4a13-b90c-a66e9d470c03' for framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.509162 20123 slave.cpp:8137] Checkpointing FrameworkInfo to '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/meta/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/framework.info' 3: I1211 20:45:37.509554 20123 slave.cpp:8148] Checkpointing framework pid '[email protected]:34623' to '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/meta/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/framework.pid' 3: I1211 20:45:37.510293 20123 slave.cpp:2079] Authorizing task '98860645-b714-4a13-b90c-a66e9d470c03' for framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.510347 20123 slave.cpp:7744] Authorizing framework principal 'test-principal' to launch task 98860645-b714-4a13-b90c-a66e9d470c03 3: I1211 20:45:37.511277 20119 slave.cpp:2471] Launching task '98860645-b714-4a13-b90c-a66e9d470c03' for framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.511762 20119 paths.cpp:702] Trying to chown '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7' to user 'mesos' 3: I1211 20:45:37.512010 20119 slave.cpp:8842] Checkpointing ExecutorInfo to '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/meta/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/executor.info' 3: I1211 20:45:37.512670 20119 slave.cpp:8218] Launching executor '98860645-b714-4a13-b90c-a66e9d470c03' of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7' 3: I1211 20:45:37.513710 20119 slave.cpp:8885] Checkpointing TaskInfo to '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/meta/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7/tasks/98860645-b714-4a13-b90c-a66e9d470c03/task.info' 3: I1211 20:45:37.514225 20119 slave.cpp:2557] Queued task '98860645-b714-4a13-b90c-a66e9d470c03' for executor '98860645-b714-4a13-b90c-a66e9d470c03' of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.514314 20119 slave.cpp:984] Successfully attached '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7' to virtual path '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/latest' 3: I1211 20:45:37.514364 20119 slave.cpp:984] Successfully attached '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7' to virtual path '/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/latest' 3: I1211 20:45:37.514760 20119 slave.cpp:3023] Launching container 61c7334b-6fb8-45e0-a59e-01916a88f1a7 for executor '98860645-b714-4a13-b90c-a66e9d470c03' of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.515370 20119 slave.cpp:984] Successfully attached '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7' to virtual path '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7' 3: I1211 20:45:37.515655 20115 containerizer.cpp:1201] Starting container 61c7334b-6fb8-45e0-a59e-01916a88f1a7 3: I1211 20:45:37.516472 20115 containerizer.cpp:1373] Checkpointed ContainerConfig at '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_yOtLeh/containers/61c7334b-6fb8-45e0-a59e-01916a88f1a7/config' 3: I1211 20:45:37.516499 20115 containerizer.cpp:2930] Transitioning the state of container 61c7334b-6fb8-45e0-a59e-01916a88f1a7 from PROVISIONING to PREPARING 3: I1211 20:45:37.522029 20114 containerizer.cpp:1842] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:34623"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG\/slaves\/461dffc4-a0e0-4d23-b228-1382a605e95f-S0\/frameworks\/461dffc4-a0e0-4d23-b228-1382a605e95f-0000\/executors\/98860645-b714-4a13-b90c-a66e9d470c03\/runs\/61c7334b-6fb8-45e0-a59e-01916a88f1a7"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiI2MWM3MzM0Yi02ZmI4LTQ1ZTAtYTU5ZS0wMTkxNmE4OGYxYTciLCJlaWQiOiI5ODg2MDY0NS1iNzE0LTRhMTMtYjkwYy1hNjZlOWQ0NzBjMDMiLCJmaWQiOiI0NjFkZmZjNC1hMGUwLTRkMjMtYjIyOC0xMzgyYTYwNWU5NWYtMDAwMCJ9.tf4AIK7jojnyDAQu4QI-ypf2YZ0mPFkU2lXB-IU6mPU"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"98860645-b714-4a13-b90c-a66e9d470c03"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"461dffc4-a0e0-4d23-b228-1382a605e95f-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_RECOVERY_TIMEOUT","type":"VALUE","value":"15mins"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"461dffc4-a0e0-4d23-b228-1382a605e95f-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(680)@172.17.0.2:34623"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"2secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG\/slaves\/461dffc4-a0e0-4d23-b228-1382a605e95f-S0\/frameworks\/461dffc4-a0e0-4d23-b228-1382a605e95f-0000\/executors\/98860645-b714-4a13-b90c-a66e9d470c03\/runs\/61c7334b-6fb8-45e0-a59e-01916a88f1a7"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG\/slaves\/461dffc4-a0e0-4d23-b228-1382a605e95f-S0\/frameworks\/461dffc4-a0e0-4d23-b228-1382a605e95f-0000\/executors\/98860645-b714-4a13-b90c-a66e9d470c03\/runs\/61c7334b-6fb8-45e0-a59e-01916a88f1a7"}" --pipe_read="10" --pipe_write="11" --runtime_directory="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_yOtLeh/containers/61c7334b-6fb8-45e0-a59e-01916a88f1a7" --unshare_namespace_mnt="false"' 3: I1211 20:45:37.528065 20114 launcher.cpp:140] Forked child with pid '27742' for container '61c7334b-6fb8-45e0-a59e-01916a88f1a7' 3: I1211 20:45:37.528259 20114 containerizer.cpp:1934] Checkpointing container's forked pid 27742 to '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/meta/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7/pids/forked.pid' 3: I1211 20:45:37.529429 20114 containerizer.cpp:2930] Transitioning the state of container 61c7334b-6fb8-45e0-a59e-01916a88f1a7 from PREPARING to ISOLATING 3: I1211 20:45:37.531502 20114 containerizer.cpp:2930] Transitioning the state of container 61c7334b-6fb8-45e0-a59e-01916a88f1a7 from ISOLATING to FETCHING 3: I1211 20:45:37.531812 20109 fetcher.cpp:369] Starting to fetch URIs for container: 61c7334b-6fb8-45e0-a59e-01916a88f1a7, directory: /tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7 3: I1211 20:45:37.532907 20121 containerizer.cpp:2930] Transitioning the state of container 61c7334b-6fb8-45e0-a59e-01916a88f1a7 from FETCHING to RUNNING 3: I1211 20:45:37.826686 27743 exec.cpp:162] Version: 1.5.0 3: I1211 20:45:37.838475 20107 slave.cpp:4275] Got registration for executor '98860645-b714-4a13-b90c-a66e9d470c03' of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 from executor(1)@172.17.0.2:43661 3: I1211 20:45:37.839347 20107 slave.cpp:4361] Checkpointing executor pid 'executor(1)@172.17.0.2:43661' to '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/meta/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7/pids/libprocess.pid' 3: I1211 20:45:37.843010 20108 slave.cpp:2762] Sending queued task '98860645-b714-4a13-b90c-a66e9d470c03' to executor '98860645-b714-4a13-b90c-a66e9d470c03' of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 at executor(1)@172.17.0.2:43661 3: I1211 20:45:37.846441 27762 exec.cpp:237] Executor registered on agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 3: I1211 20:45:37.850021 27767 executor.cpp:171] Received SUBSCRIBED event 3: I1211 20:45:37.851598 27767 executor.cpp:175] Subscribed executor on 7480d98e41ff 3: I1211 20:45:37.851876 27767 executor.cpp:171] Received LAUNCH event 3: I1211 20:45:37.853987 27767 executor.cpp:637] Starting task 98860645-b714-4a13-b90c-a66e9d470c03 3: I1211 20:45:37.857276 20115 slave.cpp:4732] Handling status update TASK_STARTING (Status UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 from executor(1)@172.17.0.2:43661 3: I1211 20:45:37.859274 20126 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.859328 20126 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.860288 20126 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.860582 20126 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 to the agent 3: I1211 20:45:37.860806 20111 slave.cpp:5215] Forwarding the update TASK_STARTING (Status UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 to [email protected]:34623 3: I1211 20:45:37.861064 20111 slave.cpp:5108] Task status update manager successfully handled status update TASK_STARTING (Status UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.861115 20111 slave.cpp:5124] Sending acknowledgement for status update TASK_STARTING (Status UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 to executor(1)@172.17.0.2:43661 3: I1211 20:45:37.861323 20113 master.cpp:7800] Status update TASK_STARTING (Status UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 from agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) 3: I1211 20:45:37.861392 20113 master.cpp:7856] Forwarding status update TASK_STARTING (Status UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.861585 20113 master.cpp:10103] Updating the state of task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING) 3: I1211 20:45:37.861915 20128 sched.cpp:1029] Scheduler::statusUpdate took 115627ns 3: I1211 20:45:37.862403 20129 master.cpp:5847] Processing ACKNOWLEDGE call 16c83474-9981-4b01-ac72-b113ea75d8ea for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 (default) at [email protected]:34623 on agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 3: I1211 20:45:37.862815 20108 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.862923 20108 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.863296 20118 slave.cpp:4010] Task status update manager successfully handled status update acknowledgement (UUID: 16c83474-9981-4b01-ac72-b113ea75d8ea) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.865844 20120 process.cpp:3503] Handling HTTP event for process 'slave(680)' with path: '/slave(680)/api/v1' 3: I1211 20:45:37.867969 20113 http.cpp:1185] HTTP POST for /slave(680)/api/v1 from 172.17.0.2:58100 3: I1211 20:45:37.868502 20113 http.cpp:2164] Processing GET_CONTAINERS call 3: I1211 20:45:37.871342 27767 executor.cpp:477] Running '/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>' 3: I1211 20:45:37.874944 27767 executor.cpp:650] Forked command at 27769 3: I1211 20:45:37.877624 20106 process.cpp:3503] Handling HTTP event for process 'slave(680)' with path: '/slave(680)/api/v1' 3: I1211 20:45:37.878680 20113 slave.cpp:4732] Handling status update TASK_RUNNING (Status UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 from executor(1)@172.17.0.2:43661 3: I1211 20:45:37.879612 20116 http.cpp:1185] HTTP POST for /slave(680)/api/v1 from 172.17.0.2:58102 3: I1211 20:45:37.880154 20116 http.cpp:2406] Processing LAUNCH_NESTED_CONTAINER call for container '61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4' 3: I1211 20:45:37.880920 20121 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.881000 20121 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.881269 20121 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 to the agent 3: I1211 20:45:37.881466 20110 containerizer.cpp:1167] Trying to chown '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7/containers/f468df44-3815-4914-85dc-c3ea8cabeed4' to user 'mesos' 3: I1211 20:45:37.881467 20106 slave.cpp:5215] Forwarding the update TASK_RUNNING (Status UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 to [email protected]:34623 3: I1211 20:45:37.881695 20106 slave.cpp:5108] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.881733 20110 containerizer.cpp:1201] Starting container 61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4 3: I1211 20:45:37.881744 20106 slave.cpp:5124] Sending acknowledgement for status update TASK_RUNNING (Status UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 to executor(1)@172.17.0.2:43661 3: I1211 20:45:37.881945 20107 master.cpp:7800] Status update TASK_RUNNING (Status UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 from agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) 3: I1211 20:45:37.882011 20107 master.cpp:7856] Forwarding status update TASK_RUNNING (Status UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.882216 20107 master.cpp:10103] Updating the state of task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING) 3: I1211 20:45:37.882441 20125 sched.cpp:1029] Scheduler::statusUpdate took 22564ns 3: I1211 20:45:37.882556 20110 containerizer.cpp:1373] Checkpointed ContainerConfig at '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_yOtLeh/containers/61c7334b-6fb8-45e0-a59e-01916a88f1a7/containers/f468df44-3815-4914-85dc-c3ea8cabeed4/config' 3: I1211 20:45:37.882588 20110 containerizer.cpp:2930] Transitioning the state of container 61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4 from PROVISIONING to PREPARING 3: I1211 20:45:37.882726 20126 master.cpp:5847] Processing ACKNOWLEDGE call ef61db84-d77a-42a2-98b0-69161deab0a7 for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 (default) at [email protected]:34623 on agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 3: I1211 20:45:37.883127 20114 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.883219 20114 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_RUNNING (Status UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.883481 20127 slave.cpp:4010] Task status update manager successfully handled status update acknowledgement (UUID: ef61db84-d77a-42a2-98b0-69161deab0a7) for task 98860645-b714-4a13-b90c-a66e9d470c03 of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:37.885939 20115 containerizer.cpp:1842] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"shell":true,"value":"sleep 100"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG\/slaves\/461dffc4-a0e0-4d23-b228-1382a605e95f-S0\/frameworks\/461dffc4-a0e0-4d23-b228-1382a605e95f-0000\/executors\/98860645-b714-4a13-b90c-a66e9d470c03\/runs\/61c7334b-6fb8-45e0-a59e-01916a88f1a7\/containers\/f468df44-3815-4914-85dc-c3ea8cabeed4"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG\/slaves\/461dffc4-a0e0-4d23-b228-1382a605e95f-S0\/frameworks\/461dffc4-a0e0-4d23-b228-1382a605e95f-0000\/executors\/98860645-b714-4a13-b90c-a66e9d470c03\/runs\/61c7334b-6fb8-45e0-a59e-01916a88f1a7\/containers\/f468df44-3815-4914-85dc-c3ea8cabeed4"}" --pipe_read="17" --pipe_write="18" --runtime_directory="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_yOtLeh/containers/61c7334b-6fb8-45e0-a59e-01916a88f1a7/containers/f468df44-3815-4914-85dc-c3ea8cabeed4" --unshare_namespace_mnt="false"' 3: I1211 20:45:37.892274 20115 launcher.cpp:140] Forked child with pid '27770' for container '61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4' 3: I1211 20:45:37.893088 20115 containerizer.cpp:2930] Transitioning the state of container 61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4 from PREPARING to ISOLATING 3: I1211 20:45:37.894371 20115 containerizer.cpp:2930] Transitioning the state of container 61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4 from ISOLATING to FETCHING 3: I1211 20:45:37.894646 20116 fetcher.cpp:369] Starting to fetch URIs for container: 61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4, directory: /tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_XOqAUG/slaves/461dffc4-a0e0-4d23-b228-1382a605e95f-S0/frameworks/461dffc4-a0e0-4d23-b228-1382a605e95f-0000/executors/98860645-b714-4a13-b90c-a66e9d470c03/runs/61c7334b-6fb8-45e0-a59e-01916a88f1a7/containers/f468df44-3815-4914-85dc-c3ea8cabeed4 3: I1211 20:45:37.895853 20121 containerizer.cpp:2930] Transitioning the state of container 61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4 from FETCHING to RUNNING 3: I1211 20:45:37.900813 20112 process.cpp:3503] Handling HTTP event for process 'slave(680)' with path: '/slave(680)/api/v1' 3: I1211 20:45:37.902956 20123 http.cpp:1185] HTTP POST for /slave(680)/api/v1 from 172.17.0.2:58104 3: I1211 20:45:37.903568 20123 http.cpp:2406] Processing LAUNCH_NESTED_CONTAINER call for container '61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4' 3: I1211 20:45:37.907860 20122 process.cpp:3503] Handling HTTP event for process 'slave(680)' with path: '/slave(680)/api/v1' 3: I1211 20:45:37.909786 20129 http.cpp:1185] HTTP POST for /slave(680)/api/v1 from 172.17.0.2:58106 3: I1211 20:45:37.910295 20129 http.cpp:2406] Processing LAUNCH_NESTED_CONTAINER call for container '61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4' 3: I1211 20:45:37.914124 20117 process.cpp:3503] Handling HTTP event for process 'slave(680)' with path: '/slave(680)/api/v1' 3: I1211 20:45:37.915922 20118 http.cpp:1185] HTTP POST for /slave(680)/api/v1 from 172.17.0.2:58108 3: I1211 20:45:37.916419 20118 http.cpp:2406] Processing LAUNCH_NESTED_CONTAINER call for container '61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4' 3: I1211 20:45:37.924777 20117 process.cpp:3503] Handling HTTP event for process 'slave(680)' with path: '/slave(680)/api/v1' 3: I1211 20:45:37.925276 20118 process.cpp:3503] Handling HTTP event for process 'slave(680)' with path: '/slave(680)/api/v1' 3: I1211 20:45:37.928196 20111 http.cpp:1185] HTTP POST for /slave(680)/api/v1 from 172.17.0.2:58110 3: I1211 20:45:37.928596 20111 http.cpp:1185] HTTP POST for /slave(680)/api/v1 from 172.17.0.2:58112 3: I1211 20:45:37.929112 20111 http.cpp:2633] Processing WAIT_NESTED_CONTAINER call for container '61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4' 3: I1211 20:45:37.929560 20111 http.cpp:2791] Processing KILL_NESTED_CONTAINER call for container '61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4' 3: I1211 20:45:38.026968 20123 containerizer.cpp:2779] Container 61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4 has exited 3: I1211 20:45:38.027024 20123 containerizer.cpp:2328] Destroying container 61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4 in RUNNING state 3: I1211 20:45:38.027038 20123 containerizer.cpp:2930] Transitioning the state of container 61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4 from RUNNING to DESTROYING 3: I1211 20:45:38.027570 20123 launcher.cpp:156] Asked to destroy container 61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4 3: I1211 20:45:38.032099 20107 provisioner.cpp:598] Ignoring destroy request for unknown container 61c7334b-6fb8-45e0-a59e-01916a88f1a7.f468df44-3815-4914-85dc-c3ea8cabeed4 3: I1211 20:45:38.032374 20108 containerizer.cpp:2617] Checkpointing termination state to nested container's runtime directory '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_2_yOtLeh/containers/61c7334b-6fb8-45e0-a59e-01916a88f1a7/containers/f468df44-3815-4914-85dc-c3ea8cabeed4/termination' 3: I1211 20:45:38.035250 20105 slave.cpp:909] Agent terminating 3: I1211 20:45:38.035825 20125 master.cpp:1310] Agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) disconnected 3: I1211 20:45:38.035866 20125 master.cpp:3369] Disconnecting agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) 3: I1211 20:45:38.035933 20125 master.cpp:3388] Deactivating agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) 3: I1211 20:45:38.036206 20119 hierarchical.cpp:762] Agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 deactivated 3: I1211 20:45:38.036257 20127 containerizer.cpp:2328] Destroying container 61c7334b-6fb8-45e0-a59e-01916a88f1a7 in RUNNING state 3: I1211 20:45:38.036290 20127 containerizer.cpp:2930] Transitioning the state of container 61c7334b-6fb8-45e0-a59e-01916a88f1a7 from RUNNING to DESTROYING 3: I1211 20:45:38.036691 20127 launcher.cpp:156] Asked to destroy container 61c7334b-6fb8-45e0-a59e-01916a88f1a7 3: I1211 20:45:38.128476 20110 containerizer.cpp:2779] Container 61c7334b-6fb8-45e0-a59e-01916a88f1a7 has exited 3: I1211 20:45:38.131759 20122 provisioner.cpp:598] Ignoring destroy request for unknown container 61c7334b-6fb8-45e0-a59e-01916a88f1a7 3: I1211 20:45:38.144860 20105 master.cpp:1152] Master terminating 3: W1211 20:45:38.145092 20105 master.cpp:10193] Removing task 98860645-b714-4a13-b90c-a66e9d470c03 with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 on agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 at slave(680)@172.17.0.2:34623 (7480d98e41ff) in non-removable state TASK_RUNNING 3: I1211 20:45:38.145711 20118 hierarchical.cpp:605] Removed agent 461dffc4-a0e0-4d23-b228-1382a605e95f-S0 3: I1211 20:45:38.146971 20118 hierarchical.cpp:344] Removed framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: I1211 20:45:38.149646 20105 sched.cpp:2009] Asked to stop the driver 3: I1211 20:45:38.149788 20110 sched.cpp:1191] Stopping framework 461dffc4-a0e0-4d23-b228-1382a605e95f-0000 3: [ OK ] ParentChildContainerTypeAndContentType/AgentContainerAPITest.NestedContainerIdempotentLaunch/2 (704 ms) 3: [ RUN ] ParentChildContainerTypeAndContentType/AgentContainerAPITest.NestedContainerIdempotentLaunch/4 3: I1211 20:45:38.157171 20105 cluster.cpp:172] Creating default 'local' authorizer 3: I1211 20:45:38.162016 20114 master.cpp:456] Master 83c524dd-c551-43b0-b73a-66dc10770df8 (7480d98e41ff) started on 172.17.0.2:34623 3: I1211 20:45:38.162039 20114 master.cpp:458] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/PMk9wM/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/PMk9wM/master" --zk_session_timeout="10secs" 3: I1211 20:45:38.162391 20114 master.cpp:507] Master only allowing authenticated frameworks to register 3: I1211 20:45:38.162398 20114 master.cpp:513] Master only allowing authenticated agents to register 3: I1211 20:45:38.162402 20114 master.cpp:519] Master only allowing authenticated HTTP frameworks to register 3: I1211 20:45:38.162407 20114 credentials.hpp:37] Loading credentials for authentication from '/tmp/PMk9wM/credentials' 3: I1211 20:45:38.162751 20114 master.cpp:563] Using default 'crammd5' authenticator 3: I1211 20:45:38.162914 20114 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1211 20:45:38.163074 20114 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1211 20:45:38.163194 20114 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1211 20:45:38.163313 20114 master.cpp:642] Authorization enabled 3: I1211 20:45:38.163486 20119 whitelist_watcher.cpp:77] No whitelist given 3: I1211 20:45:38.163640 20116 hierarchical.cpp:175] Initialized hierarchical allocator process 3: I1211 20:45:38.166280 20108 master.cpp:2214] Elected as the leading master! 3: I1211 20:45:38.166311 20108 master.cpp:1694] Recovering from registrar 3: I1211 20:45:38.166501 20123 registrar.cpp:347] Recovering registrar 3: I1211 20:45:38.167189 20123 registrar.cpp:391] Successfully fetched the registry (0B) in 643840ns 3: I1211 20:45:38.167309 20123 registrar.cpp:495] Applied 1 operations in 36964ns; attempting to update the registry 3: I1211 20:45:38.167891 20123 registrar.cpp:552] Successfully updated the registry in 530944ns 3: I1211 20:45:38.168005 20123 registrar.cpp:424] Successfully recovered registrar 3: I1211 20:45:38.168429 20107 master.cpp:1807] Recovered 0 agents from the registry (135B); allowing 10mins for agents to re-register 3: I1211 20:45:38.168530 20120 hierarchical.cpp:213] Skipping recovery of hierarchical allocator: nothing to recover 3: W1211 20:45:38.175487 20105 process.cpp:2756] Attempted to spawn already running process [email protected]:34623 3: I1211 20:45:38.176877 20105 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: W1211 20:45:38.177675 20105 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W1211 20:45:38.177865 20105 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I1211 20:45:38.177914 20105 provisioner.cpp:299] Using default backend 'copy' 3: I1211 20:45:38.180727 20105 cluster.cpp:460] Creating default 'local' authorizer 3: I1211 20:45:38.184185 20120 slave.cpp:258] Mesos agent started on (681)@172.17.0.2:34623 3: I1211 20:45:38.184203 20120 slave.cpp:259] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_4_c2rXz0/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_4_c2rXz0/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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_4_c2rXz0/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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_4_c2rXz0/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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_4_c2rXz0/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_4_c2rXz0/jwt_secret_key" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_4_c2rXz0" --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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_4_Nbxxyo" --zk_session_timeout="10secs" 3: I1211 20:45:38.184650 20120 credentials.hpp:86] Loading credential for authentication from '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_4_c2rXz0/credential' 3: I1211 20:45:38.184813 20120 slave.cpp:291] Agent using credential for: test-principal 3: I1211 20:45:38.184829 20120 credentials.hpp:37] Loading credentials for authentication from '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_4_c2rXz0/http_credentials' 3: W1211 20:45:38.184918 20105 process.cpp:2756] Attempted to spawn already running process [email protected]:34623 3: I1211 20:45:38.185108 20120 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' 3: I1211 20:45:38.185216 20120 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' 3: I1211 20:45:38.185444 20120 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1211 20:45:38.185557 20120 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1211 20:45:38.185735 20120 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1211 20:45:38.185843 20120 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1211 20:45:38.185999 20105 sched.cpp:232] Version: 1.5.0 3: I1211 20:45:38.186601 20107 sched.cpp:336] New master detected at [email protected]:34623 3: I1211 20:45:38.186695 20107 sched.cpp:396] Authenticating with master [email protected]:34623 3: I1211 20:45:38.186710 20107 sched.cpp:403] Using default CRAM-MD5 authenticatee 3: I1211 20:45:38.187019 20129 authenticatee.cpp:121] Creating new client SASL connection 3: I1211 20:45:38.187533 20117 master.cpp:8877] Authenticating [email protected]:34623 3: I1211 20:45:38.187813 20114 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1290)@172.17.0.2:34623 3: I1211 20:45:38.187620 20120 slave.cpp:590] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] 3: I1211 20:45:38.187871 20120 slave.cpp:598] Agent attributes: [ ] 3: I1211 20:45:38.187885 20120 slave.cpp:607] Agent hostname: 7480d98e41ff 3: I1211 20:45:38.188052 20121 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1211 20:45:38.188256 20128 authenticator.cpp:98] Creating new server SASL connection 3: I1211 20:45:38.188568 20116 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1211 20:45:38.188602 20116 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1211 20:45:38.188763 20116 authenticator.cpp:204] Received SASL authentication start 3: I1211 20:45:38.188843 20116 authenticator.cpp:326] Authentication requires more steps 3: I1211 20:45:38.188990 20118 authenticatee.cpp:259] Received SASL authentication step 3: I1211 20:45:38.189138 20118 authenticator.cpp:232] Received SASL authentication step 3: I1211 20:45:38.189172 20118 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7480d98e41ff' server FQDN: '7480d98e41ff' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1211 20:45:38.189182 20118 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1211 20:45:38.189213 20118 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1211 20:45:38.189237 20118 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7480d98e41ff' server FQDN: '7480d98e41ff' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1211 20:45:38.189249 20118 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1211 20:45:38.189254 20118 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1211 20:45:38.189270 20118 authenticator.cpp:318] Authentication success 3: I1211 20:45:38.189393 20111 authenticatee.cpp:299] Authentication success 3: I1211 20:45:38.189483 20113 master.cpp:8907] Successfully authenticated principal 'test-principal' at [email protected]:34623 3: I1211 20:45:38.189549 20106 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1290)@172.17.0.2:34623 3: I1211 20:45:38.189666 20112 state.cpp:66] Recovering state from '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_NestedContainerIdempotentLaunch_4_Nbxxyo/meta' 3: I1211 20:45:38.189788 20115 sched.cpp:502] Successfully authenticated with master [email protected]:34623 3: I1211 20:45:38.189805 20115 sched.cpp:824] Sending SUBSCRIBE call to [email protected]:34623 3: I1211 20:45:38.189923 20115 sched.cpp:857] Will retry registration in 270.735197ms if necessary 3: I1211 20:45:38.190011 20129 task_status_update_manager.cpp:207] Recovering task status update manager 3: I1211 20:45:38.190146 20125 master.cpp:2962] Received SUBSCRIBE call for framework 'default' at [email protected]:34623 3: I1211 20:45:38.190225 20125 master.cpp:2279] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1211 20:45:38.190336 20121 containerizer.cpp:674] Recovering containerizer 3: I1211 20:45:38.191150 20127 master.cpp:3042] Subscribing framework default with checkpointing enabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 3: I1211 20:45:38.191381 20127 master.cpp:9098] Adding framework 83c524dd-c551-43b0-b73a-66dc10770df8-0000 (default) at [email protected]:34623 with roles { } suppressed 3: I1211 20:45:38.191849 20127 sched.cpp:751] Framework registered with 83c524dd-c551-43b0-b73a-66dc10770df8-0000 3: I1211 20:45:38.191898 20127 sched.cpp:765] Scheduler::registered took 28804ns 3: I1211 20:45:38.191921 20113 hierarchical.cpp:297] Added framework 83c524dd-c551-43b0-b73a-66dc10770df8-0000 3: I1211 20:45:38.192112 20113 hierarchical.cpp:1513] Performed allocation for 0 agents in 77818ns 3: I1211 20:45:38.192719 20112 provisioner.cpp:495] Provisioner recovery complete 3: I1211 20:45:38.193131 20109 slave.cpp:6727] Finished recovery 3: I1211 20:45:38.193886 20125 slave.cpp:1033] New master detected at [email protected]:34623 3: I1211 20:45:38.193905 20114 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1211 20:45:38.193977 20125 slave.cpp:1088] Detecting new master 3: I1211 20:45:38.201341 20116 slave.cpp:1115] Authenticating with master [email protected]:34623 3: I1211 20:45:38.201460 20116 slave.cpp:1124] Using default CRAM-MD5 authenticatee 3: I1211 20:45:38.201759 20108 authenticatee.cpp:121] Creating new client SASL connection 3: I1211 20:45:38.202059 20124 master.cpp:8877] Authenticating slave(681)@172.17.0.2:34623 3: I1211 20:45:38.202219 20123 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1291)@172.17.0.2:34623 3: I1211 20:45:38.202491 20111 authenticator.cpp:98] Creating new server SASL connection 3: I1211 20:45:38.202775 20121 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1211 20:45:38.202800 20121 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1211 20:45:38.202934 20121 authenticator.cpp:204] Received SASL authentication start 3: I1211 20:45:38.202996 20121 authenticator.cpp:326] Authentication requires more steps write /dev/stdout: resource temporarily unavailable + docker rmi mesos-1513022529-2169 Error response from daemon: conflict: unable to remove repository reference "mesos-1513022529-2169" (must force) - container 7480d98e41ff is using its referenced image ce801fc8becf Build step 'Execute shell' marked build as failure Not sending mail to unregistered user [email protected]
