mesos-reviews mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Mesos Reviewbot <revi...@mesos.apache.org>
Subject Re: Review Request 72858: Reduced build parallelism to avoid aborted builds in CI.
Date Thu, 10 Sep 2020 16:23:46 GMT

-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72858/#review221850
-----------------------------------------------------------



Bad patch!

Reviews applied: [72856, 72857, 72858]

Failed command: ['bash', '-c', "set -o pipefail; export OS='ubuntu:16.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/jenkins/buildbot.sh 2>&1 | tee build_72858"]

Error:
...<truncated>...
ff_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/pEXd2f/baTpbz/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/pEXd2f/baTpbz/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_r
 egistration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/pEXd2f/baTpbz/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/pEXd2f/baTpbz/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/pEXd2f/baTpbz/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/tmp/SRC/build/mesos-1.11.0/_build/sub/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --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_ReconnectExecutorRetry_jgNk87" --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_ReconnectExecutorRetry_poBg5G" --zk_session_timeout="10secs"
I0910 16:23:24.395692  5494 credentials.hpp:73] Loading credential for authentication from '/tmp/pEXd2f/baTpbz/credential'
I0910 16:23:24.395958  5494 slave.cpp:314] Agent using credential for: test-principal
I0910 16:23:24.396001  5494 credentials.hpp:37] Loading credentials for authentication from '/tmp/pEXd2f/baTpbz/http_credentials'
I0910 16:23:24.396335  5494 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
W0910 16:23:24.396414  5488 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:43909
I0910 16:23:24.396939  5494 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0910 16:23:24.398557  5488 sched.cpp:239] Version: 1.11.0
I0910 16:23:24.399698  5499 sched.cpp:343] New master detected at master@172.17.0.2:43909
I0910 16:23:24.399467  5494 slave.cpp:629] 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"}]
I0910 16:23:24.399878  5494 slave.cpp:637] Agent attributes: [  ]
I0910 16:23:24.399910  5494 slave.cpp:646] Agent hostname: 7a0b504a5d17
I0910 16:23:24.399912  5499 sched.cpp:408] Authenticating with master master@172.17.0.2:43909
I0910 16:23:24.399950  5499 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0910 16:23:24.400215  5489 task_status_update_manager.cpp:181] Pausing sending task status updates
I0910 16:23:24.400238  5509 status_update_manager_process.hpp:379] Pausing operation status update manager
I0910 16:23:24.400499  5497 authenticatee.cpp:121] Creating new client SASL connection
I0910 16:23:24.401062  5495 master.cpp:9738] Authenticating scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909
I0910 16:23:24.401293  5503 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1097)@172.17.0.2:43909
I0910 16:23:24.401834  5507 authenticator.cpp:98] Creating new server SASL connection
I0910 16:23:24.402223  5505 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0910 16:23:24.402287  5505 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0910 16:23:24.402484  5505 authenticator.cpp:204] Received SASL authentication start
I0910 16:23:24.402593  5505 authenticator.cpp:326] Authentication requires more steps
I0910 16:23:24.402886  5500 authenticatee.cpp:259] Received SASL authentication step
I0910 16:23:24.403208  5498 authenticator.cpp:232] Received SASL authentication step
I0910 16:23:24.403316  5498 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7a0b504a5d17' server FQDN: '7a0b504a5d17' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0910 16:23:24.403324  5500 state.cpp:68] Recovering state from '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta'
I0910 16:23:24.403358  5498 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0910 16:23:24.403475  5498 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0910 16:23:24.403533  5498 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7a0b504a5d17' server FQDN: '7a0b504a5d17' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0910 16:23:24.403573  5498 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0910 16:23:24.403594  5498 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0910 16:23:24.403642  5498 authenticator.cpp:318] Authentication success
I0910 16:23:24.403761  5493 slave.cpp:7741] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta', beginning agent recovery
I0910 16:23:24.403858  5502 authenticatee.cpp:299] Authentication success
I0910 16:23:24.404009  5501 master.cpp:9770] Successfully authenticated principal 'test-principal' at scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909
I0910 16:23:24.404095  5511 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1097)@172.17.0.2:43909
I0910 16:23:24.404522  5500 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:43909
I0910 16:23:24.404579  5500 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:43909
I0910 16:23:24.404626  5511 task_status_update_manager.cpp:207] Recovering task status update manager
I0910 16:23:24.404901  5500 sched.cpp:870] Will retry registration in 1.776438899secs if necessary
I0910 16:23:24.405261  5512 master.cpp:2944] Received SUBSCRIBE call for framework 'default' at scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909
I0910 16:23:24.405354  5503 containerizer.cpp:830] Recovering Mesos containers
I0910 16:23:24.405838  5503 containerizer.cpp:1170] Recovering isolators
I0910 16:23:24.406950  5501 containerizer.cpp:1209] Recovering provisioner
I0910 16:23:24.408069  5502 provisioner.cpp:518] Provisioner recovery complete
I0910 16:23:24.409505  5506 composing.cpp:343] Finished recovering all containerizers
I0910 16:23:24.409817  5490 master.cpp:3027] Subscribing framework default with checkpointing enabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0910 16:23:24.410102  5503 slave.cpp:8223] Recovering executors
I0910 16:23:24.410331  5503 slave.cpp:8376] Finished recovery
I0910 16:23:24.411686  5499 status_update_manager_process.hpp:379] Pausing operation status update manager
I0910 16:23:24.411720  5491 task_status_update_manager.cpp:181] Pausing sending task status updates
I0910 16:23:24.411790  5496 slave.cpp:1473] New master detected at master@172.17.0.2:43909
I0910 16:23:24.411926  5496 slave.cpp:1538] Detecting new master
I0910 16:23:24.412735  5490 master.cpp:9969] Adding framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 (default) at scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909 with roles {  } suppressed
I0910 16:23:24.413594  5502 sched.cpp:751] Framework registered with 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:24.413697  5502 sched.cpp:770] Scheduler::registered took 45603ns
I0910 16:23:24.414141  5493 hierarchical.cpp:774] Added framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:24.414604  5493 hierarchical.cpp:1935] Performed allocation for 0 agents in 185096ns
I0910 16:23:24.419281  5508 slave.cpp:1565] Authenticating with master master@172.17.0.2:43909
I0910 16:23:24.419435  5508 slave.cpp:1574] Using default CRAM-MD5 authenticatee
I0910 16:23:24.419878  5505 authenticatee.cpp:121] Creating new client SASL connection
I0910 16:23:24.420354  5511 master.cpp:9738] Authenticating slave(540)@172.17.0.2:43909
I0910 16:23:24.420598  5498 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1098)@172.17.0.2:43909
I0910 16:23:24.421105  5495 authenticator.cpp:98] Creating new server SASL connection
I0910 16:23:24.421494  5504 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0910 16:23:24.421569  5504 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0910 16:23:24.421844  5492 authenticator.cpp:204] Received SASL authentication start
I0910 16:23:24.421936  5492 authenticator.cpp:326] Authentication requires more steps
I0910 16:23:24.422137  5507 authenticatee.cpp:259] Received SASL authentication step
I0910 16:23:24.422343  5507 authenticator.cpp:232] Received SASL authentication step
I0910 16:23:24.422394  5507 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7a0b504a5d17' server FQDN: '7a0b504a5d17' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0910 16:23:24.422420  5507 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0910 16:23:24.422473  5507 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0910 16:23:24.422519  5507 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7a0b504a5d17' server FQDN: '7a0b504a5d17' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0910 16:23:24.422542  5507 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0910 16:23:24.422560  5507 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0910 16:23:24.422588  5507 authenticator.cpp:318] Authentication success
I0910 16:23:24.422765  5506 authenticatee.cpp:299] Authentication success
I0910 16:23:24.422864  5512 master.cpp:9770] Successfully authenticated principal 'test-principal' at slave(540)@172.17.0.2:43909
I0910 16:23:24.422900  5503 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1098)@172.17.0.2:43909
I0910 16:23:24.423554  5510 slave.cpp:1665] Successfully authenticated with master master@172.17.0.2:43909
I0910 16:23:24.424376  5510 slave.cpp:2131] Will retry registration in 13.341339ms if necessary
I0910 16:23:24.424621  5489 master.cpp:6232] Received register agent message from slave(540)@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:24.425324  5489 master.cpp:3763] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I0910 16:23:24.426219  5493 master.cpp:6299] Authorized registration of agent at slave(540)@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:24.426378  5493 master.cpp:6411] Registering agent at slave(540)@172.17.0.2:43909 (7a0b504a5d17) with id 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0
I0910 16:23:24.427553  5497 registrar.cpp:487] Applied 1 operations in 509671ns; attempting to update the registry
I0910 16:23:24.428689  5497 registrar.cpp:544] Successfully updated the registry in 1.027072ms
I0910 16:23:24.429035  5498 master.cpp:6459] Admitted agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 at slave(540)@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:24.430294  5498 master.cpp:6504] Registered agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 at slave(540)@172.17.0.2:43909 (7a0b504a5d17) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0910 16:23:24.430435  5504 slave.cpp:1698] Registered with master master@172.17.0.2:43909; given agent ID 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0
I0910 16:23:24.430527  5492 hierarchical.cpp:1041] Added agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 (7a0b504a5d17) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I0910 16:23:24.430650  5507 task_status_update_manager.cpp:188] Resuming sending task status updates
I0910 16:23:24.431253  5504 slave.cpp:1733] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/slave.info'
I0910 16:23:24.431380  5499 status_update_manager_process.hpp:385] Resuming operation status update manager
I0910 16:23:24.432569  5492 hierarchical.cpp:1935] Performed allocation for 1 agents in 1.740475ms
I0910 16:23:24.433615  5501 master.cpp:9547] Sending offers [ 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-O0 ] to framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 (default) at scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909
I0910 16:23:24.433624  5504 slave.cpp:1793] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"inAMgXPdSvmVHRzW8IsHYg=="},"slave_id":{"value":"1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0"},"update_oversubscribed_resources":false}
I0910 16:23:24.434196  5490 sched.cpp:934] Scheduler::resourceOffers took 87747ns
I0910 16:23:24.434494  5501 master.cpp:7646] Ignoring update on agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 at slave(540)@172.17.0.2:43909 (7a0b504a5d17) as it reports no changes
I0910 16:23:24.437266  5505 master.cpp:4325] Processing ACCEPT call for offers: [ 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-O0 ] on agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 at slave(540)@172.17.0.2:43909 (7a0b504a5d17) for framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 (default) at scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909
I0910 16:23:24.438174  5505 master.cpp:11841] Removing offer 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-O0
I0910 16:23:24.441416  5505 master.cpp:3868] Adding task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 with resources ports(allocated: *):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 (default) at scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909 on agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 at slave(540)@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:24.442611  5505 master.cpp:5004] Launching task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 (default) at scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909 with resources [{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"},{"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"}] on agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 at slave(540)@172.17.0.2:43909 (7a0b504a5d17) on  new executor
I0910 16:23:24.443526  5511 hierarchical.cpp:1859] Allocation paused
I0910 16:23:24.444391  5511 hierarchical.cpp:1869] Allocation resumed
I0910 16:23:24.445120  5500 slave.cpp:2300] Got assigned task '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' for framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:24.445400  5500 slave.cpp:10290] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/framework.info'
I0910 16:23:24.446161  5500 slave.cpp:10301] Checkpointing framework pid 'scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909' to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/framework.pid'
I0910 16:23:24.448940  5500 slave.cpp:2707] Authorizing task '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' for framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:24.449079  5500 slave.cpp:9715] Authorizing framework principal 'test-principal' to launch task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6
I0910 16:23:24.452524  5499 slave.cpp:3181] Launching task '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' for framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:24.452651  5499 paths.cpp:832] Creating sandbox '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848' for user 'mesos'
I0910 16:23:24.453511  5499 slave.cpp:11081] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/executor.info'
I0910 16:23:24.574898  5499 paths.cpp:835] Creating sandbox '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848'
I0910 16:23:24.575561  5499 slave.cpp:10379] Launching executor '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-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_ReconnectExecutorRetry_poBg5G/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848'
I0910 16:23:24.578106  5499 slave.cpp:11121] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848/tasks/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/task.info'
I0910 16:23:24.579656  5499 slave.cpp:3415] Queued task '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' for executor '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:24.579862  5499 slave.cpp:1206] Successfully attached '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848' to virtual path '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/latest'
I0910 16:23:24.579952  5499 slave.cpp:1206] Successfully attached '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848' to virtual path '/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/latest'
I0910 16:23:24.580029  5499 slave.cpp:1206] Successfully attached '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848' to virtual path '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848'
I0910 16:23:24.581089  5499 slave.cpp:3876] Launching container 3149456f-2cec-4590-9585-f2b74c55c848 for executor '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:24.582294  5510 containerizer.cpp:1405] Starting container 3149456f-2cec-4590-9585-f2b74c55c848
I0910 16:23:24.583274  5510 containerizer.cpp:3414] Transitioning the state of container 3149456f-2cec-4590-9585-f2b74c55c848 from STARTING to PROVISIONING after 0ns
I0910 16:23:24.584874  5510 containerizer.cpp:1584] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_jgNk87/containers/3149456f-2cec-4590-9585-f2b74c55c848/config'
I0910 16:23:24.584949  5510 containerizer.cpp:3414] Transitioning the state of container 3149456f-2cec-4590-9585-f2b74c55c848 from PROVISIONING to PREPARING after 0ns
I0910 16:23:24.596074  5501 containerizer.cpp:2110] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/tmp/SRC/build/mesos-1.11.0/_build/sub/src"],"shell":false,"value":"/tmp/SRC/build/mesos-1.11.0/_build/sub/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:43909"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"4b6c5b4b-6b35-4628-8dc1-363d8e8392b6"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"
 MESOS_FRAMEWORK_ID","type":"VALUE","value":"1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-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":"1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(540)@172.17.0.2:43909"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"2secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-
 4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848"}" --pipe_read="28" --pipe_write="31" --runtime_directory="/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_jgNk87/containers/3149456f-2cec-4590-9585-f2b74c55c848" --unshare_namespace_mnt="false"'
