mesos-reviews mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Mesos Reviewbot <revi...@mesos.apache.org>
Subject Re: Review Request 72788: Added a work around in v1 volume manager for Portworx CSI plugin.
Date Thu, 20 Aug 2020 13:35:13 GMT

-----------------------------------------------------------
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
> 
>


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