mesos-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Till Toenshoff (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (MESOS-7687) SlaveRecoveryTest flaky on Debian8
Date Fri, 16 Jun 2017 18:24:00 GMT

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

Mime
View raw message