I0910 16:23:24.605610  5501 launcher.cpp:145] Forked child with pid '12398' for container '3149456f-2cec-4590-9585-f2b74c55c848'
I0910 16:23:24.605877  5501 containerizer.cpp:2219] Checkpointing container's forked pid 12398 to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848/pids/forked.pid'
I0910 16:23:24.607530  5501 containerizer.cpp:3414] Transitioning the state of container 3149456f-2cec-4590-9585-f2b74c55c848 from PREPARING to ISOLATING after 0ns
I0910 16:23:24.611235  5501 containerizer.cpp:3414] Transitioning the state of container 3149456f-2cec-4590-9585-f2b74c55c848 from ISOLATING to FETCHING after 0ns
I0910 16:23:24.611791  5499 fetcher.cpp:369] Starting to fetch URIs for container: 3149456f-2cec-4590-9585-f2b74c55c848, directory: /tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848
I0910 16:23:24.613343  5502 containerizer.cpp:3414] Transitioning the state of container 3149456f-2cec-4590-9585-f2b74c55c848 from FETCHING to RUNNING after 0ns
I0910 16:23:25.251701 12412 exec.cpp:164] Version: 1.11.0
I0910 16:23:25.270285  5497 slave.cpp:5487] Got registration for executor '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 from executor(1)@172.17.0.2:33867
I0910 16:23:25.271232  5497 slave.cpp:5573] Checkpointing executor pid 'executor(1)@172.17.0.2:33867' to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta/slaves/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0/frameworks/1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000/executors/4b6c5b4b-6b35-4628-8dc1-363d8e8392b6/runs/3149456f-2cec-4590-9585-f2b74c55c848/pids/libprocess.pid'
I0910 16:23:25.276923  5501 slave.cpp:3641] Sending queued task '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' to executor '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 at executor(1)@172.17.0.2:33867
I0910 16:23:25.277349 12419 exec.cpp:237] Executor registered on agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0
I0910 16:23:25.283964 12406 executor.cpp:190] Received SUBSCRIBED event
I0910 16:23:25.287564 12406 executor.cpp:194] Subscribed executor on 7a0b504a5d17
I0910 16:23:25.288185 12406 executor.cpp:190] Received LAUNCH event
I0910 16:23:25.292143 12406 executor.cpp:722] Starting task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6
I0910 16:23:25.297200  5499 slave.cpp:5980] Handling status update TASK_STARTING (Status UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 from executor(1)@172.17.0.2:33867
I0910 16:23:25.300735  5498 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.300832  5498 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.302047  5498 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.302498  5498 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 to the agent
I0910 16:23:25.302933  5506 slave.cpp:6526] Forwarding the update TASK_STARTING (Status UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 to master@172.17.0.2:43909
I0910 16:23:25.303454  5506 slave.cpp:6410] Task status update manager successfully handled status update TASK_STARTING (Status UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.303675  5506 slave.cpp:6437] Sending acknowledgement for status update TASK_STARTING (Status UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 to executor(1)@172.17.0.2:33867
I0910 16:23:25.303714  5512 master.cpp:8128] Status update TASK_STARTING (Status UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 from agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 at slave(540)@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:25.303834  5512 master.cpp:8185] Forwarding status update TASK_STARTING (Status UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.304458  5512 master.cpp:11158] Updating the state of task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I0910 16:23:25.304915  5510 sched.cpp:1042] Scheduler::statusUpdate took 116595ns
I0910 16:23:25.305511  5492 master.cpp:5839] Processing ACKNOWLEDGE call for status 577508c3-1927-41ed-b903-54770286b9b8 for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 (default) at scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909 on agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0
I0910 16:23:25.306378  5507 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.306639  5507 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.307299  5503 slave.cpp:5089] Task status update manager successfully handled status update acknowledgement (UUID: 577508c3-1927-41ed-b903-54770286b9b8) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.313413  5488 slave.cpp:1002] Agent terminating
I0910 16:23:25.315143  5491 master.cpp:1297] Agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 at slave(540)@172.17.0.2:43909 (7a0b504a5d17) disconnected
I0910 16:23:25.315202  5491 master.cpp:3431] Disconnecting agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 at slave(540)@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:25.315349  5491 master.cpp:3450] Deactivating agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 at slave(540)@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:25.315443  5488 containerizer.cpp:320] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I0910 16:23:25.315675  5505 hierarchical.cpp:1238] Agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 deactivated
W0910 16:23:25.316618  5488 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0910 16:23:25.316671  5488 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0910 16:23:25.316704  5488 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0910 16:23:25.316766  5488 provisioner.cpp:294] Using default backend 'copy'
W0910 16:23:25.330449  5488 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:43909
I0910 16:23:25.331223  5488 resolver.cpp:69] Creating default secret resolver
I0910 16:23:25.331446  5488 cluster.cpp:620] Creating default 'local' authorizer
I0910 16:23:25.335580  5505 slave.cpp:281] Mesos agent started on (541)@172.17.0.2:43909
I0910 16:23:25.335633  5505 slave.cpp:282] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/pEXd2f/baTpbz/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/pEXd2f/baTpbz/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/pEXd2f/baTpbz/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_retry_interval="1secs" --executor_reregistration_timeout="5secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/pEXd2f/baTpbz/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/pEXd2f/baTpbz/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/pEXd2f/baTpbz/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_d
 ir="/tmp/SRC/build/mesos-1.11.0/_build/sub/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --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_ReconnectExecutorRetry_jgNk87" --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_ReconnectExecutorRetry_poBg5G" --zk_session_timeout="10secs"
