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/29 20:48:17 UTC
Build failed in Jenkins: Mesos-Reviewbot #23586
See <https://builds.apache.org/job/Mesos-Reviewbot/23586/display/redirect?page=changes>
Changes:
[chhsiao] Changed the semantics of `CREATE_DISK` and `DESTROY_DISK` operations.
[chhsiao] Added profiles to storage pools in tests for `CREATE_DISK`.
[chhsiao] Rewrote test `ReconcileDroppedOperation` for `CREATE_DISK`.
[chhsiao] Rewrote test `ConvertPreExistingVolume` for `CREATE_DISK`.
[chhsiao] Implemented the new `CREATE_DISK`/`DESTROY_DISK` semantics in SLRP.
[chhsiao] Added validation for `Offer.Operation.CreateDisk.target_profile`.
[chhsiao] Cleaned up `include/mesos/type_utils.hpp`.
[chhsiao] Checkpointed creation parameters for CSI volumes.
[chhsiao] Added MESOS-9275 to the 1.7.1 CHANGELOG.
[chhsiao] Refactored the test CSI plugin.
[chhsiao] Fixed `CreateVolume` of the test CSI plugin.
[chhsiao] Added the `--create_parameters` flag to the test CSI plugin.
[chhsiao] Recovered disk through `CREATE_DISK` in test `AgentRegisteredWithNewId`.
[chhsiao] Used `OperationID` instead of `string` in test helpers.
------------------------------------------
[...truncated 43.84 MB...]
I1129 20:33:03.864327 19802 master.cpp:6782] Registering agent at slave@172.17.0.2:46848 (0bb05c232136) with id 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0
I1129 20:33:03.864971 19818 registrar.cpp:487] Applied 1 operations in 232516ns; attempting to update the registry
I1129 20:33:03.865634 19818 registrar.cpp:544] Successfully updated the registry in 601088ns
I1129 20:33:03.865785 19835 master.cpp:6830] Admitted agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 at slave@172.17.0.2:46848 (0bb05c232136)
I1129 20:33:03.866447 19835 master.cpp:6875] Registered agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 at slave@172.17.0.2:46848 (0bb05c232136) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1129 20:33:03.866482 19798 slave.cpp:1484] Registered with master master@172.17.0.2:46848; given agent ID 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0
I1129 20:33:03.866586 19847 task_status_update_manager.cpp:188] Resuming sending task status updates
I1129 20:33:03.866787 19798 slave.cpp:1504] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/meta/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/slave.info'
I1129 20:33:03.866822 19814 hierarchical.cpp:603] Added agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 (0bb05c232136) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I1129 20:33:03.867683 19798 slave.cpp:1553] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"pv5jClrxRwWY10ABVtbZhQ=="},"slave_id":{"value":"7eae80d5-bdae-4e10-9518-a8c1a45db248-S0"},"update_oversubscribed_resources":false}
I1129 20:33:03.868165 19851 master.cpp:7934] Ignoring update on agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 at slave@172.17.0.2:46848 (0bb05c232136) as it reports no changes
I1129 20:33:03.868193 19814 hierarchical.cpp:1566] Performed allocation for 1 agents in 1.200833ms
I1129 20:33:03.868644 19851 master.cpp:9464] Sending offers [ 7eae80d5-bdae-4e10-9518-a8c1a45db248-O0 ] to framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 (default) at scheduler-bb7d46bd-0b2d-4c9d-8020-c4a1a2a90783@172.17.0.2:46848
I1129 20:33:03.869120 19865 sched.cpp:914] Scheduler::resourceOffers took 103552ns
I1129 20:33:03.870900 19823 master.cpp:11463] Removing offer 7eae80d5-bdae-4e10-9518-a8c1a45db248-O0
I1129 20:33:03.871245 19823 master.cpp:4451] Processing ACCEPT call for offers: [ 7eae80d5-bdae-4e10-9518-a8c1a45db248-O0 ] on agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 at slave@172.17.0.2:46848 (0bb05c232136) for framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 (default) at scheduler-bb7d46bd-0b2d-4c9d-8020-c4a1a2a90783@172.17.0.2:46848
I1129 20:33:03.871381 19823 master.cpp:3547] Authorizing framework principal 'test-principal' to launch task a809b28e-77ea-4a71-b79d-9a30a7d4f785
I1129 20:33:03.873549 19818 master.cpp:4028] Adding task a809b28e-77ea-4a71-b79d-9a30a7d4f785 with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 (default) at scheduler-bb7d46bd-0b2d-4c9d-8020-c4a1a2a90783@172.17.0.2:46848 on agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 at slave@172.17.0.2:46848 (0bb05c232136)
I1129 20:33:03.874238 19818 master.cpp:5423] Launching task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 (default) at scheduler-bb7d46bd-0b2d-4c9d-8020-c4a1a2a90783@172.17.0.2:46848 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 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 at slave@172.17.0.2:46848 (0bb05c232136) on new executor
I1129 20:33:03.875425 19835 slave.cpp:2019] Got assigned task 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' for framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:03.875587 19835 slave.cpp:8895] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/meta/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/framework.info'
I1129 20:33:03.876080 19835 slave.cpp:8906] Checkpointing framework pid 'scheduler-bb7d46bd-0b2d-4c9d-8020-c4a1a2a90783@172.17.0.2:46848' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/meta/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/framework.pid'
I1129 20:33:03.877460 19835 slave.cpp:2393] Authorizing task 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' for framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:03.877517 19835 slave.cpp:8471] Authorizing framework principal 'test-principal' to launch task a809b28e-77ea-4a71-b79d-9a30a7d4f785
I1129 20:33:03.879369 19843 slave.cpp:2836] Launching task 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' for framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:03.879462 19843 paths.cpp:752] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9' for user 'mesos'
I1129 20:33:03.880075 19843 slave.cpp:9681] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/meta/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/executor.info'
I1129 20:33:03.880580 19843 paths.cpp:755] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/meta/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9'
I1129 20:33:03.880851 19843 slave.cpp:8981] Launching executor 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-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_LhEOdp/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9'
I1129 20:33:03.881578 19843 slave.cpp:3514] Launching container 2eb5b45a-898a-48f8-9acc-8e45f3e96cb9 for executor 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:03.882114 19843 slave.cpp:9712] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/meta/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9/tasks/a809b28e-77ea-4a71-b79d-9a30a7d4f785/task.info'
I1129 20:33:03.882740 19843 slave.cpp:3033] Queued task 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' for executor 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:03.882833 19843 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/latest'
I1129 20:33:03.882876 19843 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9' to virtual path '/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/latest'
I1129 20:33:03.882912 19843 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9'
I1129 20:33:03.883474 19851 containerizer.cpp:1288] Starting container 2eb5b45a-898a-48f8-9acc-8e45f3e96cb9
I1129 20:33:03.886989 19851 containerizer.cpp:1454] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_QoauRi/containers/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9/config'
I1129 20:33:03.887044 19851 containerizer.cpp:3130] Transitioning the state of container 2eb5b45a-898a-48f8-9acc-8e45f3e96cb9 from PROVISIONING to PREPARING
I1129 20:33:03.891901 19789 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:46848"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"a809b28e-77ea-4a71-b79d-9a30a7d4f785"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"7eae80d5-bdae-4e10-9518-a8c1a45db248-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":"7eae80d5-bdae-4e10-9518-a8c1a45db248-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave@172.17.0.2:46848"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"15secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9"}" --pipe_read="24" --pipe_write="26" --runtime_directory="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_QoauRi/containers/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9" --unshare_namespace_mnt="false"'
I1129 20:33:03.896776 19789 launcher.cpp:145] Forked child with pid '27569' for container '2eb5b45a-898a-48f8-9acc-8e45f3e96cb9'
I1129 20:33:03.896956 19789 containerizer.cpp:2052] Checkpointing container's forked pid 27569 to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/meta/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9/pids/forked.pid'
I1129 20:33:03.897902 19789 containerizer.cpp:3130] Transitioning the state of container 2eb5b45a-898a-48f8-9acc-8e45f3e96cb9 from PREPARING to ISOLATING
I1129 20:33:03.900387 19851 containerizer.cpp:3130] Transitioning the state of container 2eb5b45a-898a-48f8-9acc-8e45f3e96cb9 from ISOLATING to FETCHING
I1129 20:33:03.900609 19865 fetcher.cpp:369] Starting to fetch URIs for container: 2eb5b45a-898a-48f8-9acc-8e45f3e96cb9, directory: /tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9
I1129 20:33:03.901793 19858 containerizer.cpp:3130] Transitioning the state of container 2eb5b45a-898a-48f8-9acc-8e45f3e96cb9 from FETCHING to RUNNING
I1129 20:33:04.338563 27612 exec.cpp:162] Version: 1.8.0
I1129 20:33:04.350209 19827 slave.cpp:4808] Got registration for executor 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 from executor(1)@172.17.0.2:40003
I1129 20:33:04.350766 19827 slave.cpp:4894] Checkpointing executor pid 'executor(1)@172.17.0.2:40003' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/meta/slaves/7eae80d5-bdae-4e10-9518-a8c1a45db248-S0/frameworks/7eae80d5-bdae-4e10-9518-a8c1a45db248-0000/executors/a809b28e-77ea-4a71-b79d-9a30a7d4f785/runs/2eb5b45a-898a-48f8-9acc-8e45f3e96cb9/pids/libprocess.pid'
I1129 20:33:04.353883 19865 slave.cpp:3246] Sending queued task 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' to executor 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 at executor(1)@172.17.0.2:40003
I1129 20:33:04.357547 27620 exec.cpp:236] Executor registered on agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0
I1129 20:33:04.362157 27600 executor.cpp:184] Received SUBSCRIBED event
I1129 20:33:04.363499 27600 executor.cpp:188] Subscribed executor on 0bb05c232136
I1129 20:33:04.363723 27600 executor.cpp:184] Received LAUNCH event
I1129 20:33:04.365800 27600 executor.cpp:687] Starting task a809b28e-77ea-4a71-b79d-9a30a7d4f785
I1129 20:33:04.369236 19802 slave.cpp:5274] Handling status update TASK_STARTING (Status UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 from executor(1)@172.17.0.2:40003
I1129 20:33:04.371795 19794 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.371857 19794 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.372686 19794 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.372936 19794 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 to the agent
I1129 20:33:04.373140 19814 slave.cpp:5766] Forwarding the update TASK_STARTING (Status UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 to master@172.17.0.2:46848
I1129 20:33:04.373375 19814 slave.cpp:5659] Task status update manager successfully handled status update TASK_STARTING (Status UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.373432 19814 slave.cpp:5675] Sending acknowledgement for status update TASK_STARTING (Status UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 to executor(1)@172.17.0.2:40003
I1129 20:33:04.374073 19814 master.cpp:8370] Status update TASK_STARTING (Status UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 from agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 at slave@172.17.0.2:46848 (0bb05c232136)
I1129 20:33:04.374140 19814 master.cpp:8427] Forwarding status update TASK_STARTING (Status UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.374402 19814 master.cpp:10928] Updating the state of task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I1129 20:33:04.374666 19843 sched.cpp:1022] Scheduler::statusUpdate took 130023ns
I1129 20:33:04.375609 19827 master.cpp:6226] Processing ACKNOWLEDGE call for status a8cf07ae-7e2d-4710-9924-83ddd4c2346f for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 (default) at scheduler-bb7d46bd-0b2d-4c9d-8020-c4a1a2a90783@172.17.0.2:46848 on agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0
I1129 20:33:04.375988 19784 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.376121 19784 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.376413 19784 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: a8cf07ae-7e2d-4710-9924-83ddd4c2346f) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.386286 27600 executor.cpp:502] Running '/mesos/mesos-1.8.0/_build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
I1129 20:33:04.389493 27600 executor.cpp:702] Forked command at 27625
I1129 20:33:04.392913 19835 slave.cpp:5274] Handling status update TASK_RUNNING (Status UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 from executor(1)@172.17.0.2:40003
I1129 20:33:04.394752 19867 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.394825 19867 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.395048 19867 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 to the agent
I1129 20:33:04.395236 19806 slave.cpp:5766] Forwarding the update TASK_RUNNING (Status UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 to master@172.17.0.2:46848
I1129 20:33:04.395476 19806 slave.cpp:5659] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.395531 19806 slave.cpp:5675] Sending acknowledgement for status update TASK_RUNNING (Status UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 to executor(1)@172.17.0.2:40003
I1129 20:33:04.395591 19810 master.cpp:8370] Status update TASK_RUNNING (Status UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 from agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 at slave@172.17.0.2:46848 (0bb05c232136)
I1129 20:33:04.395645 19810 master.cpp:8427] Forwarding status update TASK_RUNNING (Status UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.395865 19810 master.cpp:10928] Updating the state of task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1129 20:33:04.396209 19810 sched.cpp:1022] Scheduler::statusUpdate took 94347ns
I1129 20:33:04.396934 19798 master.cpp:6226] Processing ACKNOWLEDGE call for status c1344809-9b02-4738-860b-ff1bc62ec504 for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 (default) at scheduler-bb7d46bd-0b2d-4c9d-8020-c4a1a2a90783@172.17.0.2:46848 on agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0
I1129 20:33:04.397325 19818 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.397439 19818 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_RUNNING (Status UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.397713 19854 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: c1344809-9b02-4738-860b-ff1bc62ec504) for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.398095 19854 slave.cpp:914] Agent terminating
I1129 20:33:04.826603 19784 hierarchical.cpp:1566] Performed allocation for 1 agents in 321707ns
I1129 20:33:04.910949 19789 master.cpp:1275] Agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 at slave@172.17.0.2:46848 (0bb05c232136) disconnected
I1129 20:33:04.910987 19789 master.cpp:3273] Disconnecting agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 at slave@172.17.0.2:46848 (0bb05c232136)
I1129 20:33:04.911059 19789 master.cpp:3292] Deactivating agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 at slave@172.17.0.2:46848 (0bb05c232136)
I1129 20:33:04.911168 19835 hierarchical.cpp:801] Agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0 deactivated
I1129 20:33:04.911249 19274 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1129 20:33:04.911933 19274 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1129 20:33:04.912096 19274 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1129 20:33:04.912137 19274 provisioner.cpp:298] Using default backend 'copy'
W1129 20:33:04.928838 19274 process.cpp:2829] Attempted to spawn already running process files@172.17.0.2:46848
I1129 20:33:04.929538 19274 cluster.cpp:485] Creating default 'local' authorizer
I1129 20:33:04.931643 19854 slave.cpp:268] Mesos agent started on @172.17.0.2:46848
I1129 20:33:04.931666 19854 slave.cpp:269] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_QoauRi/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_QoauRi/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_QoauRi/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_QoauRi/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_QoauRi/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_QoauRi/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_QoauRi" --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_LhEOdp" --zk_session_timeout="10secs"
I1129 20:33:04.932219 19854 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_QoauRi/credential'
I1129 20:33:04.932384 19854 slave.cpp:301] Agent using credential for: test-principal
I1129 20:33:04.932407 19854 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_QoauRi/http_credentials'
I1129 20:33:04.932646 19854 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1129 20:33:04.932992 19854 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1129 20:33:04.934466 19854 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"}]
I1129 20:33:04.934729 19854 slave.cpp:624] Agent attributes: [ ]
I1129 20:33:04.934748 19854 slave.cpp:633] Agent hostname: 0bb05c232136
I1129 20:33:04.934875 19798 task_status_update_manager.cpp:181] Pausing sending task status updates
I1129 20:33:04.936260 19867 state.cpp:66] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/meta'
I1129 20:33:04.936336 19867 state.cpp:711] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/meta/resources/resources.info'
I1129 20:33:04.943081 19865 slave.cpp:6914] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_LhEOdp/meta', beginning agent recovery
I1129 20:33:04.943889 19865 slave.cpp:7393] Recovering framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.944082 19865 slave.cpp:9099] Recovering executor 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.945282 19827 task_status_update_manager.cpp:207] Recovering task status update manager
I1129 20:33:04.945334 19827 task_status_update_manager.cpp:215] Recovering executor 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.945458 19827 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task a809b28e-77ea-4a71-b79d-9a30a7d4f785 of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.945951 19827 task_status_update_manager.cpp:818] Replaying task status update stream for task a809b28e-77ea-4a71-b79d-9a30a7d4f785
I1129 20:33:04.946885 19851 containerizer.cpp:727] Recovering Mesos containers
I1129 20:33:04.946975 19851 containerizer.cpp:784] Recovering container 2eb5b45a-898a-48f8-9acc-8e45f3e96cb9 for executor 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.948909 19851 containerizer.cpp:1053] Recovering isolators
I1129 20:33:04.950135 19835 containerizer.cpp:1092] Recovering provisioner
I1129 20:33:04.950803 19789 provisioner.cpp:494] Provisioner recovery complete
I1129 20:33:04.952543 19784 composing.cpp:339] Finished recovering all containerizers
I1129 20:33:04.952702 19806 slave.cpp:7143] Recovering executors
I1129 20:33:04.952870 19806 slave.cpp:7167] Sending reconnect request to executor 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000 at executor(1)@172.17.0.2:40003
I1129 20:33:04.955159 27620 exec.cpp:282] Received reconnect request from agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0
I1129 20:33:04.959553 19835 slave.cpp:4971] Received re-registration message from executor 'a809b28e-77ea-4a71-b79d-9a30a7d4f785' of framework 7eae80d5-bdae-4e10-9518-a8c1a45db248-0000
I1129 20:33:04.961063 19823 hierarchical.cpp:1566] Performed allocation for 1 agents in 500678ns
I1129 20:33:04.961102 27622 exec.cpp:259] Executor reregistered on agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0
I1129 20:33:04.961100 19835 slave.cpp:5888] No pings from master received within 75secs
F1129 20:33:04.961735 19835 slave.cpp:1232] Check failed: state == DISCONNECTED || state == RUNNING || state == TERMINATING RECOVERING
*** Check failure stack trace: ***
I1129 20:33:04.964874 27602 executor.cpp:184] Received SUBSCRIBED event
I1129 20:33:04.964912 27602 executor.cpp:188] Subscribed executor on 0bb05c232136
@ 0x2ba3369b1a8e google::LogMessage::Fail()
@ 0x2ba3369b19da google::LogMessage::SendToLog()
@ 0x2ba3369b13dc google::LogMessage::Flush()
@ 0x2ba3369b42f0 google::LogMessageFatal::~LogMessageFatal()
@ 0x2ba3355baf00 mesos::internal::slave::Slave::detected()
@ 0x2ba33564ec50 _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEESB_EEvRKNS_3PIDIT_EEMSD_FvT0_EOT1_ENKUlOS9_PNS_11ProcessBaseEE_clESM_SO_
@ 0x2ba3356f6ea9 _ZN5cpp176invokeIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINS3_10MasterInfoEEEESD_EEvRKNS1_3PIDIT_EEMSF_FvT0_EOT1_EUlOSB_PNS1_11ProcessBaseEE_ISB_SQ_EEEDTclcl7forwardISF_Efp_Espcl7forwardIT0_Efp0_EEEOSF_DpOSS_
@ 0x2ba3356ede55 _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_
@ 0x2ba3356e7e95 _ZNO6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEEclIJSR_EEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOS10_
@ 0x2ba3356e4d0d _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS4_6FutureI6OptionINS6_10MasterInfoEEEESG_EEvRKNS4_3PIDIT_EEMSI_FvT0_EOT1_EUlOSE_PNS4_11ProcessBaseEE_ISE_St12_PlaceholderILi1EEEEEIST_EEEDTclcl7forwardISI_Efp_Espcl7forwardIT0_Efp0_EEEOSI_DpOSY_
@ 0x2ba3356e301b _ZN6lambda8internal6InvokeIvEclINS0_7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS5_6FutureI6OptionINS7_10MasterInfoEEEESH_EEvRKNS5_3PIDIT_EEMSJ_FvT0_EOT1_EUlOSF_PNS5_11ProcessBaseEE_JSF_St12_PlaceholderILi1EEEEEJSU_EEEvOSJ_DpOT0_
@ 0x2ba3356e0ed5 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINSA_10MasterInfoEEEESK_EEvRKNS1_3PIDIT_EEMSM_FvT0_EOT1_EUlOSI_S3_E_ISI_St12_PlaceholderILi1EEEEEEclEOS3_
@ 0x2ba3368d6599 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEEclES3_
@ 0x2ba33689ffc9 process::ProcessBase::consume()
@ 0x2ba3368c42ec _ZNO7process13DispatchEvent7consumeEPNS_13EventConsumerE
@ 0x55ea2d82b468 process::ProcessBase::serve()
@ 0x2ba33689d2a6 process::ProcessManager::resume()
@ 0x2ba336899720 _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
@ 0x2ba3368bf138 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2ba3368be459 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
@ 0x2ba3368bd618 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
@ 0x2ba339775a60 (unknown)
@ 0x2ba339eec184 start_thread
@ 0x2ba33a20003d (unknown)
I1129 20:33:05.712857 27616 exec.cpp:518] Agent exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with agent 7eae80d5-bdae-4e10-9518-a8c1a45db248-S0
I1129 20:48:05.714097 27612 exec.cpp:499] Recovery timeout of 15mins exceeded; Shutting down
I1129 20:48:05.714308 27612 exec.cpp:445] Executor asked to shutdown
I1129 20:48:05.715261 27621 executor.cpp:184] Received SHUTDOWN event
I1129 20:48:05.715354 27621 executor.cpp:805] Shutting down
I1129 20:48:05.715442 27621 executor.cpp:918] Sending SIGTERM to process tree at pid 27625
I1129 20:48:05.732570 27621 executor.cpp:931] Sent SIGTERM to the following process trees:
[
-+- 27625 sh -c sleep 1000
\--- 27627 sleep 1000
]
I1129 20:48:05.732607 27621 executor.cpp:935] Scheduling escalation to SIGKILL in 3secs from now
I1129 20:48:05.814141 27622 executor.cpp:1003] Command terminated with signal Terminated (pid: 27625)
W1129 20:48:05.819507 27624 process.cpp:1890] Failed to send 'mesos.internal.StatusUpdateMessage' to '172.17.0.2:46848', connect: Failed to connect to 172.17.0.2:46848: Connection refused
I1129 20:48:06.818373 27624 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-1543519366-26358
Untagged: mesos-1543519366-26358:latest
Deleted: sha256:454830b54c31b66c7ca00220f3b2a305c9f8e2e41562109f3c0a29094bb04c6a
Deleted: sha256:27d8aa7d25eb79c7eece4537cc959e99d3a2c4bf6288414a66d65595db147c63
Deleted: sha256:fe77ab1df1496f921b1879453a8d4a7610086a9865e552340621247015c8f1e8
Deleted: sha256:de298d5294f431c091bd8b077559e94716743d9df14357eeedd1ea68a24ba7f9
Deleted: sha256:4bb75bad694b996bd638f3a4e9b13142431ff0dc0e75739ef922f99534e05c76
Deleted: sha256:ee24fa26b181b6b152aa18365229fb39efba7f1a1620e3d3637a20c736cace23
Deleted: sha256:c2f3091d3621ff46aa7370c00efb48797c782c0edbb772860d9228fa6c2f734d
Deleted: sha256:055a8ab18ebbfad56a329981cae9775fd6dadfbcdc46f378c6154e5dfaa7806a
Deleted: sha256:b99e24e1641e3eba16aea84a03b8cf51ea2c5d6c51edc6404e1975b8a3308ac6
Deleted: sha256:43e8aca381a873fb5c9c6683e482fa2d69d6c701ee25b7fdbbb3bf2dea8c3cce
Deleted: sha256:a67868ad6109ac8f7ce32fc30128ab01afaac099bf5560bf21ae2cf2a988be2e
Deleted: sha256:fa92edbc06be05164f146c426a3497915fd7f1f52b1c26dd24599d8b9e0766f5
Deleted: sha256:dbbf84fcd0b5abc93008b971a417cc6bd9975156dde6cbe9ee6fd9e6413e84cc
Deleted: sha256:495ea257a86dd6e5114f96f24cdc7716006061d6e77a056b279b33068cefb680
Deleted: sha256:9c44a64eb45630ce9bcf56ca42a913f37fe69f185ba64f8be78af228fefefb5b
Deleted: sha256:1f212a551ec8ff3b3f9cedadcbf709becd25a831540a9f636747675cafec2be8
Deleted: sha256:f75d70b14e675ae2e7480e73e982478be39d8c946b34eb00f83561115b5f23a0
Deleted: sha256:525bc61d18908046aa09e4706268662f5c849e5f985825b4101482406514b329
Deleted: sha256:b29fc084d5fcf8fe09cc9c8b5897e460dfdff7c818d9a6afbdc0893fe80b9de5
Deleted: sha256:359fffcaec25186748a1050d73586feac322c68b0901296b337c6d7d69fd9346
Deleted: sha256:64e96eb0522837428295c71ebe74a9ccc31391ac6d38d17e7e00599082bcc396
Deleted: sha256:46795314dc529d41fe3cf46dbe32e84beda22922c85f6921e01dca855c77f731
Deleted: sha256:39b22aa709dd5fcab31fc581af4d2989acf7065bf65257dddbd17d33066d13bb
Deleted: sha256:e13257aef39cb6a8265330e3e4e637aa74d085d531d6915f97d180102e1036f0
Deleted: sha256:f9815fe6e4b46d5d56c541a93971ea8d7fcc8b4d5ddb5acb56942ebdad58d4a7
Deleted: sha256:6f4fb20439499ebde93803b2666b27b6dfe1c38c3f7e12202a1d8156a9dace5b
Deleted: sha256:662335338eb1fbeb6e399232d48588da6856709f15bfcf749c5ff1b1a651bcbb
Deleted: sha256:077a33986a880a961826c9756c87c8ae3f53def9523634440daa5a10a796d818
Deleted: sha256:99cb0803c9da0fa6517e0a72956745973423f1b70e9b0038a70421ddee88a239
Deleted: sha256:1ab0d8697632f4681d86849898efb34be25dae2c9c2dc28e5cdbb5c25b002726
Deleted: sha256:f17b6a61de28594fb3ec53b1cca7164fba66357d1635b414eeed4d586744342e
Deleted: sha256:62faa9fad606573b982c0444778746244947829aa8ebefbf29b3a5291875dc84
Deleted: sha256:5848a5ca21d07333dbdf428bbdde15d5c7cecc7614b24562b49b205d8d20199a
Deleted: sha256:cd509aa64a17350b03bf6af7f41d849fc273a0f2c9d1a309e897380617fca46e
Deleted: sha256:960c7c5516b277c5c23644b2cfb53d0106543eace96d517141611fa34e1b957c
11-29-18_19:22:43 - Running <https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py>
Checking if review 69084 needs verification
Patch never verified, needs verification
Verifying review 69084
Applying review 69084
/usr/bin/python3 support/apply-reviews.py -n -r 69084
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_69084"]' 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 #23588
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/23588/display/redirect?page=changes>
Build failed in Jenkins: Mesos-Reviewbot #23587
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/23587/display/redirect>
------------------------------------------
[...truncated 43.78 MB...]
I1129 22:49:05.700670 19844 slave.cpp:1451] Successfully authenticated with master master@172.17.0.2:46877
I1129 22:49:05.701035 19844 slave.cpp:1882] Will retry registration in 13.777724ms if necessary
I1129 22:49:05.701186 19815 master.cpp:6600] Received register agent message from slave@172.17.0.2:46877 (a2f8afefe3c9)
I1129 22:49:05.701447 19815 master.cpp:3930] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I1129 22:49:05.702095 19813 master.cpp:6667] Authorized registration of agent at slave@172.17.0.2:46877 (a2f8afefe3c9)
I1129 22:49:05.702194 19813 master.cpp:6782] Registering agent at slave@172.17.0.2:46877 (a2f8afefe3c9) with id 102b125f-1892-4651-8c17-77519f422c4c-S0
I1129 22:49:05.702798 19811 registrar.cpp:487] Applied 1 operations in 186914ns; attempting to update the registry
I1129 22:49:05.703408 19811 registrar.cpp:544] Successfully updated the registry in 552960ns
I1129 22:49:05.703572 19801 master.cpp:6830] Admitted agent 102b125f-1892-4651-8c17-77519f422c4c-S0 at slave@172.17.0.2:46877 (a2f8afefe3c9)
I1129 22:49:05.704224 19801 master.cpp:6875] Registered agent 102b125f-1892-4651-8c17-77519f422c4c-S0 at slave@172.17.0.2:46877 (a2f8afefe3c9) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1129 22:49:05.704255 19829 slave.cpp:1484] Registered with master master@172.17.0.2:46877; given agent ID 102b125f-1892-4651-8c17-77519f422c4c-S0
I1129 22:49:05.704340 19801 task_status_update_manager.cpp:188] Resuming sending task status updates
I1129 22:49:05.704579 19829 slave.cpp:1504] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/meta/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/slave.info'
I1129 22:49:05.704794 19845 hierarchical.cpp:603] Added agent 102b125f-1892-4651-8c17-77519f422c4c-S0 (a2f8afefe3c9) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I1129 22:49:05.705557 19829 slave.cpp:1553] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"5rNXOKZZQhGxtqEFVZv9OA=="},"slave_id":{"value":"102b125f-1892-4651-8c17-77519f422c4c-S0"},"update_oversubscribed_resources":false}
I1129 22:49:05.706354 19844 master.cpp:7934] Ignoring update on agent 102b125f-1892-4651-8c17-77519f422c4c-S0 at slave@172.17.0.2:46877 (a2f8afefe3c9) as it reports no changes
I1129 22:49:05.706398 19845 hierarchical.cpp:1566] Performed allocation for 1 agents in 1.411348ms
I1129 22:49:05.707090 19844 master.cpp:9464] Sending offers [ 102b125f-1892-4651-8c17-77519f422c4c-O0 ] to framework 102b125f-1892-4651-8c17-77519f422c4c-0000 (default) at scheduler-64ceec50-cb92-4308-a7ed-55a3120ed1c7@172.17.0.2:46877
I1129 22:49:05.707806 19844 sched.cpp:914] Scheduler::resourceOffers took 152940ns
I1129 22:49:05.709586 19821 master.cpp:11463] Removing offer 102b125f-1892-4651-8c17-77519f422c4c-O0
I1129 22:49:05.709930 19821 master.cpp:4451] Processing ACCEPT call for offers: [ 102b125f-1892-4651-8c17-77519f422c4c-O0 ] on agent 102b125f-1892-4651-8c17-77519f422c4c-S0 at slave@172.17.0.2:46877 (a2f8afefe3c9) for framework 102b125f-1892-4651-8c17-77519f422c4c-0000 (default) at scheduler-64ceec50-cb92-4308-a7ed-55a3120ed1c7@172.17.0.2:46877
I1129 22:49:05.710034 19821 master.cpp:3547] Authorizing framework principal 'test-principal' to launch task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed
I1129 22:49:05.711949 19827 master.cpp:4028] Adding task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 (default) at scheduler-64ceec50-cb92-4308-a7ed-55a3120ed1c7@172.17.0.2:46877 on agent 102b125f-1892-4651-8c17-77519f422c4c-S0 at slave@172.17.0.2:46877 (a2f8afefe3c9)
I1129 22:49:05.712543 19827 master.cpp:5423] Launching task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 (default) at scheduler-64ceec50-cb92-4308-a7ed-55a3120ed1c7@172.17.0.2:46877 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 102b125f-1892-4651-8c17-77519f422c4c-S0 at slave@172.17.0.2:46877 (a2f8afefe3c9) on new executor
I1129 22:49:05.713791 19801 slave.cpp:2019] Got assigned task '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' for framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:05.713974 19801 slave.cpp:8895] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/meta/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/framework.info'
I1129 22:49:05.714460 19801 slave.cpp:8906] Checkpointing framework pid 'scheduler-64ceec50-cb92-4308-a7ed-55a3120ed1c7@172.17.0.2:46877' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/meta/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/framework.pid'
I1129 22:49:05.716197 19801 slave.cpp:2393] Authorizing task '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' for framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:05.716264 19801 slave.cpp:8471] Authorizing framework principal 'test-principal' to launch task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed
I1129 22:49:05.718207 19829 slave.cpp:2836] Launching task '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' for framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:05.718291 19829 paths.cpp:752] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557' for user 'mesos'
I1129 22:49:05.718976 19829 slave.cpp:9681] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/meta/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/executor.info'
I1129 22:49:05.719519 19829 paths.cpp:755] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/meta/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557'
I1129 22:49:05.719794 19829 slave.cpp:8981] Launching executor '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' of framework 102b125f-1892-4651-8c17-77519f422c4c-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_xpxYOf/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557'
I1129 22:49:05.720521 19829 slave.cpp:3514] Launching container 07e0039e-d9b1-418e-ae35-cf359ea5f557 for executor '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:05.721071 19829 slave.cpp:9712] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/meta/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557/tasks/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/task.info'
I1129 22:49:05.721774 19829 slave.cpp:3033] Queued task '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' for executor '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:05.721861 19829 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/latest'
I1129 22:49:05.721904 19829 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557' to virtual path '/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/latest'
I1129 22:49:05.721940 19829 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557'
I1129 22:49:05.722471 19842 containerizer.cpp:1288] Starting container 07e0039e-d9b1-418e-ae35-cf359ea5f557
I1129 22:49:05.723489 19842 containerizer.cpp:1454] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4YJqob/containers/07e0039e-d9b1-418e-ae35-cf359ea5f557/config'
I1129 22:49:05.723521 19842 containerizer.cpp:3130] Transitioning the state of container 07e0039e-d9b1-418e-ae35-cf359ea5f557 from PROVISIONING to PREPARING
I1129 22:49:05.728168 19825 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:46877"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"0cf3420d-77d8-41ac-b516-bb2388f3a6ed"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"102b125f-1892-4651-8c17-77519f422c4c-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":"102b125f-1892-4651-8c17-77519f422c4c-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave@172.17.0.2:46877"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"15secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557"}" --pipe_read="24" --pipe_write="26" --runtime_directory="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4YJqob/containers/07e0039e-d9b1-418e-ae35-cf359ea5f557" --unshare_namespace_mnt="false"'
I1129 22:49:05.735224 19825 launcher.cpp:145] Forked child with pid '27536' for container '07e0039e-d9b1-418e-ae35-cf359ea5f557'
I1129 22:49:05.735415 19825 containerizer.cpp:2052] Checkpointing container's forked pid 27536 to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/meta/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557/pids/forked.pid'
I1129 22:49:05.736461 19825 containerizer.cpp:3130] Transitioning the state of container 07e0039e-d9b1-418e-ae35-cf359ea5f557 from PREPARING to ISOLATING
I1129 22:49:05.738999 19842 containerizer.cpp:3130] Transitioning the state of container 07e0039e-d9b1-418e-ae35-cf359ea5f557 from ISOLATING to FETCHING
I1129 22:49:05.739239 19834 fetcher.cpp:369] Starting to fetch URIs for container: 07e0039e-d9b1-418e-ae35-cf359ea5f557, directory: /tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557
I1129 22:49:05.740666 19798 containerizer.cpp:3130] Transitioning the state of container 07e0039e-d9b1-418e-ae35-cf359ea5f557 from FETCHING to RUNNING
I1129 22:49:06.175890 27578 exec.cpp:162] Version: 1.8.0
I1129 22:49:06.185596 19809 slave.cpp:4808] Got registration for executor '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 from executor(1)@172.17.0.2:32790
I1129 22:49:06.186075 19809 slave.cpp:4894] Checkpointing executor pid 'executor(1)@172.17.0.2:32790' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/meta/slaves/102b125f-1892-4651-8c17-77519f422c4c-S0/frameworks/102b125f-1892-4651-8c17-77519f422c4c-0000/executors/0cf3420d-77d8-41ac-b516-bb2388f3a6ed/runs/07e0039e-d9b1-418e-ae35-cf359ea5f557/pids/libprocess.pid'
I1129 22:49:06.189364 19813 slave.cpp:3246] Sending queued task '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' to executor '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 at executor(1)@172.17.0.2:32790
I1129 22:49:06.191263 27599 exec.cpp:236] Executor registered on agent 102b125f-1892-4651-8c17-77519f422c4c-S0
I1129 22:49:06.195125 27580 executor.cpp:184] Received SUBSCRIBED event
I1129 22:49:06.196424 27580 executor.cpp:188] Subscribed executor on a2f8afefe3c9
I1129 22:49:06.196683 27580 executor.cpp:184] Received LAUNCH event
I1129 22:49:06.198679 27580 executor.cpp:687] Starting task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed
I1129 22:49:06.201898 19821 slave.cpp:5274] Handling status update TASK_STARTING (Status UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 from executor(1)@172.17.0.2:32790
I1129 22:49:06.203953 19844 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.204030 19844 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.205305 19844 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.205642 19844 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 to the agent
I1129 22:49:06.205889 19825 slave.cpp:5766] Forwarding the update TASK_STARTING (Status UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 to master@172.17.0.2:46877
I1129 22:49:06.206164 19825 slave.cpp:5659] Task status update manager successfully handled status update TASK_STARTING (Status UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.206224 19825 slave.cpp:5675] Sending acknowledgement for status update TASK_STARTING (Status UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 to executor(1)@172.17.0.2:32790
I1129 22:49:06.206285 19798 master.cpp:8370] Status update TASK_STARTING (Status UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 from agent 102b125f-1892-4651-8c17-77519f422c4c-S0 at slave@172.17.0.2:46877 (a2f8afefe3c9)
I1129 22:49:06.206346 19798 master.cpp:8427] Forwarding status update TASK_STARTING (Status UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.206601 19798 master.cpp:10928] Updating the state of task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I1129 22:49:06.206828 19834 sched.cpp:1022] Scheduler::statusUpdate took 99807ns
I1129 22:49:06.207660 19813 master.cpp:6226] Processing ACKNOWLEDGE call for status ce1b73b1-671c-4e81-8cfa-94f82fabecf6 for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 (default) at scheduler-64ceec50-cb92-4308-a7ed-55a3120ed1c7@172.17.0.2:46877 on agent 102b125f-1892-4651-8c17-77519f422c4c-S0
I1129 22:49:06.208007 19823 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.208125 19823 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.208423 19801 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: ce1b73b1-671c-4e81-8cfa-94f82fabecf6) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.218502 27580 executor.cpp:502] Running '/mesos/mesos-1.8.0/_build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
I1129 22:49:06.221768 27580 executor.cpp:702] Forked command at 27604
I1129 22:49:06.225594 19809 slave.cpp:5274] Handling status update TASK_RUNNING (Status UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 from executor(1)@172.17.0.2:32790
I1129 22:49:06.227926 19811 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.228001 19811 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.228256 19811 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 to the agent
I1129 22:49:06.228451 19827 slave.cpp:5766] Forwarding the update TASK_RUNNING (Status UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 to master@172.17.0.2:46877
I1129 22:49:06.228653 19827 slave.cpp:5659] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.228703 19827 slave.cpp:5675] Sending acknowledgement for status update TASK_RUNNING (Status UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 to executor(1)@172.17.0.2:32790
I1129 22:49:06.228782 19821 master.cpp:8370] Status update TASK_RUNNING (Status UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 from agent 102b125f-1892-4651-8c17-77519f422c4c-S0 at slave@172.17.0.2:46877 (a2f8afefe3c9)
I1129 22:49:06.228840 19821 master.cpp:8427] Forwarding status update TASK_RUNNING (Status UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.229084 19821 master.cpp:10928] Updating the state of task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1129 22:49:06.229307 19832 sched.cpp:1022] Scheduler::statusUpdate took 98958ns
I1129 22:49:06.230002 19845 master.cpp:6226] Processing ACKNOWLEDGE call for status c1f7ec10-5f13-4782-961c-0c1b5873f14d for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 (default) at scheduler-64ceec50-cb92-4308-a7ed-55a3120ed1c7@172.17.0.2:46877 on agent 102b125f-1892-4651-8c17-77519f422c4c-S0
I1129 22:49:06.230348 19829 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.230445 19829 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_RUNNING (Status UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.230722 19840 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: c1f7ec10-5f13-4782-961c-0c1b5873f14d) for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:06.230948 19292 slave.cpp:914] Agent terminating
I1129 22:49:06.670981 19801 hierarchical.cpp:1566] Performed allocation for 1 agents in 322130ns
I1129 22:49:07.061554 19840 master.cpp:1275] Agent 102b125f-1892-4651-8c17-77519f422c4c-S0 at slave@172.17.0.2:46877 (a2f8afefe3c9) disconnected
I1129 22:49:07.061585 19292 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I1129 22:49:07.061604 19840 master.cpp:3273] Disconnecting agent 102b125f-1892-4651-8c17-77519f422c4c-S0 at slave@172.17.0.2:46877 (a2f8afefe3c9)
I1129 22:49:07.061669 19840 master.cpp:3292] Deactivating agent 102b125f-1892-4651-8c17-77519f422c4c-S0 at slave@172.17.0.2:46877 (a2f8afefe3c9)
I1129 22:49:07.061823 19798 hierarchical.cpp:801] Agent 102b125f-1892-4651-8c17-77519f422c4c-S0 deactivated
W1129 22:49:07.062314 19292 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1129 22:49:07.062484 19292 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1129 22:49:07.062521 19292 provisioner.cpp:298] Using default backend 'copy'
W1129 22:49:07.070878 19292 process.cpp:2829] Attempted to spawn already running process files@172.17.0.2:46877
I1129 22:49:07.071555 19292 cluster.cpp:485] Creating default 'local' authorizer
I1129 22:49:07.073781 19844 slave.cpp:268] Mesos agent started on @172.17.0.2:46877
I1129 22:49:07.073806 19844 slave.cpp:269] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4YJqob/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_4YJqob/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_4YJqob/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_4YJqob/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4YJqob/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_4YJqob/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_4YJqob" --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_xpxYOf" --zk_session_timeout="10secs"
I1129 22:49:07.074399 19844 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4YJqob/credential'
I1129 22:49:07.074621 19844 slave.cpp:301] Agent using credential for: test-principal
I1129 22:49:07.074647 19844 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_4YJqob/http_credentials'
I1129 22:49:07.074910 19844 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1129 22:49:07.075366 19844 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1129 22:49:07.077446 19844 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"}]
I1129 22:49:07.077723 19844 slave.cpp:624] Agent attributes: [ ]
I1129 22:49:07.077744 19844 slave.cpp:633] Agent hostname: a2f8afefe3c9
I1129 22:49:07.077968 19809 task_status_update_manager.cpp:181] Pausing sending task status updates
I1129 22:49:07.083585 19832 state.cpp:66] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/meta'
I1129 22:49:07.083681 19832 state.cpp:711] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/meta/resources/resources.info'
I1129 22:49:07.091985 19803 slave.cpp:6914] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_xpxYOf/meta', beginning agent recovery
I1129 22:49:07.092866 19803 slave.cpp:7393] Recovering framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:07.093086 19803 slave.cpp:9099] Recovering executor '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:07.094293 19823 task_status_update_manager.cpp:207] Recovering task status update manager
I1129 22:49:07.094357 19823 task_status_update_manager.cpp:215] Recovering executor '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:07.094524 19823 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:07.095489 19823 task_status_update_manager.cpp:818] Replaying task status update stream for task 0cf3420d-77d8-41ac-b516-bb2388f3a6ed
I1129 22:49:07.096637 19809 containerizer.cpp:727] Recovering Mesos containers
I1129 22:49:07.096758 19809 containerizer.cpp:784] Recovering container 07e0039e-d9b1-418e-ae35-cf359ea5f557 for executor '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:07.099202 19809 containerizer.cpp:1053] Recovering isolators
I1129 22:49:07.100492 19842 containerizer.cpp:1092] Recovering provisioner
I1129 22:49:07.101331 19811 provisioner.cpp:494] Provisioner recovery complete
I1129 22:49:07.103265 19838 composing.cpp:339] Finished recovering all containerizers
I1129 22:49:07.103404 19840 slave.cpp:7143] Recovering executors
I1129 22:49:07.103562 19840 slave.cpp:7167] Sending reconnect request to executor '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' of framework 102b125f-1892-4651-8c17-77519f422c4c-0000 at executor(1)@172.17.0.2:32790
I1129 22:49:07.105507 27598 exec.cpp:282] Received reconnect request from agent 102b125f-1892-4651-8c17-77519f422c4c-S0
I1129 22:49:07.108954 19811 slave.cpp:4971] Received re-registration message from executor '0cf3420d-77d8-41ac-b516-bb2388f3a6ed' of framework 102b125f-1892-4651-8c17-77519f422c4c-0000
I1129 22:49:07.110585 27602 exec.cpp:259] Executor reregistered on agent 102b125f-1892-4651-8c17-77519f422c4c-S0
I1129 22:49:07.111269 19838 slave.cpp:5888] No pings from master received within 75secs
I1129 22:49:07.111349 19829 hierarchical.cpp:1566] Performed allocation for 1 agents in 237612ns
F1129 22:49:07.111955 19838 slave.cpp:1232] Check failed: state == DISCONNECTED || state == RUNNING || state == TERMINATING RECOVERING
*** Check failure stack trace: ***
I1129 22:49:07.113835 27579 executor.cpp:184] Received SUBSCRIBED event
I1129 22:49:07.113880 27579 executor.cpp:188] Subscribed executor on a2f8afefe3c9
@ 0x2b6998ffba8e google::LogMessage::Fail()
@ 0x2b6998ffb9da google::LogMessage::SendToLog()
@ 0x2b6998ffb3dc google::LogMessage::Flush()
@ 0x2b6998ffe2f0 google::LogMessageFatal::~LogMessageFatal()
@ 0x2b6997c04f00 mesos::internal::slave::Slave::detected()
@ 0x2b6997c98c50 _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEESB_EEvRKNS_3PIDIT_EEMSD_FvT0_EOT1_ENKUlOS9_PNS_11ProcessBaseEE_clESM_SO_
@ 0x2b6997d40ea9 _ZN5cpp176invokeIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINS3_10MasterInfoEEEESD_EEvRKNS1_3PIDIT_EEMSF_FvT0_EOT1_EUlOSB_PNS1_11ProcessBaseEE_ISB_SQ_EEEDTclcl7forwardISF_Efp_Espcl7forwardIT0_Efp0_EEEOSF_DpOSS_
@ 0x2b6997d37e55 _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_
@ 0x2b6997d31e95 _ZNO6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEEclIJSR_EEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOS10_
@ 0x2b6997d2ed0d _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS4_6FutureI6OptionINS6_10MasterInfoEEEESG_EEvRKNS4_3PIDIT_EEMSI_FvT0_EOT1_EUlOSE_PNS4_11ProcessBaseEE_ISE_St12_PlaceholderILi1EEEEEIST_EEEDTclcl7forwardISI_Efp_Espcl7forwardIT0_Efp0_EEEOSI_DpOSY_
@ 0x2b6997d2d01b _ZN6lambda8internal6InvokeIvEclINS0_7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS5_6FutureI6OptionINS7_10MasterInfoEEEESH_EEvRKNS5_3PIDIT_EEMSJ_FvT0_EOT1_EUlOSF_PNS5_11ProcessBaseEE_JSF_St12_PlaceholderILi1EEEEEJSU_EEEvOSJ_DpOT0_
@ 0x2b6997d2aed5 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINSA_10MasterInfoEEEESK_EEvRKNS1_3PIDIT_EEMSM_FvT0_EOT1_EUlOSI_S3_E_ISI_St12_PlaceholderILi1EEEEEEclEOS3_
@ 0x2b6998f20599 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEEclES3_
@ 0x2b6998ee9fc9 process::ProcessBase::consume()
@ 0x2b6998f0e2ec _ZNO7process13DispatchEvent7consumeEPNS_13EventConsumerE
@ 0x56223e425468 process::ProcessBase::serve()
@ 0x2b6998ee72a6 process::ProcessManager::resume()
@ 0x2b6998ee3720 _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
@ 0x2b6998f09138 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2b6998f08459 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
@ 0x2b6998f07618 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
@ 0x2b699bdbfa60 (unknown)
@ 0x2b699c536184 start_thread
@ 0x2b699c84a03d (unknown)
I1129 22:49:08.024569 27585 exec.cpp:518] Agent exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with agent 102b125f-1892-4651-8c17-77519f422c4c-S0
I1129 23:04:08.026060 27599 exec.cpp:499] Recovery timeout of 15mins exceeded; Shutting down
I1129 23:04:08.026206 27599 exec.cpp:445] Executor asked to shutdown
I1129 23:04:08.026829 27579 executor.cpp:184] Received SHUTDOWN event
I1129 23:04:08.026902 27579 executor.cpp:805] Shutting down
I1129 23:04:08.026973 27579 executor.cpp:918] Sending SIGTERM to process tree at pid 27604
I1129 23:04:08.045104 27579 executor.cpp:931] Sent SIGTERM to the following process trees:
[
-+- 27604 sh -c sleep 1000
\--- 27606 sleep 1000
]
I1129 23:04:08.045140 27579 executor.cpp:935] Scheduling escalation to SIGKILL in 3secs from now
I1129 23:04:08.104084 27581 executor.cpp:1003] Command terminated with signal Terminated (pid: 27604)
W1129 23:04:08.111861 27603 process.cpp:1890] Failed to send 'mesos.internal.StatusUpdateMessage' to '172.17.0.2:46877', connect: Failed to connect to 172.17.0.2:46877: Connection refused
I1129 23:04:09.109871 27603 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-1543527488-6297
Untagged: mesos-1543527488-6297:latest
Deleted: sha256:7c7ca06314a562c57d72cdf2e68ad7978307a45f057eb2070bf64e6ff755263d
Deleted: sha256:43f5b9c027cc56284ecfd981e028c19664e67d895c1dd0915abcf9ec217e9f0a
Deleted: sha256:c4109075e2566b60184c318cea25384f877148b65a5fb37e54a63ff7326e7f31
Deleted: sha256:dda49773ba087324f505a9780f3d005ee3f3fe3be4002fd4c96e0226ebf7ac5a
Deleted: sha256:6a77c81ccf8330309f81c02eeed1c8143dd20965c95d3c864e186bc3ba4d9f12
Deleted: sha256:78b5eae80991ff5b6232d11f2317f41b2bcb2a751f4ed2e98a9c7ed957b4d3f5
Deleted: sha256:cf953227bb2dd0df9857a364fef1b1fed099495ba5a45634019457f6d359fe4c
Deleted: sha256:53ef3b438baeaf1d52ef7cdfa119fdf7be1800784412926eafdd46531ee91fa8
Deleted: sha256:c57a2dfde3c4c53ea86e7685ef5d08bc38474042ca8fb53d7c113dbfcd8794c7
Deleted: sha256:1a9d8602959ce508273537814361ebfb72fa995f17e76374600e7f698443512f
Deleted: sha256:8ba23524d2496e2927cc827ccbb9b445243b0fb6f810a9f2488111ec1da5085b
Deleted: sha256:b22a2eb7f103e343add448ce68d803cef1359feab49b4cdce47cbc8e03551349
Deleted: sha256:59009a880cc897e0e6c5d319458670e9e983d9362b6ac9778a78b669510c1c13
Deleted: sha256:80810c25c0c0c4257c201661f374c1f7c1da15149deaaca04d60b1f4f917cc54
Deleted: sha256:513578694283363a0ab93d4bb7c8e017597886257ddd6906d1ed2a904804f2b6
Deleted: sha256:47e73d5e69cb2388219361d7ea0650dce2c1ee07caa0ae598ff28228218d1ede
Deleted: sha256:8bb2ab10e5c33cd4aafbb7add7506f7ebe207230ce984278001937b611ff23ce
Deleted: sha256:8383acf3b6af9825d040a4f3257c3650edf9a850807c8247e55a9087bb81aad6
Deleted: sha256:2d0487245f3100c1817df60d8e1b272899d7d776c03fd7adf3f391b175a28269
Deleted: sha256:99fe4ab4fff49e6e8b2f0f0af38fa5d80d34c48eab90f25754ba0f7309e8d6c7
Deleted: sha256:322542d3c886504568f5478ed8195b9ab539060fab06e943b43d9e94ef32e53b
Deleted: sha256:02fdf31ddbbf83b9604037f91e299c523af66a88d9d1d635691617821094522c
Deleted: sha256:1d117dce37f8ec5a9a0b8a14a6e4a962ff5d61f89c58a6a8fd31e87c70c81847
Deleted: sha256:d0f949bae8f3137b7c6fadd66efd8233a646def526969b624bc541cf3de144c1
Deleted: sha256:6e6839735d416410a30d06524817e7ddacb9dbf25e3cdf4a72ed79a98963d2ad
Deleted: sha256:906de03907b0644882e1b978a9f5f8e3d78c6e79c94e81cc1df88a067e111b69
Deleted: sha256:d4d93a2c2502198d41b513709f40a5a7ab6e073c0a24b89a3e211f5bf06c7b40
Deleted: sha256:d72ec7430f43e958cd8fbd0c9032c4d487d4c75e43189762dc374e95d5ef3774
Deleted: sha256:e646e7af1fe2961939f5c29e6e361bb55862b60f06ac72109c734f18525f299c
Deleted: sha256:bf4f15dff5e1a9a8f4b354e2eff127af23ae392588b51c24b61f880c9989402a
11-29-18_21:38:05 - Running <https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py>
Checking if review 69084 needs verification
Patch never verified, needs verification
Verifying review 69084
Applying review 69084
/usr/bin/python3 support/apply-reviews.py -n -r 69084
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_69084"]' 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