You are viewing a plain text version of this content. The canonical link for it is here.
Posted to reviews@mesos.apache.org by Qian Zhang <zh...@gmail.com> on 2020/08/20 09:13:35 UTC
Review Request 72788: Added a work around in v1 volume manager for
Portworx CSI plugin.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72788/
-----------------------------------------------------------
Review request for mesos, Andrei Budnik and Greg Mann.
Bugs: MESOS-10150
https://issues.apache.org/jira/browse/MESOS-10150
Repository: mesos
Description
-------
Added a work around in v1 volume manager for Portworx CSI plugin.
Diffs
-----
src/csi/v1_volume_manager.cpp c05265cd514de745e824c16a0acef276deed1510
Diff: https://reviews.apache.org/r/72788/diff/1/
Testing
-------
Thanks,
Qian Zhang
Re: Review Request 72788: Introduced the
`CSIPluginInfo.target_path_exists` field.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72788/#review221677
-----------------------------------------------------------
Bad patch!
Reviews applied: [72788]
Failed command: cd .. && /usr/bin/python3 support/apply-reviews.py -n -r 72788
Error:
2020-08-21 16:09:15 URL:https://reviews.apache.org/r/72788/diff/raw/ [4332/4332] -> "72788.patch" [1]
*** Please tell me who you are.
Run
git config --global user.email "you@example.com"
git config --global user.name "Your Name"
to set your account's default identity.
Omit --global to set the identity only in this repository.
fatal: empty ident name (for <je...@asf931.gq1.ygridcore.net>) not allowed
Full log: https://ci-builds.apache.org/job/Mesos/job/Mesos-Reviewbot-Linux/15/console
- Mesos Reviewbot
On Aug. 21, 2020, 2:37 p.m., Qian Zhang wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72788/
> -----------------------------------------------------------
>
> (Updated Aug. 21, 2020, 2:37 p.m.)
>
>
> Review request for mesos, Andrei Budnik and Greg Mann.
>
>
> Bugs: MESOS-10150
> https://issues.apache.org/jira/browse/MESOS-10150
>
>
> Repository: mesos
>
>
> Description
> -------
>
> Introduced the `CSIPluginInfo.target_path_exists` field.
>
>
> Diffs
> -----
>
> include/mesos/mesos.proto 661f746dda9c1d2350867bd9139e73c3e3a34f5d
> include/mesos/v1/mesos.proto ffe45c305ab46c73f0da5908287aa3eab8ecf5dd
> src/csi/v1_volume_manager.cpp c05265cd514de745e824c16a0acef276deed1510
>
>
> Diff: https://reviews.apache.org/r/72788/diff/2/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Qian Zhang
>
>
Re: Review Request 72788: Introduced the
`CSIPluginInfo.target_path_exists` field.
Posted by Greg Mann <gr...@mesosphere.io>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72788/#review221679
-----------------------------------------------------------
Ship it!
Ship It!
- Greg Mann
On Aug. 21, 2020, 2:37 p.m., Qian Zhang wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72788/
> -----------------------------------------------------------
>
> (Updated Aug. 21, 2020, 2:37 p.m.)
>
>
> Review request for mesos, Andrei Budnik and Greg Mann.
>
>
> Bugs: MESOS-10150
> https://issues.apache.org/jira/browse/MESOS-10150
>
>
> Repository: mesos
>
>
> Description
> -------
>
> Introduced the `CSIPluginInfo.target_path_exists` field.
>
>
> Diffs
> -----
>
> include/mesos/mesos.proto 661f746dda9c1d2350867bd9139e73c3e3a34f5d
> include/mesos/v1/mesos.proto ffe45c305ab46c73f0da5908287aa3eab8ecf5dd
> src/csi/v1_volume_manager.cpp c05265cd514de745e824c16a0acef276deed1510
>
>
> Diff: https://reviews.apache.org/r/72788/diff/2/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Qian Zhang
>
>
Re: Review Request 72788: Introduced the
`CSIPluginInfo.target_path_exists` field.
Posted by Qian Zhang <zh...@gmail.com>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72788/
-----------------------------------------------------------
(Updated Aug. 25, 2020, 9:23 a.m.)
Review request for mesos, Andrei Budnik and Greg Mann.
Bugs: MESOS-10148
https://issues.apache.org/jira/browse/MESOS-10148
Repository: mesos
Description
-------
Introduced the `CSIPluginInfo.target_path_exists` field.
Diffs
-----
include/mesos/mesos.proto 661f746dda9c1d2350867bd9139e73c3e3a34f5d
include/mesos/v1/mesos.proto ffe45c305ab46c73f0da5908287aa3eab8ecf5dd
src/csi/v1_volume_manager.cpp c05265cd514de745e824c16a0acef276deed1510
Diff: https://reviews.apache.org/r/72788/diff/2/
Testing
-------
Thanks,
Qian Zhang
Re: Review Request 72788: Introduced the
`CSIPluginInfo.target_path_exists` field.
Posted by Qian Zhang <zh...@gmail.com>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72788/
-----------------------------------------------------------
(Updated Aug. 21, 2020, 10:37 p.m.)
Review request for mesos, Andrei Budnik and Greg Mann.
Changes
-------
Changed the solution by introducing a protobuf message field `CSIPluginInfo.target_path_exists`.
Summary (updated)
-----------------
Introduced the `CSIPluginInfo.target_path_exists` field.
Bugs: MESOS-10150
https://issues.apache.org/jira/browse/MESOS-10150
Repository: mesos
Description (updated)
-------
Introduced the `CSIPluginInfo.target_path_exists` field.
Diffs (updated)
-----
include/mesos/mesos.proto 661f746dda9c1d2350867bd9139e73c3e3a34f5d
include/mesos/v1/mesos.proto ffe45c305ab46c73f0da5908287aa3eab8ecf5dd
src/csi/v1_volume_manager.cpp c05265cd514de745e824c16a0acef276deed1510
Diff: https://reviews.apache.org/r/72788/diff/2/
Changes: https://reviews.apache.org/r/72788/diff/1-2/
Testing
-------
Thanks,
Qian Zhang
Re: Review Request 72788: Added a work around in v1 volume manager for
Portworx CSI plugin.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72788/#review221660
-----------------------------------------------------------
Bad patch!
Reviews applied: [72788]
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_72788"]
Error:
...<truncated>...
ent started on (538)@172.17.0.2:33425
I0820 13:34:44.219992 4634 slave.cpp:280] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/5mOShp/ptftS7/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/5mOShp/ptftS7/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/5mOShp/ptftS7/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="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/5mOShp/ptftS7/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/5mOShp/ptftS7/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/5mOShp/ptftS7/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_dPyAly" --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_9ySIOY" --zk_session_timeout="10secs"
I0820 13:34:44.220916 4634 credentials.hpp:73] Loading credential for authentication from '/tmp/5mOShp/ptftS7/credential'
W0820 13:34:44.221071 4614 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:33425
I0820 13:34:44.221210 4634 slave.cpp:312] Agent using credential for: test-principal
I0820 13:34:44.221257 4634 credentials.hpp:37] Loading credentials for authentication from '/tmp/5mOShp/ptftS7/http_credentials'
I0820 13:34:44.221657 4634 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0820 13:34:44.222364 4634 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0820 13:34:44.223048 4614 sched.cpp:239] Version: 1.11.0
I0820 13:34:44.224231 4624 sched.cpp:343] New master detected at master@172.17.0.2:33425
I0820 13:34:44.224447 4624 sched.cpp:408] Authenticating with master master@172.17.0.2:33425
I0820 13:34:44.224509 4624 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0820 13:34:44.225033 4620 authenticatee.cpp:121] Creating new client SASL connection
I0820 13:34:44.225076 4634 slave.cpp:627] 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"}]
I0820 13:34:44.225466 4632 master.cpp:9667] Authenticating scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425
I0820 13:34:44.225502 4634 slave.cpp:635] Agent attributes: [ ]
I0820 13:34:44.225533 4634 slave.cpp:644] Agent hostname: e6b655f501eb
I0820 13:34:44.225693 4635 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1094)@172.17.0.2:33425
I0820 13:34:44.225821 4625 status_update_manager_process.hpp:379] Pausing operation status update manager
I0820 13:34:44.225883 4637 task_status_update_manager.cpp:181] Pausing sending task status updates
I0820 13:34:44.226281 4638 authenticator.cpp:98] Creating new server SASL connection
I0820 13:34:44.226748 4622 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0820 13:34:44.226807 4622 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0820 13:34:44.227035 4636 authenticator.cpp:204] Received SASL authentication start
I0820 13:34:44.227180 4636 authenticator.cpp:326] Authentication requires more steps
I0820 13:34:44.227546 4629 authenticatee.cpp:259] Received SASL authentication step
I0820 13:34:44.227807 4619 authenticator.cpp:232] Received SASL authentication step
I0820 13:34:44.227880 4619 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'e6b655f501eb' server FQDN: 'e6b655f501eb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0820 13:34:44.227905 4619 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0820 13:34:44.227990 4619 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0820 13:34:44.228042 4619 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'e6b655f501eb' server FQDN: 'e6b655f501eb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0820 13:34:44.228068 4619 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0820 13:34:44.228087 4619 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0820 13:34:44.228118 4619 authenticator.cpp:318] Authentication success
I0820 13:34:44.228294 4618 authenticatee.cpp:299] Authentication success
I0820 13:34:44.228492 4617 master.cpp:9699] Successfully authenticated principal 'test-principal' at scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425
I0820 13:34:44.228611 4630 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1094)@172.17.0.2:33425
I0820 13:34:44.229120 4615 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:33425
I0820 13:34:44.229188 4615 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:33425
I0820 13:34:44.229406 4633 state.cpp:68] Recovering state from '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta'
I0820 13:34:44.229481 4615 sched.cpp:870] Will retry registration in 1.108768684secs if necessary
I0820 13:34:44.229820 4624 slave.cpp:7723] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta', beginning agent recovery
I0820 13:34:44.229907 4621 master.cpp:2901] Received SUBSCRIBE call for framework 'default' at scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425
I0820 13:34:44.230765 4616 task_status_update_manager.cpp:207] Recovering task status update manager
I0820 13:34:44.231482 4637 containerizer.cpp:830] Recovering Mesos containers
I0820 13:34:44.232023 4637 containerizer.cpp:1170] Recovering isolators
I0820 13:34:44.233234 4628 containerizer.cpp:1209] Recovering provisioner
I0820 13:34:44.233808 4630 master.cpp:2983] Subscribing framework default with checkpointing enabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0820 13:34:44.234144 4615 provisioner.cpp:518] Provisioner recovery complete
I0820 13:34:44.234931 4636 composing.cpp:343] Finished recovering all containerizers
I0820 13:34:44.235229 4629 slave.cpp:8205] Recovering executors
I0820 13:34:44.235385 4629 slave.cpp:8358] Finished recovery
I0820 13:34:44.236200 4630 master.cpp:9897] Adding framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 (default) at scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425 with roles { } suppressed
I0820 13:34:44.236306 4631 task_status_update_manager.cpp:181] Pausing sending task status updates
I0820 13:34:44.236328 4620 status_update_manager_process.hpp:379] Pausing operation status update manager
I0820 13:34:44.236325 4637 slave.cpp:1471] New master detected at master@172.17.0.2:33425
I0820 13:34:44.236564 4637 slave.cpp:1536] Detecting new master
I0820 13:34:44.237058 4628 sched.cpp:751] Framework registered with becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:44.237170 4628 sched.cpp:770] Scheduler::registered took 61066ns
I0820 13:34:44.237548 4617 hierarchical.cpp:767] Added framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:44.237849 4617 hierarchical.cpp:1920] Performed allocation for 0 agents in 110717ns
I0820 13:34:44.240975 4638 slave.cpp:1563] Authenticating with master master@172.17.0.2:33425
I0820 13:34:44.241111 4638 slave.cpp:1572] Using default CRAM-MD5 authenticatee
I0820 13:34:44.241573 4634 authenticatee.cpp:121] Creating new client SASL connection
I0820 13:34:44.241946 4616 master.cpp:9667] Authenticating slave(538)@172.17.0.2:33425
I0820 13:34:44.242137 4615 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1095)@172.17.0.2:33425
I0820 13:34:44.242559 4632 authenticator.cpp:98] Creating new server SASL connection
I0820 13:34:44.242871 4624 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0820 13:34:44.242925 4624 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0820 13:34:44.243144 4635 authenticator.cpp:204] Received SASL authentication start
I0820 13:34:44.243239 4635 authenticator.cpp:326] Authentication requires more steps
I0820 13:34:44.243446 4621 authenticatee.cpp:259] Received SASL authentication step
I0820 13:34:44.243707 4625 authenticator.cpp:232] Received SASL authentication step
I0820 13:34:44.243768 4625 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'e6b655f501eb' server FQDN: 'e6b655f501eb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0820 13:34:44.243796 4625 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0820 13:34:44.243854 4625 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0820 13:34:44.243897 4625 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'e6b655f501eb' server FQDN: 'e6b655f501eb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0820 13:34:44.243921 4625 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0820 13:34:44.243937 4625 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0820 13:34:44.243966 4625 authenticator.cpp:318] Authentication success
I0820 13:34:44.244153 4626 authenticatee.cpp:299] Authentication success
I0820 13:34:44.244258 4636 master.cpp:9699] Successfully authenticated principal 'test-principal' at slave(538)@172.17.0.2:33425
I0820 13:34:44.244304 4622 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1095)@172.17.0.2:33425
I0820 13:34:44.244969 4623 slave.cpp:1663] Successfully authenticated with master master@172.17.0.2:33425
I0820 13:34:44.245733 4623 slave.cpp:2113] Will retry registration in 11.300876ms if necessary
I0820 13:34:44.246021 4637 master.cpp:6162] Received register agent message from slave(538)@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:44.246816 4637 master.cpp:3693] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I0820 13:34:44.247680 4628 master.cpp:6229] Authorized registration of agent at slave(538)@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:44.247886 4628 master.cpp:6341] Registering agent at slave(538)@172.17.0.2:33425 (e6b655f501eb) with id becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0
I0820 13:34:44.249435 4633 registrar.cpp:487] Applied 1 operations in 749816ns; attempting to update the registry
I0820 13:34:44.250779 4633 registrar.cpp:544] Successfully updated the registry in 1.208064ms
I0820 13:34:44.251134 4615 master.cpp:6389] Admitted agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 at slave(538)@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:44.252410 4615 master.cpp:6434] Registered agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 at slave(538)@172.17.0.2:33425 (e6b655f501eb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0820 13:34:44.252537 4624 slave.cpp:1696] Registered with master master@172.17.0.2:33425; given agent ID becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0
I0820 13:34:44.252754 4625 task_status_update_manager.cpp:188] Resuming sending task status updates
I0820 13:34:44.252698 4632 hierarchical.cpp:1026] Added agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 (e6b655f501eb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I0820 13:34:44.253402 4624 slave.cpp:1731] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/slave.info'
I0820 13:34:44.253518 4619 status_update_manager_process.hpp:385] Resuming operation status update manager
I0820 13:34:44.255030 4632 hierarchical.cpp:1920] Performed allocation for 1 agents in 1.914208ms
I0820 13:34:44.255676 4624 slave.cpp:1783] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"Zp/2jjZdQo6WKBPPe70Gvw=="},"slave_id":{"value":"becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0"},"update_oversubscribed_resources":false}
I0820 13:34:44.255961 4629 master.cpp:9476] Sending offers [ becbfb1b-a08d-4124-9a29-1727de4a4c5d-O0 ] to framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 (default) at scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425
I0820 13:34:44.256578 4630 sched.cpp:934] Scheduler::resourceOffers took 93468ns
I0820 13:34:44.256886 4629 master.cpp:7575] Ignoring update on agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 at slave(538)@172.17.0.2:33425 (e6b655f501eb) as it reports no changes
I0820 13:34:44.258977 4618 master.cpp:4255] Processing ACCEPT call for offers: [ becbfb1b-a08d-4124-9a29-1727de4a4c5d-O0 ] on agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 at slave(538)@172.17.0.2:33425 (e6b655f501eb) for framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 (default) at scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425
I0820 13:34:44.259871 4618 master.cpp:11775] Removing offer becbfb1b-a08d-4124-9a29-1727de4a4c5d-O0
I0820 13:34:44.263219 4618 master.cpp:3798] Adding task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 with resources ports(allocated: *):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 (default) at scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425 on agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 at slave(538)@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:44.264405 4618 master.cpp:4934] Launching task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 (default) at scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425 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 becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 at slave(538)@172.17.0.2:33425 (e6b655f501eb) on new executor
I0820 13:34:44.265419 4616 hierarchical.cpp:1844] Allocation paused
I0820 13:34:44.266482 4616 hierarchical.cpp:1854] Allocation resumed
I0820 13:34:44.267328 4634 slave.cpp:2282] Got assigned task 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' for framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:44.267632 4634 slave.cpp:10272] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/framework.info'
I0820 13:34:44.268448 4634 slave.cpp:10283] Checkpointing framework pid 'scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425' to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/framework.pid'
I0820 13:34:44.271229 4634 slave.cpp:2689] Authorizing task 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' for framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:44.271351 4634 slave.cpp:9697] Authorizing framework principal 'test-principal' to launch task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5
I0820 13:34:44.275406 4634 slave.cpp:3163] Launching task 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' for framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:44.275554 4634 paths.cpp:832] Creating sandbox '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900' for user 'mesos'
I0820 13:34:44.276612 4634 slave.cpp:11063] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/executor.info'
I0820 13:34:44.535449 4634 paths.cpp:835] Creating sandbox '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900'
I0820 13:34:44.536226 4634 slave.cpp:10361] Launching executor 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-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_9ySIOY/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900'
I0820 13:34:44.539913 4634 slave.cpp:11103] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900/tasks/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/task.info'
I0820 13:34:44.542166 4634 slave.cpp:3397] Queued task 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' for executor 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:44.542421 4634 slave.cpp:1204] Successfully attached '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900' to virtual path '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/latest'
I0820 13:34:44.542555 4634 slave.cpp:1204] Successfully attached '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900' to virtual path '/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/latest'
I0820 13:34:44.542665 4634 slave.cpp:1204] Successfully attached '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900' to virtual path '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900'
I0820 13:34:44.544083 4634 slave.cpp:3858] Launching container a59062eb-a877-40bd-8b66-8bbd2c53b900 for executor 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:44.545423 4636 containerizer.cpp:1405] Starting container a59062eb-a877-40bd-8b66-8bbd2c53b900
I0820 13:34:44.546391 4636 containerizer.cpp:3414] Transitioning the state of container a59062eb-a877-40bd-8b66-8bbd2c53b900 from STARTING to PROVISIONING after 0ns
I0820 13:34:44.548080 4636 containerizer.cpp:1584] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_dPyAly/containers/a59062eb-a877-40bd-8b66-8bbd2c53b900/config'
I0820 13:34:44.548179 4636 containerizer.cpp:3414] Transitioning the state of container a59062eb-a877-40bd-8b66-8bbd2c53b900 from PROVISIONING to PREPARING after 0ns
I0820 13:34:44.557016 4628 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:33425"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"b9c0b5e5-c390-45af-a746-9ab6f9efb4d5"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"
MESOS_FRAMEWORK_ID","type":"VALUE","value":"becbfb1b-a08d-4124-9a29-1727de4a4c5d-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":"becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(538)@172.17.0.2:33425"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"2secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-
45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900"}" --pipe_read="28" --pipe_write="31" --runtime_directory="/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_dPyAly/containers/a59062eb-a877-40bd-8b66-8bbd2c53b900" --unshare_namespace_mnt="false"'
I0820 13:34:44.566370 4628 launcher.cpp:145] Forked child with pid '11521' for container 'a59062eb-a877-40bd-8b66-8bbd2c53b900'
I0820 13:34:44.566658 4628 containerizer.cpp:2219] Checkpointing container's forked pid 11521 to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900/pids/forked.pid'
I0820 13:34:44.568001 4628 containerizer.cpp:3414] Transitioning the state of container a59062eb-a877-40bd-8b66-8bbd2c53b900 from PREPARING to ISOLATING after 0ns
I0820 13:34:44.571236 4628 containerizer.cpp:3414] Transitioning the state of container a59062eb-a877-40bd-8b66-8bbd2c53b900 from ISOLATING to FETCHING after 0ns
I0820 13:34:44.572012 4620 fetcher.cpp:369] Starting to fetch URIs for container: a59062eb-a877-40bd-8b66-8bbd2c53b900, directory: /tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900
I0820 13:34:44.574337 4624 containerizer.cpp:3414] Transitioning the state of container a59062eb-a877-40bd-8b66-8bbd2c53b900 from FETCHING to RUNNING after 0ns
I0820 13:34:45.203084 11522 exec.cpp:164] Version: 1.11.0
I0820 13:34:45.224691 4635 slave.cpp:5469] Got registration for executor 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 from executor(1)@172.17.0.2:43687
I0820 13:34:45.225772 4635 slave.cpp:5555] Checkpointing executor pid 'executor(1)@172.17.0.2:43687' to '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta/slaves/becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0/frameworks/becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000/executors/b9c0b5e5-c390-45af-a746-9ab6f9efb4d5/runs/a59062eb-a877-40bd-8b66-8bbd2c53b900/pids/libprocess.pid'
I0820 13:34:45.230798 4628 slave.cpp:3623] Sending queued task 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' to executor 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 at executor(1)@172.17.0.2:43687
I0820 13:34:45.233551 11541 exec.cpp:237] Executor registered on agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0
I0820 13:34:45.239678 11545 executor.cpp:190] Received SUBSCRIBED event
I0820 13:34:45.242879 11545 executor.cpp:194] Subscribed executor on e6b655f501eb
I0820 13:34:45.243372 11545 executor.cpp:190] Received LAUNCH event
I0820 13:34:45.246933 11545 executor.cpp:722] Starting task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5
I0820 13:34:45.252004 4620 slave.cpp:5962] Handling status update TASK_STARTING (Status UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 from executor(1)@172.17.0.2:43687
I0820 13:34:45.255558 4619 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.255615 4619 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.256412 4619 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.256708 4619 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 to the agent
I0820 13:34:45.256948 4625 slave.cpp:6508] Forwarding the update TASK_STARTING (Status UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 to master@172.17.0.2:33425
I0820 13:34:45.257359 4625 slave.cpp:6392] Task status update manager successfully handled status update TASK_STARTING (Status UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.257586 4625 slave.cpp:6419] Sending acknowledgement for status update TASK_STARTING (Status UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 to executor(1)@172.17.0.2:43687
I0820 13:34:45.257624 4634 master.cpp:8057] Status update TASK_STARTING (Status UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 from agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 at slave(538)@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:45.257748 4634 master.cpp:8114] Forwarding status update TASK_STARTING (Status UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.258323 4634 master.cpp:11092] Updating the state of task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I0820 13:34:45.258648 4626 sched.cpp:1042] Scheduler::statusUpdate took 90742ns
I0820 13:34:45.259117 4636 master.cpp:5769] Processing ACKNOWLEDGE call for status 52d15c1b-8150-4cb7-8867-a057298aa6a9 for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 (default) at scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425 on agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0
I0820 13:34:45.259613 4615 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.259742 4615 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.260089 4623 slave.cpp:5071] Task status update manager successfully handled status update acknowledgement (UUID: 52d15c1b-8150-4cb7-8867-a057298aa6a9) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.265530 4614 slave.cpp:1000] Agent terminating
I0820 13:34:45.267019 4638 master.cpp:1292] Agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 at slave(538)@172.17.0.2:33425 (e6b655f501eb) disconnected
I0820 13:34:45.267076 4638 master.cpp:3361] Disconnecting agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 at slave(538)@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:45.267208 4614 containerizer.cpp:320] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I0820 13:34:45.267215 4638 master.cpp:3380] Deactivating agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 at slave(538)@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:45.267560 4637 hierarchical.cpp:1223] Agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 deactivated
W0820 13:34:45.268324 4614 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0820 13:34:45.268374 4614 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0820 13:34:45.268419 4614 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0820 13:34:45.268487 4614 provisioner.cpp:294] Using default backend 'copy'
W0820 13:34:45.285751 4614 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:33425
I0820 13:34:45.287314 4614 cluster.cpp:533] Creating default 'local' authorizer
I0820 13:34:45.291738 4637 slave.cpp:279] Mesos agent started on (539)@172.17.0.2:33425
I0820 13:34:45.291792 4637 slave.cpp:280] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/5mOShp/ptftS7/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/5mOShp/ptftS7/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/5mOShp/ptftS7/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/5mOShp/ptftS7/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/5mOShp/ptftS7/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/5mOShp/ptftS7/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_dPyAly" --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_9ySIOY" --zk_session_timeout="10secs"
I0820 13:34:45.292793 4637 credentials.hpp:73] Loading credential for authentication from '/tmp/5mOShp/ptftS7/credential'
I0820 13:34:45.293094 4637 slave.cpp:312] Agent using credential for: test-principal
I0820 13:34:45.293148 4637 credentials.hpp:37] Loading credentials for authentication from '/tmp/5mOShp/ptftS7/http_credentials'
I0820 13:34:45.293550 4637 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0820 13:34:45.294387 4637 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0820 13:34:45.296725 4637 slave.cpp:627] 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"}]
I0820 13:34:45.297120 4637 slave.cpp:635] Agent attributes: [ ]
I0820 13:34:45.297147 4637 slave.cpp:644] Agent hostname: e6b655f501eb
I0820 13:34:45.297485 4621 task_status_update_manager.cpp:181] Pausing sending task status updates
I0820 13:34:45.297539 4635 status_update_manager_process.hpp:379] Pausing operation status update manager
I0820 13:34:45.299818 4634 state.cpp:68] Recovering state from '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta'
I0820 13:34:45.299950 4634 state.cpp:913] No committed checkpointed resources and operations found at '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta/resources/resources_and_operations.state'
I0820 13:34:45.300030 4634 state.cpp:919] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta/resources/resources.info'
I0820 13:34:45.305162 11545 executor.cpp:740] Forked command at 11549
I0820 13:34:45.307936 4622 slave.cpp:7723] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_ReconnectExecutorRetry_9ySIOY/meta', beginning agent recovery
I0820 13:34:45.309705 4622 slave.cpp:8455] Recovering framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.309906 4622 slave.cpp:10479] Recovering executor 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.311745 4639 process.cpp:2678] Failed to deliver libprocess message to /slave(538)/mesos.internal.StatusUpdateMessage
I0820 13:34:45.313517 4633 task_status_update_manager.cpp:207] Recovering task status update manager
I0820 13:34:45.313571 4633 task_status_update_manager.cpp:215] Recovering executor 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.313724 4633 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.314762 4633 task_status_update_manager.cpp:818] Replaying task status update stream for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5
I0820 13:34:45.317211 4635 containerizer.cpp:830] Recovering Mesos containers
I0820 13:34:45.317389 4635 containerizer.cpp:887] Recovering container a59062eb-a877-40bd-8b66-8bbd2c53b900 for executor 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.320701 4635 containerizer.cpp:1170] Recovering isolators
I0820 13:34:45.323072 4627 containerizer.cpp:1209] Recovering provisioner
I0820 13:34:45.324177 4620 provisioner.cpp:518] Provisioner recovery complete
I0820 13:34:45.326297 4625 composing.cpp:343] Finished recovering all containerizers
I0820 13:34:45.327116 4615 status_update_manager_process.hpp:314] Recovering operation status update manager
I0820 13:34:45.327781 4634 slave.cpp:8205] Recovering executors
I0820 13:34:45.327980 4634 slave.cpp:8229] Sending reconnect request to executor 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 at executor(1)@172.17.0.2:43687
I0820 13:34:45.330358 11530 exec.cpp:283] Received reconnect request from agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0
I0820 13:34:45.460136 4630 slave.cpp:8284] Re-sending reconnect request to executor 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 at executor(1)@172.17.0.2:43687
I0820 13:34:45.460543 4617 hierarchical.cpp:1920] Performed allocation for 1 agents in 349892ns
I0820 13:34:45.462769 11534 exec.cpp:283] Received reconnect request from agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0
I0820 13:34:45.467716 4623 slave.cpp:5645] Received re-registration message from executor 'b9c0b5e5-c390-45af-a746-9ab6f9efb4d5' of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.468788 4623 slave.cpp:5962] Handling status update TASK_RUNNING (Status UUID: 6cf7b803-2b87-4f6e-a504-2cdf5bf5ba9d) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 from executor(1)@172.17.0.2:43687
I0820 13:34:45.470755 11537 exec.cpp:260] Executor reregistered on agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0
I0820 13:34:45.471942 4632 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 6cf7b803-2b87-4f6e-a504-2cdf5bf5ba9d) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.472050 4632 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: 6cf7b803-2b87-4f6e-a504-2cdf5bf5ba9d) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.472517 4637 slave.cpp:6392] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 6cf7b803-2b87-4f6e-a504-2cdf5bf5ba9d) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.472750 4637 slave.cpp:6419] Sending acknowledgement for status update TASK_RUNNING (Status UUID: 6cf7b803-2b87-4f6e-a504-2cdf5bf5ba9d) for task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 to executor(1)@172.17.0.2:43687
I0820 13:34:45.473959 4636 hierarchical.cpp:1920] Performed allocation for 1 agents in 187079ns
I0820 13:34:45.474820 4614 sched.cpp:2166] Asked to stop the driver
I0820 13:34:45.474881 11539 executor.cpp:190] Received SUBSCRIBED event
I0820 13:34:45.474929 11539 executor.cpp:194] Subscribed executor on e6b655f501eb
I0820 13:34:45.474999 4634 sched.cpp:1204] Stopping framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.475517 4628 master.cpp:10264] Processing TEARDOWN call for framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 (default) at scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425
I0820 13:34:45.475591 4628 master.cpp:10276] Removing framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 (default) at scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425
I0820 13:34:45.475641 4628 master.cpp:3326] Deactivating framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 (default) at scheduler-8d39ad87-2c08-4d8e-ba36-401ff6201e99@172.17.0.2:33425
I0820 13:34:45.475935 4618 hierarchical.cpp:880] Deactivated framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.476058 4628 master.cpp:11092] Updating the state of task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
I0820 13:34:45.476516 4618 hierarchical.cpp:1920] Performed allocation for 1 agents in 167931ns
I0820 13:34:45.477044 4619 slave.cpp:1000] Agent terminating
I0820 13:34:45.477761 4628 master.cpp:11192] Removing task b9c0b5e5-c390-45af-a746-9ab6f9efb4d5 with resources ports(allocated: *):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024 of framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000 on agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 at slave(538)@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:45.478574 4618 hierarchical.cpp:1643] 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 becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0 from framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.478955 4620 containerizer.cpp:2716] Destroying container a59062eb-a877-40bd-8b66-8bbd2c53b900 in RUNNING state
I0820 13:34:45.479074 4620 containerizer.cpp:3414] Transitioning the state of container a59062eb-a877-40bd-8b66-8bbd2c53b900 from RUNNING to DESTROYING after 3.22203008secs
I0820 13:34:45.479574 4620 launcher.cpp:161] Asked to destroy container a59062eb-a877-40bd-8b66-8bbd2c53b900
I0820 13:34:45.480177 4618 hierarchical.cpp:1844] Allocation paused
I0820 13:34:45.480680 4618 hierarchical.cpp:824] Removed framework becbfb1b-a08d-4124-9a29-1727de4a4c5d-0000
I0820 13:34:45.480751 4618 hierarchical.cpp:1854] Allocation resumed
I0820 13:34:45.577945 4617 containerizer.cpp:3252] Container a59062eb-a877-40bd-8b66-8bbd2c53b900 has exited
I0820 13:34:45.582206 4621 provisioner.cpp:652] Ignoring destroy request for unknown container a59062eb-a877-40bd-8b66-8bbd2c53b900
I0820 13:34:45.599472 4614 master.cpp:1140] Master terminating
I0820 13:34:45.600100 4636 hierarchical.cpp:1199] Removed all filters for agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0
I0820 13:34:45.600164 4636 hierarchical.cpp:1075] Removed agent becbfb1b-a08d-4124-9a29-1727de4a4c5d-S0
[ OK ] SlaveRecoveryTest/0.ReconnectExecutorRetry (1433 ms)
[ RUN ] SlaveRecoveryTest/0.PingTimeoutDuringRecovery
I0820 13:34:45.620759 4614 cluster.cpp:186] Creating default 'local' authorizer
I0820 13:34:45.631022 4623 master.cpp:443] Master 1c5f2212-e3c6-4e97-94d5-e099c6e52b23 (e6b655f501eb) started on 172.17.0.2:33425
I0820 13:34:45.631075 4623 master.cpp:446] 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/JFUW9J/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" --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/JFUW9J/master" --zk_session_timeout="10secs"
I0820 13:34:45.631652 4623 master.cpp:495] Master only allowing authenticated frameworks to register
I0820 13:34:45.631676 4623 master.cpp:501] Master only allowing authenticated agents to register
I0820 13:34:45.631691 4623 master.cpp:507] Master only allowing authenticated HTTP frameworks to register
I0820 13:34:45.631707 4623 credentials.hpp:37] Loading credentials for authentication from '/tmp/JFUW9J/credentials'
I0820 13:34:45.632112 4623 master.cpp:551] Using default 'crammd5' authenticator
I0820 13:34:45.632433 4623 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0820 13:34:45.632836 4623 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0820 13:34:45.633186 4623 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0820 13:34:45.633524 4623 master.cpp:632] Authorization enabled
I0820 13:34:45.634268 4615 hierarchical.cpp:634] Initialized hierarchical allocator process
I0820 13:34:45.634284 4630 whitelist_watcher.cpp:77] No whitelist given
I0820 13:34:45.638964 4625 master.cpp:2165] Elected as the leading master!
I0820 13:34:45.639009 4625 master.cpp:1661] Recovering from registrar
I0820 13:34:45.639307 4622 registrar.cpp:339] Recovering registrar
I0820 13:34:45.640126 4622 registrar.cpp:383] Successfully fetched the registry (0B) in 761856ns
I0820 13:34:45.640302 4622 registrar.cpp:487] Applied 1 operations in 66301ns; attempting to update the registry
I0820 13:34:45.641067 4622 registrar.cpp:544] Successfully updated the registry in 670208ns
I0820 13:34:45.641305 4622 registrar.cpp:416] Successfully recovered registrar
I0820 13:34:45.642079 4632 master.cpp:1814] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I0820 13:34:45.642149 4627 hierarchical.cpp:673] Skipping recovery of hierarchical allocator: nothing to recover
I0820 13:34:45.648636 4614 containerizer.cpp:320] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0820 13:34:45.649718 4614 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0820 13:34:45.649782 4614 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0820 13:34:45.649845 4614 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0820 13:34:45.649924 4614 provisioner.cpp:294] Using default backend 'copy'
W0820 13:34:45.659740 4614 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:33425
I0820 13:34:45.661126 4614 cluster.cpp:533] Creating default 'local' authorizer
I0820 13:34:45.664139 4630 slave.cpp:279] Mesos agent started on @172.17.0.2:33425
I0820 13:34:45.664170 4630 slave.cpp:280] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/JFUW9J/JvIgFC/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/JFUW9J/JvIgFC/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/JFUW9J/JvIgFC/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/JFUW9J/JvIgFC/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/JFUW9J/JvIgFC/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/JFUW9J/JvIgFC/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_gMAtPZ" --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_RskHZm" --zk_session_timeout="10secs"
I0820 13:34:45.664747 4630 credentials.hpp:73] Loading credential for authentication from '/tmp/JFUW9J/JvIgFC/credential'
W0820 13:34:45.664918 4614 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:33425
I0820 13:34:45.664942 4630 slave.cpp:312] Agent using credential for: test-principal
I0820 13:34:45.664966 4630 credentials.hpp:37] Loading credentials for authentication from '/tmp/JFUW9J/JvIgFC/http_credentials'
I0820 13:34:45.665304 4630 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0820 13:34:45.665900 4630 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0820 13:34:45.666684 4614 sched.cpp:239] Version: 1.11.0
I0820 13:34:45.667752 4628 sched.cpp:343] New master detected at master@172.17.0.2:33425
I0820 13:34:45.667970 4628 sched.cpp:408] Authenticating with master master@172.17.0.2:33425
I0820 13:34:45.668020 4628 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0820 13:34:45.668552 4626 authenticatee.cpp:121] Creating new client SASL connection
I0820 13:34:45.668218 4630 slave.cpp:627] 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"}]
I0820 13:34:45.668639 4630 slave.cpp:635] Agent attributes: [ ]
I0820 13:34:45.668689 4630 slave.cpp:644] Agent hostname: e6b655f501eb
I0820 13:34:45.668977 4621 status_update_manager_process.hpp:379] Pausing operation status update manager
I0820 13:34:45.668995 4622 task_status_update_manager.cpp:181] Pausing sending task status updates
I0820 13:34:45.669148 4635 master.cpp:9667] Authenticating scheduler-8ffb0208-9502-4899-b9ce-87176d1f724e@172.17.0.2:33425
I0820 13:34:45.669420 4638 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1096)@172.17.0.2:33425
I0820 13:34:45.669917 4632 authenticator.cpp:98] Creating new server SASL connection
I0820 13:34:45.670332 4615 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0820 13:34:45.670401 4615 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0820 13:34:45.670653 4627 authenticator.cpp:204] Received SASL authentication start
I0820 13:34:45.670765 4627 authenticator.cpp:326] Authentication requires more steps
I0820 13:34:45.670940 4627 authenticatee.cpp:259] Received SASL authentication step
I0820 13:34:45.671149 4619 authenticator.cpp:232] Received SASL authentication step
I0820 13:34:45.671195 4619 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'e6b655f501eb' server FQDN: 'e6b655f501eb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0820 13:34:45.671213 4619 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0820 13:34:45.671285 4619 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0820 13:34:45.671347 4619 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'e6b655f501eb' server FQDN: 'e6b655f501eb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0820 13:34:45.671386 4619 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0820 13:34:45.671411 4619 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0820 13:34:45.671442 4619 authenticator.cpp:318] Authentication success
I0820 13:34:45.671579 4631 authenticatee.cpp:299] Authentication success
I0820 13:34:45.671710 4636 master.cpp:9699] Successfully authenticated principal 'test-principal' at scheduler-8ffb0208-9502-4899-b9ce-87176d1f724e@172.17.0.2:33425
I0820 13:34:45.671766 4633 state.cpp:68] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta'
I0820 13:34:45.671947 4618 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1096)@172.17.0.2:33425
I0820 13:34:45.672178 4620 slave.cpp:7723] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta', beginning agent recovery
I0820 13:34:45.672325 4634 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:33425
I0820 13:34:45.672389 4634 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:33425
I0820 13:34:45.672643 4634 sched.cpp:870] Will retry registration in 374.052143ms if necessary
I0820 13:34:45.672837 4628 master.cpp:2901] Received SUBSCRIBE call for framework 'default' at scheduler-8ffb0208-9502-4899-b9ce-87176d1f724e@172.17.0.2:33425
I0820 13:34:45.672912 4626 task_status_update_manager.cpp:207] Recovering task status update manager
I0820 13:34:45.673573 4635 containerizer.cpp:830] Recovering Mesos containers
I0820 13:34:45.674216 4635 containerizer.cpp:1170] Recovering isolators
I0820 13:34:45.675765 4636 containerizer.cpp:1209] Recovering provisioner
I0820 13:34:45.676980 4633 provisioner.cpp:518] Provisioner recovery complete
I0820 13:34:45.677157 4616 master.cpp:2983] Subscribing framework default with checkpointing enabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0820 13:34:45.678071 4615 composing.cpp:343] Finished recovering all containerizers
I0820 13:34:45.678480 4638 slave.cpp:8205] Recovering executors
I0820 13:34:45.678732 4638 slave.cpp:8358] Finished recovery
I0820 13:34:45.679834 4637 task_status_update_manager.cpp:181] Pausing sending task status updates
I0820 13:34:45.679854 4628 slave.cpp:1471] New master detected at master@172.17.0.2:33425
I0820 13:34:45.679857 4630 status_update_manager_process.hpp:379] Pausing operation status update manager
I0820 13:34:45.680059 4628 slave.cpp:1536] Detecting new master
I0820 13:34:45.680327 4616 master.cpp:9897] Adding framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 (default) at scheduler-8ffb0208-9502-4899-b9ce-87176d1f724e@172.17.0.2:33425 with roles { } suppressed
I0820 13:34:45.681036 4631 sched.cpp:751] Framework registered with 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:45.681114 4631 sched.cpp:770] Scheduler::registered took 35957ns
I0820 13:34:45.681511 4629 hierarchical.cpp:767] Added framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:45.681877 4629 hierarchical.cpp:1920] Performed allocation for 0 agents in 125475ns
I0820 13:34:45.683421 4625 slave.cpp:1563] Authenticating with master master@172.17.0.2:33425
I0820 13:34:45.683545 4625 slave.cpp:1572] Using default CRAM-MD5 authenticatee
I0820 13:34:45.683974 4623 authenticatee.cpp:121] Creating new client SASL connection
I0820 13:34:45.684396 4633 master.cpp:9667] Authenticating slave@172.17.0.2:33425
I0820 13:34:45.684605 4620 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1097)@172.17.0.2:33425
I0820 13:34:45.685015 4634 authenticator.cpp:98] Creating new server SASL connection
I0820 13:34:45.685374 4624 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0820 13:34:45.685431 4624 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0820 13:34:45.685636 4622 authenticator.cpp:204] Received SASL authentication start
I0820 13:34:45.685747 4622 authenticator.cpp:326] Authentication requires more steps
I0820 13:34:45.685961 4621 authenticatee.cpp:259] Received SASL authentication step
I0820 13:34:45.686179 4615 authenticator.cpp:232] Received SASL authentication step
I0820 13:34:45.686256 4615 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'e6b655f501eb' server FQDN: 'e6b655f501eb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0820 13:34:45.686303 4615 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0820 13:34:45.686388 4615 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0820 13:34:45.686465 4615 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'e6b655f501eb' server FQDN: 'e6b655f501eb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0820 13:34:45.686501 4615 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0820 13:34:45.686578 4615 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0820 13:34:45.686631 4615 authenticator.cpp:318] Authentication success
I0820 13:34:45.686805 4619 authenticatee.cpp:299] Authentication success
I0820 13:34:45.686923 4627 master.cpp:9699] Successfully authenticated principal 'test-principal' at slave@172.17.0.2:33425
I0820 13:34:45.686973 4638 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1097)@172.17.0.2:33425
I0820 13:34:45.687475 4635 slave.cpp:1663] Successfully authenticated with master master@172.17.0.2:33425
I0820 13:34:45.688411 4635 slave.cpp:2113] Will retry registration in 12.754612ms if necessary
I0820 13:34:45.688628 4628 master.cpp:6162] Received register agent message from slave@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:45.689168 4628 master.cpp:3693] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I0820 13:34:45.689846 4631 master.cpp:6229] Authorized registration of agent at slave@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:45.690028 4631 master.cpp:6341] Registering agent at slave@172.17.0.2:33425 (e6b655f501eb) with id 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0
I0820 13:34:45.691182 4626 registrar.cpp:487] Applied 1 operations in 447136ns; attempting to update the registry
I0820 13:34:45.692302 4626 registrar.cpp:544] Successfully updated the registry in 1.011968ms
I0820 13:34:45.692668 4620 master.cpp:6389] Admitted agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 at slave@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:45.693859 4620 master.cpp:6434] Registered agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 at slave@172.17.0.2:33425 (e6b655f501eb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0820 13:34:45.693984 4624 slave.cpp:1696] Registered with master master@172.17.0.2:33425; given agent ID 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0
I0820 13:34:45.694181 4621 task_status_update_manager.cpp:188] Resuming sending task status updates
I0820 13:34:45.694172 4634 hierarchical.cpp:1026] Added agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 (e6b655f501eb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I0820 13:34:45.694829 4624 slave.cpp:1731] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/slave.info'
I0820 13:34:45.694942 4627 status_update_manager_process.hpp:385] Resuming operation status update manager
I0820 13:34:45.696378 4634 hierarchical.cpp:1920] Performed allocation for 1 agents in 1.851823ms
I0820 13:34:45.696913 4624 slave.cpp:1783] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"baZVkKTQSl2QMLS9xEt5xw=="},"slave_id":{"value":"1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0"},"update_oversubscribed_resources":false}
I0820 13:34:45.697275 4615 master.cpp:9476] Sending offers [ 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-O0 ] to framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 (default) at scheduler-8ffb0208-9502-4899-b9ce-87176d1f724e@172.17.0.2:33425
I0820 13:34:45.697841 4635 sched.cpp:934] Scheduler::resourceOffers took 93536ns
I0820 13:34:45.698094 4615 master.cpp:7575] Ignoring update on agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 at slave@172.17.0.2:33425 (e6b655f501eb) as it reports no changes
I0820 13:34:45.700969 4623 master.cpp:4255] Processing ACCEPT call for offers: [ 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-O0 ] on agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 at slave@172.17.0.2:33425 (e6b655f501eb) for framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 (default) at scheduler-8ffb0208-9502-4899-b9ce-87176d1f724e@172.17.0.2:33425
I0820 13:34:45.701860 4623 master.cpp:11775] Removing offer 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-O0
I0820 13:34:45.705129 4623 master.cpp:3798] Adding task 6668e631-e163-4b09-8381-365d95f69952 with resources ports(allocated: *):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 (default) at scheduler-8ffb0208-9502-4899-b9ce-87176d1f724e@172.17.0.2:33425 on agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 at slave@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:45.706264 4623 master.cpp:4934] Launching task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 (default) at scheduler-8ffb0208-9502-4899-b9ce-87176d1f724e@172.17.0.2:33425 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 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 at slave@172.17.0.2:33425 (e6b655f501eb) on new executor
I0820 13:34:45.707226 4626 hierarchical.cpp:1844] Allocation paused
I0820 13:34:45.708168 4626 hierarchical.cpp:1854] Allocation resumed
I0820 13:34:45.709199 4633 slave.cpp:2282] Got assigned task '6668e631-e163-4b09-8381-365d95f69952' for framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:45.709560 4633 slave.cpp:10272] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/framework.info'
I0820 13:34:45.710451 4633 slave.cpp:10283] Checkpointing framework pid 'scheduler-8ffb0208-9502-4899-b9ce-87176d1f724e@172.17.0.2:33425' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/framework.pid'
I0820 13:34:45.713430 4633 slave.cpp:2689] Authorizing task '6668e631-e163-4b09-8381-365d95f69952' for framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:45.713593 4633 slave.cpp:9697] Authorizing framework principal 'test-principal' to launch task 6668e631-e163-4b09-8381-365d95f69952
I0820 13:34:45.717766 4619 slave.cpp:3163] Launching task '6668e631-e163-4b09-8381-365d95f69952' for framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:45.717959 4619 paths.cpp:832] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6' for user 'mesos'
I0820 13:34:45.719300 4619 slave.cpp:11063] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/executor.info'
I0820 13:34:45.873891 4619 paths.cpp:835] Creating sandbox '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6'
I0820 13:34:45.874575 4619 slave.cpp:10361] Launching executor '6668e631-e163-4b09-8381-365d95f69952' of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-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_RskHZm/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6'
I0820 13:34:45.877959 4619 slave.cpp:11103] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6/tasks/6668e631-e163-4b09-8381-365d95f69952/task.info'
I0820 13:34:45.879581 4619 slave.cpp:3397] Queued task '6668e631-e163-4b09-8381-365d95f69952' for executor '6668e631-e163-4b09-8381-365d95f69952' of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:45.879788 4619 slave.cpp:1204] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/latest'
I0820 13:34:45.879879 4619 slave.cpp:1204] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6' to virtual path '/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/latest'
I0820 13:34:45.879978 4619 slave.cpp:1204] Successfully attached '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6' to virtual path '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6'
I0820 13:34:45.881049 4619 slave.cpp:3858] Launching container 4a29cf57-b455-4c0a-ade8-3f387b8cf5a6 for executor '6668e631-e163-4b09-8381-365d95f69952' of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:45.882325 4629 containerizer.cpp:1405] Starting container 4a29cf57-b455-4c0a-ade8-3f387b8cf5a6
I0820 13:34:45.883324 4629 containerizer.cpp:3414] Transitioning the state of container 4a29cf57-b455-4c0a-ade8-3f387b8cf5a6 from STARTING to PROVISIONING after 592128ns
I0820 13:34:45.884979 4629 containerizer.cpp:1584] Checkpointed ContainerConfig at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_gMAtPZ/containers/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6/config'
I0820 13:34:45.885064 4629 containerizer.cpp:3414] Transitioning the state of container 4a29cf57-b455-4c0a-ade8-3f387b8cf5a6 from PROVISIONING to PREPARING after 1.742848ms
I0820 13:34:45.896636 4632 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:33425"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"6668e631-e163-4b09-8381-365d95f69952"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name
":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"1c5f2212-e3c6-4e97-94d5-e099c6e52b23-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":"1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave@172.17.0.2:33425"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"15secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6"}]},"task_environment":{},"user":"mesos","working_directory":"/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-
e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6"}" --pipe_read="28" --pipe_write="31" --runtime_directory="/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_gMAtPZ/containers/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6" --unshare_namespace_mnt="false"'
I0820 13:34:45.906392 4632 launcher.cpp:145] Forked child with pid '11551' for container '4a29cf57-b455-4c0a-ade8-3f387b8cf5a6'
I0820 13:34:45.906657 4632 containerizer.cpp:2219] Checkpointing container's forked pid 11551 to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6/pids/forked.pid'
I0820 13:34:45.907773 4632 containerizer.cpp:3414] Transitioning the state of container 4a29cf57-b455-4c0a-ade8-3f387b8cf5a6 from PREPARING to ISOLATING after 22.710272ms
I0820 13:34:45.910493 4632 containerizer.cpp:3414] Transitioning the state of container 4a29cf57-b455-4c0a-ade8-3f387b8cf5a6 from ISOLATING to FETCHING after 2.689792ms
I0820 13:34:45.911140 4617 fetcher.cpp:369] Starting to fetch URIs for container: 4a29cf57-b455-4c0a-ade8-3f387b8cf5a6, directory: /tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6
I0820 13:34:45.913681 4625 containerizer.cpp:3414] Transitioning the state of container 4a29cf57-b455-4c0a-ade8-3f387b8cf5a6 from FETCHING to RUNNING after 3.06304ms
I0820 13:34:46.554317 11558 exec.cpp:164] Version: 1.11.0
I0820 13:34:46.578500 4618 slave.cpp:5469] Got registration for executor '6668e631-e163-4b09-8381-365d95f69952' of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 from executor(1)@172.17.0.2:38497
I0820 13:34:46.579728 4618 slave.cpp:5555] Checkpointing executor pid 'executor(1)@172.17.0.2:38497' to '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta/slaves/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0/frameworks/1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000/executors/6668e631-e163-4b09-8381-365d95f69952/runs/4a29cf57-b455-4c0a-ade8-3f387b8cf5a6/pids/libprocess.pid'
I0820 13:34:46.584645 4636 slave.cpp:3623] Sending queued task '6668e631-e163-4b09-8381-365d95f69952' to executor '6668e631-e163-4b09-8381-365d95f69952' of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 at executor(1)@172.17.0.2:38497
I0820 13:34:46.591553 11573 exec.cpp:237] Executor registered on agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0
I0820 13:34:46.597824 11554 executor.cpp:190] Received SUBSCRIBED event
I0820 13:34:46.600683 11554 executor.cpp:194] Subscribed executor on e6b655f501eb
I0820 13:34:46.601169 11554 executor.cpp:190] Received LAUNCH event
I0820 13:34:46.604782 11554 executor.cpp:722] Starting task 6668e631-e163-4b09-8381-365d95f69952
I0820 13:34:46.610317 4624 slave.cpp:5962] Handling status update TASK_STARTING (Status UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 from executor(1)@172.17.0.2:38497
I0820 13:34:46.614562 4630 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.614706 4630 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.616466 4630 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_STARTING (Status UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.617157 4630 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 to the agent
I0820 13:34:46.617703 4627 slave.cpp:6508] Forwarding the update TASK_STARTING (Status UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 to master@172.17.0.2:33425
I0820 13:34:46.618273 4627 slave.cpp:6392] Task status update manager successfully handled status update TASK_STARTING (Status UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.618518 4620 master.cpp:8057] Status update TASK_STARTING (Status UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 from agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 at slave@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:46.618621 4627 slave.cpp:6419] Sending acknowledgement for status update TASK_STARTING (Status UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 to executor(1)@172.17.0.2:38497
I0820 13:34:46.618664 4620 master.cpp:8114] Forwarding status update TASK_STARTING (Status UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.618973 4620 master.cpp:11092] Updating the state of task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I0820 13:34:46.619400 4638 sched.cpp:1042] Scheduler::statusUpdate took 146085ns
I0820 13:34:46.620250 4624 master.cpp:5769] Processing ACKNOWLEDGE call for status ec518988-1cb5-4ae0-95e6-87d70120c7bf for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 (default) at scheduler-8ffb0208-9502-4899-b9ce-87176d1f724e@172.17.0.2:33425 on agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0
I0820 13:34:46.620754 4635 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.620889 4635 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_STARTING (Status UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.621284 4619 slave.cpp:5071] Task status update manager successfully handled status update acknowledgement (UUID: ec518988-1cb5-4ae0-95e6-87d70120c7bf) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.635964 4632 hierarchical.cpp:1920] Performed allocation for 1 agents in 328046ns
I0820 13:34:46.667726 11554 executor.cpp:740] Forked command at 11578
I0820 13:34:46.675150 4625 slave.cpp:5962] Handling status update TASK_RUNNING (Status UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 from executor(1)@172.17.0.2:38497
I0820 13:34:46.679296 4633 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.679453 4633 task_status_update_manager.cpp:842] Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.679872 4633 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 to the agent
I0820 13:34:46.680260 4634 slave.cpp:6508] Forwarding the update TASK_RUNNING (Status UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 to master@172.17.0.2:33425
I0820 13:34:46.680577 4634 slave.cpp:6392] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.680759 4634 slave.cpp:6419] Sending acknowledgement for status update TASK_RUNNING (Status UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 to executor(1)@172.17.0.2:38497
I0820 13:34:46.680811 4637 master.cpp:8057] Status update TASK_RUNNING (Status UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 from agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 at slave@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:46.680908 4637 master.cpp:8114] Forwarding status update TASK_RUNNING (Status UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.681326 4637 master.cpp:11092] Updating the state of task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0820 13:34:46.681612 4636 sched.cpp:1042] Scheduler::statusUpdate took 131110ns
I0820 13:34:46.682723 4617 master.cpp:5769] Processing ACKNOWLEDGE call for status bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 (default) at scheduler-8ffb0208-9502-4899-b9ce-87176d1f724e@172.17.0.2:33425 on agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0
I0820 13:34:46.683240 4631 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.683359 4631 task_status_update_manager.cpp:842] Checkpointing ACK for task status update TASK_RUNNING (Status UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.683763 4626 slave.cpp:5071] Task status update manager successfully handled status update acknowledgement (UUID: bd1afa14-6ef7-4d40-9d49-d47d70d6ef8b) for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.684160 4616 slave.cpp:1000] Agent terminating
I0820 13:34:46.685595 4624 master.cpp:1292] Agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 at slave@172.17.0.2:33425 (e6b655f501eb) disconnected
I0820 13:34:46.685647 4624 master.cpp:3361] Disconnecting agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 at slave@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:46.685778 4624 master.cpp:3380] Deactivating agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 at slave@172.17.0.2:33425 (e6b655f501eb)
I0820 13:34:46.686051 4628 hierarchical.cpp:1223] Agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0 deactivated
I0820 13:34:46.686308 4614 containerizer.cpp:320] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0820 13:34:46.687847 4614 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0820 13:34:46.687916 4614 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0820 13:34:46.687968 4614 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0820 13:34:46.688042 4614 provisioner.cpp:294] Using default backend 'copy'
W0820 13:34:46.707999 4614 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:33425
I0820 13:34:46.709944 4614 cluster.cpp:533] Creating default 'local' authorizer
I0820 13:34:46.716142 4635 slave.cpp:279] Mesos agent started on @172.17.0.2:33425
I0820 13:34:46.716197 4635 slave.cpp:280] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/JFUW9J/JvIgFC/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/JFUW9J/JvIgFC/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/JFUW9J/JvIgFC/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/JFUW9J/JvIgFC/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/JFUW9J/JvIgFC/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/JFUW9J/JvIgFC/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_gMAtPZ" --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_RskHZm" --zk_session_timeout="10secs"
I0820 13:34:46.717207 4635 credentials.hpp:73] Loading credential for authentication from '/tmp/JFUW9J/JvIgFC/credential'
I0820 13:34:46.717588 4635 slave.cpp:312] Agent using credential for: test-principal
I0820 13:34:46.717638 4635 credentials.hpp:37] Loading credentials for authentication from '/tmp/JFUW9J/JvIgFC/http_credentials'
I0820 13:34:46.718076 4635 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0820 13:34:46.718842 4635 disk_profile_adaptor.cpp:78] Creating default disk profile adaptor module
I0820 13:34:46.720994 4635 slave.cpp:627] 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"}]
I0820 13:34:46.721324 4635 slave.cpp:635] Agent attributes: [ ]
I0820 13:34:46.721346 4635 slave.cpp:644] Agent hostname: e6b655f501eb
I0820 13:34:46.721666 4629 status_update_manager_process.hpp:379] Pausing operation status update manager
I0820 13:34:46.721670 4616 task_status_update_manager.cpp:181] Pausing sending task status updates
I0820 13:34:46.724187 4622 state.cpp:68] Recovering state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta'
I0820 13:34:46.724319 4622 state.cpp:913] No committed checkpointed resources and operations found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta/resources/resources_and_operations.state'
I0820 13:34:46.724380 4622 state.cpp:919] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta/resources/resources.info'
I0820 13:34:46.729753 4624 slave.cpp:7723] Finished recovering checkpointed state from '/tmp/SlaveRecoveryTest_0_PingTimeoutDuringRecovery_RskHZm/meta', beginning agent recovery
I0820 13:34:46.731050 4624 slave.cpp:8455] Recovering framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.731241 4624 slave.cpp:10479] Recovering executor '6668e631-e163-4b09-8381-365d95f69952' of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.733834 4627 task_status_update_manager.cpp:207] Recovering task status update manager
I0820 13:34:46.733875 4627 task_status_update_manager.cpp:215] Recovering executor '6668e631-e163-4b09-8381-365d95f69952' of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.734050 4627 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 6668e631-e163-4b09-8381-365d95f69952 of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.734966 4627 task_status_update_manager.cpp:818] Replaying task status update stream for task 6668e631-e163-4b09-8381-365d95f69952
I0820 13:34:46.737690 4628 containerizer.cpp:830] Recovering Mesos containers
I0820 13:34:46.737958 4628 containerizer.cpp:887] Recovering container 4a29cf57-b455-4c0a-ade8-3f387b8cf5a6 for executor '6668e631-e163-4b09-8381-365d95f69952' of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.741086 4628 containerizer.cpp:1170] Recovering isolators
I0820 13:34:46.743211 4633 containerizer.cpp:1209] Recovering provisioner
I0820 13:34:46.744299 4629 provisioner.cpp:518] Provisioner recovery complete
I0820 13:34:46.747390 4637 composing.cpp:343] Finished recovering all containerizers
I0820 13:34:46.748459 4628 status_update_manager_process.hpp:314] Recovering operation status update manager
I0820 13:34:46.749199 4622 slave.cpp:8205] Recovering executors
I0820 13:34:46.749416 4622 slave.cpp:8229] Sending reconnect request to executor '6668e631-e163-4b09-8381-365d95f69952' of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000 at executor(1)@172.17.0.2:38497
I0820 13:34:46.753057 11561 exec.cpp:283] Received reconnect request from agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0
I0820 13:34:46.759769 4630 slave.cpp:5645] Received re-registration message from executor '6668e631-e163-4b09-8381-365d95f69952' of framework 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-0000
I0820 13:34:46.762202 11570 exec.cpp:260] Executor reregistered on agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0
I0820 13:34:46.763262 4635 slave.cpp:6678] No pings from master received within 75secs
I0820 13:34:46.763797 4638 hierarchical.cpp:1920] Performed allocation for 1 agents in 400131ns
F0820 13:34:46.764468 4635 slave.cpp:1443] Check failed: state == DISCONNECTED || state == RUNNING || state == TERMINATING RECOVERING
*** Check failure stack trace: ***
I0820 13:34:46.767621 11558 executor.cpp:190] Received SUBSCRIBED event
I0820 13:34:46.767694 11558 executor.cpp:194] Subscribed executor on e6b655f501eb
@ 0x7f0b9217cf3c google::LogMessage::Fail()
@ 0x7f0b9217ce81 google::LogMessage::SendToLog()
@ 0x7f0b9217c808 google::LogMessage::Flush()
@ 0x7f0b9218009c google::LogMessageFatal::~LogMessageFatal()
@ 0x7f0b90252dc3 mesos::internal::slave::Slave::detected()
@ 0x7f0b90303ee9 _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEESB_EEvRKNS_3PIDIT_EEMSD_FvT0_EOT1_ENKUlOS9_PNS_11ProcessBaseEE_clESM_SO_
@ 0x7f0b903fa9de _ZN5cpp176invokeIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINS3_10MasterInfoEEEESD_EEvRKNS1_3PIDIT_EEMSF_FvT0_EOT1_EUlOSB_PNS1_11ProcessBaseEE_ISB_SQ_EEEDTclcl7forwardISF_Efp_Espcl7forwardIT0_Efp0_EEEOSF_DpOSS_
@ 0x7f0b903eb24f _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_
@ 0x7f0b903dbf30 _ZNO6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS2_6FutureI6OptionINS4_10MasterInfoEEEESE_EEvRKNS2_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS2_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEEclIJSR_EEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOS10_
@ 0x7f0b903d5954 _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS4_6FutureI6OptionINS6_10MasterInfoEEEESG_EEvRKNS4_3PIDIT_EEMSI_FvT0_EOT1_EUlOSE_PNS4_11ProcessBaseEE_ISE_St12_PlaceholderILi1EEEEEIST_EEEDTclcl7forwardISI_Efp_Espcl7forwardIT0_Efp0_EEEOSI_DpOSY_
@ 0x7f0b903d2cb5 _ZN6lambda8internal6InvokeIvEclINS0_7PartialIZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS5_6FutureI6OptionINS7_10MasterInfoEEEESH_EEvRKNS5_3PIDIT_EEMSJ_FvT0_EOT1_EUlOSF_PNS5_11ProcessBaseEE_JSF_St12_PlaceholderILi1EEEEEJSU_EEEvOSJ_DpOT0_
@ 0x7f0b903cfa3c _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchIN5mesos8internal5slave5SlaveERKNS1_6FutureI6OptionINSA_10MasterInfoEEEESK_EEvRKNS1_3PIDIT_EEMSM_FvT0_EOT1_EUlOSI_S3_E_ISI_St12_PlaceholderILi1EEEEEEclEOS3_
@ 0x7f0b92084bf0 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEEclES3_
@ 0x7f0b920475d8 process::ProcessBase::consume()
@ 0x7f0b92070eaa _ZNO7process13DispatchEvent7consumeEPNS_13EventConsumerE
@ 0x5639b2ee3fd4 process::ProcessBase::serve()
@ 0x7f0b92043db5 process::ProcessManager::resume()
@ 0x7f0b9203ff36 _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
@ 0x7f0b920697ec _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIJEEEvSt12_Index_tupleIJXspT_EEE
@ 0x7f0b9206884e _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
@ 0x7f0b92067692 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
@ 0x7f0b7eef3c80 (unknown)
@ 0x7f0b7e7066ba start_thread
@ 0x7f0b7e43c41d clone
I0820 13:34:48.046952 11569 exec.cpp:551] Agent exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with agent 1c5f2212-e3c6-4e97-94d5-e099c6e52b23-S0
Makefile:15974: 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:15082: 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:15086: 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://builds.apache.org/job/Mesos-Reviewbot-Linux/12017/console
- Mesos Reviewbot
On Aug. 20, 2020, 9:13 a.m., Qian Zhang wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72788/
> -----------------------------------------------------------
>
> (Updated Aug. 20, 2020, 9:13 a.m.)
>
>
> Review request for mesos, Andrei Budnik and Greg Mann.
>
>
> Bugs: MESOS-10150
> https://issues.apache.org/jira/browse/MESOS-10150
>
>
> Repository: mesos
>
>
> Description
> -------
>
> Added a work around in v1 volume manager for Portworx CSI plugin.
>
>
> Diffs
> -----
>
> src/csi/v1_volume_manager.cpp c05265cd514de745e824c16a0acef276deed1510
>
>
> Diff: https://reviews.apache.org/r/72788/diff/1/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Qian Zhang
>
>