I0910 16:23:25.336880  5505 credentials.hpp:73] Loading credential for authentication from '/tmp/pEXd2f/baTpbz/credential'
I0910 16:23:25.337211  5505 slave.cpp:314] Agent using credential for: test-principal
I0910 16:23:25.337262  5505 credentials.hpp:37] Loading credentials for authentication from '/tmp/pEXd2f/baTpbz/http_credentials'
I0910 16:23:25.337751  5505 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0910 16:23:25.338588  5505 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0910 16:23:25.340721  5505 slave.cpp:629] 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"}]
I0910 16:23:25.341076  5505 slave.cpp:637] Agent attributes: [  ]
I0910 16:23:25.341104  5505 slave.cpp:646] Agent hostname: 7a0b504a5d17
I0910 16:23:25.341435  5498 status_update_manager_process.hpp:379] Pausing operation status update manager
I0910 16:23:25.341444  5491 task_status_update_manager.cpp:181] Pausing sending task status updates
I0910 16:23:25.344177  5503 state.cpp:68] Recovering state from '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta'
I0910 16:23:25.344300  5503 state.cpp:913] No committed checkpointed resources and operations found at '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta/resources/resources_and_operations.state'
I0910 16:23:25.344349  5503 state.cpp:919] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta/resources/resources.info'
I0910 16:23:25.350272  5499 slave.cpp:7741] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_poBg5G/meta', beginning agent recovery
I0910 16:23:25.351624 12406 executor.cpp:740] Forked command at 12426
I0910 16:23:25.352025  5499 slave.cpp:8473] Recovering framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.352216  5499 slave.cpp:10497] Recovering executor '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.354575  5494 task_status_update_manager.cpp:207] Recovering task status update manager
I0910 16:23:25.354614  5494 task_status_update_manager.cpp:215] Recovering executor '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.354707  5494 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.355444  5494 task_status_update_manager.cpp:818] Replaying task status update stream for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6
I0910 16:23:25.356665  5513 process.cpp:2678] Failed to deliver libprocess message to /slave(540)/mesos.internal.StatusUpdateMessage
I0910 16:23:25.357831  5506 containerizer.cpp:830] Recovering Mesos containers
I0910 16:23:25.358008  5506 containerizer.cpp:887] Recovering container 3149456f-2cec-4590-9585-f2b74c55c848 for executor '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.361109  5506 containerizer.cpp:1170] Recovering isolators
I0910 16:23:25.363436  5507 containerizer.cpp:1209] Recovering provisioner
I0910 16:23:25.364593  5508 provisioner.cpp:518] Provisioner recovery complete
I0910 16:23:25.367888  5492 composing.cpp:343] Finished recovering all containerizers
I0910 16:23:25.368949  5506 status_update_manager_process.hpp:314] Recovering operation status update manager
I0910 16:23:25.369737  5511 slave.cpp:8223] Recovering executors
I0910 16:23:25.369956  5511 slave.cpp:8247] Sending reconnect request to executor '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 at executor(1)@172.17.0.2:33867
I0910 16:23:25.372189 12408 exec.cpp:283] Received reconnect request from agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0
I0910 16:23:25.464372  5512 slave.cpp:8302] Re-sending reconnect request to executor '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 at executor(1)@172.17.0.2:33867
I0910 16:23:25.464720  5510 hierarchical.cpp:1935] Performed allocation for 1 agents in 256195ns
I0910 16:23:25.466007 12409 exec.cpp:283] Received reconnect request from agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0
I0910 16:23:25.470340  5495 slave.cpp:5663] Received re-registration message from executor '4b6c5b4b-6b35-4628-8dc1-363d8e8392b6' of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.471562  5495 slave.cpp:5980] Handling status update TASK_RUNNING (Status UUID: b14b1bd2-9e28-4d17-81e4-b7f52f5c1509) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 from executor(1)@172.17.0.2:33867
I0910 16:23:25.473213 12415 exec.cpp:260] Executor reregistered on agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0
I0910 16:23:25.475877  5499 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: b14b1bd2-9e28-4d17-81e4-b7f52f5c1509) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.476043  5499 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: b14b1bd2-9e28-4d17-81e4-b7f52f5c1509) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.476773  5504 slave.cpp:6410] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: b14b1bd2-9e28-4d17-81e4-b7f52f5c1509) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.477033  5504 slave.cpp:6437] Sending acknowledgement for status update TASK_RUNNING (Status UUID: b14b1bd2-9e28-4d17-81e4-b7f52f5c1509) for task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 to executor(1)@172.17.0.2:33867
II0910 16:23:25.478139 12420 executor.cpp:190] Received SUBSCRIBED event
0910 16:23:25.478144  5511 hierarchical.cpp:1935] Performed allocation for 1 agents in 200844ns
I0910 16:23:25.478193 12420 executor.cpp:194] Subscribed executor on 7a0b504a5d17
I0910 16:23:25.478914  5488 sched.cpp:2166] Asked to stop the driver
I0910 16:23:25.479140  5495 sched.cpp:1204] Stopping framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.479758  5508 master.cpp:10330] Processing TEARDOWN call for framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 (default) at scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909
I0910 16:23:25.479823  5508 master.cpp:10342] Removing framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 (default) at scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909
I0910 16:23:25.479856  5508 master.cpp:3396] Deactivating framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 (default) at scheduler-9a950df1-8e50-480e-8092-969a7e2ae5eb@172.17.0.2:43909
I0910 16:23:25.479907  5503 hierarchical.cpp:1935] Performed allocation for 1 agents in 133182ns
I0910 16:23:25.480298  5508 master.cpp:11158] Updating the state of task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
I0910 16:23:25.480331  5503 hierarchical.cpp:887] Deactivated framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.480890  5500 slave.cpp:1002] Agent terminating
I0910 16:23:25.481817  5508 master.cpp:11258] Removing task 4b6c5b4b-6b35-4628-8dc1-363d8e8392b6 with resources ports(allocated: *):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024 of framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000 on agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 at slave(540)@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:25.482543  5491 hierarchical.cpp:1658] Recovered ports(allocated: *):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], offered or allocated: {}) on agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0 from framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.482964  5498 containerizer.cpp:2716] Destroying container 3149456f-2cec-4590-9585-f2b74c55c848 in RUNNING state
I0910 16:23:25.483043  5498 containerizer.cpp:3414] Transitioning the state of container 3149456f-2cec-4590-9585-f2b74c55c848 from RUNNING to DESTROYING after 3.048333056secs
I0910 16:23:25.483656  5498 launcher.cpp:161] Asked to destroy container 3149456f-2cec-4590-9585-f2b74c55c848
I0910 16:23:25.484069  5491 hierarchical.cpp:1859] Allocation paused
I0910 16:23:25.484625  5491 hierarchical.cpp:831] Removed framework 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-0000
I0910 16:23:25.484699  5491 hierarchical.cpp:1869] Allocation resumed
I0910 16:23:25.582197  5501 containerizer.cpp:3252] Container 3149456f-2cec-4590-9585-f2b74c55c848 has exited
I0910 16:23:25.586683  5491 provisioner.cpp:652] Ignoring destroy request for unknown container 3149456f-2cec-4590-9585-f2b74c55c848
I0910 16:23:25.603343  5488 master.cpp:1145] Master terminating
I0910 16:23:25.603876  5500 hierarchical.cpp:1214] Removed all filters for agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0
I0910 16:23:25.603929  5500 hierarchical.cpp:1090] Removed agent 1fa8b3a7-5e71-4399-ab5d-5445f47d5d58-S0
[       OK ] SlaveRecoveryTest/0.ReconnectExecutorRetry (1264 ms)
[ RUN      ] SlaveRecoveryTest/0.PingTimeoutDuringRecovery
I0910 16:23:25.620960  5488 cluster.cpp:195] Creating default 'local' authorizer
I0910 16:23:25.628938  5495 master.cpp:448] Master d39494b1-36d4-43d0-9f15-008c0255dad8 (7a0b504a5d17) started on 172.17.0.2:43909
I0910 16:23:25.628996  5495 master.cpp:451] Flags at startup: --acls="" --agent_ping_timeout="1secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/4BW46m/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="2" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_alloca
 table_resources="cpus:0.01|mem:32" --offer_constraints_re2_max_mem="4KB" --offer_constraints_re2_max_program_size="100" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.11.0/_inst/share/mesos/webui" --work_dir="/tmp/4BW46m/master" --zk_session_timeout="10secs"
