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 2018/11/19 22:52:37 UTC
Build failed in Jenkins: Mesos-Reviewbot #23564
See <https://builds.apache.org/job/Mesos-Reviewbot/23564/display/redirect?page=changes>
Changes:
[yujie.jay] Added blog post for Mesos Mini.
------------------------------------------
[...truncated 43.71 MB...]
I1119 22:37:23.151458 19346 slave.cpp:1485] Registered with master master@172.17.0.2:38356; given agent ID bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0
I1119 22:37:23.151566 19402 task_status_update_manager.cpp:188] Resuming sending task status updates
I1119 22:37:23.151721 19419 hierarchical.cpp:603] Added agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0 (4903083bb424) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I1119 22:37:23.151747 19346 slave.cpp:1505] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/meta/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/slave.info'
I1119 22:37:23.152698 19346 slave.cpp:1554] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"WsfL6N3RQ0GihDDHTj4Sfw=="},"slave_id":{"value":"bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0"},"update_oversubscribed_resources":false}
I1119 22:37:23.152820 19419 hierarchical.cpp:1566] Performed allocation for 1 agents in 944723ns
I1119 22:37:23.153232 19381 master.cpp:9514] Sending offers [ bbb60306-d3f9-409c-a84b-a8ff93dde0bf-O0 ] to framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 (default) at scheduler-8aa79eed-2792-4f71-bb95-d1147e4b632a@172.17.0.2:38356
I1119 22:37:23.153725 19375 sched.cpp:914] Scheduler::resourceOffers took 104750ns
I1119 22:37:23.153743 19381 master.cpp:7984] Ignoring update on agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0 at slave@172.17.0.2:38356 (4903083bb424) as it reports no changes
I1119 22:37:23.155308 19338 master.cpp:11513] Removing offer bbb60306-d3f9-409c-a84b-a8ff93dde0bf-O0
I1119 22:37:23.155632 19338 master.cpp:4511] Processing ACCEPT call for offers: [ bbb60306-d3f9-409c-a84b-a8ff93dde0bf-O0 ] on agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0 at slave@172.17.0.2:38356 (4903083bb424) for framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 (default) at scheduler-8aa79eed-2792-4f71-bb95-d1147e4b632a@172.17.0.2:38356
I1119 22:37:23.155719 19338 master.cpp:3563] Authorizing framework principal 'test-principal' to launch task f16a4ac2-d1fb-4813-ba3c-d5d828a27661
I1119 22:37:23.157385 19389 master.cpp:4088] Adding task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 (default) at scheduler-8aa79eed-2792-4f71-bb95-d1147e4b632a@172.17.0.2:38356 on agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0 at slave@172.17.0.2:38356 (4903083bb424)
I1119 22:37:23.157923 19389 master.cpp:5483] Launching task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 (default) at scheduler-8aa79eed-2792-4f71-bb95-d1147e4b632a@172.17.0.2:38356 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 bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0 at slave@172.17.0.2:38356 (4903083bb424) on new executor
I1119 22:37:23.158977 19425 slave.cpp:2020] Got assigned task 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' for framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.159132 19425 slave.cpp:8914] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/meta/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/framework.info'
I1119 22:37:23.159508 19425 slave.cpp:8925] Checkpointing framework pid 'scheduler-8aa79eed-2792-4f71-bb95-d1147e4b632a@172.17.0.2:38356' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/meta/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/framework.pid'
I1119 22:37:23.160722 19425 slave.cpp:2394] Authorizing task 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' for framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.160779 19425 slave.cpp:8472] Authorizing framework principal 'test-principal' to launch task f16a4ac2-d1fb-4813-ba3c-d5d828a27661
I1119 22:37:23.162642 19421 slave.cpp:2837] Launching task 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' for framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.162732 19421 paths.cpp:752] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561' for user 'mesos'
I1119 22:37:23.163334 19421 slave.cpp:9700] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/meta/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/executor.info'
I1119 22:37:23.163831 19421 paths.cpp:755] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/meta/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561'
I1119 22:37:23.164086 19421 slave.cpp:9000] Launching executor 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-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/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561'
I1119 22:37:23.164796 19421 slave.cpp:3515] Launching container 3019fd42-17dd-4aa5-b8a2-726cb5de6561 for executor 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.165307 19421 slave.cpp:9731] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/meta/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561/tasks/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/task.info'
I1119 22:37:23.165933 19421 slave.cpp:3034] Queued task 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' for executor 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.166023 19421 slave.cpp:994] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/latest'
I1119 22:37:23.166069 19421 slave.cpp:994] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561' to virtual path '/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/latest'
I1119 22:37:23.166122 19421 slave.cpp:994] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561'
I1119 22:37:23.166651 19381 containerizer.cpp:1288] Starting container 3019fd42-17dd-4aa5-b8a2-726cb5de6561
I1119 22:37:23.167656 19381 containerizer.cpp:1454] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_bjoJ7n/containers/3019fd42-17dd-4aa5-b8a2-726cb5de6561/config'
I1119 22:37:23.167695 19381 containerizer.cpp:3130] Transitioning the state of container 3019fd42-17dd-4aa5-b8a2-726cb5de6561 from PROVISIONING to PREPARING
I1119 22:37:23.172255 19338 containerizer.cpp:1947] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/mesos/mesos-1.8.0/_build/src"],"shell":false,"value":"/mesos/mesos-1.8.0/_build/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:38356"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"f16a4ac2-d1fb-4813-ba3c-d5d828a27661"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"bbb60306-d3f9-409c-a84b-a8ff93dde0bf-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":"bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave@172.17.0.2:38356"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"15secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561"}" --pipe_read="24" --pipe_write="26" --runtime_directory="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_bjoJ7n/containers/3019fd42-17dd-4aa5-b8a2-726cb5de6561" --unshare_namespace_mnt="false"'
I1119 22:37:23.176724 19338 launcher.cpp:145] Forked child with pid '27224' for container '3019fd42-17dd-4aa5-b8a2-726cb5de6561'
I1119 22:37:23.176838 19338 containerizer.cpp:2052] Checkpointing container's forked pid 27224 to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/meta/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561/pids/forked.pid'
I1119 22:37:23.177527 19338 containerizer.cpp:3130] Transitioning the state of container 3019fd42-17dd-4aa5-b8a2-726cb5de6561 from PREPARING to ISOLATING
I1119 22:37:23.179266 19429 containerizer.cpp:3130] Transitioning the state of container 3019fd42-17dd-4aa5-b8a2-726cb5de6561 from ISOLATING to FETCHING
I1119 22:37:23.179498 19353 fetcher.cpp:369] Starting to fetch URIs for container: 3019fd42-17dd-4aa5-b8a2-726cb5de6561, directory: /tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561
I1119 22:37:23.180563 19381 containerizer.cpp:3130] Transitioning the state of container 3019fd42-17dd-4aa5-b8a2-726cb5de6561 from FETCHING to RUNNING
I1119 22:37:23.587801 27267 exec.cpp:162] Version: 1.8.0
I1119 22:37:23.597365 19431 slave.cpp:4809] Got registration for executor 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 from executor(1)@172.17.0.2:44337
I1119 22:37:23.597913 19431 slave.cpp:4895] Checkpointing executor pid 'executor(1)@172.17.0.2:44337' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/meta/slaves/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0/frameworks/bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000/executors/f16a4ac2-d1fb-4813-ba3c-d5d828a27661/runs/3019fd42-17dd-4aa5-b8a2-726cb5de6561/pids/libprocess.pid'
I1119 22:37:23.601056 19426 slave.cpp:3247] Sending queued task 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' to executor 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 at executor(1)@172.17.0.2:44337
I1119 22:37:23.602526 27275 exec.cpp:236] Executor registered on agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0
I1119 22:37:23.606156 27279 executor.cpp:184] Received SUBSCRIBED event
I1119 22:37:23.607645 27279 executor.cpp:188] Subscribed executor on 4903083bb424
I1119 22:37:23.607834 27279 executor.cpp:184] Received LAUNCH event
I1119 22:37:23.609743 27279 executor.cpp:687] Starting task f16a4ac2-d1fb-4813-ba3c-d5d828a27661
I1119 22:37:23.612413 19369 slave.cpp:5275] Handling status update TASK_STARTING (Status UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 from executor(1)@172.17.0.2:44337
I1119 22:37:23.614317 19394 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.614377 19394 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.615204 19394 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.615458 19394 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 to the agent
I1119 22:37:23.615675 19419 slave.cpp:5767] Forwarding the update TASK_STARTING (Status UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 to master@172.17.0.2:38356
I1119 22:37:23.615872 19419 slave.cpp:5660] Task status update manager successfully handled status update TASK_STARTING (Status UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.615922 19419 slave.cpp:5676] Sending acknowledgement for status update TASK_STARTING (Status UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 to executor(1)@172.17.0.2:44337
I1119 22:37:23.616053 19422 master.cpp:8420] Status update TASK_STARTING (Status UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 from agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0 at slave@172.17.0.2:38356 (4903083bb424)
I1119 22:37:23.616117 19422 master.cpp:8477] Forwarding status update TASK_STARTING (Status UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.616351 19422 master.cpp:10978] Updating the state of task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I1119 22:37:23.616621 19381 sched.cpp:1022] Scheduler::statusUpdate took 106129ns
I1119 22:37:23.617362 19408 master.cpp:6286] Processing ACKNOWLEDGE call for status 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 (default) at scheduler-8aa79eed-2792-4f71-bb95-d1147e4b632a@172.17.0.2:38356 on agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0
I1119 22:37:23.617734 19398 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.617842 19398 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.618857 19421 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: 04abe8ff-4d43-4a6e-9cd5-5633b6b9598e) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.629403 27279 executor.cpp:502] Running '/mesos/mesos-1.8.0/_build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
I1119 22:37:23.632479 27279 executor.cpp:702] Forked command at 27283
I1119 22:37:23.636060 19346 slave.cpp:5275] Handling status update TASK_RUNNING (Status UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 from executor(1)@172.17.0.2:44337
I1119 22:37:23.637876 19414 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.637970 19414 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.638278 19414 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 to the agent
I1119 22:37:23.638478 19426 slave.cpp:5767] Forwarding the update TASK_RUNNING (Status UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 to master@172.17.0.2:38356
I1119 22:37:23.638672 19426 slave.cpp:5660] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.638720 19426 slave.cpp:5676] Sending acknowledgement for status update TASK_RUNNING (Status UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 to executor(1)@172.17.0.2:44337
I1119 22:37:23.638804 19411 master.cpp:8420] Status update TASK_RUNNING (Status UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 from agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0 at slave@172.17.0.2:38356 (4903083bb424)
I1119 22:37:23.638864 19411 master.cpp:8477] Forwarding status update TASK_RUNNING (Status UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.639091 19411 master.cpp:10978] Updating the state of task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1119 22:37:23.639327 19389 sched.cpp:1022] Scheduler::statusUpdate took 86041ns
I1119 22:37:23.639953 19421 master.cpp:6286] Processing ACKNOWLEDGE call for status 95ef77a6-0229-40b6-8618-d1bcd6e93b1a for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 (default) at scheduler-8aa79eed-2792-4f71-bb95-d1147e4b632a@172.17.0.2:38356 on agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0
I1119 22:37:23.640328 19415 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.640461 19415 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_RUNNING (Status UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.640775 19394 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: 95ef77a6-0229-40b6-8618-d1bcd6e93b1a) for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:23.641047 19422 slave.cpp:915] Agent terminating
I1119 22:37:24.113992 19408 hierarchical.cpp:1566] Performed allocation for 1 agents in 288598ns
I1119 22:37:24.226253 19338 master.cpp:1273] Agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0 at slave@172.17.0.2:38356 (4903083bb424) disconnected
I1119 22:37:24.226294 19338 master.cpp:3289] Disconnecting agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0 at slave@172.17.0.2:38356 (4903083bb424)
I1119 22:37:24.226363 19338 master.cpp:3308] Deactivating agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0 at slave@172.17.0.2:38356 (4903083bb424)
I1119 22:37:24.226506 19419 hierarchical.cpp:801] Agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0 deactivated
I1119 22:37:24.226630 19199 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1119 22:37:24.227228 19199 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1119 22:37:24.227372 19199 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1119 22:37:24.227406 19199 provisioner.cpp:298] Using default backend 'copy'
W1119 22:37:24.234592 19199 process.cpp:2829] Attempted to spawn already running process files@172.17.0.2:38356
I1119 22:37:24.235146 19199 cluster.cpp:485] Creating default 'local' authorizer
I1119 22:37:24.237373 19422 slave.cpp:267] Mesos agent started on @172.17.0.2:38356
I1119 22:37:24.237395 19422 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_bjoJ7n/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_bjoJ7n/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_bjoJ7n/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="15secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_bjoJ7n/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_bjoJ7n/frameworks" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_bjoJ7n/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.8.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --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/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_bjoJ7n" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI" --zk_session_timeout="10secs"
I1119 22:37:24.237800 19422 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_bjoJ7n/credential'
I1119 22:37:24.237995 19422 slave.cpp:300] Agent using credential for: test-principal
I1119 22:37:24.238018 19422 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_bjoJ7n/http_credentials'
I1119 22:37:24.238235 19422 http.cpp:1042] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1119 22:37:24.238555 19422 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1119 22:37:24.239724 19422 slave.cpp:615] 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"}]
I1119 22:37:24.239924 19422 slave.cpp:623] Agent attributes: [ ]
I1119 22:37:24.239939 19422 slave.cpp:632] Agent hostname: 4903083bb424
I1119 22:37:24.240134 19426 task_status_update_manager.cpp:181] Pausing sending task status updates
I1119 22:37:24.243101 19398 state.cpp:66] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/meta'
I1119 22:37:24.243186 19398 state.cpp:711] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/meta/resources/resources.info'
I1119 22:37:24.248404 19425 slave.cpp:6915] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RgaezI/meta', beginning agent recovery
I1119 22:37:24.249064 19425 slave.cpp:7394] Recovering framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:24.249238 19425 slave.cpp:9118] Recovering executor 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:24.250160 19421 task_status_update_manager.cpp:207] Recovering task status update manager
I1119 22:37:24.250221 19421 task_status_update_manager.cpp:215] Recovering executor 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:24.250313 19421 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661 of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:24.250746 19421 task_status_update_manager.cpp:818] Replaying task status update stream for task f16a4ac2-d1fb-4813-ba3c-d5d828a27661
I1119 22:37:24.251425 19415 containerizer.cpp:727] Recovering Mesos containers
I1119 22:37:24.251521 19415 containerizer.cpp:784] Recovering container 3019fd42-17dd-4aa5-b8a2-726cb5de6561 for executor 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:24.253314 19415 containerizer.cpp:1053] Recovering isolators
I1119 22:37:24.254317 19429 containerizer.cpp:1092] Recovering provisioner
I1119 22:37:24.254956 19375 provisioner.cpp:494] Provisioner recovery complete
I1119 22:37:24.256487 19327 composing.cpp:339] Finished recovering all containerizers
I1119 22:37:24.256608 19431 slave.cpp:7144] Recovering executors
I1119 22:37:24.256747 19431 slave.cpp:7168] Sending reconnect request to executor 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000 at executor(1)@172.17.0.2:44337
I1119 22:37:24.258412 27270 exec.cpp:282] Received reconnect request from agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0
I1119 22:37:24.261373 19394 slave.cpp:4972] Received re-registration message from executor 'f16a4ac2-d1fb-4813-ba3c-d5d828a27661' of framework bbb60306-d3f9-409c-a84b-a8ff93dde0bf-0000
I1119 22:37:24.263509 27273 exec.cpp:259] Executor reregistered on agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0
I1119 22:37:24.263684 19415 slave.cpp:5889] No pings from master received within 75secs
I1119 22:37:24.263948 19419 hierarchical.cpp:1566] Performed allocation for 1 agents in 291733ns
F1119 22:37:24.264214 19415 slave.cpp:1233] Check failed: state == DISCONNECTED || state == RUNNING || state == TERMINATING RECOVERING
*** Check failure stack trace: ***
I1119 22:37:24.266170 27278 executor.cpp:184] Received SUBSCRIBED event
I1119 22:37:24.266202 27278 executor.cpp:188] Subscribed executor on 4903083bb424
@ 0x2ba1aee193c0 google::LogMessage::Fail()
@ 0x2ba1aee1930c google::LogMessage::SendToLog()
@ 0x2ba1aee18d0e google::LogMessage::Flush()
@ 0x2ba1aee1bc22 google::LogMessageFatal::~LogMessageFatal()
@ 0x2ba1ad552a0e mesos::internal::slave::Slave::detected()
@ 0x2ba1ad5ebcae _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEESB_EEvRKNS_3PIDIT_EEMSD_FvT0_EOT1_ENKUlOS9_PNS_11ProcessBaseEE_clESM_SO_
@ 0x2ba1ad6a5ee9 _ZN5cpp176invokeIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINS3_10MasterInfoEEEESD_EEvRKNS1_3PIDIT_EEMSF_FvT0_EOT1_EUlOSB_PNS1_11ProcessBaseEE_ISB_SQ_EEEDTclcl7forwardISF_Efp_Espcl7forwardIT0_Efp0_EEEOSF_DpOSS_
@ 0x2ba1ad69c51d _ZN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_ISC_St12_PlaceholderILi1EEEE13invoke_expandISS_St5tupleIISC_SU_EESX_IIOSR_EEILm0ELm1EEEEDTcl6invokecl7forwardIT_Efp_Espcl6expandcl3getIXT2_EEcl7forwardIT0_Efp0_EEcl7forwardIT1_Efp2_EEEEOS11_OS12_N5cpp1416integer_sequenceImIXspT2_EEEEOS13_
@ 0x2ba1ad695f19 _ZNO6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEEclIJSR_EEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOS10_
@ 0x2ba1ad6928f5 _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS4_6FutureI6OptionINS6_10MasterInfoEEEESG_EEvRKNS4_3PIDIT_EEMSI_FvT0_EOT1_EUlOSE_PNS4_11ProcessBaseEE_ISE_St12_PlaceholderILi1EEEEEIST_EEEDTclcl7forwardISI_Efp_Espcl7forwardIT0_Efp0_EEEOSI_DpOSY_
@ 0x2ba1ad69098b _ZN6lambda8internal6InvokeIvEclINS0_7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS5_6FutureI6OptionINS7_10MasterInfoEEEESH_EEvRKNS5_3PIDIT_EEMSJ_FvT0_EOT1_EUlOSF_PNS5_11ProcessBaseEE_JSF_St12_PlaceholderILi1EEEEEJSU_EEEvOSJ_DpOT0_
@ 0x2ba1ad68e593 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINSA_10MasterInfoEEEESK_EEvRKNS1_3PIDIT_EEMSM_FvT0_EOT1_EUlOSI_S3_E_ISI_St12_PlaceholderILi1EEEEEEclEOS3_
@ 0x2ba1aed3a701 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEEclES3_
@ 0x2ba1aed04117 process::ProcessBase::consume()
@ 0x2ba1aed2843a _ZNO7process13DispatchEvent7consumeEPNS_13EventConsumerE
@ 0x55a8d8b8e198 process::ProcessBase::serve()
@ 0x2ba1aed013f4 process::ProcessManager::resume()
@ 0x2ba1aecfd86e _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
@ 0x2ba1aed23286 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2ba1aed225a7 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
@ 0x2ba1aed21766 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
@ 0x2ba1b1bdba60 (unknown)
@ 0x2ba1b2352184 start_thread
@ 0x2ba1b266603d (unknown)
I1119 22:37:24.983165 27262 exec.cpp:518] Agent exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with agent bbb60306-d3f9-409c-a84b-a8ff93dde0bf-S0
I1119 22:52:24.984135 27272 exec.cpp:499] Recovery timeout of 15mins exceeded; Shutting down
I1119 22:52:24.984232 27272 exec.cpp:445] Executor asked to shutdown
I1119 22:52:24.984657 27274 executor.cpp:184] Received SHUTDOWN event
I1119 22:52:24.984705 27274 executor.cpp:805] Shutting down
I1119 22:52:24.984755 27274 executor.cpp:918] Sending SIGTERM to process tree at pid 27283
I1119 22:52:25.000823 27274 executor.cpp:931] Sent SIGTERM to the following process trees:
[
-+- 27283 sh -c sleep 1000
\--- 27286 sleep 1000
]
I1119 22:52:25.000864 27274 executor.cpp:935] Scheduling escalation to SIGKILL in 3secs from now
I1119 22:52:25.071135 27276 executor.cpp:1003] Command terminated with signal Terminated (pid: 27283)
W1119 22:52:25.074605 27280 process.cpp:1890] Failed to send 'mesos.internal.StatusUpdateMessage' to '172.17.0.2:38356', connect: Failed to connect to 172.17.0.2:38356: Connection refused
I1119 22:52:26.075907 27280 process.cpp:927] Stopped the socket accept loop
[FAIL]: 1 shard(s) have failed tests
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.8.0/_build'
make: *** [distcheck] Error 1
+ docker rmi --force mesos-1542663023-19704
Untagged: mesos-1542663023-19704:latest
Deleted: sha256:a32d378adaf9482d7912e2623147da52867f1405d6396e427673e261fd5288a2
Deleted: sha256:b7825857964c854e365fa7b7c8c6c4ce734abd2beccdd59d7847625e98e89420
Deleted: sha256:c87f00e1cfd6349b9163dbd9b4f4840eca2037e6ffa15c81b9af92499b70b7a1
Deleted: sha256:87fda415fe9eeba39d8e9aefe45b4d5b248852753515fc1c2e56d9e4223122fd
Deleted: sha256:04b86643cd7c8ecbe4b5ea244b2d4f79a4f58596ea65da2b225de3d5409a9587
Deleted: sha256:53d43788028a53b612cd4e086a10c966c084a0fe439b26eab5583f9fbe76e573
Deleted: sha256:273f379a4934ccbc69ca6d51a09837268f14862e76a12aa3bc0037186227d70d
Deleted: sha256:74ea24fe8eae22d4cf3222ecae91956a90bb1c829b3a57da2a029bee829e83a9
Deleted: sha256:27de27e3e81502fae31020b20d1d30ad38937eb8f654323c6192740ef205de17
Deleted: sha256:489050b0aa29e0ff594c4c1edb97e6670601b2265feb0b785f1fd9a3a8e708c9
Deleted: sha256:df6a3a0cedc99c2f2d3844842b86c0ba395e7ddfe137d0400dd2b4c85abad5ff
Deleted: sha256:dfcce0cd581f1f2d56a88420ef06efc5dc27eaa77449ac2fb7a86937e7c53a36
Deleted: sha256:04266d847f22f313b2fb3f7d53348cc86f8076a10e9c8225f585e0c8604169f4
Deleted: sha256:3336308517842b60f093cd368c8dc927ade017aa4b10ea7f0a2d2fec940a0411
Deleted: sha256:f5cd7e9e356104a68fcabc5c1f2ff1ccdf4445ab6b6708b91998a5b1a80f3fcf
Deleted: sha256:daf29d841b949cc1e5314e3782adfc20e72c4066e9e350bc16a1cdaad1a0c91d
Deleted: sha256:d3096062c669e91857eb329001bc669c9b8cf405e351a9a08885129c1b5261ec
Deleted: sha256:283765f3ee0236a695ccc8535d0ce97ad96531c1657ecf873b471144609381eb
Deleted: sha256:053e45d224ba1d25ea22134d7cd17db49ef041994561879443f16536baf9e527
Deleted: sha256:8c7ad6b3337fce48e39ca5de6dba444677f67625fafd9e62da57593453c60bef
Deleted: sha256:925e2d06c0ed6d433ba7b204cef861b875364c18fbe8021a61ccce43ee5f693a
Deleted: sha256:dcaeac666ae61cf3fa31d0806db7b3de84539b386cd534f262f796f2956c1276
Deleted: sha256:d1eb1a7fe136f74895af1562fbd46b2e4ebd1a2991041627a9fc264722f82529
Deleted: sha256:7ba4e846954d676f0bc49424d205d2ac7302d9dca6d69a85d2c34731452b66e9
Deleted: sha256:d5c9536a7210ee952c0c8d56a5fee791525c4e5debf9a1b1db2c1e7a16768b89
Deleted: sha256:2c6ce555435e126020bc99020507803606bd7ec90013059c9fa738a1c47dfe9f
Deleted: sha256:48dd46f27fcfec3fdb819305af88b4e27ce3e797a2a186f84170546b992019a5
Deleted: sha256:73ed7181b1c0c0ea205846ce076ddf96e9f3507929320cb7e6f67152014226d0
Deleted: sha256:aead845d871427658c3c6302000f357a6b7d39c79c8a4f81b6b8697dff76487c
Deleted: sha256:88eef300897257984eb51a4a65761e7ed3381a730fb9eb882d8c7404b6bb1fff
11-19-18_21:30:19 - Running <https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py>
Checking if review 69394 needs verification
Skipping blocking review 69394
Checking if review 69397 needs verification
Skipping blocking review 69397
Checking if review 69390 needs verification
Patch never verified, needs verification
Dependent review: https://reviews.apache.org/api/review-requests/69381/
The review request 69381 is already submitted
Dependent review: https://reviews.apache.org/api/review-requests/69380/
The review request 69380 is already submitted
Verifying review 69390
Dependent review: https://reviews.apache.org/api/review-requests/69381/
Dependent review: https://reviews.apache.org/api/review-requests/69380/
Applying review 69390
/usr/bin/python3 support/apply-reviews.py -n -r 69390
Traceback (most recent call last):
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 186, in verify_review
% (command, build_output)])
File "/usr/lib/python3.5/subprocess.py", line 581, in check_call
raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['bash', '-c', "set -o pipefail; export OS='ubuntu:14.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/docker-build.sh 2>&1 | tee build_69390"]' returned non-zero exit status 2
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 294, in <module>
main()
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 288, in main
verify_review(review_request, handler)
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 201, in verify_review
output = open(build_output).read().decode(sys.stdout.encoding)
AttributeError: 'str' object has no attribute 'decode'
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos-Reviewbot #23568
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/23568/display/redirect?page=changes>
Build failed in Jenkins: Mesos-Reviewbot #23567
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/23567/display/redirect?page=changes>
Changes:
[alexr] Added MasterActorResponsiveness_BENCHMARK_Test.
------------------------------------------
[...truncated 43.67 MB...]
I1120 20:13:42.009759 19775 registrar.cpp:487] Applied 1 operations in 229060ns; attempting to update the registry
I1120 20:13:42.010432 19775 registrar.cpp:544] Successfully updated the registry in 611840ns
I1120 20:13:42.010601 19795 master.cpp:6820] Admitted agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 at slave@172.17.0.2:46510 (bf5b563e1415)
I1120 20:13:42.011306 19779 slave.cpp:1484] Registered with master master@172.17.0.2:46510; given agent ID 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0
I1120 20:13:42.011313 19795 master.cpp:6865] Registered agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 at slave@172.17.0.2:46510 (bf5b563e1415) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1120 20:13:42.011592 19779 slave.cpp:1504] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/meta/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/slave.info'
I1120 20:13:42.011919 19794 task_status_update_manager.cpp:188] Resuming sending task status updates
I1120 20:13:42.011919 19795 hierarchical.cpp:603] Added agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 (bf5b563e1415) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I1120 20:13:42.012600 19779 slave.cpp:1553] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"04hIrVGoTPSwibMWwlUtfQ=="},"slave_id":{"value":"362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0"},"update_oversubscribed_resources":false}
I1120 20:13:42.013308 19795 hierarchical.cpp:1566] Performed allocation for 1 agents in 1.213316ms
I1120 20:13:42.013607 19779 master.cpp:7924] Ignoring update on agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 at slave@172.17.0.2:46510 (bf5b563e1415) as it reports no changes
I1120 20:13:42.014283 19779 master.cpp:9454] Sending offers [ 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-O0 ] to framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 (default) at scheduler-40bda406-3cc4-48a3-9b00-9b65b19274cc@172.17.0.2:46510
I1120 20:13:42.014792 19779 sched.cpp:914] Scheduler::resourceOffers took 99355ns
I1120 20:13:42.016918 19782 master.cpp:11453] Removing offer 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-O0
I1120 20:13:42.017421 19782 master.cpp:4451] Processing ACCEPT call for offers: [ 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-O0 ] on agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 at slave@172.17.0.2:46510 (bf5b563e1415) for framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 (default) at scheduler-40bda406-3cc4-48a3-9b00-9b65b19274cc@172.17.0.2:46510
I1120 20:13:42.017539 19782 master.cpp:3547] Authorizing framework principal 'test-principal' to launch task 753806e5-12be-4e43-af99-130f40a90afb
I1120 20:13:42.019203 19776 master.cpp:4028] Adding task 753806e5-12be-4e43-af99-130f40a90afb with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 (default) at scheduler-40bda406-3cc4-48a3-9b00-9b65b19274cc@172.17.0.2:46510 on agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 at slave@172.17.0.2:46510 (bf5b563e1415)
I1120 20:13:42.019775 19776 master.cpp:5423] Launching task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 (default) at scheduler-40bda406-3cc4-48a3-9b00-9b65b19274cc@172.17.0.2:46510 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 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 at slave@172.17.0.2:46510 (bf5b563e1415) on new executor
I1120 20:13:42.021183 19785 slave.cpp:2019] Got assigned task '753806e5-12be-4e43-af99-130f40a90afb' for framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.021384 19785 slave.cpp:8895] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/meta/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/framework.info'
I1120 20:13:42.021869 19785 slave.cpp:8906] Checkpointing framework pid 'scheduler-40bda406-3cc4-48a3-9b00-9b65b19274cc@172.17.0.2:46510' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/meta/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/framework.pid'
I1120 20:13:42.023496 19785 slave.cpp:2393] Authorizing task '753806e5-12be-4e43-af99-130f40a90afb' for framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.023564 19785 slave.cpp:8471] Authorizing framework principal 'test-principal' to launch task 753806e5-12be-4e43-af99-130f40a90afb
I1120 20:13:42.027531 19795 slave.cpp:2836] Launching task '753806e5-12be-4e43-af99-130f40a90afb' for framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.027629 19795 paths.cpp:752] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402' for user 'mesos'
I1120 20:13:42.028713 19795 slave.cpp:9681] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/meta/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/executor.info'
I1120 20:13:42.029544 19795 paths.cpp:755] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/meta/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402'
I1120 20:13:42.029989 19795 slave.cpp:8981] Launching executor '753806e5-12be-4e43-af99-130f40a90afb' of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-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/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402'
I1120 20:13:42.030961 19795 slave.cpp:3514] Launching container 96facb14-b025-4e4c-b5b5-34e4f0a6c402 for executor '753806e5-12be-4e43-af99-130f40a90afb' of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.031623 19795 slave.cpp:9712] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/meta/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402/tasks/753806e5-12be-4e43-af99-130f40a90afb/task.info'
I1120 20:13:42.033382 19795 slave.cpp:3033] Queued task '753806e5-12be-4e43-af99-130f40a90afb' for executor '753806e5-12be-4e43-af99-130f40a90afb' of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.033491 19795 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/latest'
I1120 20:13:42.033545 19795 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402' to virtual path '/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/latest'
I1120 20:13:42.033589 19795 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402'
I1120 20:13:42.034142 19779 containerizer.cpp:1288] Starting container 96facb14-b025-4e4c-b5b5-34e4f0a6c402
I1120 20:13:42.035181 19779 containerizer.cpp:1454] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_8YmUy0/containers/96facb14-b025-4e4c-b5b5-34e4f0a6c402/config'
I1120 20:13:42.035219 19779 containerizer.cpp:3130] Transitioning the state of container 96facb14-b025-4e4c-b5b5-34e4f0a6c402 from PROVISIONING to PREPARING
I1120 20:13:42.040313 19782 containerizer.cpp:1947] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/mesos/mesos-1.8.0/_build/src"],"shell":false,"value":"/mesos/mesos-1.8.0/_build/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:46510"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"753806e5-12be-4e43-af99-130f40a90afb"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"362fe7e7-7b3f-4863-a2c5-0589eb83fab8-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":"362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave@172.17.0.2:46510"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"15secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402"}" --pipe_read="24" --pipe_write="27" --runtime_directory="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_8YmUy0/containers/96facb14-b025-4e4c-b5b5-34e4f0a6c402" --unshare_namespace_mnt="false"'
I1120 20:13:42.048179 19782 launcher.cpp:145] Forked child with pid '27727' for container '96facb14-b025-4e4c-b5b5-34e4f0a6c402'
I1120 20:13:42.048352 19782 containerizer.cpp:2052] Checkpointing container's forked pid 27727 to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/meta/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402/pids/forked.pid'
I1120 20:13:42.049304 19782 containerizer.cpp:3130] Transitioning the state of container 96facb14-b025-4e4c-b5b5-34e4f0a6c402 from PREPARING to ISOLATING
I1120 20:13:42.051530 19782 containerizer.cpp:3130] Transitioning the state of container 96facb14-b025-4e4c-b5b5-34e4f0a6c402 from ISOLATING to FETCHING
I1120 20:13:42.051834 19787 fetcher.cpp:369] Starting to fetch URIs for container: 96facb14-b025-4e4c-b5b5-34e4f0a6c402, directory: /tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402
I1120 20:13:42.053154 19788 containerizer.cpp:3130] Transitioning the state of container 96facb14-b025-4e4c-b5b5-34e4f0a6c402 from FETCHING to RUNNING
I1120 20:13:42.539047 27807 exec.cpp:162] Version: 1.8.0
I1120 20:13:42.552835 19784 slave.cpp:4808] Got registration for executor '753806e5-12be-4e43-af99-130f40a90afb' of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 from executor(1)@172.17.0.2:33308
I1120 20:13:42.553407 19784 slave.cpp:4894] Checkpointing executor pid 'executor(1)@172.17.0.2:33308' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/meta/slaves/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0/frameworks/362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000/executors/753806e5-12be-4e43-af99-130f40a90afb/runs/96facb14-b025-4e4c-b5b5-34e4f0a6c402/pids/libprocess.pid'
I1120 20:13:42.557070 19796 slave.cpp:3246] Sending queued task '753806e5-12be-4e43-af99-130f40a90afb' to executor '753806e5-12be-4e43-af99-130f40a90afb' of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 at executor(1)@172.17.0.2:33308
I1120 20:13:42.559257 27816 exec.cpp:236] Executor registered on agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0
I1120 20:13:42.564141 27797 executor.cpp:184] Received SUBSCRIBED event
I1120 20:13:42.565637 27797 executor.cpp:188] Subscribed executor on bf5b563e1415
I1120 20:13:42.565805 27797 executor.cpp:184] Received LAUNCH event
I1120 20:13:42.568116 27797 executor.cpp:687] Starting task 753806e5-12be-4e43-af99-130f40a90afb
I1120 20:13:42.571625 19775 slave.cpp:5274] Handling status update TASK_STARTING (Status UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 from executor(1)@172.17.0.2:33308
I1120 20:13:42.574025 19794 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.574079 19794 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.575147 19794 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.575431 19794 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 to the agent
I1120 20:13:42.575673 19787 slave.cpp:5766] Forwarding the update TASK_STARTING (Status UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 to master@172.17.0.2:46510
I1120 20:13:42.575968 19787 slave.cpp:5659] Task status update manager successfully handled status update TASK_STARTING (Status UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.576025 19787 slave.cpp:5675] Sending acknowledgement for status update TASK_STARTING (Status UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 to executor(1)@172.17.0.2:33308
I1120 20:13:42.576122 19777 master.cpp:8360] Status update TASK_STARTING (Status UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 from agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 at slave@172.17.0.2:46510 (bf5b563e1415)
I1120 20:13:42.576189 19777 master.cpp:8417] Forwarding status update TASK_STARTING (Status UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.576480 19777 master.cpp:10918] Updating the state of task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I1120 20:13:42.576915 19787 sched.cpp:1022] Scheduler::statusUpdate took 124304ns
I1120 20:13:42.577803 19775 master.cpp:6226] Processing ACKNOWLEDGE call for status 35b637b6-680e-4fc9-9f69-69e09ac44da3 for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 (default) at scheduler-40bda406-3cc4-48a3-9b00-9b65b19274cc@172.17.0.2:46510 on agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0
I1120 20:13:42.578173 19781 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.578307 19781 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.578610 19781 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: 35b637b6-680e-4fc9-9f69-69e09ac44da3) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.591604 27797 executor.cpp:502] Running '/mesos/mesos-1.8.0/_build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
I1120 20:13:42.595381 27797 executor.cpp:702] Forked command at 27844
I1120 20:13:42.599390 19784 slave.cpp:5274] Handling status update TASK_RUNNING (Status UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 from executor(1)@172.17.0.2:33308
I1120 20:13:42.601734 19798 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.601838 19798 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.602210 19798 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 to the agent
I1120 20:13:42.602437 19787 slave.cpp:5766] Forwarding the update TASK_RUNNING (Status UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 to master@172.17.0.2:46510
I1120 20:13:42.602669 19787 slave.cpp:5659] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.602726 19787 slave.cpp:5675] Sending acknowledgement for status update TASK_RUNNING (Status UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 to executor(1)@172.17.0.2:33308
I1120 20:13:42.602818 19790 master.cpp:8360] Status update TASK_RUNNING (Status UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 from agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 at slave@172.17.0.2:46510 (bf5b563e1415)
I1120 20:13:42.602887 19790 master.cpp:8417] Forwarding status update TASK_RUNNING (Status UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.603163 19790 master.cpp:10918] Updating the state of task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1120 20:13:42.603492 19785 sched.cpp:1022] Scheduler::statusUpdate took 112729ns
I1120 20:13:42.604167 19783 master.cpp:6226] Processing ACKNOWLEDGE call for status f719be8f-e00c-4d56-920f-7163dd56cff7 for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 (default) at scheduler-40bda406-3cc4-48a3-9b00-9b65b19274cc@172.17.0.2:46510 on agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0
I1120 20:13:42.604548 19780 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.604665 19780 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_RUNNING (Status UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.604943 19782 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: f719be8f-e00c-4d56-920f-7163dd56cff7) for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:42.605190 19786 slave.cpp:914] Agent terminating
I1120 20:13:42.971276 19781 hierarchical.cpp:1566] Performed allocation for 1 agents in 288164ns
I1120 20:13:43.142565 19786 master.cpp:1275] Agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 at slave@172.17.0.2:46510 (bf5b563e1415) disconnected
I1120 20:13:43.142611 19786 master.cpp:3273] Disconnecting agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 at slave@172.17.0.2:46510 (bf5b563e1415)
I1120 20:13:43.142681 19786 master.cpp:3292] Deactivating agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 at slave@172.17.0.2:46510 (bf5b563e1415)
I1120 20:13:43.142789 19782 hierarchical.cpp:801] Agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0 deactivated
I1120 20:13:43.142799 19244 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1120 20:13:43.143328 19244 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1120 20:13:43.143474 19244 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1120 20:13:43.143510 19244 provisioner.cpp:298] Using default backend 'copy'
W1120 20:13:43.156525 19244 process.cpp:2829] Attempted to spawn already running process files@172.17.0.2:46510
I1120 20:13:43.157251 19244 cluster.cpp:485] Creating default 'local' authorizer
I1120 20:13:43.159600 19788 slave.cpp:268] Mesos agent started on @172.17.0.2:46510
I1120 20:13:43.159631 19788 slave.cpp:269] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_8YmUy0/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_8YmUy0/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_8YmUy0/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="15secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_8YmUy0/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_8YmUy0/frameworks" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_8YmUy0/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.8.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --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/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_8YmUy0" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY" --zk_session_timeout="10secs"
I1120 20:13:43.160091 19788 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_8YmUy0/credential'
I1120 20:13:43.160315 19788 slave.cpp:301] Agent using credential for: test-principal
I1120 20:13:43.160341 19788 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_8YmUy0/http_credentials'
I1120 20:13:43.160557 19788 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1120 20:13:43.160903 19788 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1120 20:13:43.162261 19788 slave.cpp:616] 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"}]
I1120 20:13:43.162528 19788 slave.cpp:624] Agent attributes: [ ]
I1120 20:13:43.162550 19788 slave.cpp:633] Agent hostname: bf5b563e1415
I1120 20:13:43.163370 19794 task_status_update_manager.cpp:181] Pausing sending task status updates
I1120 20:13:43.164463 19800 state.cpp:66] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/meta'
I1120 20:13:43.164548 19800 state.cpp:711] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/meta/resources/resources.info'
I1120 20:13:43.171524 19775 slave.cpp:6914] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_kJYPSY/meta', beginning agent recovery
I1120 20:13:43.172240 19775 slave.cpp:7393] Recovering framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:43.172472 19775 slave.cpp:9099] Recovering executor '753806e5-12be-4e43-af99-130f40a90afb' of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:43.173503 19793 task_status_update_manager.cpp:207] Recovering task status update manager
I1120 20:13:43.173555 19793 task_status_update_manager.cpp:215] Recovering executor '753806e5-12be-4e43-af99-130f40a90afb' of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:43.173684 19793 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 753806e5-12be-4e43-af99-130f40a90afb of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:43.174306 19793 task_status_update_manager.cpp:818] Replaying task status update stream for task 753806e5-12be-4e43-af99-130f40a90afb
I1120 20:13:43.175312 19785 containerizer.cpp:727] Recovering Mesos containers
I1120 20:13:43.175429 19785 containerizer.cpp:784] Recovering container 96facb14-b025-4e4c-b5b5-34e4f0a6c402 for executor '753806e5-12be-4e43-af99-130f40a90afb' of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:43.178099 19785 containerizer.cpp:1053] Recovering isolators
I1120 20:13:43.179220 19790 containerizer.cpp:1092] Recovering provisioner
I1120 20:13:43.180006 19778 provisioner.cpp:494] Provisioner recovery complete
I1120 20:13:43.181632 19795 composing.cpp:339] Finished recovering all containerizers
I1120 20:13:43.181777 19776 slave.cpp:7143] Recovering executors
I1120 20:13:43.181957 19776 slave.cpp:7167] Sending reconnect request to executor '753806e5-12be-4e43-af99-130f40a90afb' of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000 at executor(1)@172.17.0.2:33308
I1120 20:13:43.183784 27807 exec.cpp:282] Received reconnect request from agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0
I1120 20:13:43.186987 19787 slave.cpp:4971] Received re-registration message from executor '753806e5-12be-4e43-af99-130f40a90afb' of framework 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-0000
I1120 20:13:43.188449 27815 exec.cpp:259] Executor reregistered on agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0
I1120 20:13:43.188977 19785 slave.cpp:5888] No pings from master received within 75secs
I1120 20:13:43.189268 19783 hierarchical.cpp:1566] Performed allocation for 1 agents in 258049ns
F1120 20:13:43.189698 19785 slave.cpp:1232] Check failed: state == DISCONNECTED || state == RUNNING || state == TERMINATING RECOVERING
*** Check failure stack trace: ***
I1120 20:13:43.191437 27794 executor.cpp:184] Received SUBSCRIBED event
I1120 20:13:43.191478 27794 executor.cpp:188] Subscribed executor on bf5b563e1415
@ 0x2ae1254f8c7a google::LogMessage::Fail()
@ 0x2ae1254f8bc6 google::LogMessage::SendToLog()
@ 0x2ae1254f85c8 google::LogMessage::Flush()
@ 0x2ae1254fb4dc google::LogMessageFatal::~LogMessageFatal()
@ 0x2ae123c2fdb4 mesos::internal::slave::Slave::detected()
@ 0x2ae123cc89f8 _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEESB_EEvRKNS_3PIDIT_EEMSD_FvT0_EOT1_ENKUlOS9_PNS_11ProcessBaseEE_clESM_SO_
@ 0x2ae123d82971 _ZN5cpp176invokeIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINS3_10MasterInfoEEEESD_EEvRKNS1_3PIDIT_EEMSF_FvT0_EOT1_EUlOSB_PNS1_11ProcessBaseEE_ISB_SQ_EEEDTclcl7forwardISF_Efp_Espcl7forwardIT0_Efp0_EEEOSF_DpOSS_
@ 0x2ae123d79079 _ZN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_ISC_St12_PlaceholderILi1EEEE13invoke_expandISS_St5tupleIISC_SU_EESX_IIOSR_EEILm0ELm1EEEEDTcl6invokecl7forwardIT_Efp_Espcl6expandcl3getIXT2_EEcl7forwardIT0_Efp0_EEcl7forwardIT1_Efp2_EEEEOS11_OS12_N5cpp1416integer_sequenceImIXspT2_EEEEOS13_
@ 0x2ae123d72ae1 _ZNO6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEEclIJSR_EEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOS10_
@ 0x2ae123d6f4fb _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS4_6FutureI6OptionINS6_10MasterInfoEEEESG_EEvRKNS4_3PIDIT_EEMSI_FvT0_EOT1_EUlOSE_PNS4_11ProcessBaseEE_ISE_St12_PlaceholderILi1EEEEEIST_EEEDTclcl7forwardISI_Efp_Espcl7forwardIT0_Efp0_EEEOSI_DpOSY_
@ 0x2ae123d6d5d3 _ZN6lambda8internal6InvokeIvEclINS0_7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS5_6FutureI6OptionINS7_10MasterInfoEEEESH_EEvRKNS5_3PIDIT_EEMSJ_FvT0_EOT1_EUlOSF_PNS5_11ProcessBaseEE_JSF_St12_PlaceholderILi1EEEEEJSU_EEEvOSJ_DpOT0_
@ 0x2ae123d6b227 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINSA_10MasterInfoEEEESK_EEvRKNS1_3PIDIT_EEMSM_FvT0_EOT1_EUlOSI_S3_E_ISI_St12_PlaceholderILi1EEEEEEclEOS3_
@ 0x2ae125419fbb _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEEclES3_
@ 0x2ae1253e39d1 process::ProcessBase::consume()
@ 0x2ae125407cf4 _ZNO7process13DispatchEvent7consumeEPNS_13EventConsumerE
@ 0x558b55eeb2e8 process::ProcessBase::serve()
@ 0x2ae1253e0cae process::ProcessManager::resume()
@ 0x2ae1253dd128 _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
@ 0x2ae125402b40 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2ae125401e61 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
@ 0x2ae125401020 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
@ 0x2ae1282b9a60 (unknown)
@ 0x2ae128a30184 start_thread
@ 0x2ae128d4403d (unknown)
I1120 20:13:43.945423 27805 exec.cpp:518] Agent exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with agent 362fe7e7-7b3f-4863-a2c5-0589eb83fab8-S0
I1120 20:28:43.946471 27809 exec.cpp:499] Recovery timeout of 15mins exceeded; Shutting down
I1120 20:28:43.946609 27809 exec.cpp:445] Executor asked to shutdown
I1120 20:28:43.947180 27809 executor.cpp:184] Received SHUTDOWN event
I1120 20:28:43.947232 27809 executor.cpp:805] Shutting down
I1120 20:28:43.947279 27809 executor.cpp:918] Sending SIGTERM to process tree at pid 27844
I1120 20:28:43.962340 27809 executor.cpp:931] Sent SIGTERM to the following process trees:
[
-+- 27844 sh -c sleep 1000
\--- 27850 sleep 1000
]
I1120 20:28:43.962369 27809 executor.cpp:935] Scheduling escalation to SIGKILL in 3secs from now
I1120 20:28:44.061399 27807 executor.cpp:1003] Command terminated with signal Terminated (pid: 27844)
W1120 20:28:44.063539 27818 process.cpp:1890] Failed to send 'mesos.internal.StatusUpdateMessage' to '172.17.0.2:46510', connect: Failed to connect to 172.17.0.2:46510: Connection refused
I1120 20:28:45.065009 27818 process.cpp:927] Stopped the socket accept loop
[FAIL]: 1 shard(s) have failed tests
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.8.0/_build'
make: *** [distcheck] Error 1
+ docker rmi --force mesos-1542740371-31622
Untagged: mesos-1542740371-31622:latest
Deleted: sha256:b7b3325cbc20d3f2723cc83a7dd925d5ef7ce2104b19171c5acb27a054ab3642
Deleted: sha256:86f7fc57d1eea4374a40fb3a44cdb802efa665c3fe5584db3fe0f0c3fe92184f
Deleted: sha256:e0b1de1a787bd2d51914710326b74bed0953ace2a7e663b3d71ffb6e0055f899
Deleted: sha256:a5afd7cd1a1464e0d4af84cce0777c6524462350cea642bceb7311ae977849f3
Deleted: sha256:8c8e609b2362edcb70f4dff8cf066af8943dfd8282b718614a801121b6038bd6
Deleted: sha256:a945c38dea629143663464b18f273377e187e7417fda98e1efdc13a6dd436970
Deleted: sha256:4beaaed42e376b236c6e57251fb45158b1c58d2ea4451da689f2b3fcb91bddfc
Deleted: sha256:cbe22d0a228768308b466175c0c4d3329c34bc3b63efc9f9b7e9e4606c32c13c
Deleted: sha256:f64e05a7780cf05744c75dacdec34a19b724d289e09b69b57593cba169def9e0
Deleted: sha256:795a06614a5c67ffcfbb88d5e67950864c0d1174abd7632f9eab9cdf128a5785
Deleted: sha256:a39d6de97cebd1df1e1da4f42a78139c471aa471a57b53187312dfad54306e0a
Deleted: sha256:b03b270166eea2187d14ea3cb21d0e8510c5f9fe848cb2bec4a44ce5dc5c6d1f
Deleted: sha256:9131b1180b1d2dad89b5c1d9f7d71c231343fef24980f754c5bac826610a5b50
Deleted: sha256:8057f84455ff8528fec9a25a6afb26b0874b4557814c1823d3b09e2734967888
Deleted: sha256:5be28ba02734b25eeb55a606e1f0dd4a5a7bb7a97a33bb602d1bdab59124315b
Deleted: sha256:eb2419c984526cbe7b79bf6ae420fcdd90c87deaee044d50c4944ec116f0f596
Deleted: sha256:2138b174de88dca3b5582bf8f3e80cf4c9f2578903261add6e9760c5586f33d0
Deleted: sha256:0a6d337d2783efed02ef62bac7dcf3ac3f464acaf1eff7f90bfeb8806d70e73c
Deleted: sha256:7894445e387f3497de1b89ec1e8fd8f8d684607715ea7f9613bfa88f595f144f
Deleted: sha256:26c20e2aa310aedde9236d3ad1db6a4620dadff6f0ed2d375676bc9b6d84467e
Deleted: sha256:fac306b3fe596ba87f9125dd1960edb429a702fbe5bf507d851a6c3b6dde917e
Deleted: sha256:802a94c2a05ba65794932dd699bf0cd159a53eb2e0db58d51823712610c87fe7
Deleted: sha256:bcf550738a12d34129b1f478ef0629b4538e54ade4aceb1267f3cf09d1cb1fd1
Deleted: sha256:1d07849c310f966da9c6b5c337a4cd538c94d576515fe39c6a8788a033b3fc32
Deleted: sha256:d5c6556a30e71fb7bd4568a62fa52d7e3a0b7ca2c65068e1808f1fe5f7cd92ba
Deleted: sha256:fd74ebd99523cafe9e3f088e12b08b1c147f8c042d5f6ffc2e6a1cb885b349c0
Deleted: sha256:90ac5be649dbd7ccc2e2de5efdf62e4d93fbec58e91a0dcffeee5ec107e21d50
Deleted: sha256:31d834e6e1362eb99e6e7d97534af142887742d776e86f89d951a2d3b2f686f4
Deleted: sha256:e9fe2765d801beb44cb4b97e1cd12b206f94d6581091774735f1fd73a6d33255
Deleted: sha256:8f754b87877d3f9ea6d3b98b29aa58c5c7620b82bce5cc1cb428536714cd55db
11-20-18_18:59:27 - Running <https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py>
Checking if review 69390 needs verification
Patch never verified, needs verification
Dependent review: https://reviews.apache.org/api/review-requests/69381/
The review request 69381 is already submitted
Dependent review: https://reviews.apache.org/api/review-requests/69380/
The review request 69380 is already submitted
Verifying review 69390
Dependent review: https://reviews.apache.org/api/review-requests/69381/
Dependent review: https://reviews.apache.org/api/review-requests/69380/
Applying review 69390
/usr/bin/python3 support/apply-reviews.py -n -r 69390
Traceback (most recent call last):
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 186, in verify_review
% (command, build_output)])
File "/usr/lib/python3.5/subprocess.py", line 581, in check_call
raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['bash', '-c', "set -o pipefail; export OS='ubuntu:14.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/docker-build.sh 2>&1 | tee build_69390"]' returned non-zero exit status 2
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 294, in <module>
main()
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 288, in main
verify_review(review_request, handler)
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 201, in verify_review
output = open(build_output).read().decode(sys.stdout.encoding)
AttributeError: 'str' object has no attribute 'decode'
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos-Reviewbot #23566
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/23566/display/redirect?page=changes>
Changes:
[toenshoff] Added test reproducing crash on authorization failure.
[toenshoff] Added collectAuthorizations helper to master.hpp.
[toenshoff] Introduced common/authorization and refactored collectAuthorizations.
[toenshoff] Refactored createSubject and authorizeLogAccess to common/authorization.
[toenshoff] Added test for ACCESS_MESOS_LOG authorization.
------------------------------------------
[...truncated 43.74 MB...]
I1120 17:55:25.124773 19847 master.cpp:9454] Sending offers [ 6914250f-729d-4792-962f-4d39fec77cc7-O0 ] to framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 (default) at scheduler-e8dfd2cf-3558-4dcc-8f02-4a6a345c8ca9@172.17.0.2:33427
I1120 17:55:25.125282 19821 sched.cpp:914] Scheduler::resourceOffers took 100612ns
I1120 17:55:25.127012 19817 master.cpp:11453] Removing offer 6914250f-729d-4792-962f-4d39fec77cc7-O0
I1120 17:55:25.127341 19817 master.cpp:4451] Processing ACCEPT call for offers: [ 6914250f-729d-4792-962f-4d39fec77cc7-O0 ] on agent 6914250f-729d-4792-962f-4d39fec77cc7-S0 at slave@172.17.0.2:33427 (38e634d86211) for framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 (default) at scheduler-e8dfd2cf-3558-4dcc-8f02-4a6a345c8ca9@172.17.0.2:33427
I1120 17:55:25.127436 19817 master.cpp:3547] Authorizing framework principal 'test-principal' to launch task 760347f5-9381-4f33-b47e-c7deffae60ac
I1120 17:55:25.129160 19858 master.cpp:4028] Adding task 760347f5-9381-4f33-b47e-c7deffae60ac with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 (default) at scheduler-e8dfd2cf-3558-4dcc-8f02-4a6a345c8ca9@172.17.0.2:33427 on agent 6914250f-729d-4792-962f-4d39fec77cc7-S0 at slave@172.17.0.2:33427 (38e634d86211)
I1120 17:55:25.129735 19858 master.cpp:5423] Launching task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 (default) at scheduler-e8dfd2cf-3558-4dcc-8f02-4a6a345c8ca9@172.17.0.2:33427 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 6914250f-729d-4792-962f-4d39fec77cc7-S0 at slave@172.17.0.2:33427 (38e634d86211) on new executor
I1120 17:55:25.139879 19843 slave.cpp:1504] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/meta/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/slave.info'
I1120 17:55:25.142000 19843 slave.cpp:1553] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"jjiOGv97TNGr969uiHe2/g=="},"slave_id":{"value":"6914250f-729d-4792-962f-4d39fec77cc7-S0"},"update_oversubscribed_resources":false}
I1120 17:55:25.142768 19819 master.cpp:7924] Ignoring update on agent 6914250f-729d-4792-962f-4d39fec77cc7-S0 at slave@172.17.0.2:33427 (38e634d86211) as it reports no changes
I1120 17:55:25.143338 19843 slave.cpp:2019] Got assigned task '760347f5-9381-4f33-b47e-c7deffae60ac' for framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.143544 19843 slave.cpp:8895] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/meta/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/framework.info'
I1120 17:55:25.143996 19843 slave.cpp:8906] Checkpointing framework pid 'scheduler-e8dfd2cf-3558-4dcc-8f02-4a6a345c8ca9@172.17.0.2:33427' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/meta/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/framework.pid'
I1120 17:55:25.146021 19843 slave.cpp:2393] Authorizing task '760347f5-9381-4f33-b47e-c7deffae60ac' for framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.146121 19843 slave.cpp:8471] Authorizing framework principal 'test-principal' to launch task 760347f5-9381-4f33-b47e-c7deffae60ac
I1120 17:55:25.148465 19845 slave.cpp:2836] Launching task '760347f5-9381-4f33-b47e-c7deffae60ac' for framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.148571 19845 paths.cpp:752] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a' for user 'mesos'
I1120 17:55:25.149349 19845 slave.cpp:9681] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/meta/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/executor.info'
I1120 17:55:25.150102 19845 paths.cpp:755] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/meta/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a'
I1120 17:55:25.151731 19845 slave.cpp:8981] Launching executor '760347f5-9381-4f33-b47e-c7deffae60ac' of framework 6914250f-729d-4792-962f-4d39fec77cc7-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/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a'
I1120 17:55:25.152730 19845 slave.cpp:3514] Launching container 75393d65-fc67-487c-b45c-1de4560c4a7a for executor '760347f5-9381-4f33-b47e-c7deffae60ac' of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.153445 19845 slave.cpp:9712] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/meta/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a/tasks/760347f5-9381-4f33-b47e-c7deffae60ac/task.info'
I1120 17:55:25.154387 19845 slave.cpp:3033] Queued task '760347f5-9381-4f33-b47e-c7deffae60ac' for executor '760347f5-9381-4f33-b47e-c7deffae60ac' of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.154543 19845 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/latest'
I1120 17:55:25.154618 19845 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a' to virtual path '/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/latest'
I1120 17:55:25.154665 19845 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a'
I1120 17:55:25.155237 19825 containerizer.cpp:1288] Starting container 75393d65-fc67-487c-b45c-1de4560c4a7a
I1120 17:55:25.156323 19825 containerizer.cpp:1454] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4aSM4F/containers/75393d65-fc67-487c-b45c-1de4560c4a7a/config'
I1120 17:55:25.156361 19825 containerizer.cpp:3130] Transitioning the state of container 75393d65-fc67-487c-b45c-1de4560c4a7a from PROVISIONING to PREPARING
I1120 17:55:25.161631 19835 containerizer.cpp:1947] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/mesos/mesos-1.8.0/_build/src"],"shell":false,"value":"/mesos/mesos-1.8.0/_build/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:33427"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"760347f5-9381-4f33-b47e-c7deffae60ac"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"6914250f-729d-4792-962f-4d39fec77cc7-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":"6914250f-729d-4792-962f-4d39fec77cc7-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave@172.17.0.2:33427"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"15secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a"}" --pipe_read="24" --pipe_write="27" --runtime_directory="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4aSM4F/containers/75393d65-fc67-487c-b45c-1de4560c4a7a" --unshare_namespace_mnt="false"'
I1120 17:55:25.168236 19835 launcher.cpp:145] Forked child with pid '27610' for container '75393d65-fc67-487c-b45c-1de4560c4a7a'
I1120 17:55:25.168433 19835 containerizer.cpp:2052] Checkpointing container's forked pid 27610 to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/meta/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a/pids/forked.pid'
I1120 17:55:25.169601 19835 containerizer.cpp:3130] Transitioning the state of container 75393d65-fc67-487c-b45c-1de4560c4a7a from PREPARING to ISOLATING
I1120 17:55:25.171989 19825 containerizer.cpp:3130] Transitioning the state of container 75393d65-fc67-487c-b45c-1de4560c4a7a from ISOLATING to FETCHING
I1120 17:55:25.172281 19825 fetcher.cpp:369] Starting to fetch URIs for container: 75393d65-fc67-487c-b45c-1de4560c4a7a, directory: /tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a
I1120 17:55:25.173631 19831 containerizer.cpp:3130] Transitioning the state of container 75393d65-fc67-487c-b45c-1de4560c4a7a from FETCHING to RUNNING
I1120 17:55:25.637883 27693 exec.cpp:162] Version: 1.8.0
I1120 17:55:25.653926 19813 slave.cpp:4808] Got registration for executor '760347f5-9381-4f33-b47e-c7deffae60ac' of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 from executor(1)@172.17.0.2:39837
I1120 17:55:25.654453 19813 slave.cpp:4894] Checkpointing executor pid 'executor(1)@172.17.0.2:39837' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/meta/slaves/6914250f-729d-4792-962f-4d39fec77cc7-S0/frameworks/6914250f-729d-4792-962f-4d39fec77cc7-0000/executors/760347f5-9381-4f33-b47e-c7deffae60ac/runs/75393d65-fc67-487c-b45c-1de4560c4a7a/pids/libprocess.pid'
I1120 17:55:25.657424 19815 slave.cpp:3246] Sending queued task '760347f5-9381-4f33-b47e-c7deffae60ac' to executor '760347f5-9381-4f33-b47e-c7deffae60ac' of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 at executor(1)@172.17.0.2:39837
I1120 17:55:25.659694 27710 exec.cpp:236] Executor registered on agent 6914250f-729d-4792-962f-4d39fec77cc7-S0
I1120 17:55:25.664117 27718 executor.cpp:184] Received SUBSCRIBED event
I1120 17:55:25.665632 27718 executor.cpp:188] Subscribed executor on 38e634d86211
I1120 17:55:25.665829 27718 executor.cpp:184] Received LAUNCH event
I1120 17:55:25.667814 27718 executor.cpp:687] Starting task 760347f5-9381-4f33-b47e-c7deffae60ac
I1120 17:55:25.671875 19837 slave.cpp:5274] Handling status update TASK_STARTING (Status UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 from executor(1)@172.17.0.2:39837
I1120 17:55:25.673895 19831 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.673950 19831 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.674916 19831 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.675222 19831 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 to the agent
I1120 17:55:25.675443 19858 slave.cpp:5766] Forwarding the update TASK_STARTING (Status UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 to master@172.17.0.2:33427
I1120 17:55:25.675653 19858 slave.cpp:5659] Task status update manager successfully handled status update TASK_STARTING (Status UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.675701 19858 slave.cpp:5675] Sending acknowledgement for status update TASK_STARTING (Status UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 to executor(1)@172.17.0.2:39837
I1120 17:55:25.675829 19825 master.cpp:8360] Status update TASK_STARTING (Status UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 from agent 6914250f-729d-4792-962f-4d39fec77cc7-S0 at slave@172.17.0.2:33427 (38e634d86211)
I1120 17:55:25.675896 19825 master.cpp:8417] Forwarding status update TASK_STARTING (Status UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.676163 19825 master.cpp:10918] Updating the state of task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I1120 17:55:25.676440 19852 sched.cpp:1022] Scheduler::statusUpdate took 120460ns
I1120 17:55:25.677175 19819 master.cpp:6226] Processing ACKNOWLEDGE call for status 8fb01077-c4ad-469a-898a-611a0ab2ee54 for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 (default) at scheduler-e8dfd2cf-3558-4dcc-8f02-4a6a345c8ca9@172.17.0.2:33427 on agent 6914250f-729d-4792-962f-4d39fec77cc7-S0
I1120 17:55:25.677536 19827 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.677659 19827 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.677919 19821 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: 8fb01077-c4ad-469a-898a-611a0ab2ee54) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.687355 27718 executor.cpp:502] Running '/mesos/mesos-1.8.0/_build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
I1120 17:55:25.690891 27718 executor.cpp:702] Forked command at 27723
I1120 17:55:25.694700 19834 slave.cpp:5274] Handling status update TASK_RUNNING (Status UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 from executor(1)@172.17.0.2:39837
I1120 17:55:25.696815 19843 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.696911 19843 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.697211 19843 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 to the agent
I1120 17:55:25.697412 19837 slave.cpp:5766] Forwarding the update TASK_RUNNING (Status UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 to master@172.17.0.2:33427
I1120 17:55:25.697600 19837 slave.cpp:5659] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.697662 19837 slave.cpp:5675] Sending acknowledgement for status update TASK_RUNNING (Status UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 to executor(1)@172.17.0.2:39837
I1120 17:55:25.697753 19843 master.cpp:8360] Status update TASK_RUNNING (Status UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 from agent 6914250f-729d-4792-962f-4d39fec77cc7-S0 at slave@172.17.0.2:33427 (38e634d86211)
I1120 17:55:25.697824 19843 master.cpp:8417] Forwarding status update TASK_RUNNING (Status UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.698107 19843 master.cpp:10918] Updating the state of task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1120 17:55:25.698343 19839 sched.cpp:1022] Scheduler::statusUpdate took 105804ns
I1120 17:55:25.699086 19823 master.cpp:6226] Processing ACKNOWLEDGE call for status a008083b-f9c7-4cf0-9462-55dc633679db for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 (default) at scheduler-e8dfd2cf-3558-4dcc-8f02-4a6a345c8ca9@172.17.0.2:33427 on agent 6914250f-729d-4792-962f-4d39fec77cc7-S0
I1120 17:55:25.699463 19812 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.699558 19812 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_RUNNING (Status UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.699816 19858 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: a008083b-f9c7-4cf0-9462-55dc633679db) for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:25.700067 19277 slave.cpp:914] Agent terminating
I1120 17:55:26.082116 19827 hierarchical.cpp:1566] Performed allocation for 1 agents in 369704ns
I1120 17:55:26.171790 19823 master.cpp:1275] Agent 6914250f-729d-4792-962f-4d39fec77cc7-S0 at slave@172.17.0.2:33427 (38e634d86211) disconnected
I1120 17:55:26.171836 19823 master.cpp:3273] Disconnecting agent 6914250f-729d-4792-962f-4d39fec77cc7-S0 at slave@172.17.0.2:33427 (38e634d86211)
I1120 17:55:26.171907 19823 master.cpp:3292] Deactivating agent 6914250f-729d-4792-962f-4d39fec77cc7-S0 at slave@172.17.0.2:33427 (38e634d86211)
I1120 17:55:26.172003 19277 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I1120 17:55:26.172212 19823 hierarchical.cpp:801] Agent 6914250f-729d-4792-962f-4d39fec77cc7-S0 deactivated
W1120 17:55:26.172706 19277 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1120 17:55:26.172891 19277 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1120 17:55:26.172935 19277 provisioner.cpp:298] Using default backend 'copy'
W1120 17:55:26.190671 19277 process.cpp:2829] Attempted to spawn already running process files@172.17.0.2:33427
I1120 17:55:26.191221 19277 cluster.cpp:485] Creating default 'local' authorizer
I1120 17:55:26.192917 19823 slave.cpp:268] Mesos agent started on @172.17.0.2:33427
I1120 17:55:26.192942 19823 slave.cpp:269] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4aSM4F/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4aSM4F/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4aSM4F/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="15secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4aSM4F/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4aSM4F/frameworks" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4aSM4F/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.8.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --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/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4aSM4F" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E" --zk_session_timeout="10secs"
I1120 17:55:26.193359 19823 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4aSM4F/credential'
I1120 17:55:26.193584 19823 slave.cpp:301] Agent using credential for: test-principal
I1120 17:55:26.193615 19823 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4aSM4F/http_credentials'
I1120 17:55:26.193836 19823 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1120 17:55:26.194151 19823 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1120 17:55:26.195300 19823 slave.cpp:616] 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"}]
I1120 17:55:26.195526 19823 slave.cpp:624] Agent attributes: [ ]
I1120 17:55:26.195549 19823 slave.cpp:633] Agent hostname: 38e634d86211
I1120 17:55:26.195845 19815 task_status_update_manager.cpp:181] Pausing sending task status updates
I1120 17:55:26.197131 19834 state.cpp:66] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/meta'
I1120 17:55:26.197216 19834 state.cpp:711] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/meta/resources/resources.info'
I1120 17:55:26.203985 19837 slave.cpp:6914] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_B4Jf8E/meta', beginning agent recovery
I1120 17:55:26.204851 19837 slave.cpp:7393] Recovering framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:26.205072 19837 slave.cpp:9099] Recovering executor '760347f5-9381-4f33-b47e-c7deffae60ac' of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:26.206285 19815 task_status_update_manager.cpp:207] Recovering task status update manager
I1120 17:55:26.206336 19815 task_status_update_manager.cpp:215] Recovering executor '760347f5-9381-4f33-b47e-c7deffae60ac' of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:26.206454 19815 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 760347f5-9381-4f33-b47e-c7deffae60ac of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:26.207217 19815 task_status_update_manager.cpp:818] Replaying task status update stream for task 760347f5-9381-4f33-b47e-c7deffae60ac
I1120 17:55:26.208137 19827 containerizer.cpp:727] Recovering Mesos containers
I1120 17:55:26.208313 19827 containerizer.cpp:784] Recovering container 75393d65-fc67-487c-b45c-1de4560c4a7a for executor '760347f5-9381-4f33-b47e-c7deffae60ac' of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:26.210408 19827 containerizer.cpp:1053] Recovering isolators
I1120 17:55:26.211519 19856 containerizer.cpp:1092] Recovering provisioner
I1120 17:55:26.212141 19854 provisioner.cpp:494] Provisioner recovery complete
I1120 17:55:26.213806 19825 composing.cpp:339] Finished recovering all containerizers
I1120 17:55:26.213937 19812 slave.cpp:7143] Recovering executors
I1120 17:55:26.214077 19812 slave.cpp:7167] Sending reconnect request to executor '760347f5-9381-4f33-b47e-c7deffae60ac' of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000 at executor(1)@172.17.0.2:39837
I1120 17:55:26.215589 27697 exec.cpp:282] Received reconnect request from agent 6914250f-729d-4792-962f-4d39fec77cc7-S0
I1120 17:55:26.217988 19856 slave.cpp:4971] Received re-registration message from executor '760347f5-9381-4f33-b47e-c7deffae60ac' of framework 6914250f-729d-4792-962f-4d39fec77cc7-0000
I1120 17:55:26.220028 27708 exec.cpp:259] Executor reregistered on agent 6914250f-729d-4792-962f-4d39fec77cc7-S0
I1120 17:55:26.220480 19825 slave.cpp:5888] No pings from master received within 75secs
I1120 17:55:26.220548 19856 hierarchical.cpp:1566] Performed allocation for 1 agents in 249730ns
F1120 17:55:26.221237 19858 slave.cpp:1232] Check failed: state == DISCONNECTED || state == RUNNING || state == TERMINATING RECOVERING
*** Check failure stack trace: ***
I1120 17:55:26.222951 27714 executor.cpp:184] Received SUBSCRIBED event
I1120 17:55:26.223004 27714 executor.cpp:188] Subscribed executor on 38e634d86211
@ 0x2b6b05a8ec7a google::LogMessage::Fail()
@ 0x2b6b05a8ebc6 google::LogMessage::SendToLog()
@ 0x2b6b05a8e5c8 google::LogMessage::Flush()
@ 0x2b6b05a914dc google::LogMessageFatal::~LogMessageFatal()
@ 0x2b6b041c5db4 mesos::internal::slave::Slave::detected()
@ 0x2b6b0425e9f8 _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEESB_EEvRKNS_3PIDIT_EEMSD_FvT0_EOT1_ENKUlOS9_PNS_11ProcessBaseEE_clESM_SO_
@ 0x2b6b04318971 _ZN5cpp176invokeIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINS3_10MasterInfoEEEESD_EEvRKNS1_3PIDIT_EEMSF_FvT0_EOT1_EUlOSB_PNS1_11ProcessBaseEE_ISB_SQ_EEEDTclcl7forwardISF_Efp_Espcl7forwardIT0_Efp0_EEEOSF_DpOSS_
@ 0x2b6b0430f079 _ZN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_ISC_St12_PlaceholderILi1EEEE13invoke_expandISS_St5tupleIISC_SU_EESX_IIOSR_EEILm0ELm1EEEEDTcl6invokecl7forwardIT_Efp_Espcl6expandcl3getIXT2_EEcl7forwardIT0_Efp0_EEcl7forwardIT1_Efp2_EEEEOS11_OS12_N5cpp1416integer_sequenceImIXspT2_EEEEOS13_
@ 0x2b6b04308ae1 _ZNO6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEEclIJSR_EEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOS10_
@ 0x2b6b043054fb _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS4_6FutureI6OptionINS6_10MasterInfoEEEESG_EEvRKNS4_3PIDIT_EEMSI_FvT0_EOT1_EUlOSE_PNS4_11ProcessBaseEE_ISE_St12_PlaceholderILi1EEEEEIST_EEEDTclcl7forwardISI_Efp_Espcl7forwardIT0_Efp0_EEEOSI_DpOSY_
@ 0x2b6b043035d3 _ZN6lambda8internal6InvokeIvEclINS0_7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS5_6FutureI6OptionINS7_10MasterInfoEEEESH_EEvRKNS5_3PIDIT_EEMSJ_FvT0_EOT1_EUlOSF_PNS5_11ProcessBaseEE_JSF_St12_PlaceholderILi1EEEEEJSU_EEEvOSJ_DpOT0_
@ 0x2b6b04301227 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINSA_10MasterInfoEEEESK_EEvRKNS1_3PIDIT_EEMSM_FvT0_EOT1_EUlOSI_S3_E_ISI_St12_PlaceholderILi1EEEEEEclEOS3_
@ 0x2b6b059affbb _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEEclES3_
@ 0x2b6b059799d1 process::ProcessBase::consume()
@ 0x2b6b0599dcf4 _ZNO7process13DispatchEvent7consumeEPNS_13EventConsumerE
@ 0x559d2c59bff8 process::ProcessBase::serve()
@ 0x2b6b05976cae process::ProcessManager::resume()
@ 0x2b6b05973128 _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
@ 0x2b6b05998b40 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2b6b05997e61 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
@ 0x2b6b05997020 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
@ 0x2b6b0884fa60 (unknown)
@ 0x2b6b08fc6184 start_thread
@ 0x2b6b092da03d (unknown)
I1120 17:55:27.014524 27685 exec.cpp:518] Agent exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with agent 6914250f-729d-4792-962f-4d39fec77cc7-S0
I1120 18:10:27.015513 27703 exec.cpp:499] Recovery timeout of 15mins exceeded; Shutting down
I1120 18:10:27.015677 27703 exec.cpp:445] Executor asked to shutdown
I1120 18:10:27.016536 27693 executor.cpp:184] Received SHUTDOWN event
I1120 18:10:27.016613 27693 executor.cpp:805] Shutting down
I1120 18:10:27.016696 27693 executor.cpp:918] Sending SIGTERM to process tree at pid 27723
I1120 18:10:27.034428 27693 executor.cpp:931] Sent SIGTERM to the following process trees:
[
-+- 27723 sh -c sleep 1000
\--- 27729 sleep 1000
]
I1120 18:10:27.034462 27693 executor.cpp:935] Scheduling escalation to SIGKILL in 3secs from now
I1120 18:10:27.039531 27708 executor.cpp:1003] Command terminated with signal Terminated (pid: 27723)
W1120 18:10:27.044592 27720 process.cpp:1890] Failed to send 'mesos.internal.StatusUpdateMessage' to '172.17.0.2:33427', connect: Failed to connect to 172.17.0.2:33427: Connection refused
I1120 18:10:28.043051 27720 process.cpp:927] Stopped the socket accept loop
[FAIL]: 1 shard(s) have failed tests
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.8.0/_build'
make: *** [distcheck] Error 1
+ docker rmi --force mesos-1542732483-26480
Untagged: mesos-1542732483-26480:latest
Deleted: sha256:0de282db8fee1ce54581eeeccff211ab1d26aa43015d25cb39adaaeb5b85320a
Deleted: sha256:786482e11f21debedde04ed5e741966ba902c97b977024fd06c31704d14f564d
Deleted: sha256:394534ccc0d38d1cb7b48f57546df8255d3c3c624554319aad408015be247db8
Deleted: sha256:9b4b542ee689c4e0e916f26c399e03aeb1ecd7282e1c1aa0ba95e28e50f45352
Deleted: sha256:e33dfa40bea7c054b469750cd6bd28624105b7e1c0326ae15818075d15677316
Deleted: sha256:0eb50711127baff377fc992d86bbe874e4b241c845e6b1dec38d2688d3359361
Deleted: sha256:6abc91dab9e0d8f3fcd75d494ddb4b597b62b4fe27576eb8823478fb2d7fb68c
Deleted: sha256:fbff244f8166d46c000ce350b70e9be4209f6638e77f46847dafbc27e7c049de
Deleted: sha256:43bd7075094ba4459fc5ec01833fb277ba84ea412b09b954d47708143ce6833e
Deleted: sha256:fbd2def7f365c160773d861292516fdff28bba54c6cad5162081ec9a986f0f1a
Deleted: sha256:e38a7ad3536b6d868d05286111799a256229e1d80a5a8cb978ea3fb3bd09b3e1
Deleted: sha256:049f5fbfae2eeb8013bde623cacf7253527731ce8414001f9a65294d46e41314
Deleted: sha256:a7101d1571c03a5e4ae4c87bb4fa67decf3dfa2f7484049cc1dd0a18c93015b7
Deleted: sha256:9bc384fb9b2643c77d19f1cff732a6146aec7247b42300abd373a9e3c7ac21fd
Deleted: sha256:d43034db1b3384867c791fe9fa2d88ef192cb5ab45ee98db1ecedaa277544c06
Deleted: sha256:5631d24380cd94b1364d49677d9e206ad176d3b2d7a9c4c2799f76b45a4f2a13
Deleted: sha256:8ebecf76a95b20a3ebf35b38248a593a207a006c94c404cc9ed1487c9cb7bb93
Deleted: sha256:5e9f347b53049b244eba23e952b5b3f548594bf9db29cfb278ed73986983a659
Deleted: sha256:e290c0f97678c86d3d6e41e3ace734ad7f4244054baa1880be95d7b4ed168e95
Deleted: sha256:e0609507f2a3e278e00ca28c69da9a4ebf57c955ac93de1a4c529a3a7bd5f04a
Deleted: sha256:3ddfd33fb7e988b5e7f52970c38da689e5ca7f10c54b576505e6e67f45acb18e
Deleted: sha256:427e388578ce1b738b5fdbc78edb7b1ab73693c7c312e7ecea70b1bd80158e85
Deleted: sha256:5f2e4fcb88d22caae585f5427cfedd565d05e8e5351fab1f367e02a6d236e939
Deleted: sha256:2ea2e3efca9bfa3e0fcbcd222ee5bb09807e6e1ea9ceb1960160c5d87969fd80
Deleted: sha256:d9875e2b670c08dc375bbb203d8531b3e17503cf0194056f3ff0125af694338f
Deleted: sha256:110464bdef4bdf1d629ff2ee9e9666439bfd36ee12712830497300179eff61ed
Deleted: sha256:6bf6f4834ae6090416dc34a0147d7c1b8a2982bdc09ee3e8ebaa18085a830479
Deleted: sha256:b89fa2b360b684e9f69879a8f1c1fb409b60c1447d20878e2e93e44ed839c8f4
Deleted: sha256:7783226935bacdc8c0f587cc83ed849cde4b419071f24df1cf3458d283245cbf
Deleted: sha256:202a8e79d399e3f7950c2b271b6e40f5011a9b48cb8290951ac4ad008d5dfacb
11-20-18_16:47:55 - Running <https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py>
Checking if review 69313 needs verification
Patch never verified, needs verification
Dependent review: https://reviews.apache.org/api/review-requests/69312/
Dependent review: https://reviews.apache.org/api/review-requests/69311/
Dependent review: https://reviews.apache.org/api/review-requests/69310/
The review request 69310 is already submitted
Dependent review: https://reviews.apache.org/api/review-requests/69309/
The review request 69309 is already submitted
Verifying review 69313
Dependent review: https://reviews.apache.org/api/review-requests/69312/
Dependent review: https://reviews.apache.org/api/review-requests/69311/
Dependent review: https://reviews.apache.org/api/review-requests/69310/
Dependent review: https://reviews.apache.org/api/review-requests/69309/
Applying review 69311
/usr/bin/python3 support/apply-reviews.py -n -r 69311
Applying review 69312
/usr/bin/python3 support/apply-reviews.py -n -r 69312
Applying review 69313
/usr/bin/python3 support/apply-reviews.py -n -r 69313
Traceback (most recent call last):
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 186, in verify_review
% (command, build_output)])
File "/usr/lib/python3.5/subprocess.py", line 581, in check_call
raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['bash', '-c', "set -o pipefail; export OS='ubuntu:14.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/docker-build.sh 2>&1 | tee build_69313"]' returned non-zero exit status 2
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 294, in <module>
main()
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 288, in main
verify_review(review_request, handler)
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 201, in verify_review
output = open(build_output).read().decode(sys.stdout.encoding)
AttributeError: 'str' object has no attribute 'decode'
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos-Reviewbot #23565
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/23565/display/redirect?page=changes>
Changes:
[bmahler] Added --min_allocatable_resources to the multi-scheduler documentation.
------------------------------------------
[...truncated 43.70 MB...]
I1120 00:48:12.255743 19748 master.cpp:6880] Admitted agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 at slave@172.17.0.2:35765 (a11789cde9e3)
I1120 00:48:12.256489 19741 slave.cpp:1485] Registered with master master@172.17.0.2:35765; given agent ID 75f6bc92-0ff4-466d-be04-74f923553cc3-S0
I1120 00:48:12.256507 19748 master.cpp:6925] Registered agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 at slave@172.17.0.2:35765 (a11789cde9e3) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1120 00:48:12.256587 19746 task_status_update_manager.cpp:188] Resuming sending task status updates
I1120 00:48:12.256777 19741 slave.cpp:1505] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/meta/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/slave.info'
I1120 00:48:12.256805 19761 hierarchical.cpp:603] Added agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 (a11789cde9e3) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I1120 00:48:12.257733 19741 slave.cpp:1554] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"mpNcucmFQtOyRKF2rXQ5HA=="},"slave_id":{"value":"75f6bc92-0ff4-466d-be04-74f923553cc3-S0"},"update_oversubscribed_resources":false}
I1120 00:48:12.258102 19761 hierarchical.cpp:1566] Performed allocation for 1 agents in 1.144784ms
I1120 00:48:12.258375 19742 master.cpp:7984] Ignoring update on agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 at slave@172.17.0.2:35765 (a11789cde9e3) as it reports no changes
I1120 00:48:12.258898 19742 master.cpp:9514] Sending offers [ 75f6bc92-0ff4-466d-be04-74f923553cc3-O0 ] to framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 (default) at scheduler-df669210-aa08-40a4-af63-fed1e0d412f1@172.17.0.2:35765
I1120 00:48:12.259424 19753 sched.cpp:914] Scheduler::resourceOffers took 104574ns
I1120 00:48:12.261119 19745 master.cpp:11513] Removing offer 75f6bc92-0ff4-466d-be04-74f923553cc3-O0
I1120 00:48:12.261476 19745 master.cpp:4511] Processing ACCEPT call for offers: [ 75f6bc92-0ff4-466d-be04-74f923553cc3-O0 ] on agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 at slave@172.17.0.2:35765 (a11789cde9e3) for framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 (default) at scheduler-df669210-aa08-40a4-af63-fed1e0d412f1@172.17.0.2:35765
I1120 00:48:12.261584 19745 master.cpp:3563] Authorizing framework principal 'test-principal' to launch task 23484316-89d3-486c-9ef9-e9551b671c4e
I1120 00:48:12.263713 19747 master.cpp:4088] Adding task 23484316-89d3-486c-9ef9-e9551b671c4e with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 (default) at scheduler-df669210-aa08-40a4-af63-fed1e0d412f1@172.17.0.2:35765 on agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 at slave@172.17.0.2:35765 (a11789cde9e3)
I1120 00:48:12.264420 19747 master.cpp:5483] Launching task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 (default) at scheduler-df669210-aa08-40a4-af63-fed1e0d412f1@172.17.0.2:35765 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 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 at slave@172.17.0.2:35765 (a11789cde9e3) on new executor
I1120 00:48:12.265691 19743 slave.cpp:2020] Got assigned task '23484316-89d3-486c-9ef9-e9551b671c4e' for framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.265861 19743 slave.cpp:8914] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/meta/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/framework.info'
I1120 00:48:12.266266 19743 slave.cpp:8925] Checkpointing framework pid 'scheduler-df669210-aa08-40a4-af63-fed1e0d412f1@172.17.0.2:35765' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/meta/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/framework.pid'
I1120 00:48:12.267624 19743 slave.cpp:2394] Authorizing task '23484316-89d3-486c-9ef9-e9551b671c4e' for framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.267680 19743 slave.cpp:8472] Authorizing framework principal 'test-principal' to launch task 23484316-89d3-486c-9ef9-e9551b671c4e
I1120 00:48:12.269402 19754 slave.cpp:2837] Launching task '23484316-89d3-486c-9ef9-e9551b671c4e' for framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.269475 19754 paths.cpp:752] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e' for user 'mesos'
I1120 00:48:12.270128 19754 slave.cpp:9700] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/meta/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/executor.info'
I1120 00:48:12.270913 19754 paths.cpp:755] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/meta/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e'
I1120 00:48:12.271265 19754 slave.cpp:9000] Launching executor '23484316-89d3-486c-9ef9-e9551b671c4e' of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-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/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e'
I1120 00:48:12.271980 19754 slave.cpp:3515] Launching container ab95472b-fe74-4644-8f58-e2cbabcb7f3e for executor '23484316-89d3-486c-9ef9-e9551b671c4e' of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.272541 19754 slave.cpp:9731] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/meta/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e/tasks/23484316-89d3-486c-9ef9-e9551b671c4e/task.info'
I1120 00:48:12.273252 19754 slave.cpp:3034] Queued task '23484316-89d3-486c-9ef9-e9551b671c4e' for executor '23484316-89d3-486c-9ef9-e9551b671c4e' of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.273342 19754 slave.cpp:994] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/latest'
I1120 00:48:12.273386 19754 slave.cpp:994] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e' to virtual path '/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/latest'
I1120 00:48:12.273422 19754 slave.cpp:994] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e'
I1120 00:48:12.273973 19742 containerizer.cpp:1288] Starting container ab95472b-fe74-4644-8f58-e2cbabcb7f3e
I1120 00:48:12.276149 19742 containerizer.cpp:1454] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_rdYPMK/containers/ab95472b-fe74-4644-8f58-e2cbabcb7f3e/config'
I1120 00:48:12.276193 19742 containerizer.cpp:3130] Transitioning the state of container ab95472b-fe74-4644-8f58-e2cbabcb7f3e from PROVISIONING to PREPARING
I1120 00:48:12.280737 19745 containerizer.cpp:1947] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/mesos/mesos-1.8.0/_build/src"],"shell":false,"value":"/mesos/mesos-1.8.0/_build/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:35765"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"23484316-89d3-486c-9ef9-e9551b671c4e"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"75f6bc92-0ff4-466d-be04-74f923553cc3-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":"75f6bc92-0ff4-466d-be04-74f923553cc3-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave@172.17.0.2:35765"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"15secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e"}" --pipe_read="24" --pipe_write="26" --runtime_directory="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_rdYPMK/containers/ab95472b-fe74-4644-8f58-e2cbabcb7f3e" --unshare_namespace_mnt="false"'
I1120 00:48:12.285332 19745 launcher.cpp:145] Forked child with pid '27331' for container 'ab95472b-fe74-4644-8f58-e2cbabcb7f3e'
I1120 00:48:12.285449 19745 containerizer.cpp:2052] Checkpointing container's forked pid 27331 to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/meta/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e/pids/forked.pid'
I1120 00:48:12.286186 19745 containerizer.cpp:3130] Transitioning the state of container ab95472b-fe74-4644-8f58-e2cbabcb7f3e from PREPARING to ISOLATING
I1120 00:48:12.287840 19742 containerizer.cpp:3130] Transitioning the state of container ab95472b-fe74-4644-8f58-e2cbabcb7f3e from ISOLATING to FETCHING
I1120 00:48:12.288022 19762 fetcher.cpp:369] Starting to fetch URIs for container: ab95472b-fe74-4644-8f58-e2cbabcb7f3e, directory: /tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e
I1120 00:48:12.289317 19760 containerizer.cpp:3130] Transitioning the state of container ab95472b-fe74-4644-8f58-e2cbabcb7f3e from FETCHING to RUNNING
I1120 00:48:12.637451 27349 exec.cpp:162] Version: 1.8.0
I1120 00:48:12.648640 19743 slave.cpp:4809] Got registration for executor '23484316-89d3-486c-9ef9-e9551b671c4e' of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 from executor(1)@172.17.0.2:46391
I1120 00:48:12.649169 19743 slave.cpp:4895] Checkpointing executor pid 'executor(1)@172.17.0.2:46391' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/meta/slaves/75f6bc92-0ff4-466d-be04-74f923553cc3-S0/frameworks/75f6bc92-0ff4-466d-be04-74f923553cc3-0000/executors/23484316-89d3-486c-9ef9-e9551b671c4e/runs/ab95472b-fe74-4644-8f58-e2cbabcb7f3e/pids/libprocess.pid'
I1120 00:48:12.651986 19762 slave.cpp:3247] Sending queued task '23484316-89d3-486c-9ef9-e9551b671c4e' to executor '23484316-89d3-486c-9ef9-e9551b671c4e' of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 at executor(1)@172.17.0.2:46391
I1120 00:48:12.654507 27357 exec.cpp:236] Executor registered on agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0
I1120 00:48:12.658386 27337 executor.cpp:184] Received SUBSCRIBED event
I1120 00:48:12.659833 27337 executor.cpp:188] Subscribed executor on a11789cde9e3
I1120 00:48:12.660066 27337 executor.cpp:184] Received LAUNCH event
I1120 00:48:12.662044 27337 executor.cpp:687] Starting task 23484316-89d3-486c-9ef9-e9551b671c4e
I1120 00:48:12.664968 19750 slave.cpp:5275] Handling status update TASK_STARTING (Status UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 from executor(1)@172.17.0.2:46391
I1120 00:48:12.666777 19745 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.666826 19745 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.667608 19745 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.667863 19745 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 to the agent
I1120 00:48:12.668051 19761 slave.cpp:5767] Forwarding the update TASK_STARTING (Status UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 to master@172.17.0.2:35765
I1120 00:48:12.668236 19761 slave.cpp:5660] Task status update manager successfully handled status update TASK_STARTING (Status UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.668298 19761 slave.cpp:5676] Sending acknowledgement for status update TASK_STARTING (Status UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 to executor(1)@172.17.0.2:46391
I1120 00:48:12.668427 19754 master.cpp:8420] Status update TASK_STARTING (Status UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 from agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 at slave@172.17.0.2:35765 (a11789cde9e3)
I1120 00:48:12.668488 19754 master.cpp:8477] Forwarding status update TASK_STARTING (Status UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.668715 19754 master.cpp:10978] Updating the state of task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I1120 00:48:12.668936 19742 sched.cpp:1022] Scheduler::statusUpdate took 110378ns
I1120 00:48:12.669663 19760 master.cpp:6286] Processing ACKNOWLEDGE call for status 259da50f-5756-4515-85d1-6ea40f9be3f6 for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 (default) at scheduler-df669210-aa08-40a4-af63-fed1e0d412f1@172.17.0.2:35765 on agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0
I1120 00:48:12.670028 19746 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.670128 19746 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.670378 19746 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: 259da50f-5756-4515-85d1-6ea40f9be3f6) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.681090 27337 executor.cpp:502] Running '/mesos/mesos-1.8.0/_build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
I1120 00:48:12.684341 27337 executor.cpp:702] Forked command at 27362
I1120 00:48:12.687587 19751 slave.cpp:5275] Handling status update TASK_RUNNING (Status UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 from executor(1)@172.17.0.2:46391
I1120 00:48:12.689216 19758 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.689280 19758 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.689488 19758 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 to the agent
I1120 00:48:12.689689 19750 slave.cpp:5767] Forwarding the update TASK_RUNNING (Status UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 to master@172.17.0.2:35765
I1120 00:48:12.689885 19750 slave.cpp:5660] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.689930 19750 slave.cpp:5676] Sending acknowledgement for status update TASK_RUNNING (Status UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 to executor(1)@172.17.0.2:46391
I1120 00:48:12.689997 19739 master.cpp:8420] Status update TASK_RUNNING (Status UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 from agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 at slave@172.17.0.2:35765 (a11789cde9e3)
I1120 00:48:12.690049 19739 master.cpp:8477] Forwarding status update TASK_RUNNING (Status UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.690251 19739 master.cpp:10978] Updating the state of task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1120 00:48:12.690461 19762 sched.cpp:1022] Scheduler::statusUpdate took 86957ns
I1120 00:48:12.691162 19759 master.cpp:6286] Processing ACKNOWLEDGE call for status 8090718c-138a-4940-9557-b5a750a394f1 for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 (default) at scheduler-df669210-aa08-40a4-af63-fed1e0d412f1@172.17.0.2:35765 on agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0
I1120 00:48:12.691517 19741 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.691617 19741 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_RUNNING (Status UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.691875 19755 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: 8090718c-138a-4940-9557-b5a750a394f1) for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:12.692101 19752 slave.cpp:915] Agent terminating
I1120 00:48:13.220731 19743 hierarchical.cpp:1566] Performed allocation for 1 agents in 352531ns
I1120 00:48:13.624411 19745 master.cpp:1273] Agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 at slave@172.17.0.2:35765 (a11789cde9e3) disconnected
I1120 00:48:13.624459 19745 master.cpp:3289] Disconnecting agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 at slave@172.17.0.2:35765 (a11789cde9e3)
I1120 00:48:13.624538 19745 master.cpp:3308] Deactivating agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 at slave@172.17.0.2:35765 (a11789cde9e3)
I1120 00:48:13.624615 19203 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I1120 00:48:13.624672 19754 hierarchical.cpp:801] Agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0 deactivated
W1120 00:48:13.625118 19203 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1120 00:48:13.625265 19203 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1120 00:48:13.625300 19203 provisioner.cpp:298] Using default backend 'copy'
W1120 00:48:13.632294 19203 process.cpp:2829] Attempted to spawn already running process files@172.17.0.2:35765
I1120 00:48:13.632838 19203 cluster.cpp:485] Creating default 'local' authorizer
I1120 00:48:13.634464 19752 slave.cpp:267] Mesos agent started on @172.17.0.2:35765
I1120 00:48:13.634492 19752 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_rdYPMK/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_rdYPMK/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_rdYPMK/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="15secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_rdYPMK/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_rdYPMK/frameworks" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_rdYPMK/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.8.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --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/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_rdYPMK" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV" --zk_session_timeout="10secs"
I1120 00:48:13.635023 19752 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_rdYPMK/credential'
I1120 00:48:13.635196 19752 slave.cpp:300] Agent using credential for: test-principal
I1120 00:48:13.635217 19752 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_rdYPMK/http_credentials'
I1120 00:48:13.635421 19752 http.cpp:1042] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1120 00:48:13.635754 19752 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1120 00:48:13.637104 19752 slave.cpp:615] 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"}]
I1120 00:48:13.637306 19752 slave.cpp:623] Agent attributes: [ ]
I1120 00:48:13.637322 19752 slave.cpp:632] Agent hostname: a11789cde9e3
I1120 00:48:13.637455 19742 task_status_update_manager.cpp:181] Pausing sending task status updates
I1120 00:48:13.641013 19739 state.cpp:66] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/meta'
I1120 00:48:13.641106 19739 state.cpp:711] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/meta/resources/resources.info'
I1120 00:48:13.646255 19762 slave.cpp:6915] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_J3oaqV/meta', beginning agent recovery
I1120 00:48:13.646914 19762 slave.cpp:7394] Recovering framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:13.647075 19762 slave.cpp:9118] Recovering executor '23484316-89d3-486c-9ef9-e9551b671c4e' of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:13.648015 19751 task_status_update_manager.cpp:207] Recovering task status update manager
I1120 00:48:13.648069 19751 task_status_update_manager.cpp:215] Recovering executor '23484316-89d3-486c-9ef9-e9551b671c4e' of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:13.648159 19751 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 23484316-89d3-486c-9ef9-e9551b671c4e of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:13.648653 19751 task_status_update_manager.cpp:818] Replaying task status update stream for task 23484316-89d3-486c-9ef9-e9551b671c4e
I1120 00:48:13.649338 19741 containerizer.cpp:727] Recovering Mesos containers
I1120 00:48:13.649431 19741 containerizer.cpp:784] Recovering container ab95472b-fe74-4644-8f58-e2cbabcb7f3e for executor '23484316-89d3-486c-9ef9-e9551b671c4e' of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:13.651188 19741 containerizer.cpp:1053] Recovering isolators
I1120 00:48:13.652196 19758 containerizer.cpp:1092] Recovering provisioner
I1120 00:48:13.652828 19750 provisioner.cpp:494] Provisioner recovery complete
I1120 00:48:13.654594 19761 composing.cpp:339] Finished recovering all containerizers
I1120 00:48:13.654721 19755 slave.cpp:7144] Recovering executors
I1120 00:48:13.654888 19755 slave.cpp:7168] Sending reconnect request to executor '23484316-89d3-486c-9ef9-e9551b671c4e' of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000 at executor(1)@172.17.0.2:46391
I1120 00:48:13.656755 27358 exec.cpp:282] Received reconnect request from agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0
I1120 00:48:13.659759 19753 slave.cpp:4972] Received re-registration message from executor '23484316-89d3-486c-9ef9-e9551b671c4e' of framework 75f6bc92-0ff4-466d-be04-74f923553cc3-0000
I1120 00:48:13.662252 27359 exec.cpp:259] Executor reregistered on agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0
I1120 00:48:13.662940 19742 slave.cpp:5889] No pings from master received within 75secs
I1120 00:48:13.663151 19755 hierarchical.cpp:1566] Performed allocation for 1 agents in 239694ns
F1120 00:48:13.663537 19751 slave.cpp:1233] Check failed: state == DISCONNECTED || state == RUNNING || state == TERMINATING RECOVERING
*** Check failure stack trace: ***
I1120 00:48:13.664820 27344 executor.cpp:184] Received SUBSCRIBED event
I1120 00:48:13.664856 27344 executor.cpp:188] Subscribed executor on a11789cde9e3
@ 0x2b334c3e43c0 google::LogMessage::Fail()
@ 0x2b334c3e430c google::LogMessage::SendToLog()
@ 0x2b334c3e3d0e google::LogMessage::Flush()
@ 0x2b334c3e6c22 google::LogMessageFatal::~LogMessageFatal()
@ 0x2b334ab1da0e mesos::internal::slave::Slave::detected()
@ 0x2b334abb6cae _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEESB_EEvRKNS_3PIDIT_EEMSD_FvT0_EOT1_ENKUlOS9_PNS_11ProcessBaseEE_clESM_SO_
@ 0x2b334ac70ee9 _ZN5cpp176invokeIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINS3_10MasterInfoEEEESD_EEvRKNS1_3PIDIT_EEMSF_FvT0_EOT1_EUlOSB_PNS1_11ProcessBaseEE_ISB_SQ_EEEDTclcl7forwardISF_Efp_Espcl7forwardIT0_Efp0_EEEOSF_DpOSS_
@ 0x2b334ac6751d _ZN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_ISC_St12_PlaceholderILi1EEEE13invoke_expandISS_St5tupleIISC_SU_EESX_IIOSR_EEILm0ELm1EEEEDTcl6invokecl7forwardIT_Efp_Espcl6expandcl3getIXT2_EEcl7forwardIT0_Efp0_EEcl7forwardIT1_Efp2_EEEEOS11_OS12_N5cpp1416integer_sequenceImIXspT2_EEEEOS13_
@ 0x2b334ac60f19 _ZNO6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEEclIJSR_EEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOS10_
@ 0x2b334ac5d8f5 _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS4_6FutureI6OptionINS6_10MasterInfoEEEESG_EEvRKNS4_3PIDIT_EEMSI_FvT0_EOT1_EUlOSE_PNS4_11ProcessBaseEE_ISE_St12_PlaceholderILi1EEEEEIST_EEEDTclcl7forwardISI_Efp_Espcl7forwardIT0_Efp0_EEEOSI_DpOSY_
@ 0x2b334ac5b98b _ZN6lambda8internal6InvokeIvEclINS0_7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS5_6FutureI6OptionINS7_10MasterInfoEEEESH_EEvRKNS5_3PIDIT_EEMSJ_FvT0_EOT1_EUlOSF_PNS5_11ProcessBaseEE_JSF_St12_PlaceholderILi1EEEEEJSU_EEEvOSJ_DpOT0_
@ 0x2b334ac59593 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINSA_10MasterInfoEEEESK_EEvRKNS1_3PIDIT_EEMSM_FvT0_EOT1_EUlOSI_S3_E_ISI_St12_PlaceholderILi1EEEEEEclEOS3_
@ 0x2b334c305701 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEEclES3_
@ 0x2b334c2cf117 process::ProcessBase::consume()
@ 0x2b334c2f343a _ZNO7process13DispatchEvent7consumeEPNS_13EventConsumerE
@ 0x55ad6c2d9198 process::ProcessBase::serve()
@ 0x2b334c2cc3f4 process::ProcessManager::resume()
@ 0x2b334c2c886e _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
@ 0x2b334c2ee286 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2b334c2ed5a7 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
@ 0x2b334c2ec766 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
@ 0x2b334f1a6a60 (unknown)
@ 0x2b334f91d184 start_thread
@ 0x2b334fc3103d (unknown)
I1120 00:48:14.402710 27351 exec.cpp:518] Agent exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with agent 75f6bc92-0ff4-466d-be04-74f923553cc3-S0
I1120 01:03:14.404219 27352 exec.cpp:499] Recovery timeout of 15mins exceeded; Shutting down
I1120 01:03:14.404503 27352 exec.cpp:445] Executor asked to shutdown
I1120 01:03:14.405724 27349 executor.cpp:184] Received SHUTDOWN event
I1120 01:03:14.405848 27349 executor.cpp:805] Shutting down
I1120 01:03:14.405977 27349 executor.cpp:918] Sending SIGTERM to process tree at pid 27362
I1120 01:03:14.424058 27349 executor.cpp:931] Sent SIGTERM to the following process trees:
[
-+- 27362 sh -c sleep 1000
\--- 27363 sleep 1000
]
I1120 01:03:14.424091 27349 executor.cpp:935] Scheduling escalation to SIGKILL in 3secs from now
I1120 01:03:14.525334 27357 executor.cpp:1003] Command terminated with signal Terminated (pid: 27362)
W1120 01:03:14.531476 27361 process.cpp:1890] Failed to send 'mesos.internal.StatusUpdateMessage' to '172.17.0.2:35765', connect: Failed to connect to 172.17.0.2:35765: Connection refused
I1120 01:03:15.529368 27361 process.cpp:927] Stopped the socket accept loop
[FAIL]: 1 shard(s) have failed tests
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.8.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.8.0/_build'
make: *** [distcheck] Error 1
+ docker rmi --force mesos-1542670834-8927
Untagged: mesos-1542670834-8927:latest
Deleted: sha256:e769e8abb7c402cd5790ef9c53843001304b533913f0c5f0d9904a41704a051e
Deleted: sha256:d18755e75f9d5e2e9effe46bcb3499d07e553c1de7ba03b0b362fb4a1929676a
Deleted: sha256:63c64401bd4d76aed20990435800150e92e5bc5c833b866df2ddf292fc68866e
Deleted: sha256:774129d52746c6da555f3e7e8e0ec59e0f7293f189f5a6a6e0c47d19dd40a426
Deleted: sha256:82146d3ea70553abfdbf5f3b8b2c769a91bbd31690ffee0416785f708a97a453
Deleted: sha256:88bdcacece6c057ebf7f0bd001f284d3c085e601fa5693e37eb1ace8d4d605b4
Deleted: sha256:dc9b0608be844cad2ce038ed9e9887898bca0c9079507de565ce85b24377732e
Deleted: sha256:c1d2e0428f419f1535345e98299b5fc812923b40ab0e65c0392871b7038f0fee
Deleted: sha256:352fb8e9b2793ceffd674d2f7b9ee867601fc33618a5e7f1e1bf8147f5f35285
Deleted: sha256:b529f36b86ded9c6f5c3e3108f2930fd3f2cb7dcd93b2a028d5e3c81d9c3643a
Deleted: sha256:7ad3cf1a532854e67bcf3c92aeb3eac59391d5794c06c842bc5b2a5a7561463e
Deleted: sha256:aeb15378f0be5ada7b454a9182ac510fcbeac594a8a0bdce0ffd62e326749c84
Deleted: sha256:dffdfb2e883fa7a7b924bb87eef8fcdc699c1efaccb8a1018fea09aa2e754743
Deleted: sha256:8eb27f5960ea0cf877a5b4a13d792f81cb2f5ed345a6b97ae8d6e42ad4a1e10b
Deleted: sha256:80a432e6a2bfbdd227faf54562debb13829da71d68ef578aa540374a48aa871d
Deleted: sha256:aac821b1833846a54899c82121e8c6c3b90e8148dc78572ef415f7c6f61e759c
Deleted: sha256:e4bd6d4866f625c7245c3c747c8db24e4e91c03a24b02c18a951b6a7da19ef54
Deleted: sha256:bc5a284dda127386ede996422e5cf0f695c87116a1f85f3704acb3edf1c4c2c1
Deleted: sha256:04f3cc3c19b884499a08ac8d62309ae237a6d731efc227febbb9398a2dd07ac7
Deleted: sha256:8b71d9951abe63f6de5f6bfe96696628bfc2e963cbcb97a7d2859a6dda251c87
Deleted: sha256:47a75e6bc2642f332307178190c416aa7a5493fc1f3021ef22f62b9bc5b02120
Deleted: sha256:0d294cbbd1f6346cd96de72af342452702245c2bc0f0360c2a89dd19714ac701
Deleted: sha256:eeb369a438dd24f50ffaf2b5a6d9f1e105600ee681b50ab0e7fd8eaa1d2a3104
Deleted: sha256:5a9d4b967f9fe4220b710c56b38c4ba8a476c435a22ec4600e36b2b6e0f19456
Deleted: sha256:3ebbd7754b36511d48c6f7e30356c31ccbe12fa85ffb2e98045a8ae95e99bf2f
Deleted: sha256:b2a6102da03f71de74e98caef7bcf514c4ff55128159fd059e36f992e74f9b5e
Deleted: sha256:0c8057fd554ab135bcd8f00bd7d7e8a80c240f3d054827818bbef50ca66d0879
Deleted: sha256:a9654f2e1a25e3f47bad3bd070508a24933b55a738cd6f5a1501fdc8eebed7cf
Deleted: sha256:fa773fe67e70a71bd50a5d50028f425041bdd5746719bfc467eaa5ab413018f9
Deleted: sha256:bdf96ee70a7df79b42c37e6ced6f9ed7f5948d1be8fcf9091c462e200c64aa44
11-19-18_23:40:32 - Running <https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py>
Checking if review 69397 needs verification
Skipping blocking review 69397
Checking if review 69390 needs verification
Patch never verified, needs verification
Dependent review: https://reviews.apache.org/api/review-requests/69381/
The review request 69381 is already submitted
Dependent review: https://reviews.apache.org/api/review-requests/69380/
The review request 69380 is already submitted
Verifying review 69390
Dependent review: https://reviews.apache.org/api/review-requests/69381/
Dependent review: https://reviews.apache.org/api/review-requests/69380/
Applying review 69390
/usr/bin/python3 support/apply-reviews.py -n -r 69390
Traceback (most recent call last):
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 186, in verify_review
% (command, build_output)])
File "/usr/lib/python3.5/subprocess.py", line 581, in check_call
raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['bash', '-c', "set -o pipefail; export OS='ubuntu:14.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/docker-build.sh 2>&1 | tee build_69390"]' returned non-zero exit status 2
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 294, in <module>
main()
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 288, in main
verify_review(review_request, handler)
File "<https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py",> line 201, in verify_review
output = open(build_output).read().decode(sys.stdout.encoding)
AttributeError: 'str' object has no attribute 'decode'
Build step 'Execute shell' marked build as failure