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/25 21:49:32 UTC
Build failed in Jenkins: Mesos-Reviewbot #23575
See <https://builds.apache.org/job/Mesos-Reviewbot/23575/display/redirect?page=changes>
Changes:
[jpeach] Removed separate automake variables for header sources.
[jpeach] Removed some unnecessary intermediate build variables.
------------------------------------------
Started by an SCM change
Started by an SCM change
Started by an SCM change
Started by an SCM change
Started by an SCM change
[EnvInject] - Loading node environment variables.
Building remotely on H42 (ubuntu xenial) in workspace <https://builds.apache.org/job/Mesos-Reviewbot/ws/>
Wiping out workspace first.
Cloning the remote Git repository
Cloning repository https://gitbox.apache.org/repos/asf/mesos.git
> git init <https://builds.apache.org/job/Mesos-Reviewbot/ws/> # timeout=10
Fetching upstream changes from https://gitbox.apache.org/repos/asf/mesos.git
> git --version # timeout=10
> git fetch --tags --progress https://gitbox.apache.org/repos/asf/mesos.git +refs/heads/*:refs/remotes/origin/*
> git config remote.origin.url https://gitbox.apache.org/repos/asf/mesos.git # timeout=10
> git config --add remote.origin.fetch +refs/heads/*:refs/remotes/origin/* # timeout=10
> git config remote.origin.url https://gitbox.apache.org/repos/asf/mesos.git # timeout=10
Fetching upstream changes from https://gitbox.apache.org/repos/asf/mesos.git
> git fetch --tags --progress https://gitbox.apache.org/repos/asf/mesos.git +refs/heads/*:refs/remotes/origin/*
> git rev-parse origin/master^{commit} # timeout=10
Checking out Revision 0f3455ccdbf728fa052d3a13218f9d424766397f (origin/master)
> git config core.sparsecheckout # timeout=10
> git checkout -f 0f3455ccdbf728fa052d3a13218f9d424766397f
Commit message: "Removed some unnecessary intermediate build variables."
> git rev-list --no-walk c1022562f94364737711f5deb142bd594fb11785 # timeout=10
[EnvInject] - Executing scripts and injecting environment variables after the SCM step.
[EnvInject] - Injecting as environment variables the properties content
USERNAME=mesos-review
[EnvInject] - Variables injected successfully.
[EnvInject] - Mask passwords that will be passed as build parameters.
[Mesos-Reviewbot] $ /bin/bash -xe /tmp/jenkins4167641859324918560.sh
+ ./support/jenkins/reviewbot.sh
Unable to find image 'mesos/mesos-build:ubuntu-16.04' locally
docker: Error response from daemon: error parsing HTTP 404 response body: invalid character 'p' after top-level value: "404 page not found\n".
See 'docker run --help'.
"docker rmi" requires at least 1 argument(s).
See 'docker rmi --help'.
Usage: docker rmi [OPTIONS] IMAGE [IMAGE...]
Remove one or more images
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos-Reviewbot #23578
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/23578/display/redirect?page=changes>
Build failed in Jenkins: Mesos-Reviewbot #23577
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/23577/display/redirect?page=changes>
Changes:
[klueska] Fixed name of task created when running mesos-cli-tests.
[klueska] Replaced CLI test helper function 'running_tasks' by 'wait_for_task'.
[klueska] Added '--all' flag to 'mesos task list'.
------------------------------------------
[...truncated 43.67 MB...]
I1126 17:38:09.202162 19558 slave.cpp:1451] Successfully authenticated with master master@172.17.0.2:45630
I1126 17:38:09.202486 19558 slave.cpp:1882] Will retry registration in 16.347347ms if necessary
I1126 17:38:09.202668 19556 master.cpp:6590] Received register agent message from slave@172.17.0.2:45630 (08f498d6e483)
I1126 17:38:09.203056 19556 master.cpp:3930] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I1126 17:38:09.203696 19545 master.cpp:6657] Authorized registration of agent at slave@172.17.0.2:45630 (08f498d6e483)
I1126 17:38:09.203799 19545 master.cpp:6772] Registering agent at slave@172.17.0.2:45630 (08f498d6e483) with id 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0
I1126 17:38:09.204398 19537 registrar.cpp:487] Applied 1 operations in 162589ns; attempting to update the registry
I1126 17:38:09.204988 19537 registrar.cpp:544] Successfully updated the registry in 526848ns
I1126 17:38:09.205152 19541 master.cpp:6820] Admitted agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 at slave@172.17.0.2:45630 (08f498d6e483)
I1126 17:38:09.205832 19541 master.cpp:6865] Registered agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 at slave@172.17.0.2:45630 (08f498d6e483) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1126 17:38:09.205911 19548 slave.cpp:1484] Registered with master master@172.17.0.2:45630; given agent ID 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0
I1126 17:38:09.206317 19548 slave.cpp:1504] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/meta/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/slave.info'
I1126 17:38:09.206400 19546 hierarchical.cpp:603] Added agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 (08f498d6e483) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I1126 17:38:09.207123 19540 task_status_update_manager.cpp:188] Resuming sending task status updates
I1126 17:38:09.207501 19548 slave.cpp:1553] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"AE8x4GaZTcWd0BXUxsp20g=="},"slave_id":{"value":"6e587902-7782-45ea-9f8c-d76cc4e4b253-S0"},"update_oversubscribed_resources":false}
I1126 17:38:09.208034 19546 hierarchical.cpp:1566] Performed allocation for 1 agents in 1.44127ms
I1126 17:38:09.208422 19548 master.cpp:7924] Ignoring update on agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 at slave@172.17.0.2:45630 (08f498d6e483) as it reports no changes
I1126 17:38:09.208889 19548 master.cpp:9454] Sending offers [ 6e587902-7782-45ea-9f8c-d76cc4e4b253-O0 ] to framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 (default) at scheduler-73f9b1fa-8cc1-494f-b0bd-3bdc2befe20f@172.17.0.2:45630
I1126 17:38:09.209499 19548 sched.cpp:914] Scheduler::resourceOffers took 195044ns
I1126 17:38:09.211189 19560 master.cpp:11453] Removing offer 6e587902-7782-45ea-9f8c-d76cc4e4b253-O0
I1126 17:38:09.211500 19560 master.cpp:4451] Processing ACCEPT call for offers: [ 6e587902-7782-45ea-9f8c-d76cc4e4b253-O0 ] on agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 at slave@172.17.0.2:45630 (08f498d6e483) for framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 (default) at scheduler-73f9b1fa-8cc1-494f-b0bd-3bdc2befe20f@172.17.0.2:45630
I1126 17:38:09.211598 19560 master.cpp:3547] Authorizing framework principal 'test-principal' to launch task 48817f74-c4c5-496d-96ab-84109559d8ad
I1126 17:38:09.213433 19539 master.cpp:4028] Adding task 48817f74-c4c5-496d-96ab-84109559d8ad with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 (default) at scheduler-73f9b1fa-8cc1-494f-b0bd-3bdc2befe20f@172.17.0.2:45630 on agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 at slave@172.17.0.2:45630 (08f498d6e483)
I1126 17:38:09.214007 19539 master.cpp:5423] Launching task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 (default) at scheduler-73f9b1fa-8cc1-494f-b0bd-3bdc2befe20f@172.17.0.2:45630 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 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 at slave@172.17.0.2:45630 (08f498d6e483) on new executor
I1126 17:38:09.215215 19541 slave.cpp:2019] Got assigned task '48817f74-c4c5-496d-96ab-84109559d8ad' for framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.215394 19541 slave.cpp:8895] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/meta/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/framework.info'
I1126 17:38:09.215848 19541 slave.cpp:8906] Checkpointing framework pid 'scheduler-73f9b1fa-8cc1-494f-b0bd-3bdc2befe20f@172.17.0.2:45630' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/meta/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/framework.pid'
I1126 17:38:09.217206 19541 slave.cpp:2393] Authorizing task '48817f74-c4c5-496d-96ab-84109559d8ad' for framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.217267 19541 slave.cpp:8471] Authorizing framework principal 'test-principal' to launch task 48817f74-c4c5-496d-96ab-84109559d8ad
I1126 17:38:09.219171 19541 slave.cpp:2836] Launching task '48817f74-c4c5-496d-96ab-84109559d8ad' for framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.219252 19541 paths.cpp:752] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77' for user 'mesos'
I1126 17:38:09.219945 19541 slave.cpp:9681] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/meta/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/executor.info'
I1126 17:38:09.220501 19541 paths.cpp:755] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/meta/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77'
I1126 17:38:09.220770 19541 slave.cpp:8981] Launching executor '48817f74-c4c5-496d-96ab-84109559d8ad' of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-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_x3RPaL/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77'
I1126 17:38:09.221500 19541 slave.cpp:3514] Launching container 0a848099-9e5e-45c8-b611-4b713ade3c77 for executor '48817f74-c4c5-496d-96ab-84109559d8ad' of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.222020 19541 slave.cpp:9712] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/meta/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77/tasks/48817f74-c4c5-496d-96ab-84109559d8ad/task.info'
I1126 17:38:09.222689 19541 slave.cpp:3033] Queued task '48817f74-c4c5-496d-96ab-84109559d8ad' for executor '48817f74-c4c5-496d-96ab-84109559d8ad' of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.222781 19541 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/latest'
I1126 17:38:09.222826 19541 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77' to virtual path '/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/latest'
I1126 17:38:09.222863 19541 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77'
I1126 17:38:09.223482 19557 containerizer.cpp:1288] Starting container 0a848099-9e5e-45c8-b611-4b713ade3c77
I1126 17:38:09.224618 19557 containerizer.cpp:1454] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_gYa0zz/containers/0a848099-9e5e-45c8-b611-4b713ade3c77/config'
I1126 17:38:09.224651 19557 containerizer.cpp:3130] Transitioning the state of container 0a848099-9e5e-45c8-b611-4b713ade3c77 from PROVISIONING to PREPARING
I1126 17:38:09.229061 19560 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:45630"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"48817f74-c4c5-496d-96ab-84109559d8ad"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"6e587902-7782-45ea-9f8c-d76cc4e4b253-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":"6e587902-7782-45ea-9f8c-d76cc4e4b253-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave@172.17.0.2:45630"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"15secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77"}" --pipe_read="24" --pipe_write="27" --runtime_directory="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_gYa0zz/containers/0a848099-9e5e-45c8-b611-4b713ade3c77" --unshare_namespace_mnt="false"'
I1126 17:38:09.234035 19560 launcher.cpp:145] Forked child with pid '27439' for container '0a848099-9e5e-45c8-b611-4b713ade3c77'
I1126 17:38:09.234172 19560 containerizer.cpp:2052] Checkpointing container's forked pid 27439 to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/meta/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77/pids/forked.pid'
I1126 17:38:09.234905 19560 containerizer.cpp:3130] Transitioning the state of container 0a848099-9e5e-45c8-b611-4b713ade3c77 from PREPARING to ISOLATING
I1126 17:38:09.236534 19560 containerizer.cpp:3130] Transitioning the state of container 0a848099-9e5e-45c8-b611-4b713ade3c77 from ISOLATING to FETCHING
I1126 17:38:09.236760 19538 fetcher.cpp:369] Starting to fetch URIs for container: 0a848099-9e5e-45c8-b611-4b713ade3c77, directory: /tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77
I1126 17:38:09.237850 19556 containerizer.cpp:3130] Transitioning the state of container 0a848099-9e5e-45c8-b611-4b713ade3c77 from FETCHING to RUNNING
I1126 17:38:09.685204 27487 exec.cpp:162] Version: 1.8.0
I1126 17:38:09.699491 19549 slave.cpp:4808] Got registration for executor '48817f74-c4c5-496d-96ab-84109559d8ad' of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 from executor(1)@172.17.0.2:36922
I1126 17:38:09.700101 19549 slave.cpp:4894] Checkpointing executor pid 'executor(1)@172.17.0.2:36922' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/meta/slaves/6e587902-7782-45ea-9f8c-d76cc4e4b253-S0/frameworks/6e587902-7782-45ea-9f8c-d76cc4e4b253-0000/executors/48817f74-c4c5-496d-96ab-84109559d8ad/runs/0a848099-9e5e-45c8-b611-4b713ade3c77/pids/libprocess.pid'
I1126 17:38:09.703173 19555 slave.cpp:3246] Sending queued task '48817f74-c4c5-496d-96ab-84109559d8ad' to executor '48817f74-c4c5-496d-96ab-84109559d8ad' of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 at executor(1)@172.17.0.2:36922
I1126 17:38:09.703991 27495 exec.cpp:236] Executor registered on agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0
I1126 17:38:09.707969 27475 executor.cpp:184] Received SUBSCRIBED event
I1126 17:38:09.709615 27475 executor.cpp:188] Subscribed executor on 08f498d6e483
I1126 17:38:09.709812 27475 executor.cpp:184] Received LAUNCH event
I1126 17:38:09.711877 27475 executor.cpp:687] Starting task 48817f74-c4c5-496d-96ab-84109559d8ad
I1126 17:38:09.715605 19551 slave.cpp:5274] Handling status update TASK_STARTING (Status UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 from executor(1)@172.17.0.2:36922
I1126 17:38:09.718160 19548 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.718236 19548 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.719111 19548 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.719368 19548 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 to the agent
I1126 17:38:09.719558 19560 slave.cpp:5766] Forwarding the update TASK_STARTING (Status UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 to master@172.17.0.2:45630
I1126 17:38:09.719799 19560 slave.cpp:5659] Task status update manager successfully handled status update TASK_STARTING (Status UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.719852 19560 slave.cpp:5675] Sending acknowledgement for status update TASK_STARTING (Status UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 to executor(1)@172.17.0.2:36922
I1126 17:38:09.720011 19545 master.cpp:8360] Status update TASK_STARTING (Status UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 from agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 at slave@172.17.0.2:45630 (08f498d6e483)
I1126 17:38:09.720093 19545 master.cpp:8417] Forwarding status update TASK_STARTING (Status UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.720413 19545 master.cpp:10918] Updating the state of task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I1126 17:38:09.720753 19557 sched.cpp:1022] Scheduler::statusUpdate took 169119ns
I1126 17:38:09.721577 19555 master.cpp:6226] Processing ACKNOWLEDGE call for status 0569d220-68cb-45e1-beae-2c2cd7319ed4 for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 (default) at scheduler-73f9b1fa-8cc1-494f-b0bd-3bdc2befe20f@172.17.0.2:45630 on agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0
I1126 17:38:09.721983 19539 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.722100 19539 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.722365 19559 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: 0569d220-68cb-45e1-beae-2c2cd7319ed4) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.733567 27475 executor.cpp:502] Running '/mesos/mesos-1.8.0/_build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
I1126 17:38:09.737406 27475 executor.cpp:702] Forked command at 27502
I1126 17:38:09.742070 19537 slave.cpp:5274] Handling status update TASK_RUNNING (Status UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 from executor(1)@172.17.0.2:36922
I1126 17:38:09.744366 19558 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.744478 19558 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.744732 19558 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 to the agent
I1126 17:38:09.744954 19556 slave.cpp:5766] Forwarding the update TASK_RUNNING (Status UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 to master@172.17.0.2:45630
I1126 17:38:09.745164 19556 slave.cpp:5659] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.745213 19556 slave.cpp:5675] Sending acknowledgement for status update TASK_RUNNING (Status UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 to executor(1)@172.17.0.2:36922
I1126 17:38:09.745312 19551 master.cpp:8360] Status update TASK_RUNNING (Status UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 from agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 at slave@172.17.0.2:45630 (08f498d6e483)
I1126 17:38:09.745374 19551 master.cpp:8417] Forwarding status update TASK_RUNNING (Status UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.745631 19551 master.cpp:10918] Updating the state of task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1126 17:38:09.745885 19553 sched.cpp:1022] Scheduler::statusUpdate took 107368ns
I1126 17:38:09.746677 19554 master.cpp:6226] Processing ACKNOWLEDGE call for status 079a60bd-845c-495f-9246-1aa400c7dff6 for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 (default) at scheduler-73f9b1fa-8cc1-494f-b0bd-3bdc2befe20f@172.17.0.2:45630 on agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0
I1126 17:38:09.747068 19538 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.747200 19538 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_RUNNING (Status UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.747510 19543 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: 079a60bd-845c-495f-9246-1aa400c7dff6) for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:09.747723 19548 slave.cpp:914] Agent terminating
I1126 17:38:10.171025 19539 hierarchical.cpp:1566] Performed allocation for 1 agents in 359499ns
I1126 17:38:10.468111 19545 master.cpp:1275] Agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 at slave@172.17.0.2:45630 (08f498d6e483) disconnected
I1126 17:38:10.468159 19545 master.cpp:3273] Disconnecting agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 at slave@172.17.0.2:45630 (08f498d6e483)
I1126 17:38:10.468230 19545 master.cpp:3292] Deactivating agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 at slave@172.17.0.2:45630 (08f498d6e483)
I1126 17:38:10.468351 19543 hierarchical.cpp:801] Agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0 deactivated
I1126 17:38:10.468401 19284 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1126 17:38:10.468931 19284 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1126 17:38:10.469117 19284 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1126 17:38:10.469154 19284 provisioner.cpp:298] Using default backend 'copy'
W1126 17:38:10.476522 19284 process.cpp:2829] Attempted to spawn already running process files@172.17.0.2:45630
I1126 17:38:10.477071 19284 cluster.cpp:485] Creating default 'local' authorizer
I1126 17:38:10.478816 19548 slave.cpp:268] Mesos agent started on @172.17.0.2:45630
I1126 17:38:10.478842 19548 slave.cpp:269] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_gYa0zz/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_gYa0zz/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_gYa0zz/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_gYa0zz/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_gYa0zz/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_gYa0zz/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_gYa0zz" --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_x3RPaL" --zk_session_timeout="10secs"
I1126 17:38:10.479396 19548 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_gYa0zz/credential'
I1126 17:38:10.479590 19548 slave.cpp:301] Agent using credential for: test-principal
I1126 17:38:10.479612 19548 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_gYa0zz/http_credentials'
I1126 17:38:10.479833 19548 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1126 17:38:10.480242 19548 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1126 17:38:10.481663 19548 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"}]
I1126 17:38:10.481873 19548 slave.cpp:624] Agent attributes: [ ]
I1126 17:38:10.481889 19548 slave.cpp:633] Agent hostname: 08f498d6e483
I1126 17:38:10.482030 19560 task_status_update_manager.cpp:181] Pausing sending task status updates
I1126 17:38:10.483624 19546 state.cpp:66] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/meta'
I1126 17:38:10.483700 19546 state.cpp:711] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/meta/resources/resources.info'
I1126 17:38:10.489049 19547 slave.cpp:6914] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_x3RPaL/meta', beginning agent recovery
I1126 17:38:10.489892 19547 slave.cpp:7393] Recovering framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:10.490105 19547 slave.cpp:9099] Recovering executor '48817f74-c4c5-496d-96ab-84109559d8ad' of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:10.491319 19559 task_status_update_manager.cpp:207] Recovering task status update manager
I1126 17:38:10.491365 19559 task_status_update_manager.cpp:215] Recovering executor '48817f74-c4c5-496d-96ab-84109559d8ad' of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:10.491461 19559 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 48817f74-c4c5-496d-96ab-84109559d8ad of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:10.492060 19559 task_status_update_manager.cpp:818] Replaying task status update stream for task 48817f74-c4c5-496d-96ab-84109559d8ad
I1126 17:38:10.492828 19542 containerizer.cpp:727] Recovering Mesos containers
I1126 17:38:10.492939 19542 containerizer.cpp:784] Recovering container 0a848099-9e5e-45c8-b611-4b713ade3c77 for executor '48817f74-c4c5-496d-96ab-84109559d8ad' of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:10.494854 19542 containerizer.cpp:1053] Recovering isolators
I1126 17:38:10.495826 19541 containerizer.cpp:1092] Recovering provisioner
I1126 17:38:10.496587 19553 provisioner.cpp:494] Provisioner recovery complete
I1126 17:38:10.498312 19552 composing.cpp:339] Finished recovering all containerizers
I1126 17:38:10.498455 19557 slave.cpp:7143] Recovering executors
I1126 17:38:10.498615 19557 slave.cpp:7167] Sending reconnect request to executor '48817f74-c4c5-496d-96ab-84109559d8ad' of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000 at executor(1)@172.17.0.2:36922
I1126 17:38:10.500504 27494 exec.cpp:282] Received reconnect request from agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0
I1126 17:38:10.503602 19558 slave.cpp:4971] Received re-registration message from executor '48817f74-c4c5-496d-96ab-84109559d8ad' of framework 6e587902-7782-45ea-9f8c-d76cc4e4b253-0000
I1126 17:38:10.504999 27497 exec.cpp:259] Executor reregistered on agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0
I1126 17:38:10.505575 19560 slave.cpp:5888] No pings from master received within 75secs
I1126 17:38:10.505811 19554 hierarchical.cpp:1566] Performed allocation for 1 agents in 224830ns
F1126 17:38:10.506191 19560 slave.cpp:1232] Check failed: state == DISCONNECTED || state == RUNNING || state == TERMINATING RECOVERING
*** Check failure stack trace: ***
I1126 17:38:10.507704 27498 executor.cpp:184] Received SUBSCRIBED event
I1126 17:38:10.507750 27498 executor.cpp:188] Subscribed executor on 08f498d6e483
@ 0x2b28c4d78b08 google::LogMessage::Fail()
@ 0x2b28c4d78a54 google::LogMessage::SendToLog()
@ 0x2b28c4d78456 google::LogMessage::Flush()
@ 0x2b28c4d7b36a google::LogMessageFatal::~LogMessageFatal()
@ 0x2b28c398583c mesos::internal::slave::Slave::detected()
@ 0x2b28c3a1958c _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEESB_EEvRKNS_3PIDIT_EEMSD_FvT0_EOT1_ENKUlOS9_PNS_11ProcessBaseEE_clESM_SO_
@ 0x2b28c3ac17e5 _ZN5cpp176invokeIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINS3_10MasterInfoEEEESD_EEvRKNS1_3PIDIT_EEMSF_FvT0_EOT1_EUlOSB_PNS1_11ProcessBaseEE_ISB_SQ_EEEDTclcl7forwardISF_Efp_Espcl7forwardIT0_Efp0_EEEOSF_DpOSS_
@ 0x2b28c3ab8791 _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_
@ 0x2b28c3ab27d1 _ZNO6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEEclIJSR_EEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOS10_
@ 0x2b28c3aaf649 _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS4_6FutureI6OptionINS6_10MasterInfoEEEESG_EEvRKNS4_3PIDIT_EEMSI_FvT0_EOT1_EUlOSE_PNS4_11ProcessBaseEE_ISE_St12_PlaceholderILi1EEEEEIST_EEEDTclcl7forwardISI_Efp_Espcl7forwardIT0_Efp0_EEEOSI_DpOSY_
@ 0x2b28c3aad957 _ZN6lambda8internal6InvokeIvEclINS0_7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS5_6FutureI6OptionINS7_10MasterInfoEEEESH_EEvRKNS5_3PIDIT_EEMSJ_FvT0_EOT1_EUlOSF_PNS5_11ProcessBaseEE_JSF_St12_PlaceholderILi1EEEEEJSU_EEEvOSJ_DpOT0_
@ 0x2b28c3aab811 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINSA_10MasterInfoEEEESK_EEvRKNS1_3PIDIT_EEMSM_FvT0_EOT1_EUlOSI_S3_E_ISI_St12_PlaceholderILi1EEEEEEclEOS3_
@ 0x2b28c4c99e49 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEEclES3_
@ 0x2b28c4c6385f process::ProcessBase::consume()
@ 0x2b28c4c87b82 _ZNO7process13DispatchEvent7consumeEPNS_13EventConsumerE
@ 0x560d939a7578 process::ProcessBase::serve()
@ 0x2b28c4c60b3c process::ProcessManager::resume()
@ 0x2b28c4c5cfb6 _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
@ 0x2b28c4c829ce _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2b28c4c81cef _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
@ 0x2b28c4c80eae _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
@ 0x2b28c7b39a60 (unknown)
@ 0x2b28c82b0184 start_thread
@ 0x2b28c85c403d (unknown)
I1126 17:38:11.289849 27488 exec.cpp:518] Agent exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with agent 6e587902-7782-45ea-9f8c-d76cc4e4b253-S0
I1126 17:53:11.291188 27487 exec.cpp:499] Recovery timeout of 15mins exceeded; Shutting down
I1126 17:53:11.291378 27487 exec.cpp:445] Executor asked to shutdown
I1126 17:53:11.292151 27496 executor.cpp:184] Received SHUTDOWN event
I1126 17:53:11.292243 27496 executor.cpp:805] Shutting down
I1126 17:53:11.292382 27496 executor.cpp:918] Sending SIGTERM to process tree at pid 27502
I1126 17:53:11.310111 27496 executor.cpp:931] Sent SIGTERM to the following process trees:
[
-+- 27502 sh -c sleep 1000
\--- 27517 sleep 1000
]
I1126 17:53:11.310144 27496 executor.cpp:935] Scheduling escalation to SIGKILL in 3secs from now
I1126 17:53:11.364189 27497 executor.cpp:1003] Command terminated with signal Terminated (pid: 27502)
W1126 17:53:11.369813 27499 process.cpp:1890] Failed to send 'mesos.internal.StatusUpdateMessage' to '172.17.0.2:45630', connect: Failed to connect to 172.17.0.2:45630: Connection refused
I1126 17:53:12.367748 27499 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-1543249871-8012
Untagged: mesos-1543249871-8012:latest
Deleted: sha256:34c83699cfd56838ccaeaacdfe26a9a896f3d3992d06b2dc91f12f87f4422f25
Deleted: sha256:1aed04551d04b33be7b828f56e44d7b0731f23483990dd6e465ac986f0095641
Deleted: sha256:e75cd87c96d6003a91fbf1d6aeecaf1b486ba044ff347157f13e9b89561ebb70
Deleted: sha256:8d2a35e77569cb1ecc4014284f7fcb7a43b61aa58c8a9b0cf698a098e36a5caf
Deleted: sha256:318b0fcf139cbe2fa2d61557d88ae7ac10e9dcda94462866814f3e1259bb4f20
Deleted: sha256:75e89ea0dbcb43d3aa54ce6a4fa01917845511ca2e821f43f731ee1043b2752c
Deleted: sha256:0fff739ab552466489c9aa44c7a64e080bd6e15ecddd96fc092b8ec4974b70f6
Deleted: sha256:3152d0970b9b03e64b32fe249860d7d950da3f06fe4ab70a6da7a55504d27caa
Deleted: sha256:fa1b118746420a867f2b727a58e8cbd561e8a7260004d707aafeb366e6c85508
Deleted: sha256:8a6c17ca6403d90266f7f4e3193c60e4f4fab8110b925b5964c3add152e2bc95
Deleted: sha256:3841127428e80fa9f0158a298aa606ba897307e2cca72476ab74f6b655c59148
Deleted: sha256:b3934bef34c86eb07b5f88096ae3059f405eab1136ac54010d5a26b25dd43e1a
Deleted: sha256:d6b8f1b0faff13f1e60b2cfcca3a4f9c2cbc52c5f80bb341204aff0e71526aac
Deleted: sha256:b67e80f69b72d8b3e5c14e7044d7a162213387a2a6f6dbad4ef4d13646d45758
Deleted: sha256:6ca46938dee9803a77de6acaf07c8caffb061351dad17b0d62a0f9b1489ae1cb
Deleted: sha256:b8a4d66e67dd079785b5b7591f646ad25b59b6cd737eeb0cecb8f4152f934c72
Deleted: sha256:d7525d3913fbbc074d794dab89987232c6a31f48cdc32ad4ad3a6283e06f66aa
Deleted: sha256:260ea00d5222861c7d3d244e5eb58bdf281de57c058c696af86be69b2ae76357
Deleted: sha256:eb242e51275ab3bcdc4d2f76690044b85659b641174c2404dfab89e1115be288
Deleted: sha256:4eb4619a53dd5eafafd7c86adccf5ddf4a66ff133fa84eaa0dcc51ba5f69c8a1
Deleted: sha256:93d98016e96e86a43910b6a414ee079250be871eaf991a4ef693018adbf96558
Deleted: sha256:9fa3f920f5dab79dcd595a64417860dfd4f44f6da322b33eba66613610fe5190
Deleted: sha256:7c7938bf22141674bd9760cd9bd95473e7315bb3f358f3279a6c7882cc2a6ab4
Deleted: sha256:90b5ea53fb931718c533b1eaed6e88f1ce57cc84ed96f32b5e63bda8647a8b6e
Deleted: sha256:e994196760d82f09aeaba00000af43be094c60ad02d4d5a97a359e3885e29fb9
Deleted: sha256:bae1577837fad8ce9cb431bcf8961086eb8d0a56768045756734c79293b3d4a8
Deleted: sha256:b51ffcbfa5ae777dbcca9ff8994bc4c3c0184d0741040a27f198095b21cc23b0
Deleted: sha256:4b3a200ea952ee6d8391e45a0d489b0d4cb3a1652b13d2b5642943fb38b8ac39
Deleted: sha256:734694521a607e4c64333408c59ac7446ba7b7dc138eaa32e3a9b7963381648e
Deleted: sha256:0cc888f0f81fae4fdf9be91e0b5a35de37f0bf125945f2cf318266a2324c878d
11-26-18_16:31:08 - Running <https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py>
Checking if review 69436 needs verification
Patch never verified, needs verification
Verifying review 69436
Applying review 69436
/usr/bin/python3 support/apply-reviews.py -n -r 69436
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_69436"]' 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 #23576
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/23576/display/redirect?page=changes>
Changes:
[klueska] Updated 'mesos task list' to only display running tasks.
------------------------------------------
[...truncated 43.74 MB...]
I1126 15:28:19.258522 19609 master.cpp:6820] Admitted agent ae12bc56-70ed-4039-9523-7528dedda882-S0 at slave@172.17.0.2:39622 (dad6f45cdec5)
I1126 15:28:19.259333 19603 slave.cpp:1484] Registered with master master@172.17.0.2:39622; given agent ID ae12bc56-70ed-4039-9523-7528dedda882-S0
I1126 15:28:19.259338 19609 master.cpp:6865] Registered agent ae12bc56-70ed-4039-9523-7528dedda882-S0 at slave@172.17.0.2:39622 (dad6f45cdec5) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1126 15:28:19.259454 19577 task_status_update_manager.cpp:188] Resuming sending task status updates
I1126 15:28:19.259691 19563 hierarchical.cpp:603] Added agent ae12bc56-70ed-4039-9523-7528dedda882-S0 (dad6f45cdec5) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I1126 15:28:19.259708 19603 slave.cpp:1504] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/meta/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/slave.info'
I1126 15:28:19.260681 19603 slave.cpp:1553] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"eEbDYqajRBKXhZRUIPalQg=="},"slave_id":{"value":"ae12bc56-70ed-4039-9523-7528dedda882-S0"},"update_oversubscribed_resources":false}
I1126 15:28:19.260850 19563 hierarchical.cpp:1566] Performed allocation for 1 agents in 1.004785ms
I1126 15:28:19.261461 19575 master.cpp:7924] Ignoring update on agent ae12bc56-70ed-4039-9523-7528dedda882-S0 at slave@172.17.0.2:39622 (dad6f45cdec5) as it reports no changes
I1126 15:28:19.262157 19575 master.cpp:9454] Sending offers [ ae12bc56-70ed-4039-9523-7528dedda882-O0 ] to framework ae12bc56-70ed-4039-9523-7528dedda882-0000 (default) at scheduler-128be5ca-d3da-4005-8a4d-74899674155c@172.17.0.2:39622
I1126 15:28:19.262912 19592 sched.cpp:914] Scheduler::resourceOffers took 114612ns
I1126 15:28:19.264700 19565 master.cpp:11453] Removing offer ae12bc56-70ed-4039-9523-7528dedda882-O0
I1126 15:28:19.265156 19565 master.cpp:4451] Processing ACCEPT call for offers: [ ae12bc56-70ed-4039-9523-7528dedda882-O0 ] on agent ae12bc56-70ed-4039-9523-7528dedda882-S0 at slave@172.17.0.2:39622 (dad6f45cdec5) for framework ae12bc56-70ed-4039-9523-7528dedda882-0000 (default) at scheduler-128be5ca-d3da-4005-8a4d-74899674155c@172.17.0.2:39622
I1126 15:28:19.265262 19565 master.cpp:3547] Authorizing framework principal 'test-principal' to launch task fa8d2385-bd09-4a08-b3d1-481379edf456
I1126 15:28:19.267079 19581 master.cpp:4028] Adding task fa8d2385-bd09-4a08-b3d1-481379edf456 with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 (default) at scheduler-128be5ca-d3da-4005-8a4d-74899674155c@172.17.0.2:39622 on agent ae12bc56-70ed-4039-9523-7528dedda882-S0 at slave@172.17.0.2:39622 (dad6f45cdec5)
I1126 15:28:19.267879 19581 master.cpp:5423] Launching task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 (default) at scheduler-128be5ca-d3da-4005-8a4d-74899674155c@172.17.0.2:39622 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 ae12bc56-70ed-4039-9523-7528dedda882-S0 at slave@172.17.0.2:39622 (dad6f45cdec5) on new executor
I1126 15:28:19.269749 19570 slave.cpp:2019] Got assigned task 'fa8d2385-bd09-4a08-b3d1-481379edf456' for framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.269984 19570 slave.cpp:8895] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/meta/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/framework.info'
I1126 15:28:19.270615 19570 slave.cpp:8906] Checkpointing framework pid 'scheduler-128be5ca-d3da-4005-8a4d-74899674155c@172.17.0.2:39622' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/meta/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/framework.pid'
I1126 15:28:19.272490 19570 slave.cpp:2393] Authorizing task 'fa8d2385-bd09-4a08-b3d1-481379edf456' for framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.272567 19570 slave.cpp:8471] Authorizing framework principal 'test-principal' to launch task fa8d2385-bd09-4a08-b3d1-481379edf456
I1126 15:28:19.275097 19603 slave.cpp:2836] Launching task 'fa8d2385-bd09-4a08-b3d1-481379edf456' for framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.275211 19603 paths.cpp:752] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9' for user 'mesos'
I1126 15:28:19.276203 19603 slave.cpp:9681] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/meta/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/executor.info'
I1126 15:28:19.276859 19603 paths.cpp:755] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/meta/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9'
I1126 15:28:19.277115 19603 slave.cpp:8981] Launching executor 'fa8d2385-bd09-4a08-b3d1-481379edf456' of framework ae12bc56-70ed-4039-9523-7528dedda882-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_ElIRUW/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9'
I1126 15:28:19.277864 19603 slave.cpp:3514] Launching container f1cf2524-19dc-4211-94e6-47287d62a8f9 for executor 'fa8d2385-bd09-4a08-b3d1-481379edf456' of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.278420 19603 slave.cpp:9712] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/meta/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9/tasks/fa8d2385-bd09-4a08-b3d1-481379edf456/task.info'
I1126 15:28:19.279114 19603 slave.cpp:3033] Queued task 'fa8d2385-bd09-4a08-b3d1-481379edf456' for executor 'fa8d2385-bd09-4a08-b3d1-481379edf456' of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.279203 19603 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/latest'
I1126 15:28:19.279251 19603 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9' to virtual path '/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/latest'
I1126 15:28:19.279296 19603 slave.cpp:993] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9'
I1126 15:28:19.279918 19594 containerizer.cpp:1288] Starting container f1cf2524-19dc-4211-94e6-47287d62a8f9
I1126 15:28:19.280958 19594 containerizer.cpp:1454] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_tcv7Pr/containers/f1cf2524-19dc-4211-94e6-47287d62a8f9/config'
I1126 15:28:19.280992 19594 containerizer.cpp:3130] Transitioning the state of container f1cf2524-19dc-4211-94e6-47287d62a8f9 from PROVISIONING to PREPARING
I1126 15:28:19.285286 19588 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:39622"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"fa8d2385-bd09-4a08-b3d1-481379edf456"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"ae12bc56-70ed-4039-9523-7528dedda882-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":"ae12bc56-70ed-4039-9523-7528dedda882-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave@172.17.0.2:39622"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"15secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9"}" --pipe_read="24" --pipe_write="26" --runtime_directory="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_tcv7Pr/containers/f1cf2524-19dc-4211-94e6-47287d62a8f9" --unshare_namespace_mnt="false"'
I1126 15:28:19.289868 19588 launcher.cpp:145] Forked child with pid '27673' for container 'f1cf2524-19dc-4211-94e6-47287d62a8f9'
I1126 15:28:19.290020 19588 containerizer.cpp:2052] Checkpointing container's forked pid 27673 to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/meta/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9/pids/forked.pid'
I1126 15:28:19.290890 19588 containerizer.cpp:3130] Transitioning the state of container f1cf2524-19dc-4211-94e6-47287d62a8f9 from PREPARING to ISOLATING
I1126 15:28:19.292513 19588 containerizer.cpp:3130] Transitioning the state of container f1cf2524-19dc-4211-94e6-47287d62a8f9 from ISOLATING to FETCHING
I1126 15:28:19.293113 19605 fetcher.cpp:369] Starting to fetch URIs for container: f1cf2524-19dc-4211-94e6-47287d62a8f9, directory: /tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9
I1126 15:28:19.294389 19584 containerizer.cpp:3130] Transitioning the state of container f1cf2524-19dc-4211-94e6-47287d62a8f9 from FETCHING to RUNNING
I1126 15:28:19.737483 27696 exec.cpp:162] Version: 1.8.0
I1126 15:28:19.752529 19570 slave.cpp:4808] Got registration for executor 'fa8d2385-bd09-4a08-b3d1-481379edf456' of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 from executor(1)@172.17.0.2:40613
I1126 15:28:19.753136 19570 slave.cpp:4894] Checkpointing executor pid 'executor(1)@172.17.0.2:40613' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/meta/slaves/ae12bc56-70ed-4039-9523-7528dedda882-S0/frameworks/ae12bc56-70ed-4039-9523-7528dedda882-0000/executors/fa8d2385-bd09-4a08-b3d1-481379edf456/runs/f1cf2524-19dc-4211-94e6-47287d62a8f9/pids/libprocess.pid'
I1126 15:28:19.756155 19596 slave.cpp:3246] Sending queued task 'fa8d2385-bd09-4a08-b3d1-481379edf456' to executor 'fa8d2385-bd09-4a08-b3d1-481379edf456' of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 at executor(1)@172.17.0.2:40613
I1126 15:28:19.761780 27704 exec.cpp:236] Executor registered on agent ae12bc56-70ed-4039-9523-7528dedda882-S0
I1126 15:28:19.766201 27684 executor.cpp:184] Received SUBSCRIBED event
I1126 15:28:19.768782 27684 executor.cpp:188] Subscribed executor on dad6f45cdec5
I1126 15:28:19.769140 27684 executor.cpp:184] Received LAUNCH event
I1126 15:28:19.773113 27684 executor.cpp:687] Starting task fa8d2385-bd09-4a08-b3d1-481379edf456
I1126 15:28:19.776940 19609 slave.cpp:5274] Handling status update TASK_STARTING (Status UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 from executor(1)@172.17.0.2:40613
I1126 15:28:19.780494 19588 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.780571 19588 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.781707 19588 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.782114 19588 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 to the agent
I1126 15:28:19.782570 19588 slave.cpp:5766] Forwarding the update TASK_STARTING (Status UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 to master@172.17.0.2:39622
I1126 15:28:19.782804 19588 slave.cpp:5659] Task status update manager successfully handled status update TASK_STARTING (Status UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.782863 19588 slave.cpp:5675] Sending acknowledgement for status update TASK_STARTING (Status UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 to executor(1)@172.17.0.2:40613
I1126 15:28:19.783743 19588 master.cpp:8360] Status update TASK_STARTING (Status UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 from agent ae12bc56-70ed-4039-9523-7528dedda882-S0 at slave@172.17.0.2:39622 (dad6f45cdec5)
I1126 15:28:19.783810 19588 master.cpp:8417] Forwarding status update TASK_STARTING (Status UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.784035 19588 master.cpp:10918] Updating the state of task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I1126 15:28:19.784353 19601 sched.cpp:1022] Scheduler::statusUpdate took 140152ns
I1126 15:28:19.785290 19577 master.cpp:6226] Processing ACKNOWLEDGE call for status 97d48961-b90f-4427-9c70-b2d8938e8f6a for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 (default) at scheduler-128be5ca-d3da-4005-8a4d-74899674155c@172.17.0.2:39622 on agent ae12bc56-70ed-4039-9523-7528dedda882-S0
I1126 15:28:19.785686 19577 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.785809 19577 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.786104 19577 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: 97d48961-b90f-4427-9c70-b2d8938e8f6a) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.800725 27684 executor.cpp:502] Running '/mesos/mesos-1.8.0/_build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
I1126 15:28:19.804388 27684 executor.cpp:702] Forked command at 27711
I1126 15:28:19.808230 19607 slave.cpp:5274] Handling status update TASK_RUNNING (Status UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 from executor(1)@172.17.0.2:40613
I1126 15:28:19.810544 19563 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.810631 19563 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.810910 19563 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 to the agent
I1126 15:28:19.811275 19563 slave.cpp:5766] Forwarding the update TASK_RUNNING (Status UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 to master@172.17.0.2:39622
I1126 15:28:19.811743 19598 master.cpp:8360] Status update TASK_RUNNING (Status UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 from agent ae12bc56-70ed-4039-9523-7528dedda882-S0 at slave@172.17.0.2:39622 (dad6f45cdec5)
I1126 15:28:19.811838 19598 master.cpp:8417] Forwarding status update TASK_RUNNING (Status UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.812152 19598 master.cpp:10918] Updating the state of task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1126 15:28:19.812285 19563 slave.cpp:5659] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.812347 19563 slave.cpp:5675] Sending acknowledgement for status update TASK_RUNNING (Status UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 to executor(1)@172.17.0.2:40613
I1126 15:28:19.812387 19609 sched.cpp:1022] Scheduler::statusUpdate took 122533ns
I1126 15:28:19.813098 19586 master.cpp:6226] Processing ACKNOWLEDGE call for status 258cb378-720c-423c-bc6d-ddcbbcf61153 for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 (default) at scheduler-128be5ca-d3da-4005-8a4d-74899674155c@172.17.0.2:39622 on agent ae12bc56-70ed-4039-9523-7528dedda882-S0
I1126 15:28:19.813511 19594 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.813681 19594 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_RUNNING (Status UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.814070 19594 slave.cpp:4510] Task status update manager successfully handled status update acknowledgement (UUID: 258cb378-720c-423c-bc6d-ddcbbcf61153) for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:19.814566 19594 slave.cpp:914] Agent terminating
I1126 15:28:20.221581 19573 hierarchical.cpp:1566] Performed allocation for 1 agents in 489317ns
I1126 15:28:20.330348 19590 master.cpp:1275] Agent ae12bc56-70ed-4039-9523-7528dedda882-S0 at slave@172.17.0.2:39622 (dad6f45cdec5) disconnected
I1126 15:28:20.330400 19590 master.cpp:3273] Disconnecting agent ae12bc56-70ed-4039-9523-7528dedda882-S0 at slave@172.17.0.2:39622 (dad6f45cdec5)
I1126 15:28:20.330476 19590 master.cpp:3292] Deactivating agent ae12bc56-70ed-4039-9523-7528dedda882-S0 at slave@172.17.0.2:39622 (dad6f45cdec5)
I1126 15:28:20.330827 19590 hierarchical.cpp:801] Agent ae12bc56-70ed-4039-9523-7528dedda882-S0 deactivated
I1126 15:28:20.331208 19281 containerizer.cpp:305] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1126 15:28:20.331969 19281 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1126 15:28:20.332165 19281 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1126 15:28:20.332216 19281 provisioner.cpp:298] Using default backend 'copy'
W1126 15:28:20.346771 19281 process.cpp:2829] Attempted to spawn already running process files@172.17.0.2:39622
I1126 15:28:20.347785 19281 cluster.cpp:485] Creating default 'local' authorizer
I1126 15:28:20.351017 19563 slave.cpp:268] Mesos agent started on @172.17.0.2:39622
I1126 15:28:20.351048 19563 slave.cpp:269] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_tcv7Pr/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_tcv7Pr/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_tcv7Pr/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_tcv7Pr/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_tcv7Pr/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_tcv7Pr/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_tcv7Pr" --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_ElIRUW" --zk_session_timeout="10secs"
I1126 15:28:20.351740 19563 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_tcv7Pr/credential'
I1126 15:28:20.351956 19563 slave.cpp:301] Agent using credential for: test-principal
I1126 15:28:20.351981 19563 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_tcv7Pr/http_credentials'
I1126 15:28:20.352254 19563 http.cpp:1017] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1126 15:28:20.352629 19563 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I1126 15:28:20.354315 19563 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"}]
I1126 15:28:20.354611 19563 slave.cpp:624] Agent attributes: [ ]
I1126 15:28:20.354629 19563 slave.cpp:633] Agent hostname: dad6f45cdec5
I1126 15:28:20.355134 19571 task_status_update_manager.cpp:181] Pausing sending task status updates
I1126 15:28:20.357574 19584 state.cpp:66] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/meta'
I1126 15:28:20.357710 19584 state.cpp:711] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/meta/resources/resources.info'
I1126 15:28:20.366531 19588 slave.cpp:6914] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_ElIRUW/meta', beginning agent recovery
I1126 15:28:20.367453 19588 slave.cpp:7393] Recovering framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:20.367671 19588 slave.cpp:9099] Recovering executor 'fa8d2385-bd09-4a08-b3d1-481379edf456' of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:20.369035 19571 task_status_update_manager.cpp:207] Recovering task status update manager
I1126 15:28:20.369102 19571 task_status_update_manager.cpp:215] Recovering executor 'fa8d2385-bd09-4a08-b3d1-481379edf456' of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:20.369268 19571 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task fa8d2385-bd09-4a08-b3d1-481379edf456 of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:20.370098 19571 task_status_update_manager.cpp:818] Replaying task status update stream for task fa8d2385-bd09-4a08-b3d1-481379edf456
I1126 15:28:20.371376 19571 containerizer.cpp:727] Recovering Mesos containers
I1126 15:28:20.371470 19571 containerizer.cpp:784] Recovering container f1cf2524-19dc-4211-94e6-47287d62a8f9 for executor 'fa8d2385-bd09-4a08-b3d1-481379edf456' of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:20.374248 19571 containerizer.cpp:1053] Recovering isolators
I1126 15:28:20.376107 19596 containerizer.cpp:1092] Recovering provisioner
I1126 15:28:20.376933 19567 provisioner.cpp:494] Provisioner recovery complete
I1126 15:28:20.379612 19600 composing.cpp:339] Finished recovering all containerizers
I1126 15:28:20.379806 19570 slave.cpp:7143] Recovering executors
I1126 15:28:20.379979 19570 slave.cpp:7167] Sending reconnect request to executor 'fa8d2385-bd09-4a08-b3d1-481379edf456' of framework ae12bc56-70ed-4039-9523-7528dedda882-0000 at executor(1)@172.17.0.2:40613
I1126 15:28:20.381788 27696 exec.cpp:282] Received reconnect request from agent ae12bc56-70ed-4039-9523-7528dedda882-S0
I1126 15:28:20.385470 19598 slave.cpp:4971] Received re-registration message from executor 'fa8d2385-bd09-4a08-b3d1-481379edf456' of framework ae12bc56-70ed-4039-9523-7528dedda882-0000
I1126 15:28:20.387068 27703 exec.cpp:259] Executor reregistered on agent ae12bc56-70ed-4039-9523-7528dedda882-S0
I1126 15:28:20.387883 19607 slave.cpp:5888] No pings from master received within 75secs
I1126 15:28:20.388152 19600 hierarchical.cpp:1566] Performed allocation for 1 agents in 304178ns
F1126 15:28:20.388432 19577 slave.cpp:1232] Check failed: state == DISCONNECTED || state == RUNNING || state == TERMINATING RECOVERING
*** Check failure stack trace: ***
I1126 15:28:20.391386 27703 executor.cpp:184] Received SUBSCRIBED event
I1126 15:28:20.391439 27703 executor.cpp:188] Subscribed executor on dad6f45cdec5
@ 0x2b1b1f664b08 google::LogMessage::Fail()
@ 0x2b1b1f664a54 google::LogMessage::SendToLog()
@ 0x2b1b1f664456 google::LogMessage::Flush()
@ 0x2b1b1f66736a google::LogMessageFatal::~LogMessageFatal()
@ 0x2b1b1e27183c mesos::internal::slave::Slave::detected()
@ 0x2b1b1e30558c _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEESB_EEvRKNS_3PIDIT_EEMSD_FvT0_EOT1_ENKUlOS9_PNS_11ProcessBaseEE_clESM_SO_
@ 0x2b1b1e3ad7e5 _ZN5cpp176invokeIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINS3_10MasterInfoEEEESD_EEvRKNS1_3PIDIT_EEMSF_FvT0_EOT1_EUlOSB_PNS1_11ProcessBaseEE_ISB_SQ_EEEDTclcl7forwardISF_Efp_Espcl7forwardIT0_Efp0_EEEOSF_DpOSS_
@ 0x2b1b1e3a4791 _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_
@ 0x2b1b1e39e7d1 _ZNO6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEEclIJSR_EEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOS10_
@ 0x2b1b1e39b649 _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS4_6FutureI6OptionINS6_10MasterInfoEEEESG_EEvRKNS4_3PIDIT_EEMSI_FvT0_EOT1_EUlOSE_PNS4_11ProcessBaseEE_ISE_St12_PlaceholderILi1EEEEEIST_EEEDTclcl7forwardISI_Efp_Espcl7forwardIT0_Efp0_EEEOSI_DpOSY_
@ 0x2b1b1e399957 _ZN6lambda8internal6InvokeIvEclINS0_7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS5_6FutureI6OptionINS7_10MasterInfoEEEESH_EEvRKNS5_3PIDIT_EEMSJ_FvT0_EOT1_EUlOSF_PNS5_11ProcessBaseEE_JSF_St12_PlaceholderILi1EEEEEJSU_EEEvOSJ_DpOT0_
@ 0x2b1b1e397811 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINSA_10MasterInfoEEEESK_EEvRKNS1_3PIDIT_EEMSM_FvT0_EOT1_EUlOSI_S3_E_ISI_St12_PlaceholderILi1EEEEEEclEOS3_
@ 0x2b1b1f585e49 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEEclES3_
@ 0x2b1b1f54f85f process::ProcessBase::consume()
@ 0x2b1b1f573b82 _ZNO7process13DispatchEvent7consumeEPNS_13EventConsumerE
@ 0x563e7967e578 process::ProcessBase::serve()
@ 0x2b1b1f54cb3c process::ProcessManager::resume()
@ 0x2b1b1f548fb6 _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
@ 0x2b1b1f56e9ce _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2b1b1f56dcef _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
@ 0x2b1b1f56ceae _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
@ 0x2b1b22425a60 (unknown)
@ 0x2b1b22b9c184 start_thread
@ 0x2b1b22eb003d (unknown)
I1126 15:28:21.270745 27697 exec.cpp:518] Agent exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with agent ae12bc56-70ed-4039-9523-7528dedda882-S0
I1126 15:43:21.271858 27694 exec.cpp:499] Recovery timeout of 15mins exceeded; Shutting down
I1126 15:43:21.272017 27694 exec.cpp:445] Executor asked to shutdown
I1126 15:43:21.272745 27701 executor.cpp:184] Received SHUTDOWN event
I1126 15:43:21.272825 27701 executor.cpp:805] Shutting down
I1126 15:43:21.272910 27701 executor.cpp:918] Sending SIGTERM to process tree at pid 27711
I1126 15:43:21.290020 27701 executor.cpp:931] Sent SIGTERM to the following process trees:
[
-+- 27711 sh -c sleep 1000
\--- 27724 sleep 1000
]
I1126 15:43:21.290055 27701 executor.cpp:935] Scheduling escalation to SIGKILL in 3secs from now
I1126 15:43:21.334916 27698 executor.cpp:1003] Command terminated with signal Terminated (pid: 27711)
W1126 15:43:21.340308 27708 process.cpp:1890] Failed to send 'mesos.internal.StatusUpdateMessage' to '172.17.0.2:39622', connect: Failed to connect to 172.17.0.2:39622: Connection refused
I1126 15:43:22.341408 27708 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-1543242008-3991
Untagged: mesos-1543242008-3991:latest
Deleted: sha256:cb11b3880ac010aab41394e4c7aded43851140b30d2b8c1cf06a8e06fda70a4b
Deleted: sha256:c6f86a289ec3b0a55983409df2500b44d3c1294e586c813e84d603eecc7147c7
Deleted: sha256:4a4eeb7dec0f39dc8b3b9bbbd2c7f6c2d0f0a369da0764c79c6053dd094629e8
Deleted: sha256:f981094eb03f45dd12856e4d8316f06a2c88622cc8f01214db5107fb68a2804e
Deleted: sha256:a4fee67df5e636c0794974b49fe0693fb56d4c197bd643b276a07b2389f5de33
Deleted: sha256:9f0c6c5cfa918ed593f6be0287b4f679004e3bb12f491da320fb6b379e86760b
Deleted: sha256:5c8f4523b27ad976f00c9a30ed29a25b5f1d3de9966f69df42b26b0a805b35c2
Deleted: sha256:d9f7185e9bb56e98af3eeb0c411cb12748f485df6ba7684f43e63497f3f57c32
Deleted: sha256:0753f8bd2f3b505eba637f323226ee196d5f27550e188063535164a298d194aa
Deleted: sha256:ebf7992f9f69299e9c6f453de6f217169d724f1438d6ce7fff308f4320acd11a
Deleted: sha256:05169d19f2af5465778436ff42ae195ff4044e7e78cf5d5b4aea128463282975
Deleted: sha256:c7e090adf08eb4f310602225cb4bd1d3c6e14188fee6b67bc568fd6f3d978be9
Deleted: sha256:4095bbce6f3c798c89546ca329b8a8bac73bb157f7bc5a41880df2b43a3d5f0e
Deleted: sha256:87f1cd26b40c2cc883af7702a1abb73cea9d628bd63e1329904789a5e1d93c87
Deleted: sha256:8cc2ef0f9e06e7747aafe1df6fd06b4e502bbccd44b527c03902ec37973e4f92
Deleted: sha256:ac687fe28ceacfa78869678c23eea724aedf9b5e21ac3f140d8d6fd0e9fe45b6
Deleted: sha256:01116c3c6b27281ad2bdff1c138a414b1db1e8bf89488557539241a6453ef4aa
Deleted: sha256:7c8f58a9fe8ae98109ecd4ccbdf2e57a4d59983ab614d35f8ae535df315a81d0
Deleted: sha256:c2f93692d9c12aa6849224b41117e2dcad25a9b5304cf55e36e960e794cb2677
Deleted: sha256:9cd7dce1ca8d3e99351fc0ad3437e12ca2c2717768be988ebb250f23de00cae4
Deleted: sha256:dd2007ee2e4fd5a4d887810690f179f14e51fe55bb011b7424613236ec94c36c
Deleted: sha256:a56bc63b15383b99afc759d9a29080be39e03db14740068a00f74ae14e8bea01
Deleted: sha256:98a28c4e76b5e66215e21ba6595059204baf757423cf02ac2f9332db8f47d03a
Deleted: sha256:51855ea4d2c5f3382790b69e79f0b401c8117c56cbe3733c549423f4722a0cb1
Deleted: sha256:2b604642fbf68be268578424ba9103f3596ea242181e2764dbe624f5884d69c2
Deleted: sha256:be9bc0f84ae81733d384c3500639a2ee6139ce03dfe5020102321f6be5da91e9
Deleted: sha256:6e36f3e134f9321cfec16b45c43d852cd679583ec62b51592b76b53934f7a164
Deleted: sha256:5e0bc72d936e14e8b06ceef82f2400385a5c5b0dfa6f12146623e6566be928bf
Deleted: sha256:431c8888bee920168cf4446899ebbaf5da779e0dd7ea91979ab923c1998d59e6
Deleted: sha256:d9160e843f939c3d2c5ab71214e9503fd01d5f6751cfd7400c08f7a58ba3abed
11-26-18_14:20:06 - Running <https://builds.apache.org/job/Mesos-Reviewbot/ws/support/verify-reviews.py>
Checking if review 69400 needs verification
Skipping blocking review 69400
Checking if review 69402 needs verification
Skipping blocking review 69402
Checking if review 69364 needs verification
Skipping blocking review 69364
Checking if review 69365 needs verification
Skipping blocking review 69365
Checking if review 69436 needs verification
Patch never verified, needs verification
Verifying review 69436
Applying review 69436
/usr/bin/python3 support/apply-reviews.py -n -r 69436
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_69436"]' 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