I0910 16:23:25.629729  5495 master.cpp:500] Master only allowing authenticated frameworks to register
I0910 16:23:25.629760  5495 master.cpp:506] Master only allowing authenticated agents to register
I0910 16:23:25.629776  5495 master.cpp:512] Master only allowing authenticated HTTP frameworks to register
I0910 16:23:25.629798  5495 credentials.hpp:37] Loading credentials for authentication from '/tmp/4BW46m/credentials'
I0910 16:23:25.630302  5495 master.cpp:556] Using default 'crammd5' authenticator
I0910 16:23:25.630662  5495 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0910 16:23:25.631012  5495 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0910 16:23:25.631325  5495 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0910 16:23:25.631595  5495 master.cpp:637] Authorization enabled
I0910 16:23:25.632230  5512 whitelist_watcher.cpp:77] No whitelist given
I0910 16:23:25.632246  5509 hierarchical.cpp:637] Initialized hierarchical allocator process
I0910 16:23:25.637531  5511 master.cpp:2170] Elected as the leading master!
I0910 16:23:25.637583  5511 master.cpp:1666] Recovering from registrar
I0910 16:23:25.637861  5491 registrar.cpp:339] Recovering registrar
I0910 16:23:25.639277  5491 registrar.cpp:383] Successfully fetched the registry (0B) in 1.31712ms
I0910 16:23:25.639556  5491 registrar.cpp:487] Applied 1 operations in 92465ns; attempting to update the registry
I0910 16:23:25.640769  5491 registrar.cpp:544] Successfully updated the registry in 1.07904ms
I0910 16:23:25.641033  5491 registrar.cpp:416] Successfully recovered registrar
I0910 16:23:25.641834  5505 master.cpp:1819] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I0910 16:23:25.641944  5497 hierarchical.cpp:676] Skipping recovery of hierarchical allocator: nothing to recover
I0910 16:23:25.647320  5488 containerizer.cpp:320] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0910 16:23:25.648255  5488 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0910 16:23:25.648304  5488 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0910 16:23:25.648332  5488 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0910 16:23:25.648382  5488 provisioner.cpp:294] Using default backend 'copy'
W0910 16:23:25.656985  5488 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:43909
I0910 16:23:25.658052  5488 resolver.cpp:69] Creating default secret resolver
I0910 16:23:25.658175  5488 cluster.cpp:620] Creating default 'local' authorizer
I0910 16:23:25.660594  5512 slave.cpp:281] Mesos agent started on @172.17.0.2:43909
I0910 16:23:25.660624  5512 slave.cpp:282] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/4BW46m/UGVLZO/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/4BW46m/UGVLZO/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/4BW46m/UGVLZO/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="15secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/4BW46m/UGVLZO/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/4BW46m/UGVLZO/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/4BW46m/UGVLZO/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/tmp/SRC/build/mesos-1.11.0/_build/sub/src" 
 --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --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_sV3b2k" --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_GSWC4Q" --zk_session_timeout="10secs"
