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/20 01:03:26 UTC
Build failed in Jenkins: Mesos-Reviewbot #23565
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
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