You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Till Toenshoff (JIRA)" <ji...@apache.org> on 2017/06/16 18:24:00 UTC
[jira] [Updated] (MESOS-7687) SlaveRecoveryTest flaky on Debian8
[ https://issues.apache.org/jira/browse/MESOS-7687?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Till Toenshoff updated MESOS-7687:
----------------------------------
Component/s: test
> SlaveRecoveryTest flaky on Debian8
> ----------------------------------
>
> Key: MESOS-7687
> URL: https://issues.apache.org/jira/browse/MESOS-7687
> Project: Mesos
> Issue Type: Bug
> Components: test
> Affects Versions: 1.4.0
> Reporter: Till Toenshoff
> Labels: flaky, flaky-test, test
>
> Just saw the following:
> {noformat}
> 17:55:50 [ RUN ] SlaveRecoveryTest/0.RecoverTerminatedExecutor
> 17:55:50 I0616 17:55:48.895027 367 cluster.cpp:162] Creating default 'local' authorizer
> 17:55:50 I0616 17:55:48.896232 392 master.cpp:438] Master 878cb6fe-8dfd-4972-bdad-355ffe922b2d (ip-172-16-10-45.ec2.internal) started on 172.16.10.45:60241
> 17:55:50 I0616 17:55:48.896253 392 master.cpp:440] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/btNhZm/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="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --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" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/btNhZm/master" --zk_session_timeout="10secs"
> 17:55:50 I0616 17:55:48.896365 392 master.cpp:490] Master only allowing authenticated frameworks to register
> 17:55:50 I0616 17:55:48.896370 392 master.cpp:504] Master only allowing authenticated agents to register
> 17:55:50 I0616 17:55:48.896373 392 master.cpp:517] Master only allowing authenticated HTTP frameworks to register
> 17:55:50 I0616 17:55:48.896378 392 credentials.hpp:37] Loading credentials for authentication from '/tmp/btNhZm/credentials'
> 17:55:50 I0616 17:55:48.896456 392 master.cpp:562] Using default 'crammd5' authenticator
> 17:55:50 I0616 17:55:48.896502 392 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
> 17:55:50 I0616 17:55:48.896585 392 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
> 17:55:50 I0616 17:55:48.896641 392 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
> 17:55:50 I0616 17:55:48.896692 392 master.cpp:642] Authorization enabled
> 17:55:50 I0616 17:55:48.896752 387 hierarchical.cpp:169] Initialized hierarchical allocator process
> 17:55:50 I0616 17:55:48.896790 391 whitelist_watcher.cpp:77] No whitelist given
> 17:55:50 I0616 17:55:48.897276 392 master.cpp:2161] Elected as the leading master!
> 17:55:50 I0616 17:55:48.897291 392 master.cpp:1700] Recovering from registrar
> 17:55:50 I0616 17:55:48.897351 390 registrar.cpp:345] Recovering registrar
> 17:55:50 I0616 17:55:48.897519 388 registrar.cpp:389] Successfully fetched the registry (0B) in 141824ns
> 17:55:50 I0616 17:55:48.897563 388 registrar.cpp:493] Applied 1 operations in 7566ns; attempting to update the registry
> 17:55:50 I0616 17:55:48.897783 393 registrar.cpp:550] Successfully updated the registry in 176896ns
> 17:55:50 I0616 17:55:48.897830 393 registrar.cpp:422] Successfully recovered registrar
> 17:55:50 I0616 17:55:48.897943 393 master.cpp:1799] Recovered 0 agents from the registry (168B); allowing 10mins for agents to re-register
> 17:55:50 I0616 17:55:48.898000 392 hierarchical.cpp:207] Skipping recovery of hierarchical allocator: nothing to recover
> 17:55:50 I0616 17:55:48.915196 367 containerizer.cpp:230] Using isolation: cgroups/cpu,cgroups/mem,filesystem/posix,network/cni,environment_secret
> 17:55:50 I0616 17:55:48.918882 367 linux_launcher.cpp:150] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
> 17:55:50 I0616 17:55:48.919247 367 provisioner.cpp:255] Using default backend 'copy'
> 17:55:50 I0616 17:55:48.931140 367 cluster.cpp:448] Creating default 'local' authorizer
> 17:55:50 I0616 17:55:48.931576 390 slave.cpp:249] Mesos agent started on (473)@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.931598 390 slave.cpp:250] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="cgroups/cpu,cgroups/mem" --launcher="linux" --launcher_dir="/home/admin/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-debian-8/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --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_RecoverTerminatedExecutor_3jELmV" --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_RecoverTerminatedExecutor_JG70a9"
> 17:55:50 I0616 17:55:48.931767 390 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/credential'
> 17:55:50 I0616 17:55:48.931839 390 slave.cpp:282] Agent using credential for: test-principal
> 17:55:50 I0616 17:55:48.931852 390 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/http_credentials'
> 17:55:50 I0616 17:55:48.931954 390 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
> 17:55:50 I0616 17:55:48.931993 390 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
> 17:55:50 I0616 17:55:48.932065 390 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
> 17:55:50 I0616 17:55:48.932106 390 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
> 17:55:50 I0616 17:55:48.932183 390 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
> 17:55:50 I0616 17:55:48.932222 390 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
> 17:55:50 I0616 17:55:48.932759 367 sched.cpp:232] Version: 1.4.0
> 17:55:50 I0616 17:55:48.932765 390 slave.cpp:553] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> 17:55:50 I0616 17:55:48.932845 390 slave.cpp:561] Agent attributes: [ ]
> 17:55:50 I0616 17:55:48.932854 390 slave.cpp:566] Agent hostname: ip-172-16-10-45.ec2.internal
> 17:55:50 I0616 17:55:48.932915 389 status_update_manager.cpp:177] Pausing sending status updates
> 17:55:50 I0616 17:55:48.933020 388 sched.cpp:336] New master detected at master@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.933060 388 sched.cpp:407] Authenticating with master master@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.933073 388 sched.cpp:414] Using default CRAM-MD5 authenticatee
> 17:55:50 I0616 17:55:48.933171 388 state.cpp:62] Recovering state from '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta'
> 17:55:50 I0616 17:55:48.933250 389 authenticatee.cpp:121] Creating new client SASL connection
> 17:55:50 I0616 17:55:48.933404 391 status_update_manager.cpp:203] Recovering status update manager
> 17:55:50 I0616 17:55:48.933512 391 containerizer.cpp:582] Recovering containerizer
> 17:55:50 I0616 17:55:48.933646 392 master.cpp:7468] Authenticating scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.933701 389 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(985)@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.933804 392 authenticator.cpp:98] Creating new server SASL connection
> 17:55:50 I0616 17:55:48.934170 390 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
> 17:55:50 I0616 17:55:48.934190 390 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
> 17:55:50 I0616 17:55:48.934219 390 authenticator.cpp:204] Received SASL authentication start
> 17:55:50 I0616 17:55:48.934258 390 authenticator.cpp:326] Authentication requires more steps
> 17:55:50 I0616 17:55:48.934291 390 authenticatee.cpp:259] Received SASL authentication step
> 17:55:50 I0616 17:55:48.934340 390 authenticator.cpp:232] Received SASL authentication step
> 17:55:50 I0616 17:55:48.934358 390 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-45.ec2.internal' server FQDN: 'ip-172-16-10-45.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> 17:55:50 I0616 17:55:48.934365 390 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
> 17:55:50 I0616 17:55:48.934372 390 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> 17:55:50 I0616 17:55:48.934377 390 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-45.ec2.internal' server FQDN: 'ip-172-16-10-45.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> 17:55:50 I0616 17:55:48.934381 390 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> 17:55:50 I0616 17:55:48.934384 390 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> 17:55:50 I0616 17:55:48.934392 390 authenticator.cpp:318] Authentication success
> 17:55:50 I0616 17:55:48.934443 390 master.cpp:7498] Successfully authenticated principal 'test-principal' at scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.934473 388 authenticatee.cpp:299] Authentication success
> 17:55:50 I0616 17:55:48.934499 386 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(985)@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.934660 387 sched.cpp:513] Successfully authenticated with master master@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.934684 387 sched.cpp:836] Sending SUBSCRIBE call to master@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.934726 387 sched.cpp:869] Will retry registration in 1.736859028secs if necessary
> 17:55:50 I0616 17:55:48.934768 390 master.cpp:2853] Received SUBSCRIBE call for framework 'default' at scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.934792 390 master.cpp:2197] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
> 17:55:50 I0616 17:55:48.934921 386 master.cpp:2933] Subscribing framework default with checkpointing enabled and capabilities [ ]
> 17:55:50 I0616 17:55:48.935073 390 hierarchical.cpp:301] Added framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:50 I0616 17:55:48.935083 391 sched.cpp:759] Framework registered with 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:50 I0616 17:55:48.935159 390 hierarchical.cpp:1908] No allocations performed
> 17:55:50 I0616 17:55:48.935168 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:50 I0616 17:55:48.935164 391 sched.cpp:773] Scheduler::registered took 14915ns
> 17:55:50 I0616 17:55:48.935174 390 hierarchical.cpp:1493] Performed allocation for 0 agents in 21043ns
> 17:55:50 I0616 17:55:48.935706 389 provisioner.cpp:416] Provisioner recovery complete
> 17:55:50 I0616 17:55:48.935827 386 slave.cpp:6128] Finished recovery
> 17:55:50 I0616 17:55:48.936076 386 slave.cpp:6310] Querying resource estimator for oversubscribable resources
> 17:55:50 I0616 17:55:48.936180 386 slave.cpp:946] New master detected at master@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.936197 389 status_update_manager.cpp:177] Pausing sending status updates
> 17:55:50 I0616 17:55:48.936223 386 slave.cpp:981] Detecting new master
> 17:55:50 I0616 17:55:48.936254 386 slave.cpp:6324] Received oversubscribable resources {} from the resource estimator
> 17:55:50 I0616 17:55:48.938407 387 slave.cpp:1008] Authenticating with master master@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.938434 387 slave.cpp:1019] Using default CRAM-MD5 authenticatee
> 17:55:50 I0616 17:55:48.938488 387 authenticatee.cpp:121] Creating new client SASL connection
> 17:55:50 I0616 17:55:48.938944 387 master.cpp:7468] Authenticating slave(473)@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.939005 392 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(986)@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.939083 392 authenticator.cpp:98] Creating new server SASL connection
> 17:55:50 I0616 17:55:48.939407 392 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
> 17:55:50 I0616 17:55:48.939426 392 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
> 17:55:50 I0616 17:55:48.939458 392 authenticator.cpp:204] Received SASL authentication start
> 17:55:50 I0616 17:55:48.939563 392 authenticator.cpp:326] Authentication requires more steps
> 17:55:50 I0616 17:55:48.939600 392 authenticatee.cpp:259] Received SASL authentication step
> 17:55:50 I0616 17:55:48.939648 392 authenticator.cpp:232] Received SASL authentication step
> 17:55:50 I0616 17:55:48.939682 392 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-45.ec2.internal' server FQDN: 'ip-172-16-10-45.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> 17:55:50 I0616 17:55:48.939718 392 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
> 17:55:50 I0616 17:55:48.939734 392 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> 17:55:50 I0616 17:55:48.939743 392 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-45.ec2.internal' server FQDN: 'ip-172-16-10-45.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> 17:55:50 I0616 17:55:48.939746 392 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> 17:55:50 I0616 17:55:48.939749 392 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> 17:55:50 I0616 17:55:48.939759 392 authenticator.cpp:318] Authentication success
> 17:55:50 I0616 17:55:48.939832 388 authenticatee.cpp:299] Authentication success
> 17:55:50 I0616 17:55:48.939848 391 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(986)@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.939853 392 master.cpp:7498] Successfully authenticated principal 'test-principal' at slave(473)@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.939929 388 slave.cpp:1103] Successfully authenticated with master master@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.940009 388 slave.cpp:1523] Will retry registration in 2.628542ms if necessary
> 17:55:50 I0616 17:55:48.940068 389 master.cpp:5470] Received register agent message from slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:50 I0616 17:55:48.940107 389 master.cpp:3702] Authorizing agent with principal 'test-principal'
> 17:55:50 I0616 17:55:48.940249 391 master.cpp:5530] Authorized registration of agent at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:50 I0616 17:55:48.940295 391 master.cpp:5609] Registering agent at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) with id 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0
> 17:55:50 I0616 17:55:48.940413 390 registrar.cpp:493] Applied 1 operations in 16502ns; attempting to update the registry
> 17:55:50 I0616 17:55:48.940551 390 registrar.cpp:550] Successfully updated the registry in 111104ns
> 17:55:50 I0616 17:55:48.940644 388 master.cpp:5656] Admitted agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:50 I0616 17:55:48.940788 393 slave.cpp:4826] Received ping from slave-observer(465)@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.940793 388 master.cpp:5687] Registered agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> 17:55:50 I0616 17:55:48.940852 393 slave.cpp:1149] Registered with master master@172.16.10.45:60241; given agent ID 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0
> 17:55:50 I0616 17:55:48.940865 390 hierarchical.cpp:587] Added agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 (ip-172-16-10-45.ec2.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
> 17:55:50 I0616 17:55:48.940920 386 status_update_manager.cpp:184] Resuming sending status updates
> 17:55:50 I0616 17:55:48.941038 393 slave.cpp:1169] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/slave.info'
> 17:55:50 I0616 17:55:48.941119 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:50 I0616 17:55:48.941143 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 185707ns
> 17:55:50 I0616 17:55:48.941190 393 slave.cpp:1207] Forwarding total oversubscribed resources {}
> 17:55:50 I0616 17:55:48.941263 388 master.cpp:7298] Sending 1 offers to framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 (default) at scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.941351 388 master.cpp:6341] Received update of agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) with total oversubscribed resources {}
> 17:55:50 I0616 17:55:48.941505 387 sched.cpp:933] Scheduler::resourceOffers took 63593ns
> 17:55:50 I0616 17:55:48.942035 386 master.cpp:3917] Processing ACCEPT call for offers: [ 878cb6fe-8dfd-4972-bdad-355ffe922b2d-O0 ] on agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) for framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 (default) at scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241
> 17:55:50 I0616 17:55:48.942071 386 master.cpp:3469] Authorizing framework principal 'test-principal' to launch task f26c4d85-585c-48e6-be70-248daaf3e2b7
> 17:55:50 I0616 17:55:48.942523 386 master.cpp:9317] Adding task f26c4d85-585c-48e6-be70-248daaf3e2b7 with resources cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] on agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:50 I0616 17:55:48.942589 386 master.cpp:4572] Launching task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 (default) at scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241 with resources cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] on agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:50 I0616 17:55:48.942809 389 slave.cpp:1633] Got assigned task 'f26c4d85-585c-48e6-be70-248daaf3e2b7' for framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:50 I0616 17:55:48.942867 389 slave.cpp:7006] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/framework.info'
> 17:55:50 I0616 17:55:48.943025 389 slave.cpp:7017] Checkpointing framework pid 'scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241' to '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/framework.pid'
> 17:55:50 I0616 17:55:48.943040 393 hierarchical.cpp:912] Updated allocation of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 on agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 from cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] to cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000]
> 17:55:50 I0616 17:55:48.943262 389 slave.cpp:1914] Authorizing task 'f26c4d85-585c-48e6-be70-248daaf3e2b7' for framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:50 I0616 17:55:48.943285 389 slave.cpp:6627] Authorizing framework principal 'test-principal' to launch task f26c4d85-585c-48e6-be70-248daaf3e2b7
> 17:55:50 I0616 17:55:48.943536 386 slave.cpp:2101] Launching task 'f26c4d85-585c-48e6-be70-248daaf3e2b7' for framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:50 I0616 17:55:48.943774 386 paths.cpp:573] Trying to chown '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7/runs/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d' to user 'root'
> 17:55:50 I0616 17:55:48.943920 386 slave.cpp:7475] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7/executor.info'
> 17:55:50 I0616 17:55:48.944185 386 slave.cpp:7087] Launching executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 with resources cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32 in work directory '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7/runs/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d'
> 17:55:50 I0616 17:55:48.944447 386 slave.cpp:7503] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7/runs/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d/tasks/f26c4d85-585c-48e6-be70-248daaf3e2b7/task.info'
> 17:55:50 I0616 17:55:48.944635 386 slave.cpp:2330] Queued task 'f26c4d85-585c-48e6-be70-248daaf3e2b7' for executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:50 I0616 17:55:48.944682 386 slave.cpp:899] Successfully attached file '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7/runs/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d'
> 17:55:50 I0616 17:55:48.944708 386 slave.cpp:899] Successfully attached file '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7/runs/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d'
> 17:55:50 I0616 17:55:48.944841 386 slave.cpp:2796] Launching container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d for executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:50 I0616 17:55:48.944977 393 containerizer.cpp:1056] Starting container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.945444 386 cgroups.cpp:410] Creating cgroup at '/sys/fs/cgroup/cpu,cpuacct/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d' for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.966711 386 cgroups.cpp:473] Chown the cgroup at '/sys/fs/cgroup/cpu,cpuacct/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d' to user 'root' for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.966789 386 cgroups.cpp:410] Creating cgroup at '/sys/fs/cgroup/memory/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d' for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.967804 386 memory.cpp:479] Started listening for OOM events for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.968226 386 memory.cpp:590] Started listening on 'low' memory pressure events for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.968569 386 memory.cpp:590] Started listening on 'medium' memory pressure events for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.968911 386 memory.cpp:590] Started listening on 'critical' memory pressure events for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.968926 386 cgroups.cpp:473] Chown the cgroup at '/sys/fs/cgroup/memory/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d' to user 'root' for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.969631 392 memory.cpp:199] Updated 'memory.soft_limit_in_bytes' to 1056MB for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.970228 392 memory.cpp:228] Updated 'memory.limit_in_bytes' to 1056MB for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.970541 392 cpu.cpp:101] Updated 'cpu.shares' to 2150 (cpus 2.1) for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:48.971635 386 containerizer.cpp:1630] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/home\/admin\/workspace\/mesos\/Mesos_CI-build\/FLAG\/SSL\/label\/mesos-ec2-debian-8\/mesos\/build\/src"],"shell":false,"value":"\/home\/admin\/workspace\/mesos\/Mesos_CI-build\/FLAG\/SSL\/label\/mesos-ec2-debian-8\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.45:60241"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9\/slaves\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0\/frameworks\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000\/executors\/f26c4d85-585c-48e6-be70-248daaf3e2b7\/runs\/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiIyZjgwYzViNy0zYmQ4LTRmYzgtOTYxNS01ZWJjNGMyNDc1NWQiLCJlaWQiOiJmMjZjNGQ4NS01ODVjLTQ4ZTYtYmU3MC0yNDhkYWFmM2UyYjciLCJmaWQiOiI4NzhjYjZmZS04ZGZkLTQ5NzItYmRhZC0zNTVmZmU5MjJiMmQtMDAwMCJ9.DW3cQerKWnu0YS3BWT2A0o23STzQC5K_EZ73VCuHPcE"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"f26c4d85-585c-48e6-be70-248daaf3e2b7"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"878cb6fe-8dfd-4972-bdad-355ffe922b2d-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":"878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(473)@172.16.10.45:60241"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"2secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9\/slaves\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0\/frameworks\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000\/executors\/f26c4d85-585c-48e6-be70-248daaf3e2b7\/runs\/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d"}]},"task_environment":{},"user":"root","working_directory":"\/tmp\/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9\/slaves\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0\/frameworks\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000\/executors\/f26c4d85-585c-48e6-be70-248daaf3e2b7\/runs\/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d"}" --pipe_read="35" --pipe_write="36" --runtime_directory="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/containers/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d" --unshare_namespace_mnt="false"'
> 17:55:50 I0616 17:55:48.971899 388 linux_launcher.cpp:429] Launching container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d and cloning with namespaces
> 17:55:50 I0616 17:55:48.976336 386 containerizer.cpp:1722] Checkpointing container's forked pid 14090 to '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7/runs/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d/pids/forked.pid'
> 17:55:50 I0616 17:55:48.978509 392 fetcher.cpp:324] Starting to fetch URIs for container: 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d, directory: /tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7/runs/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:49.059142 14104 exec.cpp:162] Version: 1.4.0
> 17:55:50 I0616 17:55:49.060634 392 slave.cpp:3826] Got registration for executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 from executor(1)@172.16.10.45:59728
> 17:55:50 I0616 17:55:49.060847 392 slave.cpp:3912] Checkpointing executor pid 'executor(1)@172.16.10.45:59728' to '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7/runs/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d/pids/libprocess.pid'
> 17:55:50 I0616 17:55:49.061573 14124 exec.cpp:237] Executor registered on agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0
> 17:55:50 I0616 17:55:49.061880 393 memory.cpp:199] Updated 'memory.soft_limit_in_bytes' to 1056MB for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:49.062496 393 cpu.cpp:101] Updated 'cpu.shares' to 2150 (cpus 2.1) for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:50 I0616 17:55:49.062826 387 slave.cpp:2543] Sending queued task 'f26c4d85-585c-48e6-be70-248daaf3e2b7' to executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 at executor(1)@172.16.10.45:59728
> 17:55:50 I0616 17:55:49.062624 14123 executor.cpp:169] Received SUBSCRIBED event
> 17:55:50 I0616 17:55:49.062891 14123 executor.cpp:173] Subscribed executor on ip-172-16-10-45.ec2.internal
> 17:55:50 I0616 17:55:49.063300 14123 executor.cpp:169] Received LAUNCH event
> 17:55:50 I0616 17:55:49.063391 14123 executor.cpp:624] Starting task f26c4d85-585c-48e6-be70-248daaf3e2b7
> 17:55:50 I0616 17:55:49.066045 14123 executor.cpp:468] Running '/home/admin/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-debian-8/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
> 17:55:50 I0616 17:55:49.067065 14123 executor.cpp:636] Forked command at 14127
> 17:55:50 I0616 17:55:49.068809 393 slave.cpp:4296] Handling status update TASK_RUNNING (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 from executor(1)@172.16.10.45:59728
> 17:55:50 I0616 17:55:49.069618 393 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:50 I0616 17:55:49.069643 393 status_update_manager.cpp:500] Creating StatusUpdate stream for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:50 I0616 17:55:49.069949 393 status_update_manager.cpp:834] Checkpointing UPDATE for status update TASK_RUNNING (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:50 I0616 17:55:49.070060 393 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 to the agent
> 17:55:50 I0616 17:55:49.070190 391 slave.cpp:4736] Forwarding the update TASK_RUNNING (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 to master@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.070278 391 slave.cpp:4630] Status update manager successfully handled status update TASK_RUNNING (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.070300 391 slave.cpp:4646] Sending acknowledgement for status update TASK_RUNNING (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 to executor(1)@172.16.10.45:59728
> 17:55:51 I0616 17:55:49.070354 388 master.cpp:6486] Status update TASK_RUNNING (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 from agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:51 I0616 17:55:49.070392 388 master.cpp:6548] Forwarding status update TASK_RUNNING (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.070456 388 master.cpp:8559] Updating the state of task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
> 17:55:51 I0616 17:55:49.070515 393 sched.cpp:1041] Scheduler::statusUpdate took 11568ns
> 17:55:51 I0616 17:55:49.070678 386 master.cpp:5235] Processing ACKNOWLEDGE call f7ba7720-5747-4fa1-8e76-778698a70c19 for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 (default) at scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241 on agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0
> 17:55:51 I0616 17:55:49.070825 388 status_update_manager.cpp:395] Received status update acknowledgement (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.070863 388 status_update_manager.cpp:834] Checkpointing ACK for status update TASK_RUNNING (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.070960 388 slave.cpp:3546] Status update manager successfully handled status update acknowledgement (UUID: f7ba7720-5747-4fa1-8e76-778698a70c19) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.071143 367 slave.cpp:818] Agent terminating
> 17:55:51 I0616 17:55:49.071341 389 master.cpp:1316] Agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) disconnected
> 17:55:51 I0616 17:55:49.071365 389 master.cpp:3240] Disconnecting agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:51 I0616 17:55:49.071383 367 containerizer.cpp:230] Using isolation: cgroups/cpu,cgroups/mem,filesystem/posix,network/cni,environment_secret
> 17:55:51 I0616 17:55:49.071398 389 master.cpp:3259] Deactivating agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:51 I0616 17:55:49.071415 14119 exec.cpp:435] Executor asked to shutdown
> 17:55:51 I0616 17:55:49.071483 389 hierarchical.cpp:715] Agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 deactivated
> 17:55:51 I0616 17:55:49.071517 14119 executor.cpp:169] Received SHUTDOWN event
> 17:55:51 I0616 17:55:49.071529 14119 executor.cpp:733] Shutting down
> 17:55:51 I0616 17:55:49.071542 14119 executor.cpp:840] Sending SIGTERM to process tree at pid 14127
> 17:55:51 I0616 17:55:49.074781 367 linux_launcher.cpp:150] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
> 17:55:51 I0616 17:55:49.075129 367 provisioner.cpp:255] Using default backend 'copy'
> 17:55:51 I0616 17:55:49.084233 14119 executor.cpp:853] Sent SIGTERM to the following process trees:
> 17:55:51 [
> 17:55:51 -+- 14127 /bin/bash /home/admin/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-debian-8/mesos/build/src/mesos-containerizer launch --help=false --launch_info={"command":{"shell":true,"value":"sleep 1000"},"environment":{"variables":[{"name":"PWD","type":"VALUE","value":"\/tmp\/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9\/slaves\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0\/frameworks\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000\/executors\/f26c4d85-585c-48e6-be70-248daaf3e2b7\/runs\/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d"},{"name":"PATH","type":"VALUE","value":"\/usr\/local\/sbin:\/usr\/local\/bin:\/usr\/sbin:\/usr\/bin:\/sbin:\/bin"},{"name":"MESOS_RECOVERY_TIMEOUT","type":"VALUE","value":"15mins"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(473)@172.16.10.45:60241"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9\/slaves\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0\/frameworks\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000\/executors\/f26c4d85-585c-48e6-be70-248daaf3e2b7\/runs\/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9\/slaves\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0\/frameworks\/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000\/executors\/f26c4d85-585c-48e6-be70-248daaf3e2b7\/runs\/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d"},{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"BIN_SH","type":"VALUE","value":"xpg4"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.45:60241"},{"name":"SHLVL","type":"VALUE","value":"0"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"DUALCASE","type":"VALUE","value":"1"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiIyZjgwYzViNy0zYmQ4LTRmYzgtOTYxNS01ZWJjNGMyNDc1NWQiLCJlaWQiOiJmMjZjNGQ4NS01ODVjLTQ4ZTYtYmU3MC0yNDhkYWFmM2UyYjciLCJmaWQiOiI4NzhjYjZmZS04ZGZkLTQ5NzItYmRhZC0zNTVmZmU5MjJiMmQtMDAwMCJ9.DW3cQerKWnu0YS3BWT2A0o23STzQC5K_EZ73VCuHPcE"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"f26c4d85-585c-48e6-be70-248daaf3e2b7"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"2secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000"}]}} --unshare_namespace_mnt=false
> 17:55:51 \--- 14138 ()
> 17:55:51 ]
> 17:55:51 I0616 17:55:49.084267 14119 executor.cpp:857] Scheduling escalation to SIGKILL in 3secs from now
> 17:55:51 I0616 17:55:49.087218 367 cluster.cpp:448] Creating default 'local' authorizer
> 17:55:51 I0616 17:55:49.087647 389 slave.cpp:249] Mesos agent started on (474)@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.087666 389 slave.cpp:250] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="cgroups/cpu,cgroups/mem" --launcher="linux" --launcher_dir="/home/admin/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-debian-8/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --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_RecoverTerminatedExecutor_3jELmV" --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_RecoverTerminatedExecutor_JG70a9"
> 17:55:51 I0616 17:55:49.087893 389 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/credential'
> 17:55:51 I0616 17:55:49.087961 389 slave.cpp:282] Agent using credential for: test-principal
> 17:55:51 I0616 17:55:49.088002 389 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_3jELmV/http_credentials'
> 17:55:51 I0616 17:55:49.088141 389 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
> 17:55:51 I0616 17:55:49.088202 389 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
> 17:55:51 I0616 17:55:49.088304 389 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
> 17:55:51 I0616 17:55:49.088347 389 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
> 17:55:51 I0616 17:55:49.088418 389 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
> 17:55:51 I0616 17:55:49.088444 389 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
> 17:55:51 I0616 17:55:49.089440 389 slave.cpp:553] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> 17:55:51 I0616 17:55:49.089480 389 slave.cpp:561] Agent attributes: [ ]
> 17:55:51 I0616 17:55:49.089486 389 slave.cpp:566] Agent hostname: ip-172-16-10-45.ec2.internal
> 17:55:51 I0616 17:55:49.089567 387 status_update_manager.cpp:177] Pausing sending status updates
> 17:55:51 I0616 17:55:49.089882 387 state.cpp:62] Recovering state from '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta'
> 17:55:51 I0616 17:55:49.089920 387 state.cpp:710] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/resources/resources.info'
> 17:55:51 I0616 17:55:49.090970 388 slave.cpp:6219] Recovering framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.091001 388 slave.cpp:7166] Recovering executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.091330 390 status_update_manager.cpp:203] Recovering status update manager
> 17:55:51 I0616 17:55:49.091342 390 status_update_manager.cpp:211] Recovering executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.091359 390 status_update_manager.cpp:500] Creating StatusUpdate stream for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.091487 390 status_update_manager.cpp:810] Replaying status update stream for task f26c4d85-585c-48e6-be70-248daaf3e2b7
> 17:55:51 I0616 17:55:49.091714 392 containerizer.cpp:582] Recovering containerizer
> 17:55:51 I0616 17:55:49.091753 392 containerizer.cpp:638] Recovering container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d for executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.092494 388 linux_launcher.cpp:291] Recovered container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.093688 391 memory.cpp:479] Started listening for OOM events for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.094112 391 memory.cpp:590] Started listening on 'low' memory pressure events for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.094492 391 memory.cpp:590] Started listening on 'medium' memory pressure events for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.094858 391 memory.cpp:590] Started listening on 'critical' memory pressure events for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.096418 387 provisioner.cpp:416] Provisioner recovery complete
> 17:55:51 I0616 17:55:49.096827 388 slave.cpp:6012] Sending reconnect request to executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 at executor(1)@172.16.10.45:59728
> 17:55:51 I0616 17:55:49.097147 387 slave.cpp:4224] Cleaning up un-reregistered executors
> 17:55:51 I0616 17:55:49.097163 390 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.097163 387 slave.cpp:4242] Killing un-reregistered executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 at executor(1)@172.16.10.45:59728
> 17:55:51 I0616 17:55:49.097184 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.097198 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 74833ns
> 17:55:51 I0616 17:55:49.097245 387 slave.cpp:6128] Finished recovery
> 17:55:51 I0616 17:55:49.097275 393 containerizer.cpp:2101] Destroying container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d in RUNNING state
> 17:55:51 I0616 17:55:49.097379 393 linux_launcher.cpp:505] Asked to destroy container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.097574 387 slave.cpp:6310] Querying resource estimator for oversubscribable resources
> 17:55:51 I0616 17:55:49.097703 387 slave.cpp:946] New master detected at master@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.097728 387 slave.cpp:981] Detecting new master
> 17:55:51 I0616 17:55:49.097726 391 status_update_manager.cpp:177] Pausing sending status updates
> 17:55:51 I0616 17:55:49.097806 387 slave.cpp:6324] Received oversubscribable resources {} from the resource estimator
> 17:55:51 I0616 17:55:49.097875 393 linux_launcher.cpp:548] Using freezer to destroy cgroup mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.098623 386 cgroups.cpp:2692] Freezing cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.099607 387 cgroups.cpp:1405] Successfully froze cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d after 0ns
> 17:55:51 I0616 17:55:49.100739 391 cgroups.cpp:2710] Thawing cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.101768 388 cgroups.cpp:1434] Successfully thawed cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d after 0ns
> 17:55:51 I0616 17:55:49.102028 388 slave.cpp:1008] Authenticating with master master@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.102061 388 slave.cpp:1019] Using default CRAM-MD5 authenticatee
> 17:55:51 I0616 17:55:49.102203 389 authenticatee.cpp:121] Creating new client SASL connection
> 17:55:51 I0616 17:55:49.102231 388 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.102309 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.102324 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 115012ns
> 17:55:51 I0616 17:55:49.102859 389 master.cpp:7468] Authenticating slave(474)@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.102978 393 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(987)@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.103091 390 authenticator.cpp:98] Creating new server SASL connection
> 17:55:51 I0616 17:55:49.103513 390 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
> 17:55:51 I0616 17:55:49.103538 390 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
> 17:55:51 I0616 17:55:49.103605 392 authenticator.cpp:204] Received SASL authentication start
> 17:55:51 I0616 17:55:49.103648 392 authenticator.cpp:326] Authentication requires more steps
> 17:55:51 I0616 17:55:49.103688 392 authenticatee.cpp:259] Received SASL authentication step
> 17:55:51 I0616 17:55:49.103798 387 authenticator.cpp:232] Received SASL authentication step
> 17:55:51 I0616 17:55:49.103821 387 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-45.ec2.internal' server FQDN: 'ip-172-16-10-45.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> 17:55:51 I0616 17:55:49.103826 387 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
> 17:55:51 I0616 17:55:49.103837 387 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> 17:55:51 I0616 17:55:49.103843 387 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-45.ec2.internal' server FQDN: 'ip-172-16-10-45.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> 17:55:51 I0616 17:55:49.103847 387 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> 17:55:51 I0616 17:55:49.103852 387 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> 17:55:51 I0616 17:55:49.103859 387 authenticator.cpp:318] Authentication success
> 17:55:51 I0616 17:55:49.103904 387 authenticatee.cpp:299] Authentication success
> 17:55:51 I0616 17:55:49.103929 392 master.cpp:7498] Successfully authenticated principal 'test-principal' at slave(474)@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.103971 389 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(987)@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.104032 387 slave.cpp:1103] Successfully authenticated with master master@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.104212 387 slave.cpp:1523] Will retry registration in 19.474236ms if necessary
> 17:55:51 I0616 17:55:49.104312 392 master.cpp:5756] Received re-register agent message from agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(474)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:51 I0616 17:55:49.104375 392 master.cpp:3702] Authorizing agent with principal 'test-principal'
> 17:55:51 I0616 17:55:49.104543 386 master.cpp:5825] Authorized re-registration of agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(474)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:51 I0616 17:55:49.104583 386 master.cpp:5876] Re-registering agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(473)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:51 I0616 17:55:49.104683 386 master.cpp:6249] Sending updated checkpointed resources {} to agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(474)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:51 I0616 17:55:49.104701 393 hierarchical.cpp:703] Agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 reactivated
> 17:55:51 I0616 17:55:49.104701 392 slave.cpp:1249] Re-registered with master master@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.104753 392 slave.cpp:1286] Forwarding total oversubscribed resources {}
> 17:55:51 I0616 17:55:49.104780 389 status_update_manager.cpp:184] Resuming sending status updates
> 17:55:51 I0616 17:55:49.104852 392 slave.cpp:3270] Updating info for framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 with pid updated to scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.104856 389 master.cpp:6341] Received update of agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(474)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) with total oversubscribed resources {}
> 17:55:51 I0616 17:55:49.104890 392 slave.cpp:7006] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/framework.info'
> 17:55:51 I0616 17:55:49.105128 392 slave.cpp:7017] Checkpointing framework pid 'scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241' to '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/framework.pid'
> 17:55:51 I0616 17:55:49.105293 392 slave.cpp:3331] Ignoring new checkpointed resources identical to the current version: {}
> 17:55:51 I0616 17:55:49.105309 388 status_update_manager.cpp:184] Resuming sending status updates
> 17:55:51 I0616 17:55:49.105610 393 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.105626 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.105634 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 42725ns
> 17:55:51 I0616 17:55:49.105648 387 containerizer.cpp:2507] Container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d has exited
> 17:55:51 I0616 17:55:49.105810 390 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.105826 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.105837 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 37880ns
> 17:55:51 I0616 17:55:49.106020 392 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.106041 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.106053 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 50265ns
> 17:55:51 I0616 17:55:49.106243 386 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.106261 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.106267 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 41781ns
> 17:55:51 I0616 17:55:49.106436 388 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.106457 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.106469 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 46822ns
> 17:55:51 I0616 17:55:49.106633 387 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.106649 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.106657 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 41182ns
> 17:55:51 I0616 17:55:49.106804 389 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.106827 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.106839 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 49117ns
> 17:55:51 I0616 17:55:49.107028 393 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.107048 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.107059 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 48558ns
> 17:55:51 I0616 17:55:49.107215 386 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.107236 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.107244 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 46338ns
> 17:55:51 I0616 17:55:49.107417 392 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.107437 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.107448 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 44167ns
> 17:55:51 I0616 17:55:49.107640 390 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.107656 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.107663 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 42502ns
> 17:55:51 I0616 17:55:49.107833 389 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.107852 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.107864 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 44749ns
> 17:55:51 I0616 17:55:49.108009 388 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.108026 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.108032 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 36035ns
> 17:55:51 I0616 17:55:49.108198 391 slave.cpp:6310] Querying resource estimator for oversubscribable resources
> 17:55:51 I0616 17:55:49.108249 393 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.108265 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.108275 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 43818ns
> 17:55:51 I0616 17:55:49.108311 393 slave.cpp:6324] Received oversubscribable resources {} from the resource estimator
> 17:55:51 I0616 17:55:49.108461 388 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.108482 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.108494 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 44687ns
> 17:55:51 I0616 17:55:49.108644 389 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.108660 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.108667 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 35176ns
> 17:55:51 I0616 17:55:49.108837 387 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.108855 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.108861 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 48001ns
> 17:55:51 I0616 17:55:49.109012 391 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.109030 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.109036 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 41327ns
> 17:55:51 I0616 17:55:49.109311 386 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.109328 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.109333 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 37816ns
> 17:55:51 I0616 17:55:49.109479 393 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.109500 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.109513 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 46126ns
> 17:55:51 I0616 17:55:49.109668 389 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.109684 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.109690 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 37349ns
> 17:55:51 I0616 17:55:49.109835 387 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.109855 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.109869 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 44269ns
> 17:55:51 I0616 17:55:49.110044 392 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.110066 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.110077 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 51667ns
> 17:55:51 I0616 17:55:49.110244 390 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.110260 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.110267 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 43071ns
> 17:55:51 I0616 17:55:49.110445 388 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.110465 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.110471 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 47371ns
> 17:55:51 I0616 17:55:49.110648 391 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.110667 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.110676 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 44727ns
> 17:55:51 I0616 17:55:49.110834 386 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.110854 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.110862 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 48435ns
> 17:55:51 I0616 17:55:49.110986 389 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.111002 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.111008 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 35639ns
> 17:55:51 I0616 17:55:49.111135 387 slave.cpp:6310] Querying resource estimator for oversubscribable resources
> 17:55:51 I0616 17:55:49.111213 388 slave.cpp:6324] Received oversubscribable resources {} from the resource estimator
> 17:55:51 I0616 17:55:49.111277 393 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.111294 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.111300 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 37071ns
> 17:55:51 I0616 17:55:49.111436 391 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.111459 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.111469 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 47658ns
> 17:55:51 I0616 17:55:49.111649 390 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.111665 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.111672 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 36542ns
> 17:55:51 I0616 17:55:49.111821 389 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.111837 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.111845 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 37972ns
> 17:55:51 I0616 17:55:49.111994 393 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.112013 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.112020 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 43209ns
> 17:55:51 I0616 17:55:49.112177 392 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.112197 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.112210 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 47275ns
> 17:55:51 I0616 17:55:49.112346 386 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.112362 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.112370 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 36110ns
> 17:55:51 I0616 17:55:49.112521 391 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.112538 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.112545 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 41630ns
> 17:55:51 I0616 17:55:49.112680 388 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.112695 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.112702 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 34115ns
> 17:55:51 I0616 17:55:49.112831 390 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.112846 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.112854 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 33226ns
> 17:55:51 I0616 17:55:49.112989 389 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.113006 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.113013 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 41542ns
> 17:55:51 I0616 17:55:49.113163 387 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.113183 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.113190 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 44149ns
> 17:55:51 I0616 17:55:49.113370 392 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.113386 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.113394 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 38177ns
> 17:55:51 I0616 17:55:49.113538 391 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.113556 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.113564 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 44019ns
> 17:55:51 I0616 17:55:49.113731 386 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.113749 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.113756 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 42962ns
> 17:55:51 I0616 17:55:49.113879 393 slave.cpp:6310] Querying resource estimator for oversubscribable resources
> 17:55:51 I0616 17:55:49.113909 390 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.113921 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.113934 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 34685ns
> 17:55:51 I0616 17:55:49.113967 391 slave.cpp:6324] Received oversubscribable resources {} from the resource estimator
> 17:55:51 I0616 17:55:49.114131 392 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.114151 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.114162 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 42937ns
> 17:55:51 I0616 17:55:49.114322 390 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.114341 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.114352 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 43392ns
> 17:55:51 I0616 17:55:49.114483 393 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.114503 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.114514 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 41501ns
> 17:55:51 I0616 17:55:49.114694 389 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.114712 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.114720 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 43048ns
> 17:55:51 I0616 17:55:49.114866 388 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.114886 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.114898 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 44446ns
> 17:55:51 I0616 17:55:49.115046 387 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.115065 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.115078 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 43875ns
> 17:55:51 I0616 17:55:49.115226 391 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.115242 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.115249 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 39591ns
> 17:55:51 I0616 17:55:49.115391 392 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.115411 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.115422 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 41661ns
> 17:55:51 I0616 17:55:49.115562 386 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.115581 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.115593 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 41751ns
> 17:55:51 I0616 17:55:49.115741 390 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.115759 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.115772 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 41461ns
> 17:55:51 I0616 17:55:49.115933 389 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.115947 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.115953 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 37206ns
> 17:55:51 I0616 17:55:49.116122 387 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.116108 393 slave.cpp:5775] Current disk usage 12.43%. Max allowed age: 5.430177220889051days
> 17:55:51 I0616 17:55:49.116150 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.116169 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 58020ns
> 17:55:51 I0616 17:55:49.116333 389 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.116348 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.116355 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 36421ns
> 17:55:51 I0616 17:55:49.116504 393 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.116523 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.116534 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 44213ns
> 17:55:51 I0616 17:55:49.116667 390 slave.cpp:6310] Querying resource estimator for oversubscribable resources
> 17:55:51 I0616 17:55:49.116803 388 hierarchical.cpp:1908] No allocations performed
> 17:55:51 I0616 17:55:49.116822 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.116835 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 45104ns
> 17:55:51 E0616 17:55:49.116833 387 slave.cpp:5247] Termination of executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 failed: Failed to kill all processes in the container: Timed out after 1mins
> 17:55:51 I0616 17:55:49.116899 387 slave.cpp:4296] Handling status update TASK_LOST (UUID: 7db256af-076b-451c-aa50-51977df315d2) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 from @0.0.0.0:0
> 17:55:51 I0616 17:55:49.117009 387 slave.cpp:6324] Received oversubscribable resources {} from the resource estimator
> 17:55:51 W0616 17:55:49.117370 388 containerizer.cpp:2054] Skipping status for container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d because: Container does not exist
> 17:55:51 W0616 17:55:49.117585 388 containerizer.cpp:1923] Ignoring update for currently being destroyed container 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.117717 390 status_update_manager.cpp:323] Received status update TASK_LOST (UUID: 7db256af-076b-451c-aa50-51977df315d2) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.117755 390 status_update_manager.cpp:834] Checkpointing UPDATE for status update TASK_LOST (UUID: 7db256af-076b-451c-aa50-51977df315d2) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.117873 390 status_update_manager.cpp:377] Forwarding update TASK_LOST (UUID: 7db256af-076b-451c-aa50-51977df315d2) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 to the agent
> 17:55:51 I0616 17:55:49.117986 388 slave.cpp:4736] Forwarding the update TASK_LOST (UUID: 7db256af-076b-451c-aa50-51977df315d2) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 to master@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.118070 388 slave.cpp:4630] Status update manager successfully handled status update TASK_LOST (UUID: 7db256af-076b-451c-aa50-51977df315d2) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.118158 391 master.cpp:6486] Status update TASK_LOST (UUID: 7db256af-076b-451c-aa50-51977df315d2) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 from agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(474)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:51 I0616 17:55:49.118192 391 master.cpp:6548] Forwarding status update TASK_LOST (UUID: 7db256af-076b-451c-aa50-51977df315d2) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.118255 391 master.cpp:8559] Updating the state of task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 (latest state: TASK_LOST, status update state: TASK_LOST)
> 17:55:51 I0616 17:55:49.118329 388 sched.cpp:1041] Scheduler::statusUpdate took 31977ns
> 17:55:51 I0616 17:55:49.118502 391 master.cpp:5235] Processing ACKNOWLEDGE call 7db256af-076b-451c-aa50-51977df315d2 for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 (default) at scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241 on agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0
> 17:55:51 I0616 17:55:49.118537 391 master.cpp:8653] Removing task f26c4d85-585c-48e6-be70-248daaf3e2b7 with resources cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 on agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 at slave(474)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:51 I0616 17:55:49.118568 392 hierarchical.cpp:1177] Recovered cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 from framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.118705 388 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 7db256af-076b-451c-aa50-51977df315d2) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.118752 388 status_update_manager.cpp:834] Checkpointing ACK for status update TASK_LOST (UUID: 7db256af-076b-451c-aa50-51977df315d2) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.118795 388 status_update_manager.cpp:531] Cleaning up status update stream for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.118914 388 slave.cpp:3546] Status update manager successfully handled status update acknowledgement (UUID: 7db256af-076b-451c-aa50-51977df315d2) for task f26c4d85-585c-48e6-be70-248daaf3e2b7 of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.118930 388 slave.cpp:7456] Completing task f26c4d85-585c-48e6-be70-248daaf3e2b7
> 17:55:51 I0616 17:55:49.118937 388 slave.cpp:5369] Cleaning up executor 'f26c4d85-585c-48e6-be70-248daaf3e2b7' of framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 at executor(1)@172.16.10.45:59728
> 17:55:51 I0616 17:55:49.119108 393 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7/runs/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d' for gc 6.99999896870519days in the future
> 17:55:51 I0616 17:55:49.119155 393 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7' for gc 6.99999896870519days in the future
> 17:55:51 I0616 17:55:49.119159 388 slave.cpp:5465] Cleaning up framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.119177 393 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7/runs/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d' for gc 6.99999896870519days in the future
> 17:55:51 I0616 17:55:49.119200 393 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000/executors/f26c4d85-585c-48e6-be70-248daaf3e2b7' for gc 6.99999896870519days in the future
> 17:55:51 I0616 17:55:49.119227 389 status_update_manager.cpp:285] Closing status update streams for framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.119236 393 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000' for gc 6.99999896870519days in the future
> 17:55:51 I0616 17:55:49.119267 393 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JG70a9/meta/slaves/878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0/frameworks/878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000' for gc 6.99999896870519days in the future
> 17:55:51 I0616 17:55:49.119544 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:51 I0616 17:55:49.119566 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 156085ns
> 17:55:51 I0616 17:55:49.119675 391 master.cpp:7298] Sending 1 offers to framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 (default) at scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.119827 391 sched.cpp:933] Scheduler::resourceOffers took 33744ns
> 17:55:51 I0616 17:55:49.120055 367 sched.cpp:2021] Asked to stop the driver
> 17:55:51 I0616 17:55:49.120110 389 sched.cpp:1203] Stopping framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.120214 386 master.cpp:7979] Processing TEARDOWN call for framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 (default) at scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.120234 386 master.cpp:7991] Removing framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 (default) at scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.120244 386 master.cpp:3203] Deactivating framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 (default) at scheduler-0d1ec9bb-8b9d-4dfa-8c2b-947d45023f8b@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.120299 389 hierarchical.cpp:410] Deactivated framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.120481 391 slave.cpp:3099] Asked to shut down framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000 by master@172.16.10.45:60241
> 17:55:51 I0616 17:55:49.120519 387 hierarchical.cpp:1177] Recovered cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0 from framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.120566 391 slave.cpp:3114] Cannot shut down unknown framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 I0616 17:55:49.120669 387 hierarchical.cpp:353] Removed framework 878cb6fe-8dfd-4972-bdad-355ffe922b2d-0000
> 17:55:51 ../../src/tests/cluster.cpp:580: Failure
> 17:55:51 Value of: containers->empty()
> 17:55:51 Actual: false
> 17:55:51 Expected: true
> 17:55:51 Failed to destroy containers: { 2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d }
> 17:55:51 I0616 17:55:49.121384 367 slave.cpp:818] Agent terminating
> 17:55:51 I0616 17:55:49.123891 367 master.cpp:1158] Master terminating
> 17:55:51 I0616 17:55:49.124078 387 hierarchical.cpp:620] Removed agent 878cb6fe-8dfd-4972-bdad-355ffe922b2d-S0
> 17:55:51 I0616 17:55:49.131655 389 cgroups.cpp:2692] Freezing cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.132642 391 cgroups.cpp:1405] Successfully froze cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d after 955904ns
> 17:55:51 I0616 17:55:49.133661 389 cgroups.cpp:2710] Thawing cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d
> 17:55:51 I0616 17:55:49.134560 389 cgroups.cpp:1434] Successfully thawed cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8/2f80c5b7-3bd8-4fc8-9615-5ebc4c24755d after 875008ns
> 17:55:51 I0616 17:55:49.136478 386 cgroups.cpp:2692] Freezing cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8
> 17:55:51 I0616 17:55:49.238567 390 cgroups.cpp:1405] Successfully froze cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8 after 102.05696ms
> 17:55:51 I0616 17:55:49.239594 389 cgroups.cpp:2710] Thawing cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8
> 17:55:51 I0616 17:55:49.240536 387 cgroups.cpp:1434] Successfully thawed cgroup /sys/fs/cgroup/freezer/mesos_test_778a79dc-ac77-45cc-8654-ca89765f0da8 after 910848ns
> 17:55:51 [ FAILED ] SlaveRecoveryTest/0.RecoverTerminatedExecutor, where TypeParam = mesos::internal::slave::MesosContainerizer (369 ms)
> {noformat}
> {noformat}
> 17:55:52 [ RUN ] SlaveRecoveryTest/0.CleanupExecutor
> 17:55:52 I0616 17:55:51.322322 367 cluster.cpp:162] Creating default 'local' authorizer
> 17:55:52 I0616 17:55:51.323604 389 master.cpp:438] Master 172087b8-9974-4113-8f2b-6adda099319f (ip-172-16-10-45.ec2.internal) started on 172.16.10.45:60241
> 17:55:52 I0616 17:55:51.323623 389 master.cpp:440] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/auPQLb/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="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --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" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/auPQLb/master" --zk_session_timeout="10secs"
> 17:55:52 I0616 17:55:51.323757 389 master.cpp:490] Master only allowing authenticated frameworks to register
> 17:55:52 I0616 17:55:51.323767 389 master.cpp:504] Master only allowing authenticated agents to register
> 17:55:52 I0616 17:55:51.323773 389 master.cpp:517] Master only allowing authenticated HTTP frameworks to register
> 17:55:52 I0616 17:55:51.323779 389 credentials.hpp:37] Loading credentials for authentication from '/tmp/auPQLb/credentials'
> 17:55:52 I0616 17:55:51.323876 389 master.cpp:562] Using default 'crammd5' authenticator
> 17:55:52 I0616 17:55:51.323937 389 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
> 17:55:52 I0616 17:55:51.323997 389 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
> 17:55:52 I0616 17:55:51.324045 389 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
> 17:55:52 I0616 17:55:51.324095 389 master.cpp:642] Authorization enabled
> 17:55:52 I0616 17:55:51.324162 392 whitelist_watcher.cpp:77] No whitelist given
> 17:55:52 I0616 17:55:51.324232 391 hierarchical.cpp:169] Initialized hierarchical allocator process
> 17:55:52 I0616 17:55:51.324734 387 master.cpp:2161] Elected as the leading master!
> 17:55:52 I0616 17:55:51.324751 387 master.cpp:1700] Recovering from registrar
> 17:55:52 I0616 17:55:51.324805 391 registrar.cpp:345] Recovering registrar
> 17:55:52 I0616 17:55:51.324985 391 registrar.cpp:389] Successfully fetched the registry (0B) in 160us
> 17:55:52 I0616 17:55:51.325022 391 registrar.cpp:493] Applied 1 operations in 6414ns; attempting to update the registry
> 17:55:52 I0616 17:55:51.325197 390 registrar.cpp:550] Successfully updated the registry in 154112ns
> 17:55:52 I0616 17:55:51.325248 390 registrar.cpp:422] Successfully recovered registrar
> 17:55:52 I0616 17:55:51.325386 390 master.cpp:1799] Recovered 0 agents from the registry (168B); allowing 10mins for agents to re-register
> 17:55:52 I0616 17:55:51.325417 388 hierarchical.cpp:207] Skipping recovery of hierarchical allocator: nothing to recover
> 17:55:52 I0616 17:55:51.326437 367 containerizer.cpp:230] Using isolation: cgroups/cpu,cgroups/mem,filesystem/posix,network/cni,environment_secret
> 17:55:52 I0616 17:55:51.329814 367 linux_launcher.cpp:150] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
> 17:55:52 I0616 17:55:51.330134 367 provisioner.cpp:255] Using default backend 'copy'
> 17:55:52 I0616 17:55:51.341815 367 cluster.cpp:448] Creating default 'local' authorizer
> 17:55:52 I0616 17:55:51.342270 393 slave.cpp:249] Mesos agent started on (477)@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.342293 393 slave.cpp:250] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="cgroups/cpu,cgroups/mem" --launcher="linux" --launcher_dir="/home/admin/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-debian-8/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --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_CleanupExecutor_Q2K1QY" --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_CleanupExecutor_1jZqj5"
> 17:55:52 I0616 17:55:51.342453 393 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/credential'
> 17:55:52 I0616 17:55:51.342540 393 slave.cpp:282] Agent using credential for: test-principal
> 17:55:52 I0616 17:55:51.342548 393 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/http_credentials'
> 17:55:52 I0616 17:55:51.342627 393 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
> 17:55:52 I0616 17:55:51.342664 393 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
> 17:55:52 I0616 17:55:51.342731 393 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
> 17:55:52 I0616 17:55:51.342769 393 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
> 17:55:52 I0616 17:55:51.342797 393 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
> 17:55:52 I0616 17:55:51.342834 393 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
> 17:55:52 I0616 17:55:51.343206 367 sched.cpp:232] Version: 1.4.0
> 17:55:52 I0616 17:55:51.343371 393 slave.cpp:553] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> 17:55:52 I0616 17:55:51.343402 389 sched.cpp:336] New master detected at master@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.343405 393 slave.cpp:561] Agent attributes: [ ]
> 17:55:52 I0616 17:55:51.343436 393 slave.cpp:566] Agent hostname: ip-172-16-10-45.ec2.internal
> 17:55:52 I0616 17:55:51.343443 389 sched.cpp:407] Authenticating with master master@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.343452 389 sched.cpp:414] Using default CRAM-MD5 authenticatee
> 17:55:52 I0616 17:55:51.343503 386 status_update_manager.cpp:177] Pausing sending status updates
> 17:55:52 I0616 17:55:51.343540 389 authenticatee.cpp:121] Creating new client SASL connection
> 17:55:52 I0616 17:55:51.343762 393 state.cpp:62] Recovering state from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta'
> 17:55:52 I0616 17:55:51.343921 390 status_update_manager.cpp:203] Recovering status update manager
> 17:55:52 I0616 17:55:51.343925 388 master.cpp:7468] Authenticating scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.343996 390 containerizer.cpp:582] Recovering containerizer
> 17:55:52 I0616 17:55:51.344039 387 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(991)@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.344141 387 authenticator.cpp:98] Creating new server SASL connection
> 17:55:52 I0616 17:55:51.344506 387 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
> 17:55:52 I0616 17:55:51.344530 387 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
> 17:55:52 I0616 17:55:51.344758 390 authenticator.cpp:204] Received SASL authentication start
> 17:55:52 I0616 17:55:51.344805 390 authenticator.cpp:326] Authentication requires more steps
> 17:55:52 I0616 17:55:51.344861 390 authenticatee.cpp:259] Received SASL authentication step
> 17:55:52 I0616 17:55:51.344928 390 authenticator.cpp:232] Received SASL authentication step
> 17:55:52 I0616 17:55:51.344954 390 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-45.ec2.internal' server FQDN: 'ip-172-16-10-45.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> 17:55:52 I0616 17:55:51.344962 390 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
> 17:55:52 I0616 17:55:51.344974 390 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> 17:55:52 I0616 17:55:51.344990 390 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-45.ec2.internal' server FQDN: 'ip-172-16-10-45.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> 17:55:52 I0616 17:55:51.344996 390 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> 17:55:52 I0616 17:55:51.345003 390 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> 17:55:52 I0616 17:55:51.345016 390 authenticator.cpp:318] Authentication success
> 17:55:52 I0616 17:55:51.345088 390 master.cpp:7498] Successfully authenticated principal 'test-principal' at scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.345109 386 authenticatee.cpp:299] Authentication success
> 17:55:52 I0616 17:55:51.345096 392 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(991)@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.345202 386 sched.cpp:513] Successfully authenticated with master master@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.345216 386 sched.cpp:836] Sending SUBSCRIBE call to master@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.345258 386 sched.cpp:869] Will retry registration in 1.472570284secs if necessary
> 17:55:52 I0616 17:55:51.345304 393 master.cpp:2853] Received SUBSCRIBE call for framework 'default' at scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.345333 393 master.cpp:2197] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
> 17:55:52 I0616 17:55:51.345458 390 master.cpp:2933] Subscribing framework default with checkpointing enabled and capabilities [ ]
> 17:55:52 I0616 17:55:51.345626 393 hierarchical.cpp:301] Added framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.345626 390 sched.cpp:759] Framework registered with 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.345669 393 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.345676 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.345675 390 sched.cpp:773] Scheduler::registered took 12822ns
> 17:55:52 I0616 17:55:51.345682 393 hierarchical.cpp:1493] Performed allocation for 0 agents in 18515ns
> 17:55:52 I0616 17:55:51.346019 386 provisioner.cpp:416] Provisioner recovery complete
> 17:55:52 I0616 17:55:51.346191 391 slave.cpp:6128] Finished recovery
> 17:55:52 I0616 17:55:51.346444 391 slave.cpp:6310] Querying resource estimator for oversubscribable resources
> 17:55:52 I0616 17:55:51.346546 392 slave.cpp:946] New master detected at master@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.346551 393 status_update_manager.cpp:177] Pausing sending status updates
> 17:55:52 I0616 17:55:51.346591 392 slave.cpp:981] Detecting new master
> 17:55:52 I0616 17:55:51.346626 392 slave.cpp:6324] Received oversubscribable resources {} from the resource estimator
> 17:55:52 I0616 17:55:51.352785 392 slave.cpp:1008] Authenticating with master master@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.352813 392 slave.cpp:1019] Using default CRAM-MD5 authenticatee
> 17:55:52 I0616 17:55:51.352881 386 authenticatee.cpp:121] Creating new client SASL connection
> 17:55:52 I0616 17:55:51.353349 386 master.cpp:7468] Authenticating slave(477)@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.353399 389 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(992)@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.353474 386 authenticator.cpp:98] Creating new server SASL connection
> 17:55:52 I0616 17:55:51.353799 386 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
> 17:55:52 I0616 17:55:51.353818 386 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
> 17:55:52 I0616 17:55:51.353881 388 authenticator.cpp:204] Received SASL authentication start
> 17:55:52 I0616 17:55:51.353924 388 authenticator.cpp:326] Authentication requires more steps
> 17:55:52 I0616 17:55:51.353957 388 authenticatee.cpp:259] Received SASL authentication step
> 17:55:52 I0616 17:55:51.354001 388 authenticator.cpp:232] Received SASL authentication step
> 17:55:52 I0616 17:55:51.354039 388 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-45.ec2.internal' server FQDN: 'ip-172-16-10-45.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> 17:55:52 I0616 17:55:51.354049 388 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
> 17:55:52 I0616 17:55:51.354056 388 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> 17:55:52 I0616 17:55:51.354063 388 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-45.ec2.internal' server FQDN: 'ip-172-16-10-45.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> 17:55:52 I0616 17:55:51.354066 388 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> 17:55:52 I0616 17:55:51.354070 388 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> 17:55:52 I0616 17:55:51.354077 388 authenticator.cpp:318] Authentication success
> 17:55:52 I0616 17:55:51.354113 388 authenticatee.cpp:299] Authentication success
> 17:55:52 I0616 17:55:51.354135 390 master.cpp:7498] Successfully authenticated principal 'test-principal' at slave(477)@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.354166 392 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(992)@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.354233 388 slave.cpp:1103] Successfully authenticated with master master@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.354311 388 slave.cpp:1523] Will retry registration in 7.646056ms if necessary
> 17:55:52 I0616 17:55:51.354374 386 master.cpp:5470] Received register agent message from slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:52 I0616 17:55:51.354418 386 master.cpp:3702] Authorizing agent with principal 'test-principal'
> 17:55:52 I0616 17:55:51.354537 393 master.cpp:5530] Authorized registration of agent at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:52 I0616 17:55:51.354586 393 master.cpp:5609] Registering agent at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) with id 172087b8-9974-4113-8f2b-6adda099319f-S0
> 17:55:52 I0616 17:55:51.354712 387 registrar.cpp:493] Applied 1 operations in 14751ns; attempting to update the registry
> 17:55:52 I0616 17:55:51.354848 391 registrar.cpp:550] Successfully updated the registry in 111104ns
> 17:55:52 I0616 17:55:51.354931 386 master.cpp:5656] Admitted agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:52 I0616 17:55:51.355068 391 slave.cpp:4826] Received ping from slave-observer(467)@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.355084 386 master.cpp:5687] Registered agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> 17:55:52 I0616 17:55:51.355124 391 slave.cpp:1149] Registered with master master@172.16.10.45:60241; given agent ID 172087b8-9974-4113-8f2b-6adda099319f-S0
> 17:55:52 I0616 17:55:51.355155 388 hierarchical.cpp:587] Added agent 172087b8-9974-4113-8f2b-6adda099319f-S0 (ip-172-16-10-45.ec2.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
> 17:55:52 I0616 17:55:51.355185 387 status_update_manager.cpp:184] Resuming sending status updates
> 17:55:52 I0616 17:55:51.355298 391 slave.cpp:1169] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/slave.info'
> 17:55:52 I0616 17:55:51.355357 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.355374 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 177669ns
> 17:55:52 I0616 17:55:51.355448 391 slave.cpp:1207] Forwarding total oversubscribed resources {}
> 17:55:52 I0616 17:55:51.355473 393 master.cpp:7298] Sending 1 offers to framework 172087b8-9974-4113-8f2b-6adda099319f-0000 (default) at scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.355535 393 master.cpp:6341] Received update of agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) with total oversubscribed resources {}
> 17:55:52 I0616 17:55:51.355644 387 sched.cpp:933] Scheduler::resourceOffers took 52715ns
> 17:55:52 I0616 17:55:51.356107 388 master.cpp:3917] Processing ACCEPT call for offers: [ 172087b8-9974-4113-8f2b-6adda099319f-O0 ] on agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) for framework 172087b8-9974-4113-8f2b-6adda099319f-0000 (default) at scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.356142 388 master.cpp:3469] Authorizing framework principal 'test-principal' to launch task 88af9adf-0d1b-4ea6-a3d8-67d825f49766
> 17:55:52 I0616 17:55:51.356606 388 master.cpp:9317] Adding task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 with resources cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] on agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:52 I0616 17:55:51.356676 388 master.cpp:4572] Launching task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 (default) at scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241 with resources cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] on agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:52 I0616 17:55:51.356904 389 slave.cpp:1633] Got assigned task '88af9adf-0d1b-4ea6-a3d8-67d825f49766' for framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.356959 389 slave.cpp:7006] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/framework.info'
> 17:55:52 I0616 17:55:51.357098 386 hierarchical.cpp:912] Updated allocation of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 on agent 172087b8-9974-4113-8f2b-6adda099319f-S0 from cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] to cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000]
> 17:55:52 I0616 17:55:51.357115 389 slave.cpp:7017] Checkpointing framework pid 'scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241' to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/framework.pid'
> 17:55:52 I0616 17:55:51.357352 389 slave.cpp:1914] Authorizing task '88af9adf-0d1b-4ea6-a3d8-67d825f49766' for framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.357375 389 slave.cpp:6627] Authorizing framework principal 'test-principal' to launch task 88af9adf-0d1b-4ea6-a3d8-67d825f49766
> 17:55:52 I0616 17:55:51.357627 393 slave.cpp:2101] Launching task '88af9adf-0d1b-4ea6-a3d8-67d825f49766' for framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.357863 393 paths.cpp:573] Trying to chown '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766/runs/7ea3f4a1-fe4c-4daa-8b89-ad814095daea' to user 'root'
> 17:55:52 I0616 17:55:51.358008 393 slave.cpp:7475] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766/executor.info'
> 17:55:52 I0616 17:55:51.358288 393 slave.cpp:7087] Launching executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 with resources cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32 in work directory '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766/runs/7ea3f4a1-fe4c-4daa-8b89-ad814095daea'
> 17:55:52 I0616 17:55:51.358537 393 slave.cpp:7503] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766/runs/7ea3f4a1-fe4c-4daa-8b89-ad814095daea/tasks/88af9adf-0d1b-4ea6-a3d8-67d825f49766/task.info'
> 17:55:52 I0616 17:55:51.358705 393 slave.cpp:2330] Queued task '88af9adf-0d1b-4ea6-a3d8-67d825f49766' for executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.358741 393 slave.cpp:899] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766/runs/7ea3f4a1-fe4c-4daa-8b89-ad814095daea'
> 17:55:52 I0616 17:55:51.358767 393 slave.cpp:899] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766/runs/7ea3f4a1-fe4c-4daa-8b89-ad814095daea'
> 17:55:52 I0616 17:55:51.358870 393 slave.cpp:2796] Launching container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea for executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.358995 389 containerizer.cpp:1056] Starting container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.359422 393 cgroups.cpp:410] Creating cgroup at '/sys/fs/cgroup/cpu,cpuacct/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea' for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.360280 393 cgroups.cpp:473] Chown the cgroup at '/sys/fs/cgroup/cpu,cpuacct/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea' to user 'root' for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.360328 393 cgroups.cpp:410] Creating cgroup at '/sys/fs/cgroup/memory/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea' for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.361312 393 memory.cpp:479] Started listening for OOM events for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.361662 393 memory.cpp:590] Started listening on 'low' memory pressure events for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.362017 393 memory.cpp:590] Started listening on 'medium' memory pressure events for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.362370 393 memory.cpp:590] Started listening on 'critical' memory pressure events for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.362388 393 cgroups.cpp:473] Chown the cgroup at '/sys/fs/cgroup/memory/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea' to user 'root' for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.363071 388 memory.cpp:199] Updated 'memory.soft_limit_in_bytes' to 1056MB for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.363683 388 memory.cpp:228] Updated 'memory.limit_in_bytes' to 1056MB for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.364023 388 cpu.cpp:101] Updated 'cpu.shares' to 2150 (cpus 2.1) for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.365000 387 containerizer.cpp:1630] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/home\/admin\/workspace\/mesos\/Mesos_CI-build\/FLAG\/SSL\/label\/mesos-ec2-debian-8\/mesos\/build\/src"],"shell":false,"value":"\/home\/admin\/workspace\/mesos\/Mesos_CI-build\/FLAG\/SSL\/label\/mesos-ec2-debian-8\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.45:60241"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5\/slaves\/172087b8-9974-4113-8f2b-6adda099319f-S0\/frameworks\/172087b8-9974-4113-8f2b-6adda099319f-0000\/executors\/88af9adf-0d1b-4ea6-a3d8-67d825f49766\/runs\/7ea3f4a1-fe4c-4daa-8b89-ad814095daea"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiI3ZWEzZjRhMS1mZTRjLTRkYWEtOGI4OS1hZDgxNDA5NWRhZWEiLCJlaWQiOiI4OGFmOWFkZi0wZDFiLTRlYTYtYTNkOC02N2Q4MjVmNDk3NjYiLCJmaWQiOiIxNzIwODdiOC05OTc0LTQxMTMtOGYyYi02YWRkYTA5OTMxOWYtMDAwMCJ9.6QFbXHODIDsAfBOZSj2XiMBMtSa7Z_9iKfzTDDCzq_Q"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"88af9adf-0d1b-4ea6-a3d8-67d825f49766"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"172087b8-9974-4113-8f2b-6adda099319f-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":"172087b8-9974-4113-8f2b-6adda099319f-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(477)@172.16.10.45:60241"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"2secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5\/slaves\/172087b8-9974-4113-8f2b-6adda099319f-S0\/frameworks\/172087b8-9974-4113-8f2b-6adda099319f-0000\/executors\/88af9adf-0d1b-4ea6-a3d8-67d825f49766\/runs\/7ea3f4a1-fe4c-4daa-8b89-ad814095daea"}]},"task_environment":{},"user":"root","working_directory":"\/tmp\/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5\/slaves\/172087b8-9974-4113-8f2b-6adda099319f-S0\/frameworks\/172087b8-9974-4113-8f2b-6adda099319f-0000\/executors\/88af9adf-0d1b-4ea6-a3d8-67d825f49766\/runs\/7ea3f4a1-fe4c-4daa-8b89-ad814095daea"}" --pipe_read="35" --pipe_write="36" --runtime_directory="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/containers/7ea3f4a1-fe4c-4daa-8b89-ad814095daea" --unshare_namespace_mnt="false"'
> 17:55:52 I0616 17:55:51.365268 391 linux_launcher.cpp:429] Launching container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea and cloning with namespaces
> 17:55:52 I0616 17:55:51.369611 387 containerizer.cpp:1722] Checkpointing container's forked pid 14192 to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766/runs/7ea3f4a1-fe4c-4daa-8b89-ad814095daea/pids/forked.pid'
> 17:55:52 I0616 17:55:51.387183 393 fetcher.cpp:324] Starting to fetch URIs for container: 7ea3f4a1-fe4c-4daa-8b89-ad814095daea, directory: /tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766/runs/7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.448321 14226 exec.cpp:162] Version: 1.4.0
> 17:55:52 I0616 17:55:51.449728 386 slave.cpp:3826] Got registration for executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 from executor(1)@172.16.10.45:35243
> 17:55:52 I0616 17:55:51.449878 386 slave.cpp:3912] Checkpointing executor pid 'executor(1)@172.16.10.45:35243' to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766/runs/7ea3f4a1-fe4c-4daa-8b89-ad814095daea/pids/libprocess.pid'
> 17:55:52 I0616 17:55:51.450633 14224 exec.cpp:237] Executor registered on agent 172087b8-9974-4113-8f2b-6adda099319f-S0
> 17:55:52 I0616 17:55:51.450927 391 memory.cpp:199] Updated 'memory.soft_limit_in_bytes' to 1056MB for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.451548 391 cpu.cpp:101] Updated 'cpu.shares' to 2150 (cpus 2.1) for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.451869 391 slave.cpp:2543] Sending queued task '88af9adf-0d1b-4ea6-a3d8-67d825f49766' to executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 at executor(1)@172.16.10.45:35243
> 17:55:52 I0616 17:55:51.451625 14224 executor.cpp:169] Received SUBSCRIBED event
> 17:55:52 I0616 17:55:51.451958 14224 executor.cpp:173] Subscribed executor on ip-172-16-10-45.ec2.internal
> 17:55:52 I0616 17:55:51.452358 14222 executor.cpp:169] Received LAUNCH event
> 17:55:52 I0616 17:55:51.452460 14222 executor.cpp:624] Starting task 88af9adf-0d1b-4ea6-a3d8-67d825f49766
> 17:55:52 I0616 17:55:51.455173 14222 executor.cpp:468] Running '/home/admin/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-debian-8/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
> 17:55:52 I0616 17:55:51.456316 14222 executor.cpp:636] Forked command at 14229
> 17:55:52 I0616 17:55:51.458216 386 slave.cpp:4296] Handling status update TASK_RUNNING (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 from executor(1)@172.16.10.45:35243
> 17:55:52 I0616 17:55:51.458925 392 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.458950 392 status_update_manager.cpp:500] Creating StatusUpdate stream for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.459233 392 status_update_manager.cpp:834] Checkpointing UPDATE for status update TASK_RUNNING (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.459333 392 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 to the agent
> 17:55:52 I0616 17:55:51.459448 387 slave.cpp:4736] Forwarding the update TASK_RUNNING (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 to master@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.459568 387 slave.cpp:4630] Status update manager successfully handled status update TASK_RUNNING (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.459594 387 slave.cpp:4646] Sending acknowledgement for status update TASK_RUNNING (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 to executor(1)@172.16.10.45:35243
> 17:55:52 I0616 17:55:51.459597 392 master.cpp:6486] Status update TASK_RUNNING (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 from agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:52 I0616 17:55:51.459625 392 master.cpp:6548] Forwarding status update TASK_RUNNING (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.459687 392 master.cpp:8559] Updating the state of task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
> 17:55:52 I0616 17:55:51.459776 391 sched.cpp:1041] Scheduler::statusUpdate took 18025ns
> 17:55:52 I0616 17:55:51.459899 392 master.cpp:5235] Processing ACKNOWLEDGE call 5c1c31f4-3f11-4a5d-8801-e26857630d1e for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 (default) at scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241 on agent 172087b8-9974-4113-8f2b-6adda099319f-S0
> 17:55:52 I0616 17:55:51.460021 387 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.460058 387 status_update_manager.cpp:834] Checkpointing ACK for status update TASK_RUNNING (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.460144 387 slave.cpp:3546] Status update manager successfully handled status update acknowledgement (UUID: 5c1c31f4-3f11-4a5d-8801-e26857630d1e) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.460300 367 slave.cpp:818] Agent terminating
> 17:55:52 I0616 17:55:51.460427 388 master.cpp:1316] Agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) disconnected
> 17:55:52 I0616 17:55:51.460453 388 master.cpp:3240] Disconnecting agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:52 I0616 17:55:51.460486 388 master.cpp:3259] Deactivating agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:52 I0616 17:55:51.460525 387 hierarchical.cpp:715] Agent 172087b8-9974-4113-8f2b-6adda099319f-S0 deactivated
> 17:55:52 I0616 17:55:51.460556 367 containerizer.cpp:230] Using isolation: cgroups/cpu,cgroups/mem,filesystem/posix,network/cni,environment_secret
> 17:55:52 I0616 17:55:51.463657 367 linux_launcher.cpp:150] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
> 17:55:52 I0616 17:55:51.463943 367 provisioner.cpp:255] Using default backend 'copy'
> 17:55:52 I0616 17:55:51.476178 367 cluster.cpp:448] Creating default 'local' authorizer
> 17:55:52 I0616 17:55:51.476661 389 slave.cpp:249] Mesos agent started on (478)@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.476686 389 slave.cpp:250] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_secret_key="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="cgroups/cpu,cgroups/mem" --launcher="linux" --launcher_dir="/home/admin/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-debian-8/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="cleanup" --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_CleanupExecutor_Q2K1QY" --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_CleanupExecutor_1jZqj5"
> 17:55:52 I0616 17:55:51.476884 389 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/credential'
> 17:55:52 I0616 17:55:51.477035 389 slave.cpp:282] Agent using credential for: test-principal
> 17:55:52 I0616 17:55:51.477053 389 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Q2K1QY/http_credentials'
> 17:55:52 I0616 17:55:51.477180 389 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
> 17:55:52 I0616 17:55:51.477226 389 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
> 17:55:52 I0616 17:55:51.477306 389 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
> 17:55:52 I0616 17:55:51.477344 389 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
> 17:55:52 I0616 17:55:51.477407 389 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
> 17:55:52 I0616 17:55:51.477465 389 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
> 17:55:52 I0616 17:55:51.477831 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.477857 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.477870 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 75097ns
> 17:55:52 I0616 17:55:51.478394 389 slave.cpp:553] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> 17:55:52 I0616 17:55:51.478423 389 slave.cpp:561] Agent attributes: [ ]
> 17:55:52 I0616 17:55:51.478427 389 slave.cpp:566] Agent hostname: ip-172-16-10-45.ec2.internal
> 17:55:52 I0616 17:55:51.478528 393 status_update_manager.cpp:177] Pausing sending status updates
> 17:55:52 I0616 17:55:51.478847 393 state.cpp:62] Recovering state from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta'
> 17:55:52 I0616 17:55:51.478888 393 state.cpp:710] No committed checkpointed resources found at '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta/resources/resources.info'
> 17:55:52 I0616 17:55:51.480011 390 slave.cpp:6219] Recovering framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.480041 390 slave.cpp:7166] Recovering executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.480324 386 status_update_manager.cpp:203] Recovering status update manager
> 17:55:52 I0616 17:55:51.480340 386 status_update_manager.cpp:211] Recovering executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.480362 386 status_update_manager.cpp:500] Creating StatusUpdate stream for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.480550 386 status_update_manager.cpp:810] Replaying status update stream for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766
> 17:55:52 I0616 17:55:51.480801 391 containerizer.cpp:582] Recovering containerizer
> 17:55:52 I0616 17:55:51.480840 391 containerizer.cpp:638] Recovering container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea for executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.481598 387 linux_launcher.cpp:291] Recovered container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.482795 390 memory.cpp:479] Started listening for OOM events for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.483180 390 memory.cpp:590] Started listening on 'low' memory pressure events for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.483544 390 memory.cpp:590] Started listening on 'medium' memory pressure events for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.483912 390 memory.cpp:590] Started listening on 'critical' memory pressure events for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.485383 391 provisioner.cpp:416] Provisioner recovery complete
> 17:55:52 I0616 17:55:51.485731 390 slave.cpp:6088] Sending shutdown to executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 at executor(1)@172.16.10.45:35243
> 17:55:52 I0616 17:55:51.485759 390 slave.cpp:5591] Shutting down executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 at executor(1)@172.16.10.45:35243
> 17:55:52 I0616 17:55:51.485831 390 slave.cpp:6128] Finished recovery
> 17:55:52 I0616 17:55:51.486122 14227 exec.cpp:435] Executor asked to shutdown
> 17:55:52 I0616 17:55:51.486320 393 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.486340 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.486337 14224 executor.cpp:169] Received SHUTDOWN event
> 17:55:52 I0616 17:55:51.486346 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 78374ns
> 17:55:52 I0616 17:55:51.486356 14224 executor.cpp:733] Shutting down
> 17:55:52 I0616 17:55:51.486373 14224 executor.cpp:840] Sending SIGTERM to process tree at pid 14229
> 17:55:52 I0616 17:55:51.486609 389 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.486627 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.486634 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 40105ns
> 17:55:52 I0616 17:55:51.486886 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.486902 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.486908 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 48265ns
> 17:55:52 I0616 17:55:51.487071 391 slave.cpp:5664] Killing executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 at executor(1)@172.16.10.45:35243
> 17:55:52 I0616 17:55:51.487162 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.487179 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.487186 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 37405ns
> 17:55:52 I0616 17:55:51.487299 392 containerizer.cpp:2101] Destroying container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea in RUNNING state
> 17:55:52 I0616 17:55:51.487422 392 linux_launcher.cpp:505] Asked to destroy container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.488044 392 linux_launcher.cpp:548] Using freezer to destroy cgroup mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.489378 389 cgroups.cpp:2692] Freezing cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.490442 389 cgroups.cpp:1405] Successfully froze cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea after 0ns
> 17:55:52 I0616 17:55:51.491600 390 cgroups.cpp:2710] Thawing cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.492666 393 cgroups.cpp:1434] Successfully thawed cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea after 0ns
> 17:55:52 I0616 17:55:51.492988 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.493007 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.493018 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 49214ns
> 17:55:52 I0616 17:55:51.493211 393 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.493232 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.493242 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 46326ns
> 17:55:52 I0616 17:55:51.493404 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.493423 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.493432 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 48574ns
> 17:55:52 I0616 17:55:51.493587 389 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.493604 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.493612 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 38329ns
> 17:55:52 I0616 17:55:51.493778 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.493798 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.493810 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 44915ns
> 17:55:52 I0616 17:55:51.493981 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.494004 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.494014 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 47247ns
> 17:55:52 I0616 17:55:51.494103 386 containerizer.cpp:2507] Container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea has exited
> 17:55:52 I0616 17:55:51.494269 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.494292 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.494302 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 48485ns
> 17:55:52 I0616 17:55:51.494585 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.494602 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.494608 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 38108ns
> 17:55:52 I0616 17:55:51.494755 386 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.494774 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.494786 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 43502ns
> 17:55:52 I0616 17:55:51.494947 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.494971 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.494983 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 48679ns
> 17:55:52 I0616 17:55:51.495136 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.495154 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.495162 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 41225ns
> 17:55:52 I0616 17:55:51.495332 388 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.495353 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.495364 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 53563ns
> 17:55:52 I0616 17:55:51.495527 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.495546 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.495555 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 46768ns
> 17:55:52 I0616 17:55:51.495698 389 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.495717 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.495726 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 37835ns
> 17:55:52 I0616 17:55:51.495865 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.495884 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.495896 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 40790ns
> 17:55:52 I0616 17:55:51.496052 386 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.496068 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.496074 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 36720ns
> 17:55:52 I0616 17:55:51.496223 393 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.496243 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.496254 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 41097ns
> 17:55:52 I0616 17:55:51.496415 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.496434 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.496446 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 51526ns
> 17:55:52 I0616 17:55:51.496567 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.496582 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.496589 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 34654ns
> 17:55:52 I0616 17:55:51.496753 388 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.496767 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.496773 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 35508ns
> 17:55:52 I0616 17:55:51.496917 389 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.496935 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.496948 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 44797ns
> 17:55:52 I0616 17:55:51.497120 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.497141 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.497150 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 45655ns
> 17:55:52 I0616 17:55:51.497282 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.497300 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.497313 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 39087ns
> 17:55:52 I0616 17:55:51.497462 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.497479 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.497489 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 36726ns
> 17:55:52 I0616 17:55:51.497642 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.497658 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.497663 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 32276ns
> 17:55:52 I0616 17:55:51.497807 388 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.497823 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.497834 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 39735ns
> 17:55:52 I0616 17:55:51.497970 389 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.497989 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.497999 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 38232ns
> 17:55:52 I0616 17:55:51.498149 386 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.498165 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.498172 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 33021ns
> 17:55:52 I0616 17:55:51.498317 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.498335 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.498347 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 45051ns
> 17:55:52 I0616 17:55:51.498491 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.498510 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.498522 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 40853ns
> 17:55:52 I0616 17:55:51.498667 389 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.498678 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.498684 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 30026ns
> 17:55:52 I0616 17:55:51.498827 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.498847 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.498857 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 39971ns
> 17:55:52 I0616 17:55:51.500092 393 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.500113 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.500123 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 46381ns
> 17:55:52 I0616 17:55:51.500273 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.500293 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.500305 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 42203ns
> 17:55:52 I0616 17:55:51.500445 388 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.500460 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.500468 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 32995ns
> 17:55:52 I0616 17:55:51.500612 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.500628 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.500635 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 38103ns
> 17:55:52 I0616 17:55:51.500782 386 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.500798 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.500805 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 38781ns
> 17:55:52 I0616 17:55:51.500931 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.500949 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.500960 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 39429ns
> 17:55:52 I0616 17:55:51.501108 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.501121 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.501127 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 29160ns
> 17:55:52 I0616 17:55:51.501288 388 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.501309 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.501322 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 47070ns
> 17:55:52 I0616 17:55:51.501477 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.501489 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.501497 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 36916ns
> 17:55:52 I0616 17:55:51.501638 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.501654 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.501662 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 37504ns
> 17:55:52 I0616 17:55:51.501814 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.501832 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.501837 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 34863ns
> 17:55:52 I0616 17:55:51.502030 386 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.502046 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.502053 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 34629ns
> 17:55:52 I0616 17:55:51.502223 393 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.502243 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.502251 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 45027ns
> 17:55:52 I0616 17:55:51.502403 388 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.502419 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.502425 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 41090ns
> 17:55:52 I0616 17:55:51.502573 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.502588 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.502594 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 33412ns
> 17:55:52 I0616 17:55:51.502732 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.502748 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.502754 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 33631ns
> 17:55:52 I0616 17:55:51.502893 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.502908 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.502915 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 32690ns
> 17:55:52 I0616 17:55:51.503078 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.503095 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.503103 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 43475ns
> 17:55:52 I0616 17:55:51.503253 386 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.503271 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.503283 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 39347ns
> 17:55:52 I0616 17:55:51.503533 389 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.503548 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.503556 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 42215ns
> 17:55:52 I0616 17:55:51.503710 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.503722 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.503729 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 35568ns
> 17:55:52 I0616 17:55:51.503870 388 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.503885 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.503892 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 32566ns
> 17:55:52 I0616 17:55:51.504029 392 slave.cpp:5775] Current disk usage 12.43%. Max allowed age: 5.430177220889051days
> 17:55:52 I0616 17:55:51.504073 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.504088 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.504101 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 41148ns
> 17:55:52 I0616 17:55:51.504238 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.504261 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.504271 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 46807ns
> 17:55:52 I0616 17:55:51.504415 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.504431 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.504437 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 33105ns
> 17:55:52 I0616 17:55:51.504596 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.504617 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.504629 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 45600ns
> 17:55:52 I0616 17:55:51.504768 393 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.504784 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.504791 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 35253ns
> 17:55:52 I0616 17:55:51.505007 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.505023 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.505035 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 43191ns
> 17:55:52 E0616 17:55:51.505107 391 slave.cpp:5247] Termination of executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 failed: Failed to kill all processes in the container: Timed out after 1mins
> 17:55:52 I0616 17:55:51.505162 391 slave.cpp:4296] Handling status update TASK_FAILED (UUID: b2550961-5b8b-472b-9d7a-85b670b6c727) for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 from @0.0.0.0:0
> 17:55:52 I0616 17:55:51.505231 391 slave.cpp:5369] Cleaning up executor '88af9adf-0d1b-4ea6-a3d8-67d825f49766' of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 at executor(1)@172.16.10.45:35243
> 17:55:52 W0616 17:55:51.505468 390 containerizer.cpp:2054] Skipping status for container 7ea3f4a1-fe4c-4daa-8b89-ad814095daea because: Container does not exist
> 17:55:52 I0616 17:55:51.505538 391 slave.cpp:5465] Cleaning up framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.505584 388 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766/runs/7ea3f4a1-fe4c-4daa-8b89-ad814095daea' for gc 6.99999447326519days in the future
> 17:55:52 I0616 17:55:51.505605 392 status_update_manager.cpp:285] Closing status update streams for framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.505616 391 slave.cpp:818] Agent terminating
> 17:55:52 I0616 17:55:51.505625 392 status_update_manager.cpp:531] Cleaning up status update stream for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.505638 388 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766' for gc 6.99999447326519days in the future
> 17:55:52 I0616 17:55:51.505677 388 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766/runs/7ea3f4a1-fe4c-4daa-8b89-ad814095daea' for gc 6.99999447326519days in the future
> 17:55:52 I0616 17:55:51.505705 388 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000/executors/88af9adf-0d1b-4ea6-a3d8-67d825f49766' for gc 6.99999447326519days in the future
> 17:55:52 I0616 17:55:51.505722 388 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000' for gc 6.99999447326519days in the future
> 17:55:52 I0616 17:55:51.505777 388 gc.cpp:55] Scheduling '/tmp/SlaveRecoveryTest_0_CleanupExecutor_1jZqj5/meta/slaves/172087b8-9974-4113-8f2b-6adda099319f-S0/frameworks/172087b8-9974-4113-8f2b-6adda099319f-0000' for gc 6.99999447326519days in the future
> 17:55:52 I0616 17:55:51.505951 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.505972 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.505987 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 45646ns
> 17:55:52 I0616 17:55:51.506151 393 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.506168 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.506175 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 41561ns
> 17:55:52 I0616 17:55:51.506302 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.506323 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.506335 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 43250ns
> 17:55:52 I0616 17:55:51.506475 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.506494 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.506506 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 41161ns
> 17:55:52 I0616 17:55:51.506654 386 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.506675 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.506685 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 52997ns
> 17:55:52 I0616 17:55:51.506819 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.506839 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.506850 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 47251ns
> 17:55:52 I0616 17:55:51.506983 389 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.507000 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.507006 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 36149ns
> 17:55:52 I0616 17:55:51.507141 388 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.507158 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.507164 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 33721ns
> 17:55:52 I0616 17:55:51.507304 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.507325 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.507339 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 47904ns
> 17:55:52 I0616 17:55:51.507489 393 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.507506 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.507519 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 41866ns
> 17:55:52 I0616 17:55:51.507678 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.507717 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.507727 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 63301ns
> 17:55:52 I0616 17:55:51.507861 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.507880 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.507891 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 40245ns
> 17:55:52 I0616 17:55:51.508035 386 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.508051 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.508059 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 34291ns
> 17:55:52 I0616 17:55:51.508204 388 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.508219 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.508225 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 35089ns
> 17:55:52 I0616 17:55:51.508360 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.508379 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.508391 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 41215ns
> 17:55:52 I0616 17:55:51.508524 389 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.508535 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.508544 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 31001ns
> 17:55:52 I0616 17:55:51.508704 391 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.508726 391 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.508738 391 hierarchical.cpp:1493] Performed allocation for 1 agents in 44557ns
> 17:55:52 I0616 17:55:51.508877 392 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.508906 392 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.508916 392 hierarchical.cpp:1493] Performed allocation for 1 agents in 52579ns
> 17:55:52 I0616 17:55:51.509054 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.509073 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.509086 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 40761ns
> 17:55:52 I0616 17:55:51.509214 389 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.509235 389 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.509245 389 hierarchical.cpp:1493] Performed allocation for 1 agents in 43021ns
> 17:55:52 I0616 17:55:51.509382 393 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.509399 393 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.509410 393 hierarchical.cpp:1493] Performed allocation for 1 agents in 39313ns
> 17:55:52 I0616 17:55:51.509554 388 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.509569 388 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.509577 388 hierarchical.cpp:1493] Performed allocation for 1 agents in 31981ns
> 17:55:52 I0616 17:55:51.509829 390 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.509845 390 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.509851 390 hierarchical.cpp:1493] Performed allocation for 1 agents in 33856ns
> 17:55:52 I0616 17:55:51.510011 386 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.510027 386 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.510038 386 hierarchical.cpp:1493] Performed allocation for 1 agents in 43289ns
> 17:55:52 I0616 17:55:51.510236 387 hierarchical.cpp:1908] No allocations performed
> 17:55:52 I0616 17:55:51.510247 392 master.cpp:6707] Marking agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) unreachable: health check timed out
> 17:55:52 I0616 17:55:51.510257 387 hierarchical.cpp:1998] No inverse offers to send out!
> 17:55:52 I0616 17:55:51.510284 387 hierarchical.cpp:1493] Performed allocation for 1 agents in 57986ns
> 17:55:52 I0616 17:55:51.510432 392 registrar.cpp:493] Applied 1 operations in 30599ns; attempting to update the registry
> 17:55:52 I0616 17:55:51.510665 392 registrar.cpp:550] Successfully updated the registry in 0ns
> 17:55:52 I0616 17:55:51.510728 393 master.cpp:6755] Marked agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal) unreachable: health check timed out
> 17:55:52 I0616 17:55:51.510795 393 master.cpp:8559] Updating the state of task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 (latest state: TASK_LOST, status update state: TASK_LOST)
> 17:55:52 I0616 17:55:51.510869 386 hierarchical.cpp:620] Removed agent 172087b8-9974-4113-8f2b-6adda099319f-S0
> 17:55:52 I0616 17:55:51.510936 393 master.cpp:8653] Removing task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 with resources cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 on agent 172087b8-9974-4113-8f2b-6adda099319f-S0 at slave(477)@172.16.10.45:60241 (ip-172-16-10-45.ec2.internal)
> 17:55:52 I0616 17:55:51.511036 393 master.cpp:6543] Sending status update TASK_LOST for task 88af9adf-0d1b-4ea6-a3d8-67d825f49766 of framework 172087b8-9974-4113-8f2b-6adda099319f-0000 'Agent ip-172-16-10-45.ec2.internal is unreachable: health check timed out'
> 17:55:52 I0616 17:55:51.511175 393 master.cpp:2078] Notifying framework 172087b8-9974-4113-8f2b-6adda099319f-0000 (default) at scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241 of lost agent 172087b8-9974-4113-8f2b-6adda099319f-S0 (ip-172-16-10-45.ec2.internal)
> 17:55:52 I0616 17:55:51.511219 392 sched.cpp:1041] Scheduler::statusUpdate took 20134ns
> 17:55:52 I0616 17:55:51.511291 392 sched.cpp:1103] Lost agent 172087b8-9974-4113-8f2b-6adda099319f-S0
> 17:55:52 I0616 17:55:51.511351 392 sched.cpp:1114] Scheduler::slaveLost took 27127ns
> 17:55:52 I0616 17:55:51.511557 367 sched.cpp:2021] Asked to stop the driver
> 17:55:52 I0616 17:55:51.511620 389 sched.cpp:1203] Stopping framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.511711 390 master.cpp:7979] Processing TEARDOWN call for framework 172087b8-9974-4113-8f2b-6adda099319f-0000 (default) at scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.511734 390 master.cpp:7991] Removing framework 172087b8-9974-4113-8f2b-6adda099319f-0000 (default) at scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.511749 390 master.cpp:3203] Deactivating framework 172087b8-9974-4113-8f2b-6adda099319f-0000 (default) at scheduler-1be82f76-331a-4efd-acf0-6ea67c4cf283@172.16.10.45:60241
> 17:55:52 I0616 17:55:51.511808 388 hierarchical.cpp:410] Deactivated framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 I0616 17:55:51.511919 388 hierarchical.cpp:353] Removed framework 172087b8-9974-4113-8f2b-6adda099319f-0000
> 17:55:52 ../../src/tests/cluster.cpp:580: Failure
> 17:55:52 Value of: containers->empty()
> 17:55:52 Actual: false
> 17:55:52 Expected: true
> 17:55:52 Failed to destroy containers: { 7ea3f4a1-fe4c-4daa-8b89-ad814095daea }
> 17:55:52 I0616 17:55:51.514950 367 master.cpp:1158] Master terminating
> 17:55:52 I0616 17:55:51.526109 390 cgroups.cpp:2692] Freezing cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.527093 388 cgroups.cpp:1405] Successfully froze cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea after 940800ns
> 17:55:52 I0616 17:55:51.528048 387 cgroups.cpp:2710] Thawing cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea
> 17:55:52 I0616 17:55:51.529080 392 cgroups.cpp:1434] Successfully thawed cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518/7ea3f4a1-fe4c-4daa-8b89-ad814095daea after 1.00608ms
> 17:55:52 I0616 17:55:51.531054 389 cgroups.cpp:2692] Freezing cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518
> 17:55:52 I0616 17:55:51.633901 392 cgroups.cpp:1405] Successfully froze cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518 after 102.817024ms
> 17:55:52 I0616 17:55:51.634991 386 cgroups.cpp:2710] Thawing cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518
> 17:55:52 I0616 17:55:51.635907 392 cgroups.cpp:1434] Successfully thawed cgroup /sys/fs/cgroup/freezer/mesos_test_87cd8cae-7999-49be-8551-1c684c1f5518 after 879872ns
> 17:55:52 [ FAILED ] SlaveRecoveryTest/0.CleanupExecutor, where TypeParam = mesos::internal::slave::MesosContainerizer (353 ms)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)