I0910 16:23:25.661371  5512 credentials.hpp:73] Loading credential for authentication from '/tmp/4BW46m/UGVLZO/credential'
W0910 16:23:25.661531  5488 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:43909
I0910 16:23:25.661626  5512 slave.cpp:314] Agent using credential for: test-principal
I0910 16:23:25.661669  5512 credentials.hpp:37] Loading credentials for authentication from '/tmp/4BW46m/UGVLZO/http_credentials'
I0910 16:23:25.662067  5512 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0910 16:23:25.662658  5512 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0910 16:23:25.663270  5488 sched.cpp:239] Version: 1.11.0
I0910 16:23:25.664443  5506 sched.cpp:343] New master detected at master@172.17.0.2:43909
I0910 16:23:25.664641  5506 sched.cpp:408] Authenticating with master master@172.17.0.2:43909
I0910 16:23:25.664678  5506 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0910 16:23:25.664893  5512 slave.cpp:629] 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"}]
I0910 16:23:25.665235  5499 authenticatee.cpp:121] Creating new client SASL connection
I0910 16:23:25.665298  5512 slave.cpp:637] Agent attributes: [  ]
I0910 16:23:25.665325  5512 slave.cpp:646] Agent hostname: 7a0b504a5d17
I0910 16:23:25.665609  5506 task_status_update_manager.cpp:181] Pausing sending task status updates
I0910 16:23:25.665689  5491 status_update_manager_process.hpp:379] Pausing operation status update manager
I0910 16:23:25.665760  5505 master.cpp:9738] Authenticating scheduler-9d8f93f2-88c8-4a29-aea4-5224c456d606@172.17.0.2:43909
I0910 16:23:25.666059  5490 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1099)@172.17.0.2:43909
I0910 16:23:25.666558  5503 authenticator.cpp:98] Creating new server SASL connection
I0910 16:23:25.666958  5509 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0910 16:23:25.667017  5509 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0910 16:23:25.667331  5497 authenticator.cpp:204] Received SASL authentication start
I0910 16:23:25.667445  5497 authenticator.cpp:326] Authentication requires more steps
I0910 16:23:25.667726  5508 authenticatee.cpp:259] Received SASL authentication step
I0910 16:23:25.668056  5495 authenticator.cpp:232] Received SASL authentication step
I0910 16:23:25.668140  5495 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7a0b504a5d17' server FQDN: '7a0b504a5d17' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0910 16:23:25.668200  5495 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0910 16:23:25.668294  5495 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0910 16:23:25.668349  5495 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7a0b504a5d17' server FQDN: '7a0b504a5d17' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0910 16:23:25.668387  5504 state.cpp:68] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta'
I0910 16:23:25.668399  5495 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0910 16:23:25.668488  5495 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0910 16:23:25.668555  5495 authenticator.cpp:318] Authentication success
I0910 16:23:25.668669  5511 slave.cpp:7741] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta', beginning agent recovery
I0910 16:23:25.668781  5510 authenticatee.cpp:299] Authentication success
I0910 16:23:25.668959  5500 master.cpp:9770] Successfully authenticated principal 'test-principal' at scheduler-9d8f93f2-88c8-4a29-aea4-5224c456d606@172.17.0.2:43909
I0910 16:23:25.669091  5502 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1099)@172.17.0.2:43909
I0910 16:23:25.669378  5492 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:43909
I0910 16:23:25.669418  5492 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:43909
I0910 16:23:25.669454  5499 task_status_update_manager.cpp:207] Recovering task status update manager
I0910 16:23:25.669600  5492 sched.cpp:870] Will retry registration in 507.324835ms if necessary
I0910 16:23:25.669983  5490 containerizer.cpp:830] Recovering Mesos containers
I0910 16:23:25.670051  5496 master.cpp:2944] Received SUBSCRIBE call for framework 'default' at scheduler-9d8f93f2-88c8-4a29-aea4-5224c456d606@172.17.0.2:43909
I0910 16:23:25.670406  5490 containerizer.cpp:1170] Recovering isolators
I0910 16:23:25.671555  5495 containerizer.cpp:1209] Recovering provisioner
I0910 16:23:25.672983  5498 provisioner.cpp:518] Provisioner recovery complete
I0910 16:23:25.674372  5499 composing.cpp:343] Finished recovering all containerizers
I0910 16:23:25.674892  5503 slave.cpp:8223] Recovering executors
I0910 16:23:25.675012  5505 master.cpp:3027] Subscribing framework default with checkpointing enabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0910 16:23:25.675086  5503 slave.cpp:8376] Finished recovery
I0910 16:23:25.676431  5490 task_status_update_manager.cpp:181] Pausing sending task status updates
I0910 16:23:25.676470  5493 slave.cpp:1473] New master detected at master@172.17.0.2:43909
I0910 16:23:25.676520  5495 status_update_manager_process.hpp:379] Pausing operation status update manager
I0910 16:23:25.676594  5493 slave.cpp:1538] Detecting new master
I0910 16:23:25.678316  5505 master.cpp:9969] Adding framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 (default) at scheduler-9d8f93f2-88c8-4a29-aea4-5224c456d606@172.17.0.2:43909 with roles {  } suppressed
I0910 16:23:25.679323  5496 sched.cpp:751] Framework registered with d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:25.679432  5496 sched.cpp:770] Scheduler::registered took 48936ns
I0910 16:23:25.679836  5500 hierarchical.cpp:774] Added framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:25.680279  5500 hierarchical.cpp:1935] Performed allocation for 0 agents in 156497ns
I0910 16:23:25.683161  5506 slave.cpp:1565] Authenticating with master master@172.17.0.2:43909
I0910 16:23:25.683349  5506 slave.cpp:1574] Using default CRAM-MD5 authenticatee
I0910 16:23:25.683861  5509 authenticatee.cpp:121] Creating new client SASL connection
I0910 16:23:25.684350  5511 master.cpp:9738] Authenticating slave@172.17.0.2:43909
I0910 16:23:25.684603  5507 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1100)@172.17.0.2:43909
I0910 16:23:25.685042  5491 authenticator.cpp:98] Creating new server SASL connection
I0910 16:23:25.685386  5492 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0910 16:23:25.685441  5492 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0910 16:23:25.685631  5499 authenticator.cpp:204] Received SASL authentication start
I0910 16:23:25.685739  5499 authenticator.cpp:326] Authentication requires more steps
I0910 16:23:25.685963  5499 authenticatee.cpp:259] Received SASL authentication step
I0910 16:23:25.686199  5510 authenticator.cpp:232] Received SASL authentication step
I0910 16:23:25.686273  5510 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7a0b504a5d17' server FQDN: '7a0b504a5d17' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0910 16:23:25.686305  5510 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0910 16:23:25.686386  5510 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0910 16:23:25.686437  5510 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '7a0b504a5d17' server FQDN: '7a0b504a5d17' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0910 16:23:25.686462  5510 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0910 16:23:25.686480  5510 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0910 16:23:25.686511  5510 authenticator.cpp:318] Authentication success
I0910 16:23:25.686671  5508 authenticatee.cpp:299] Authentication success
I0910 16:23:25.686841  5503 master.cpp:9770] Successfully authenticated principal 'test-principal' at slave@172.17.0.2:43909
I0910 16:23:25.686902  5504 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1100)@172.17.0.2:43909
I0910 16:23:25.687408  5510 slave.cpp:1665] Successfully authenticated with master master@172.17.0.2:43909
I0910 16:23:25.688191  5510 slave.cpp:2131] Will retry registration in 12.232725ms if necessary
I0910 16:23:25.688525  5505 master.cpp:6232] Received register agent message from slave@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:25.689240  5505 master.cpp:3763] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I0910 16:23:25.690179  5501 master.cpp:6299] Authorized registration of agent at slave@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:25.690383  5501 master.cpp:6411] Registering agent at slave@172.17.0.2:43909 (7a0b504a5d17) with id d39494b1-36d4-43d0-9f15-008c0255dad8-S0
I0910 16:23:25.691799  5498 registrar.cpp:487] Applied 1 operations in 481958ns; attempting to update the registry
I0910 16:23:25.692929  5498 registrar.cpp:544] Successfully updated the registry in 1.006848ms
I0910 16:23:25.693279  5491 master.cpp:6459] Admitted agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 at slave@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:25.694519  5491 master.cpp:6504] Registered agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 at slave@172.17.0.2:43909 (7a0b504a5d17) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0910 16:23:25.694659  5492 slave.cpp:1698] Registered with master master@172.17.0.2:43909; given agent ID d39494b1-36d4-43d0-9f15-008c0255dad8-S0
I0910 16:23:25.694783  5502 hierarchical.cpp:1041] Added agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 (7a0b504a5d17) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I0910 16:23:25.694905  5512 task_status_update_manager.cpp:188] Resuming sending task status updates
I0910 16:23:25.695451  5492 slave.cpp:1733] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/slave.info'
I0910 16:23:25.695585  5503 status_update_manager_process.hpp:385] Resuming operation status update manager
I0910 16:23:25.696915  5502 hierarchical.cpp:1935] Performed allocation for 1 agents in 1.822933ms
I0910 16:23:25.697470  5492 slave.cpp:1793] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"OZRjfwnaRCmLin1BqEoK6A=="},"slave_id":{"value":"d39494b1-36d4-43d0-9f15-008c0255dad8-S0"},"update_oversubscribed_resources":false}
I0910 16:23:25.697912  5494 master.cpp:9547] Sending offers [ d39494b1-36d4-43d0-9f15-008c0255dad8-O0 ] to framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 (default) at scheduler-9d8f93f2-88c8-4a29-aea4-5224c456d606@172.17.0.2:43909
I0910 16:23:25.698915  5496 sched.cpp:934] Scheduler::resourceOffers took 161400ns
I0910 16:23:25.699549  5494 master.cpp:7646] Ignoring update on agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 at slave@172.17.0.2:43909 (7a0b504a5d17) as it reports no changes
I0910 16:23:25.702477  5507 master.cpp:4325] Processing ACCEPT call for offers: [ d39494b1-36d4-43d0-9f15-008c0255dad8-O0 ] on agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 at slave@172.17.0.2:43909 (7a0b504a5d17) for framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 (default) at scheduler-9d8f93f2-88c8-4a29-aea4-5224c456d606@172.17.0.2:43909
I0910 16:23:25.703456  5507 master.cpp:11841] Removing offer d39494b1-36d4-43d0-9f15-008c0255dad8-O0
I0910 16:23:25.706794  5507 master.cpp:3868] Adding task 237cb797-841a-4258-9bab-a112e6e7cab0 with resources ports(allocated: *):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 (default) at scheduler-9d8f93f2-88c8-4a29-aea4-5224c456d606@172.17.0.2:43909 on agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 at slave@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:25.708055  5507 master.cpp:5004] Launching task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 (default) at scheduler-9d8f93f2-88c8-4a29-aea4-5224c456d606@172.17.0.2:43909 with resources [{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"},{"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"}] on agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 at slave@172.17.0.2:43909 (7a0b504a5d17) on  new executor
I0910 16:23:25.709013  5497 hierarchical.cpp:1859] Allocation paused
I0910 16:23:25.709913  5497 hierarchical.cpp:1869] Allocation resumed
I0910 16:23:25.710875  5498 slave.cpp:2300] Got assigned task '237cb797-841a-4258-9bab-a112e6e7cab0' for framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:25.711247  5498 slave.cpp:10290] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/framework.info'
I0910 16:23:25.712102  5498 slave.cpp:10301] Checkpointing framework pid 'scheduler-9d8f93f2-88c8-4a29-aea4-5224c456d606@172.17.0.2:43909' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/framework.pid'
I0910 16:23:25.715168  5498 slave.cpp:2707] Authorizing task '237cb797-841a-4258-9bab-a112e6e7cab0' for framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:25.715292  5498 slave.cpp:9715] Authorizing framework principal 'test-principal' to launch task 237cb797-841a-4258-9bab-a112e6e7cab0
I0910 16:23:25.718248  5493 slave.cpp:3181] Launching task '237cb797-841a-4258-9bab-a112e6e7cab0' for framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:25.718381  5493 paths.cpp:832] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336' for user 'mesos'
I0910 16:23:25.719509  5493 slave.cpp:11081] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/executor.info'
I0910 16:23:25.828766  5493 paths.cpp:835] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336'
I0910 16:23:25.829319  5493 slave.cpp:10379] Launching executor '237cb797-841a-4258-9bab-a112e6e7cab0' of framework d39494b1-36d4-43d0-9f15-008c0255dad8-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_GSWC4Q/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336'
I0910 16:23:25.831270  5493 slave.cpp:11121] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336/tasks/237cb797-841a-4258-9bab-a112e6e7cab0/task.info'
I0910 16:23:25.832551  5493 slave.cpp:3415] Queued task '237cb797-841a-4258-9bab-a112e6e7cab0' for executor '237cb797-841a-4258-9bab-a112e6e7cab0' of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:25.832711  5493 slave.cpp:1206] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/latest'
I0910 16:23:25.832787  5493 slave.cpp:1206] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336' to virtual path '/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/latest'
I0910 16:23:25.832854  5493 slave.cpp:1206] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336'
I0910 16:23:25.833734  5493 slave.cpp:3876] Launching container 55f2db9f-3770-4801-bf31-55bd787bc336 for executor '237cb797-841a-4258-9bab-a112e6e7cab0' of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:25.834834  5492 containerizer.cpp:1405] Starting container 55f2db9f-3770-4801-bf31-55bd787bc336
I0910 16:23:25.835690  5492 containerizer.cpp:3414] Transitioning the state of container 55f2db9f-3770-4801-bf31-55bd787bc336 from STARTING to PROVISIONING after 511744ns
I0910 16:23:25.837289  5492 containerizer.cpp:1584] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_sV3b2k/containers/55f2db9f-3770-4801-bf31-55bd787bc336/config'
I0910 16:23:25.837370  5492 containerizer.cpp:3414] Transitioning the state of container 55f2db9f-3770-4801-bf31-55bd787bc336 from PROVISIONING to PREPARING after 1.682176ms
I0910 16:23:25.848449  5509 containerizer.cpp:2110] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/tmp/SRC/build/mesos-1.11.0/_build/sub/src"],"shell":false,"value":"/tmp/SRC/build/mesos-1.11.0/_build/sub/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:43909"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"237cb797-841a-4258-9bab-a112e6e7cab0"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name
 ":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"d39494b1-36d4-43d0-9f15-008c0255dad8-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":"d39494b1-36d4-43d0-9f15-008c0255dad8-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave@172.17.0.2:43909"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"15secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-
 841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336"}" --pipe_read="28" --pipe_write="31" --runtime_directory="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_sV3b2k/containers/55f2db9f-3770-4801-bf31-55bd787bc336" --unshare_namespace_mnt="false"'
I0910 16:23:25.859318  5509 launcher.cpp:145] Forked child with pid '12428' for container '55f2db9f-3770-4801-bf31-55bd787bc336'
I0910 16:23:25.859498  5509 containerizer.cpp:2219] Checkpointing container's forked pid 12428 to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336/pids/forked.pid'
I0910 16:23:25.860837  5509 containerizer.cpp:3414] Transitioning the state of container 55f2db9f-3770-4801-bf31-55bd787bc336 from PREPARING to ISOLATING after 23.458816ms
I0910 16:23:25.864279  5496 containerizer.cpp:3414] Transitioning the state of container 55f2db9f-3770-4801-bf31-55bd787bc336 from ISOLATING to FETCHING after 3.303936ms
I0910 16:23:25.864837  5489 fetcher.cpp:369] Starting to fetch URIs for container: 55f2db9f-3770-4801-bf31-55bd787bc336, directory: /tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336
I0910 16:23:25.866716  5501 containerizer.cpp:3414] Transitioning the state of container 55f2db9f-3770-4801-bf31-55bd787bc336 from FETCHING to RUNNING after 2.505216ms
I0910 16:23:26.578016 12442 exec.cpp:164] Version: 1.11.0
I0910 16:23:26.597461  5506 slave.cpp:5487] Got registration for executor '237cb797-841a-4258-9bab-a112e6e7cab0' of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 from executor(1)@172.17.0.2:41259
I0910 16:23:26.598515  5506 slave.cpp:5573] Checkpointing executor pid 'executor(1)@172.17.0.2:41259' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta/slaves/d39494b1-36d4-43d0-9f15-008c0255dad8-S0/frameworks/d39494b1-36d4-43d0-9f15-008c0255dad8-0000/executors/237cb797-841a-4258-9bab-a112e6e7cab0/runs/55f2db9f-3770-4801-bf31-55bd787bc336/pids/libprocess.pid'
I0910 16:23:26.604476  5493 slave.cpp:3641] Sending queued task '237cb797-841a-4258-9bab-a112e6e7cab0' to executor '237cb797-841a-4258-9bab-a112e6e7cab0' of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 at executor(1)@172.17.0.2:41259
I0910 16:23:26.605572 12450 exec.cpp:237] Executor registered on agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0
I0910 16:23:26.611326 12431 executor.cpp:190] Received SUBSCRIBED event
I0910 16:23:26.614050 12431 executor.cpp:194] Subscribed executor on 7a0b504a5d17
I0910 16:23:26.614459 12431 executor.cpp:190] Received LAUNCH event
I0910 16:23:26.617406 12431 executor.cpp:722] Starting task 237cb797-841a-4258-9bab-a112e6e7cab0
I0910 16:23:26.622478  5500 slave.cpp:5980] Handling status update TASK_STARTING (Status UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 from executor(1)@172.17.0.2:41259
I0910 16:23:26.626282  5490 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.626384  5490 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.627718  5490 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.628202  5490 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 to the agent
I0910 16:23:26.628638  5512 slave.cpp:6526] Forwarding the update TASK_STARTING (Status UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 to master@172.17.0.2:43909
I0910 16:23:26.629123  5512 slave.cpp:6410] Task status update manager successfully handled status update TASK_STARTING (Status UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.629374  5512 slave.cpp:6437] Sending acknowledgement for status update TASK_STARTING (Status UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 to executor(1)@172.17.0.2:41259
I0910 16:23:26.629559  5498 master.cpp:8128] Status update TASK_STARTING (Status UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 from agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 at slave@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:26.629711  5498 master.cpp:8185] Forwarding status update TASK_STARTING (Status UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.630331  5498 master.cpp:11158] Updating the state of task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I0910 16:23:26.630702  5502 sched.cpp:1042] Scheduler::statusUpdate took 139470ns
I0910 16:23:26.631739  5500 master.cpp:5839] Processing ACKNOWLEDGE call for status 28737a9a-cd48-4502-8075-e17bf029d95e for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 (default) at scheduler-9d8f93f2-88c8-4a29-aea4-5224c456d606@172.17.0.2:43909 on agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0
I0910 16:23:26.632297  5492 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.632416  5492 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.632882  5496 slave.cpp:5089] Task status update manager successfully handled status update acknowledgement (UUID: 28737a9a-cd48-4502-8075-e17bf029d95e) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.634366  5501 hierarchical.cpp:1935] Performed allocation for 1 agents in 374259ns
I0910 16:23:26.679005 12431 executor.cpp:740] Forked command at 12455
I0910 16:23:26.685503  5494 slave.cpp:5980] Handling status update TASK_RUNNING (Status UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 from executor(1)@172.17.0.2:41259
I0910 16:23:26.689167  5503 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.689303  5503 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.689661  5503 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 to the agent
I0910 16:23:26.690011  5491 slave.cpp:6526] Forwarding the update TASK_RUNNING (Status UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 to master@172.17.0.2:43909
I0910 16:23:26.690462  5491 slave.cpp:6410] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.690727  5491 slave.cpp:6437] Sending acknowledgement for status update TASK_RUNNING (Status UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 to executor(1)@172.17.0.2:41259
I0910 16:23:26.690724  5493 master.cpp:8128] Status update TASK_RUNNING (Status UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 from agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 at slave@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:26.690881  5493 master.cpp:8185] Forwarding status update TASK_RUNNING (Status UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.691462  5493 master.cpp:11158] Updating the state of task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0910 16:23:26.691839  5499 sched.cpp:1042] Scheduler::statusUpdate took 163540ns
I0910 16:23:26.693039  5504 master.cpp:5839] Processing ACKNOWLEDGE call for status c905fcbd-f619-4059-8676-66a645271d93 for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 (default) at scheduler-9d8f93f2-88c8-4a29-aea4-5224c456d606@172.17.0.2:43909 on agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0
I0910 16:23:26.693527  5511 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.693681  5511 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_RUNNING (Status UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.694216  5490 slave.cpp:5089] Task status update manager successfully handled status update acknowledgement (UUID: c905fcbd-f619-4059-8676-66a645271d93) for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.694782  5512 slave.cpp:1002] Agent terminating
I0910 16:23:26.696349  5508 master.cpp:1297] Agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 at slave@172.17.0.2:43909 (7a0b504a5d17) disconnected
I0910 16:23:26.696404  5508 master.cpp:3431] Disconnecting agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 at slave@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:26.696529  5508 master.cpp:3450] Deactivating agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 at slave@172.17.0.2:43909 (7a0b504a5d17)
I0910 16:23:26.696775  5488 containerizer.cpp:320] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I0910 16:23:26.696805  5496 hierarchical.cpp:1238] Agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0 deactivated
W0910 16:23:26.697800  5488 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0910 16:23:26.697849  5488 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0910 16:23:26.697877  5488 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0910 16:23:26.697932  5488 provisioner.cpp:294] Using default backend 'copy'
W0910 16:23:26.713663  5488 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:43909
I0910 16:23:26.714865  5488 resolver.cpp:69] Creating default secret resolver
I0910 16:23:26.715075  5488 cluster.cpp:620] Creating default 'local' authorizer
I0910 16:23:26.717694  5496 slave.cpp:281] Mesos agent started on @172.17.0.2:43909
I0910 16:23:26.717723  5496 slave.cpp:282] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/4BW46m/UGVLZO/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/4BW46m/UGVLZO/credential" --default_role="*" --disallow_sharing_agent_ipc_namespace="false" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" --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/4BW46m/UGVLZO/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="15secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/4BW46m/UGVLZO/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/4BW46m/UGVLZO/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/4BW46m/UGVLZO/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/tmp/SRC/build/mesos-1.11.0/_build/sub/src" 
 --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --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_sV3b2k" --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_GSWC4Q" --zk_session_timeout="10secs"
I0910 16:23:26.718341  5496 credentials.hpp:73] Loading credential for authentication from '/tmp/4BW46m/UGVLZO/credential'
I0910 16:23:26.718523  5496 slave.cpp:314] Agent using credential for: test-principal
I0910 16:23:26.718549  5496 credentials.hpp:37] Loading credentials for authentication from '/tmp/4BW46m/UGVLZO/http_credentials'
I0910 16:23:26.718842  5496 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0910 16:23:26.719363  5496 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0910 16:23:26.721505  5496 slave.cpp:629] 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"}]
I0910 16:23:26.721843  5496 slave.cpp:637] Agent attributes: [  ]
I0910 16:23:26.721866  5496 slave.cpp:646] Agent hostname: 7a0b504a5d17
I0910 16:23:26.722084  5511 status_update_manager_process.hpp:379] Pausing operation status update manager
I0910 16:23:26.722172  5489 task_status_update_manager.cpp:181] Pausing sending task status updates
I0910 16:23:26.724860  5498 state.cpp:68] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta'
I0910 16:23:26.725023  5498 state.cpp:913] No committed checkpointed resources and operations found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta/resources/resources_and_operations.state'
I0910 16:23:26.725106  5498 state.cpp:919] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta/resources/resources.info'
I0910 16:23:26.731739  5493 slave.cpp:7741] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_GSWC4Q/meta', beginning agent recovery
I0910 16:23:26.733489  5493 slave.cpp:8473] Recovering framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.733742  5493 slave.cpp:10497] Recovering executor '237cb797-841a-4258-9bab-a112e6e7cab0' of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.737313  5501 task_status_update_manager.cpp:207] Recovering task status update manager
I0910 16:23:26.737385  5501 task_status_update_manager.cpp:215] Recovering executor '237cb797-841a-4258-9bab-a112e6e7cab0' of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.737689  5501 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 237cb797-841a-4258-9bab-a112e6e7cab0 of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.738971  5501 task_status_update_manager.cpp:818] Replaying task status update stream for task 237cb797-841a-4258-9bab-a112e6e7cab0
I0910 16:23:26.741923  5508 containerizer.cpp:830] Recovering Mesos containers
I0910 16:23:26.742134  5508 containerizer.cpp:887] Recovering container 55f2db9f-3770-4801-bf31-55bd787bc336 for executor '237cb797-841a-4258-9bab-a112e6e7cab0' of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.745411  5508 containerizer.cpp:1170] Recovering isolators
I0910 16:23:26.747660  5499 containerizer.cpp:1209] Recovering provisioner
I0910 16:23:26.748994  5495 provisioner.cpp:518] Provisioner recovery complete
I0910 16:23:26.752271  5503 composing.cpp:343] Finished recovering all containerizers
I0910 16:23:26.753036  5503 status_update_manager_process.hpp:314] Recovering operation status update manager
I0910 16:23:26.753646  5505 slave.cpp:8223] Recovering executors
I0910 16:23:26.753821  5505 slave.cpp:8247] Sending reconnect request to executor '237cb797-841a-4258-9bab-a112e6e7cab0' of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000 at executor(1)@172.17.0.2:41259
I0910 16:23:26.756067 12443 exec.cpp:283] Received reconnect request from agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0
I0910 16:23:26.758999  5510 slave.cpp:5663] Received re-registration message from executor '237cb797-841a-4258-9bab-a112e6e7cab0' of framework d39494b1-36d4-43d0-9f15-008c0255dad8-0000
I0910 16:23:26.760727 12446 exec.cpp:260] Executor reregistered on agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0
I0910 16:23:26.763345  5507 slave.cpp:6696] No pings from master received within 75secs
I0910 16:23:26.763846  5501 hierarchical.cpp:1935] Performed allocation for 1 agents in 307123ns
F0910 16:23:26.764189  5491 slave.cpp:1445] Check failed: state == DISCONNECTED || state == RUNNING || state == TERMINATING RECOVERING
*** Check failure stack trace: ***
I0910 16:23:26.766342 12445 executor.cpp:190] Received SUBSCRIBED event
I0910 16:23:26.766407 12445 executor.cpp:194] Subscribed executor on 7a0b504a5d17
    @     0x7faf9449be24  google::LogMessage::Fail()
    @     0x7faf9449bd69  google::LogMessage::SendToLog()
    @     0x7faf9449b6f0  google::LogMessage::Flush()
    @     0x7faf9449ef84  google::LogMessageFatal::~LogMessageFatal()
    @     0x7faf9252d317  mesos::internal::slave::Slave::detected()
    @     0x7faf925dfbad  _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEESB_EEvRKNS_3PIDIT_EEMSD_FvT0_EOT1_ENKUlOS9_PNS_11ProcessBaseEE_clESM_SO_
    @     0x7faf926d683a  _ZN5cpp176invokeIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINS3_10MasterInfoEEEESD_EEvRKNS1_3PIDIT_EEMSF_FvT0_EOT1_EUlOSB_PNS1_11ProcessBaseEE_ISB_SQ_EEEDTclcl7forwardISF_Efp_Espcl7forwardIT0_Efp0_EEEOSF_DpOSS_
    @     0x7faf926c70ab  _ZN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEE13invoke_expandISS_St5tupleIJSC_SU_EESX_IJOSR_EEJLm0ELm1EEEEDTcl6invokecl7forwardISG_Efp_Espcl6expandcl3getIXT2_EEcl7forwardISK_Efp0_EEcl7forwardISN_Efp2_EEEEOSG_OSK_N5cpp1416integer_sequenceImJXspT2_EEEESO_
    @     0x7faf926b7d8c  _ZNO6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEEclIJSR_EEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOS10_
    @     0x7faf926b17b0  _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS4_6FutureI6OptionINS6_10MasterInfoEEEESG_EEvRKNS4_3PIDIT_EEMSI_FvT0_EOT1_EUlOSE_PNS4_11ProcessBaseEE_ISE_St12_PlaceholderILi1EEEEEIST_EEEDTclcl7forwardISI_Efp_Espcl7forwardIT0_Efp0_EEEOSI_DpOSY_
    @     0x7faf926aeb11  _ZN6lambda8internal6InvokeIvEclINS0_7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS5_6FutureI6OptionINS7_10MasterInfoEEEESH_EEvRKNS5_3PIDIT_EEMSJ_FvT0_EOT1_EUlOSF_PNS5_11ProcessBaseEE_JSF_St12_PlaceholderILi1EEEEEJSU_EEEvOSJ_DpOT0_
    @     0x7faf926ab898  _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINSA_10MasterInfoEEEESK_EEvRKNS1_3PIDIT_EEMSM_FvT0_EOT1_EUlOSI_S3_E_ISI_St12_PlaceholderILi1EEEEEEclEOS3_
    @     0x7faf943a3ad8  _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEEclES3_
    @     0x7faf943664c0  process::ProcessBase::consume()
    @     0x7faf9438fd92  _ZNO7process13DispatchEvent7consumeEPNS_13EventConsumerE
    @     0x5578924f9cf4  process::ProcessBase::serve()
    @     0x7faf94362c9d  process::ProcessManager::resume()
    @     0x7faf9435ee1e  _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
    @     0x7faf943886d4  _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIJEEEvSt12_Index_tupleIJXspT_EEE
    @     0x7faf94387736  _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
    @     0x7faf9438657a  _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
    @     0x7faf810a0c80  (unknown)
    @     0x7faf808b36ba  start_thread
    @     0x7faf805e941d  clone
I0910 16:23:28.182435 12443 exec.cpp:551] Agent exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with agent d39494b1-36d4-43d0-9f15-008c0255dad8-S0
Makefile:16043: recipe for target 'check-local' failed
make[4]: *** [check-local] Aborted (core dumped)
make[4]: Leaving directory '/tmp/SRC/build/mesos-1.11.0/_build/sub/src'
Makefile:15151: recipe for target 'check-am' failed
make[3]: *** [check-am] Error 2
make[3]: Leaving directory '/tmp/SRC/build/mesos-1.11.0/_build/sub/src'
Makefile:15155: recipe for target 'check' failed
make[2]: *** [check] Error 2
make[2]: Leaving directory '/tmp/SRC/build/mesos-1.11.0/_build/sub/src'
Makefile:785: recipe for target 'check-recursive' failed
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory '/tmp/SRC/build/mesos-1.11.0/_build/sub'
Makefile:991: recipe for target 'distcheck' failed
make: *** [distcheck] Error 1
Untagged: mesos/mesos-build:ubuntu-16.04
Untagged: mesos/mesos-build@sha256:fa967cbcfb44f55708a3cbc87f245c6d29dd891464db558af56a03ee321526bb
Deleted: sha256:e895c0531b9a9a288fabe479a49f7059aed83645351ac99ec2ea2616822c9f97
Deleted: sha256:09119b0b314a69ba6ec6251f2e89f4199fe1e874c84f9abf07dcbd23dbc3f1c1
Deleted: sha256:562fe6af5a3883058be9c784a839392215ed4185a21d21f1d99df0d17f3ae6e7
Deleted: sha256:0dcdfbe322a4f332f73ac70905d557300ec6dae3bd19586758772c750c7b4a19
Deleted: sha256:c66652d605f01094e2db53d62505dbd524e076d5aa69b89d5e620003803eb149
Deleted: sha256:a2cf79bfb9593c05fd7142ddb49afef77ea4ad5d2464e841f09fe62ffee396e0
Deleted: sha256:f7a904214b390f39d98573882f631dc908df8b2b540cf04e1062f8182c1efffd
Deleted: sha256:ce1f6fcaa83dfce189d76e08f184085732eab4eeb2562d2399953958405c5bec
Deleted: sha256:cce92fda689ab9033f0b8db214bc63edd1ae3e05831a0f3a9418976d7dc7ccdd
Deleted: sha256:d22094bbd65447c59a42c580eaa3a44cee9cd855f00905f59409be21bcefc745
Deleted: sha256:b8976847450013f3eb5e9a81a5778f73ed7bef67e6393049712ef17102b4b7b7
Deleted: sha256:b8c891f0ffec910a12757d733b178e3f62d81dbbde2b31d3b754071c416108ed

Full log: https://ci-builds.apache.org/job/Mesos/job/Mesos-Reviewbot-Linux/454/console

- Mesos Reviewbot


On Sept. 10, 2020, 12:14 p.m., Vinod Kone wrote:
> 
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72858/
> -----------------------------------------------------------
> 
> (Updated Sept. 10, 2020, 12:14 p.m.)
> 
> 
> Review request for mesos, Andrei Sekretenko and Benjamin Mahler.
> 
> 
> Repository: mesos
> 
> 
> Description
> -------
> 
> Reduced build parallelism to avoid aborted builds in CI.
> 
> 
> Diffs
> -----
> 
>   support/mesos-website/entrypoint.sh 72fd72375e63f7e0dddb5472187edfdbe7a9d148 
> 
> 
> Diff: https://reviews.apache.org/r/72858/diff/1/
> 
> 
> Testing
> -------
> 
> https://ci-builds.apache.org/job/Mesos/job/Mesos-Websitebot-test/4/console
> 
> 
> Thanks,
> 
> Vinod Kone
> 
>


Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message