[
https://issues.apache.org/jira/browse/MESOS-7506?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16011126#comment-16011126
]
Alexander Rukletsov commented on MESOS-7506:
--------------------------------------------
{noformat}
[ RUN ] SlaveRecoveryTest/0.RecoverTerminatedExecutor
I0512 23:25:58.792877 8155 cluster.cpp:162] Creating default 'local' authorizer
I0512 23:25:58.793736 8181 master.cpp:436] Master
7828d6d3-abb5-4098-9a87-a8e48cd951b3 (ip-172-16-10-226.ec2.internal) started on
172.16.10.226:36307
I0512 23:25:58.793754 8181 master.cpp:438] 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/8f7gjO/credentials"
--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/8f7gjO/master"
--zk_session_timeout="10secs"
I0512 23:25:58.793845 8181 master.cpp:488] Master only allowing authenticated
frameworks to register
I0512 23:25:58.793851 8181 master.cpp:502] Master only allowing authenticated
agents to register
I0512 23:25:58.793853 8181 master.cpp:515] Master only allowing authenticated
HTTP frameworks to register
I0512 23:25:58.793856 8181 credentials.hpp:37] Loading credentials for
authentication from '/tmp/8f7gjO/credentials'
I0512 23:25:58.793912 8181 master.cpp:560] Using default 'crammd5'
authenticator
I0512 23:25:58.793948 8181 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
I0512 23:25:58.793974 8181 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
I0512 23:25:58.793992 8181 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
I0512 23:25:58.794018 8181 master.cpp:640] Authorization enabled
I0512 23:25:58.794132 8178 hierarchical.cpp:158] Initialized hierarchical
allocator process
I0512 23:25:58.794147 8174 whitelist_watcher.cpp:77] No whitelist given
I0512 23:25:58.794579 8181 master.cpp:2161] Elected as the leading master!
I0512 23:25:58.794596 8181 master.cpp:1700] Recovering from registrar
I0512 23:25:58.794637 8175 registrar.cpp:345] Recovering registrar
I0512 23:25:58.794771 8174 registrar.cpp:389] Successfully fetched the
registry (0B) in 112128ns
I0512 23:25:58.794812 8174 registrar.cpp:493] Applied 1 operations in 5956ns;
attempting to update the registry
I0512 23:25:58.794963 8174 registrar.cpp:550] Successfully updated the
registry in 131072ns
I0512 23:25:58.795001 8174 registrar.cpp:422] Successfully recovered registrar
I0512 23:25:58.795145 8174 master.cpp:1799] Recovered 0 agents from the
registry (172B); allowing 10mins for agents to re-register
I0512 23:25:58.795168 8178 hierarchical.cpp:185] Skipping recovery of
hierarchical allocator: nothing to recover
I0512 23:25:58.795898 8155 containerizer.cpp:221] Using isolation:
cgroups/cpu,cgroups/mem,filesystem/posix,network/cni
I0512 23:25:58.799172 8155 linux_launcher.cpp:150] Using
/sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
I0512 23:25:58.799425 8155 provisioner.cpp:249] Using default backend 'copy'
I0512 23:25:58.810127 8155 cluster.cpp:448] Creating default 'local' authorizer
I0512 23:25:58.810451 8175 slave.cpp:225] Mesos agent started on
(470)@172.16.10.226:36307
I0512 23:25:58.810472 8175 slave.cpp:226] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/mesos/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_98e5188e-c334-4482-b108-4df9b0548a64"
--container_disk_watch_interval="15secs" --containerizers="mesos"
--credential="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_nZ92Xu/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/mesos/store/docker"
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
--enforce_container_disk_quota="false" --executor_registration_timeout="1mins"
--executor_secret_key="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_nZ92Xu/executor_secret_key"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_nZ92Xu/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_nZ92Xu/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_nZ92Xu"
--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_JRXEDE"
I0512 23:25:58.810663 8175 credentials.hpp:86] Loading credential for
authentication from
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_nZ92Xu/credential'
I0512 23:25:58.810725 8175 slave.cpp:258] Agent using credential for:
test-principal
I0512 23:25:58.810746 8175 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_nZ92Xu/http_credentials'
I0512 23:25:58.810847 8175 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-executor'
I0512 23:25:58.810881 8175 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-executor'
I0512 23:25:58.810988 8175 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
I0512 23:25:58.811027 8175 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readonly'
I0512 23:25:58.811051 8175 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0512 23:25:58.811094 8175 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0512 23:25:58.811357 8155 sched.cpp:232] Version: 1.4.0
I0512 23:25:58.811471 8176 sched.cpp:336] New master detected at
master@172.16.10.226:36307
I0512 23:25:58.811504 8176 sched.cpp:407] Authenticating with master
master@172.16.10.226:36307
I0512 23:25:58.811511 8176 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0512 23:25:58.811575 8178 authenticatee.cpp:121] Creating new client SASL
connection
I0512 23:25:58.811635 8175 slave.cpp:529] Agent resources: cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0512 23:25:58.811676 8175 slave.cpp:537] Agent attributes: [ ]
I0512 23:25:58.811684 8175 slave.cpp:542] Agent hostname:
ip-172-16-10-226.ec2.internal
I0512 23:25:58.811746 8176 status_update_manager.cpp:177] Pausing sending
status updates
I0512 23:25:58.811990 8178 master.cpp:7475] Authenticating
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307
I0512 23:25:58.812036 8175 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(979)@172.16.10.226:36307
I0512 23:25:58.812057 8180 state.cpp:62] Recovering state from
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta'
I0512 23:25:58.812150 8174 authenticator.cpp:98] Creating new server SASL
connection
I0512 23:25:58.812209 8178 status_update_manager.cpp:203] Recovering status
update manager
I0512 23:25:58.812312 8177 containerizer.cpp:608] Recovering containerizer
I0512 23:25:58.812511 8174 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0512 23:25:58.812541 8174 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0512 23:25:58.812600 8181 authenticator.cpp:204] Received SASL authentication
start
I0512 23:25:58.812633 8181 authenticator.cpp:326] Authentication requires more
steps
I0512 23:25:58.812677 8181 authenticatee.cpp:259] Received SASL authentication
step
I0512 23:25:58.812747 8174 authenticator.cpp:232] Received SASL authentication
step
I0512 23:25:58.812784 8174 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-226.ec2.internal' server FQDN:
'ip-172-16-10-226.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0512 23:25:58.812798 8174 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0512 23:25:58.812808 8174 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0512 23:25:58.812831 8174 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-226.ec2.internal' server FQDN:
'ip-172-16-10-226.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0512 23:25:58.812856 8174 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0512 23:25:58.812865 8174 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0512 23:25:58.812880 8174 authenticator.cpp:318] Authentication success
I0512 23:25:58.812976 8181 authenticatee.cpp:299] Authentication success
I0512 23:25:58.813052 8176 master.cpp:7505] Successfully authenticated
principal 'test-principal' at
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307
I0512 23:25:58.813204 8181 sched.cpp:513] Successfully authenticated with
master master@172.16.10.226:36307
I0512 23:25:58.813208 8177 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(979)@172.16.10.226:36307
I0512 23:25:58.813220 8181 sched.cpp:836] Sending SUBSCRIBE call to
master@172.16.10.226:36307
I0512 23:25:58.813311 8181 sched.cpp:869] Will retry registration in
1.690260313secs if necessary
I0512 23:25:58.813347 8178 master.cpp:2813] Received SUBSCRIBE call for
framework 'default' at
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307
I0512 23:25:58.813369 8178 master.cpp:2197] Authorizing framework principal
'test-principal' to receive offers for roles '{ * }'
I0512 23:25:58.813489 8178 master.cpp:2890] Subscribing framework default with
checkpointing enabled and capabilities [ ]
I0512 23:25:58.813611 8178 sched.cpp:759] Framework registered with
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.813628 8178 sched.cpp:773] Scheduler::registered took 6911ns
I0512 23:25:58.813627 8176 hierarchical.cpp:273] Added framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.813661 8176 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.813674 8176 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.813680 8176 hierarchical.cpp:1434] Performed allocation for 0
agents in 24542ns
I0512 23:25:58.814224 8175 provisioner.cpp:410] Provisioner recovery complete
I0512 23:25:58.814347 8174 slave.cpp:5974] Finished recovery
I0512 23:25:58.814539 8174 slave.cpp:6156] Querying resource estimator for
oversubscribable resources
I0512 23:25:58.814651 8174 slave.cpp:922] New master detected at
master@172.16.10.226:36307
I0512 23:25:58.814666 8178 status_update_manager.cpp:177] Pausing sending
status updates
I0512 23:25:58.814724 8174 slave.cpp:957] Detecting new master
I0512 23:25:58.814795 8174 slave.cpp:6170] Received oversubscribable resources
{} from the resource estimator
I0512 23:25:58.822902 8177 slave.cpp:984] Authenticating with master
master@172.16.10.226:36307
I0512 23:25:58.822932 8177 slave.cpp:995] Using default CRAM-MD5 authenticatee
I0512 23:25:58.822985 8177 authenticatee.cpp:121] Creating new client SASL
connection
I0512 23:25:58.823312 8177 master.cpp:7475] Authenticating
slave(470)@172.16.10.226:36307
I0512 23:25:58.823367 8174 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(980)@172.16.10.226:36307
I0512 23:25:58.823422 8174 authenticator.cpp:98] Creating new server SASL
connection
I0512 23:25:58.823716 8174 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0512 23:25:58.823747 8174 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0512 23:25:58.823778 8174 authenticator.cpp:204] Received SASL authentication
start
I0512 23:25:58.823812 8174 authenticator.cpp:326] Authentication requires more
steps
I0512 23:25:58.823838 8174 authenticatee.cpp:259] Received SASL authentication
step
I0512 23:25:58.823921 8180 authenticator.cpp:232] Received SASL authentication
step
I0512 23:25:58.823940 8180 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-226.ec2.internal' server FQDN:
'ip-172-16-10-226.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0512 23:25:58.823946 8180 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0512 23:25:58.823951 8180 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0512 23:25:58.823957 8180 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-226.ec2.internal' server FQDN:
'ip-172-16-10-226.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0512 23:25:58.823961 8180 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0512 23:25:58.823964 8180 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0512 23:25:58.823971 8180 authenticator.cpp:318] Authentication success
I0512 23:25:58.824002 8180 authenticatee.cpp:299] Authentication success
I0512 23:25:58.824023 8174 master.cpp:7505] Successfully authenticated
principal 'test-principal' at slave(470)@172.16.10.226:36307
I0512 23:25:58.824057 8179 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(980)@172.16.10.226:36307
I0512 23:25:58.824178 8180 slave.cpp:1079] Successfully authenticated with
master master@172.16.10.226:36307
I0512 23:25:58.824234 8180 slave.cpp:1507] Will retry registration in
10.035188ms if necessary
I0512 23:25:58.824290 8175 master.cpp:5429] Received register agent message
from slave(470)@172.16.10.226:36307 (ip-172-16-10-226.ec2.internal)
I0512 23:25:58.824317 8175 master.cpp:3659] Authorizing agent with principal
'test-principal'
I0512 23:25:58.824460 8181 master.cpp:5564] Registering agent at
slave(470)@172.16.10.226:36307 (ip-172-16-10-226.ec2.internal) with id
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0
I0512 23:25:58.824574 8180 registrar.cpp:493] Applied 1 operations in 12044ns;
attempting to update the registry
I0512 23:25:58.824728 8174 registrar.cpp:550] Successfully updated the
registry in 125952ns
I0512 23:25:58.824898 8178 slave.cpp:4749] Received ping from
slave-observer(464)@172.16.10.226:36307
I0512 23:25:58.824928 8179 master.cpp:5639] Registered agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(470)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal) with cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]
I0512 23:25:58.824965 8178 slave.cpp:1125] Registered with master
master@172.16.10.226:36307; given agent ID
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0
I0512 23:25:58.824980 8178 fetcher.cpp:94] Clearing fetcher cache
I0512 23:25:58.824983 8180 hierarchical.cpp:525] Added agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 (ip-172-16-10-226.ec2.internal) with
cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I0512 23:25:58.825080 8181 status_update_manager.cpp:184] Resuming sending
status updates
I0512 23:25:58.825119 8178 slave.cpp:1153] Checkpointing SlaveInfo to
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/slave.info'
I0512 23:25:58.825230 8178 slave.cpp:1191] Forwarding total oversubscribed
resources {}
I0512 23:25:58.825251 8180 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.825263 8180 hierarchical.cpp:1434] Performed allocation for 1
agents in 224814ns
I0512 23:25:58.825354 8177 master.cpp:7305] Sending 1 offers to framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 (default) at
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307
I0512 23:25:58.825419 8177 master.cpp:6324] Received update of agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(470)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal) with total oversubscribed resources {}
I0512 23:25:58.825505 8178 sched.cpp:933] Scheduler::resourceOffers took
36059ns
I0512 23:25:58.825953 8174 master.cpp:3875] Processing ACCEPT call for offers:
[ 7828d6d3-abb5-4098-9a87-a8e48cd951b3-O0 ] on agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(470)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal) for framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 (default) at
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307
I0512 23:25:58.825985 8174 master.cpp:3426] Authorizing framework principal
'test-principal' to launch task 054afbcd-fbed-4291-b53f-a15d7cf035a1
I0512 23:25:58.826454 8177 master.cpp:9326] Adding task
054afbcd-fbed-4291-b53f-a15d7cf035a1 with resources cpus(*)(allocated: *):2;
mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated:
*):[31000-32000] on agent 7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at
slave(470)@172.16.10.226:36307 (ip-172-16-10-226.ec2.internal)
I0512 23:25:58.826529 8177 master.cpp:4531] Launching task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 (default) at
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307 with
resources cpus(*)(allocated: *):2; mem(*)(allocated: *):1024;
disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] on agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(470)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal)
I0512 23:25:58.826732 8179 slave.cpp:1617] Got assigned task
'054afbcd-fbed-4291-b53f-a15d7cf035a1' for framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.826786 8179 slave.cpp:6843] Checkpointing FrameworkInfo to
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/framework.info'
I0512 23:25:58.826922 8179 slave.cpp:6854] Checkpointing framework pid
'scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307' to
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/framework.pid'
I0512 23:25:58.827056 8175 hierarchical.cpp:850] Updated allocation of
framework 7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 on agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-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]
I0512 23:25:58.827137 8179 slave.cpp:1898] Authorizing task
'054afbcd-fbed-4291-b53f-a15d7cf035a1' for framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.827158 8179 slave.cpp:6593] Authorizing framework principal
'test-principal' to launch task 054afbcd-fbed-4291-b53f-a15d7cf035a1
I0512 23:25:58.827396 8179 slave.cpp:2085] Launching task
'054afbcd-fbed-4291-b53f-a15d7cf035a1' for framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.827606 8179 paths.cpp:573] Trying to chown
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1/runs/d506edec-a057-46d8-9233-2faa42d9bc9f'
to user 'root'
I0512 23:25:58.827723 8179 slave.cpp:7296] Checkpointing ExecutorInfo to
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1/executor.info'
I0512 23:25:58.827960 8179 slave.cpp:6933] Launching executor
'054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 with resources cpus(*)(allocated:
*):0.1; mem(*)(allocated: *):32 in work directory
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1/runs/d506edec-a057-46d8-9233-2faa42d9bc9f'
I0512 23:25:58.828182 8179 slave.cpp:7324] Checkpointing TaskInfo to
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1/runs/d506edec-a057-46d8-9233-2faa42d9bc9f/tasks/054afbcd-fbed-4291-b53f-a15d7cf035a1/task.info'
I0512 23:25:58.828342 8179 slave.cpp:2314] Queued task
'054afbcd-fbed-4291-b53f-a15d7cf035a1' for executor
'054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.828375 8179 slave.cpp:875] Successfully attached file
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1/runs/d506edec-a057-46d8-9233-2faa42d9bc9f'
I0512 23:25:58.828524 8176 containerizer.cpp:1021] Starting container
d506edec-a057-46d8-9233-2faa42d9bc9f for executor
'054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.828940 8178 cgroups.cpp:410] Creating cgroup at
'/sys/fs/cgroup/cpu,cpuacct/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f'
for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.848299 8178 cgroups.cpp:473] Chown the cgroup at
'/sys/fs/cgroup/cpu,cpuacct/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f'
to user 'root' for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.848346 8178 cgroups.cpp:410] Creating cgroup at
'/sys/fs/cgroup/memory/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f'
for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.849306 8178 memory.cpp:479] Started listening for OOM events
for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.849644 8178 memory.cpp:590] Started listening on 'low' memory
pressure events for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.849970 8178 memory.cpp:590] Started listening on 'medium'
memory pressure events for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.850301 8178 memory.cpp:590] Started listening on 'critical'
memory pressure events for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.850317 8178 cgroups.cpp:473] Chown the cgroup at
'/sys/fs/cgroup/memory/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f'
to user 'root' for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.850895 8181 memory.cpp:199] Updated
'memory.soft_limit_in_bytes' to 1056MB for container
d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.851485 8181 memory.cpp:228] Updated 'memory.limit_in_bytes' to
1056MB for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.851826 8181 cpu.cpp:101] Updated 'cpu.shares' to 2150 (cpus
2.1) for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.852568 8178 containerizer.cpp:1641] 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.226:36307"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE\/slaves\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0\/frameworks\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000\/executors\/054afbcd-fbed-4291-b53f-a15d7cf035a1\/runs\/d506edec-a057-46d8-9233-2faa42d9bc9f"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiJkNTA2ZWRlYy1hMDU3LTQ2ZDgtOTIzMy0yZmFhNDJkOWJjOWYiLCJlaWQiOiIwNTRhZmJjZC1mYmVkLTQyOTEtYjUzZi1hMTVkN2NmMDM1YTEiLCJmaWQiOiI3ODI4ZDZkMy1hYmI1LTQwOTgtOWE4Ny1hOGU0OGNkOTUxYjMtMDAwMCJ9.zFTSkBpddiGL30eWgGMig-w21zoMlYvV0uc6LoQxUU8"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"054afbcd-fbed-4291-b53f-a15d7cf035a1"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"7828d6d3-abb5-4098-9a87-a8e48cd951b3-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":"7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(470)@172.16.10.226:36307"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"2secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE\/slaves\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0\/frameworks\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000\/executors\/054afbcd-fbed-4291-b53f-a15d7cf035a1\/runs\/d506edec-a057-46d8-9233-2faa42d9bc9f"}]},"user":"root","working_directory":"\/tmp\/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE\/slaves\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0\/frameworks\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000\/executors\/054afbcd-fbed-4291-b53f-a15d7cf035a1\/runs\/d506edec-a057-46d8-9233-2faa42d9bc9f"}"
--pipe_read="32" --pipe_write="36"
--runtime_directory="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_nZ92Xu/containers/d506edec-a057-46d8-9233-2faa42d9bc9f"
--unshare_namespace_mnt="false"'
I0512 23:25:58.852831 8176 linux_launcher.cpp:429] Launching container
d506edec-a057-46d8-9233-2faa42d9bc9f and cloning with namespaces
I0512 23:25:58.856884 8178 containerizer.cpp:1740] Checkpointing container's
forked pid 21229 to
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1/runs/d506edec-a057-46d8-9233-2faa42d9bc9f/pids/forked.pid'
I0512 23:25:58.858755 8181 fetcher.cpp:353] Starting to fetch URIs for
container: d506edec-a057-46d8-9233-2faa42d9bc9f, directory:
/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1/runs/d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.925112 21262 exec.cpp:162] Version: 1.4.0
I0512 23:25:58.928278 8175 slave.cpp:3788] Got registration for executor
'054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 from executor(1)@172.16.10.226:48301
I0512 23:25:58.928459 8175 slave.cpp:3874] Checkpointing executor pid
'executor(1)@172.16.10.226:48301' to
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1/runs/d506edec-a057-46d8-9233-2faa42d9bc9f/pids/libprocess.pid'
I0512 23:25:58.929154 21257 exec.cpp:237] Executor registered on agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0
I0512 23:25:58.929426 8175 memory.cpp:199] Updated
'memory.soft_limit_in_bytes' to 1056MB for container
d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.930083 8175 cpu.cpp:101] Updated 'cpu.shares' to 2150 (cpus
2.1) for container d506edec-a057-46d8-9233-2faa42d9bc9f
Received SUBSCRIBED event
Subscribed executor on ip-172-16-10-226.ec2.internal
I0512 23:25:58.930421 8175 slave.cpp:2527] Sending queued task
'054afbcd-fbed-4291-b53f-a15d7cf035a1' to executor
'054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 at executor(1)@172.16.10.226:48301
Received LAUNCH event
Starting task 054afbcd-fbed-4291-b53f-a15d7cf035a1
Running
'/home/admin/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-debian-8/mesos/build/src/mesos-containerizer
launch <POSSIBLY-SENSITIVE-DATA>'
Forked command at 21266
I0512 23:25:58.933207 8181 slave.cpp:4219] Handling status update TASK_RUNNING
(UUID: c459c454-fd9d-4a1e-b092-b2f4111fd40a) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 from executor(1)@172.16.10.226:48301
I0512 23:25:58.933746 8177 status_update_manager.cpp:323] Received status
update TASK_RUNNING (UUID: c459c454-fd9d-4a1e-b092-b2f4111fd40a) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.933770 8177 status_update_manager.cpp:500] Creating
StatusUpdate stream for task 054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.933951 8177 status_update_manager.cpp:834] Checkpointing UPDATE
for status update TASK_RUNNING (UUID: c459c454-fd9d-4a1e-b092-b2f4111fd40a) for
task 054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.934026 8177 status_update_manager.cpp:377] Forwarding update
TASK_RUNNING (UUID: c459c454-fd9d-4a1e-b092-b2f4111fd40a) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 to the agent
I0512 23:25:58.934105 8179 slave.cpp:4659] Forwarding the update TASK_RUNNING
(UUID: c459c454-fd9d-4a1e-b092-b2f4111fd40a) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 to master@172.16.10.226:36307
I0512 23:25:58.934227 8179 slave.cpp:4553] Status update manager successfully
handled status update TASK_RUNNING (UUID: c459c454-fd9d-4a1e-b092-b2f4111fd40a)
for task 054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.934249 8174 master.cpp:6469] Status update TASK_RUNNING (UUID:
c459c454-fd9d-4a1e-b092-b2f4111fd40a) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 from agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(470)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal)
I0512 23:25:58.934257 8179 slave.cpp:4569] Sending acknowledgement for status
update TASK_RUNNING (UUID: c459c454-fd9d-4a1e-b092-b2f4111fd40a) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 to executor(1)@172.16.10.226:48301
I0512 23:25:58.934281 8174 master.cpp:6537] Forwarding status update
TASK_RUNNING (UUID: c459c454-fd9d-4a1e-b092-b2f4111fd40a) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.934350 8174 master.cpp:8568] Updating the state of task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
I0512 23:25:58.934419 8179 sched.cpp:1041] Scheduler::statusUpdate took 13093ns
I0512 23:25:58.934525 8175 master.cpp:5194] Processing ACKNOWLEDGE call
c459c454-fd9d-4a1e-b092-b2f4111fd40a for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 (default) at
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307 on agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0
I0512 23:25:58.934700 8180 status_update_manager.cpp:395] Received status
update acknowledgement (UUID: c459c454-fd9d-4a1e-b092-b2f4111fd40a) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.934738 8180 status_update_manager.cpp:834] Checkpointing ACK
for status update TASK_RUNNING (UUID: c459c454-fd9d-4a1e-b092-b2f4111fd40a) for
task 054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.934806 8180 slave.cpp:3508] Status update manager successfully
handled status update acknowledgement (UUID:
c459c454-fd9d-4a1e-b092-b2f4111fd40a) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.935056 8155 slave.cpp:794] Agent terminating
I0512 23:25:58.935135 8175 master.cpp:1313] Agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(470)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal) disconnected
I0512 23:25:58.935153 8175 master.cpp:3197] Disconnecting agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(470)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal)
I0512 23:25:58.935176 8175 master.cpp:3216] Deactivating agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(470)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal)
I0512 23:25:58.935277 8174 hierarchical.cpp:653] Agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 deactivated
I0512 23:25:58.935330 8155 containerizer.cpp:221] Using isolation:
cgroups/cpu,cgroups/mem,filesystem/posix,network/cni
I0512 23:25:58.935364 21264 exec.cpp:415] Executor asked to shutdown
Received SHUTDOWN event
Shutting down
Sending SIGTERM to process tree at pid 21266
I0512 23:25:58.939229 8155 linux_launcher.cpp:150] Using
/sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
I0512 23:25:58.939527 8155 provisioner.cpp:249] Using default backend 'copy'
Sent SIGTERM to the following process trees:
[
-+- 21266 /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_JRXEDE\/slaves\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0\/frameworks\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000\/executors\/054afbcd-fbed-4291-b53f-a15d7cf035a1\/runs\/d506edec-a057-46d8-9233-2faa42d9bc9f"},{"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(470)@172.16.10.226:36307"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE\/slaves\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0\/frameworks\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000\/executors\/054afbcd-fbed-4291-b53f-a15d7cf035a1\/runs\/d506edec-a057-46d8-9233-2faa42d9bc9f"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE\/slaves\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0\/frameworks\/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000\/executors\/054afbcd-fbed-4291-b53f-a15d7cf035a1\/runs\/d506edec-a057-46d8-9233-2faa42d9bc9f"},{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"BIN_SH","type":"VALUE","value":"xpg4"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.226:36307"},{"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.eyJjaWQiOiJkNTA2ZWRlYy1hMDU3LTQ2ZDgtOTIzMy0yZmFhNDJkOWJjOWYiLCJlaWQiOiIwNTRhZmJjZC1mYmVkLTQyOTEtYjUzZi1hMTVkN2NmMDM1YTEiLCJmaWQiOiI3ODI4ZDZkMy1hYmI1LTQwOTgtOWE4Ny1hOGU0OGNkOTUxYjMtMDAwMCJ9.zFTSkBpddiGL30eWgGMig-w21zoMlYvV0uc6LoQxUU8"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"054afbcd-fbed-4291-b53f-a15d7cf035a1"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"2secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000"}]}}
--unshare_namespace_mnt=false
\--- 21273 ()
]
Scheduling escalation to SIGKILL in 3secs from now
I0512 23:25:58.950783 8155 cluster.cpp:448] Creating default 'local' authorizer
I0512 23:25:58.951172 8180 slave.cpp:225] Mesos agent started on
(471)@172.16.10.226:36307
I0512 23:25:58.951192 8180 slave.cpp:226] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/mesos/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_98e5188e-c334-4482-b108-4df9b0548a64"
--container_disk_watch_interval="15secs" --containerizers="mesos"
--credential="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_nZ92Xu/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/mesos/store/docker"
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
--enforce_container_disk_quota="false" --executor_registration_timeout="1mins"
--executor_secret_key="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_nZ92Xu/executor_secret_key"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_nZ92Xu/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_nZ92Xu/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_nZ92Xu"
--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_JRXEDE"
I0512 23:25:58.951330 8180 credentials.hpp:86] Loading credential for
authentication from
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_nZ92Xu/credential'
I0512 23:25:58.951380 8180 slave.cpp:258] Agent using credential for:
test-principal
I0512 23:25:58.951391 8180 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_nZ92Xu/http_credentials'
I0512 23:25:58.951469 8180 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-executor'
I0512 23:25:58.951501 8180 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-executor'
I0512 23:25:58.951550 8180 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
I0512 23:25:58.951588 8180 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readonly'
I0512 23:25:58.951663 8180 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0512 23:25:58.951714 8180 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0512 23:25:58.952296 8180 slave.cpp:529] Agent resources: cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0512 23:25:58.952340 8180 slave.cpp:537] Agent attributes: [ ]
I0512 23:25:58.952347 8180 slave.cpp:542] Agent hostname:
ip-172-16-10-226.ec2.internal
I0512 23:25:58.952457 8178 status_update_manager.cpp:177] Pausing sending
status updates
I0512 23:25:58.952749 8180 state.cpp:62] Recovering state from
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta'
I0512 23:25:58.952776 8180 state.cpp:710] No committed checkpointed resources
found at
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/resources/resources.info'
I0512 23:25:58.953761 8175 fetcher.cpp:94] Clearing fetcher cache
I0512 23:25:58.953788 8175 slave.cpp:6065] Recovering framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.953801 8175 slave.cpp:7041] Recovering executor
'054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.954017 8178 status_update_manager.cpp:203] Recovering status
update manager
I0512 23:25:58.954030 8178 status_update_manager.cpp:211] Recovering executor
'054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.954058 8178 status_update_manager.cpp:500] Creating
StatusUpdate stream for task 054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.954176 8178 status_update_manager.cpp:810] Replaying status
update stream for task 054afbcd-fbed-4291-b53f-a15d7cf035a1
I0512 23:25:58.954403 8176 containerizer.cpp:608] Recovering containerizer
I0512 23:25:58.954434 8176 containerizer.cpp:664] Recovering container
d506edec-a057-46d8-9233-2faa42d9bc9f for executor
'054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.955070 8177 linux_launcher.cpp:291] Recovered container
d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.956195 8174 memory.cpp:479] Started listening for OOM events
for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.956586 8174 memory.cpp:590] Started listening on 'low' memory
pressure events for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.956954 8174 memory.cpp:590] Started listening on 'medium'
memory pressure events for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.957299 8174 memory.cpp:590] Started listening on 'critical'
memory pressure events for container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.959118 8180 provisioner.cpp:410] Provisioner recovery complete
I0512 23:25:58.959403 8174 slave.cpp:5914] Sending reconnect request to
executor '054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 at executor(1)@172.16.10.226:48301
I0512 23:25:58.959630 8179 slave.cpp:4149] Cleaning up un-reregistered
executors
I0512 23:25:58.959645 8179 slave.cpp:4167] Killing un-reregistered executor
'054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 at executor(1)@172.16.10.226:48301
I0512 23:25:58.959663 8175 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.959676 8175 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.959686 8175 hierarchical.cpp:1434] Performed allocation for 1
agents in 61123ns
I0512 23:25:58.959691 8179 slave.cpp:5974] Finished recovery
I0512 23:25:58.959717 8176 containerizer.cpp:2218] Destroying container
d506edec-a057-46d8-9233-2faa42d9bc9f in RUNNING state
I0512 23:25:58.959844 8176 linux_launcher.cpp:505] Asked to destroy container
d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.959913 8179 slave.cpp:6156] Querying resource estimator for
oversubscribable resources
I0512 23:25:58.960001 8179 slave.cpp:922] New master detected at
master@172.16.10.226:36307
I0512 23:25:58.960047 8177 status_update_manager.cpp:177] Pausing sending
status updates
I0512 23:25:58.960085 8179 slave.cpp:957] Detecting new master
I0512 23:25:58.960127 8179 slave.cpp:6170] Received oversubscribable resources
{} from the resource estimator
I0512 23:25:58.960273 8176 linux_launcher.cpp:548] Using freezer to destroy
cgroup
mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.961036 8174 cgroups.cpp:2692] Freezing cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.962049 8175 cgroups.cpp:1405] Successfully froze cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f
after 0ns
I0512 23:25:58.963119 8175 cgroups.cpp:2710] Thawing cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.964277 8174 cgroups.cpp:1434] Successfully thawed cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f
after 0ns
I0512 23:25:58.964529 8175 slave.cpp:984] Authenticating with master
master@172.16.10.226:36307
I0512 23:25:58.964552 8175 slave.cpp:995] Using default CRAM-MD5 authenticatee
I0512 23:25:58.964625 8179 authenticatee.cpp:121] Creating new client SASL
connection
I0512 23:25:58.964651 8176 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.964666 8176 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.964678 8176 hierarchical.cpp:1434] Performed allocation for 1
agents in 46491ns
I0512 23:25:58.965001 8179 master.cpp:7475] Authenticating
slave(471)@172.16.10.226:36307
I0512 23:25:58.965075 8178 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(981)@172.16.10.226:36307
I0512 23:25:58.965163 8179 authenticator.cpp:98] Creating new server SASL
connection
I0512 23:25:58.965493 8179 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0512 23:25:58.965514 8179 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0512 23:25:58.965569 8179 authenticator.cpp:204] Received SASL authentication
start
I0512 23:25:58.965603 8179 authenticator.cpp:326] Authentication requires more
steps
I0512 23:25:58.965651 8179 authenticatee.cpp:259] Received SASL authentication
step
I0512 23:25:58.965746 8175 authenticator.cpp:232] Received SASL authentication
step
I0512 23:25:58.965771 8175 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-226.ec2.internal' server FQDN:
'ip-172-16-10-226.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0512 23:25:58.965777 8175 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0512 23:25:58.965786 8175 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0512 23:25:58.965797 8175 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-226.ec2.internal' server FQDN:
'ip-172-16-10-226.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0512 23:25:58.965813 8175 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0512 23:25:58.965822 8175 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0512 23:25:58.965837 8175 authenticator.cpp:318] Authentication success
I0512 23:25:58.965912 8180 authenticatee.cpp:299] Authentication success
I0512 23:25:58.965919 8175 master.cpp:7505] Successfully authenticated
principal 'test-principal' at slave(471)@172.16.10.226:36307
I0512 23:25:58.965970 8179 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(981)@172.16.10.226:36307
I0512 23:25:58.966090 8175 slave.cpp:1079] Successfully authenticated with
master master@172.16.10.226:36307
I0512 23:25:58.966182 8175 slave.cpp:1507] Will retry registration in
7.961876ms if necessary
I0512 23:25:58.966270 8177 master.cpp:5708] Received re-register agent message
from agent 7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at
slave(471)@172.16.10.226:36307 (ip-172-16-10-226.ec2.internal)
I0512 23:25:58.966331 8177 master.cpp:3659] Authorizing agent with principal
'test-principal'
I0512 23:25:58.966507 8175 master.cpp:5824] Re-registering agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(470)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal)
I0512 23:25:58.966606 8180 slave.cpp:1233] Re-registered with master
master@172.16.10.226:36307
I0512 23:25:58.966644 8180 slave.cpp:1270] Forwarding total oversubscribed
resources {}
I0512 23:25:58.966660 8175 master.cpp:6233] Sending updated checkpointed
resources {} to agent 7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at
slave(471)@172.16.10.226:36307 (ip-172-16-10-226.ec2.internal)
I0512 23:25:58.966668 8178 hierarchical.cpp:641] Agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 reactivated
I0512 23:25:58.966703 8180 slave.cpp:3232] Updating info for framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 with pid updated to
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307
I0512 23:25:58.966718 8176 status_update_manager.cpp:184] Resuming sending
status updates
I0512 23:25:58.966732 8180 slave.cpp:6843] Checkpointing FrameworkInfo to
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/framework.info'
I0512 23:25:58.966744 8175 master.cpp:6324] Received update of agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(471)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal) with total oversubscribed resources {}
I0512 23:25:58.966871 8180 slave.cpp:6854] Checkpointing framework pid
'scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307' to
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/framework.pid'
I0512 23:25:58.967015 8180 slave.cpp:3293] Ignoring new checkpointed resources
identical to the current version: {}
I0512 23:25:58.967034 8181 status_update_manager.cpp:184] Resuming sending
status updates
I0512 23:25:58.967258 8178 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.967275 8178 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.967283 8178 hierarchical.cpp:1434] Performed allocation for 1
agents in 37811ns
I0512 23:25:58.967334 8175 containerizer.cpp:2624] Container
d506edec-a057-46d8-9233-2faa42d9bc9f has exited
I0512 23:25:58.967478 8180 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.967495 8180 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.967506 8180 hierarchical.cpp:1434] Performed allocation for 1
agents in 41716ns
I0512 23:25:58.967669 8174 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.967689 8174 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.967701 8174 hierarchical.cpp:1434] Performed allocation for 1
agents in 46940ns
I0512 23:25:58.967859 8175 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.967871 8175 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.967878 8175 hierarchical.cpp:1434] Performed allocation for 1
agents in 32203ns
I0512 23:25:58.968092 8181 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.968118 8181 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.968127 8181 hierarchical.cpp:1434] Performed allocation for 1
agents in 52673ns
I0512 23:25:58.968302 8177 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.968319 8177 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.968327 8177 hierarchical.cpp:1434] Performed allocation for 1
agents in 57760ns
I0512 23:25:58.968487 8178 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.968507 8178 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.968518 8178 hierarchical.cpp:1434] Performed allocation for 1
agents in 42523ns
I0512 23:25:58.968691 8180 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.968708 8180 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.968716 8180 hierarchical.cpp:1434] Performed allocation for 1
agents in 43774ns
I0512 23:25:58.968878 8175 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.968894 8175 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.968901 8175 hierarchical.cpp:1434] Performed allocation for 1
agents in 35419ns
I0512 23:25:58.969017 8176 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.969036 8176 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.969048 8176 hierarchical.cpp:1434] Performed allocation for 1
agents in 45475ns
I0512 23:25:58.969218 8174 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.969236 8174 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.969249 8174 hierarchical.cpp:1434] Performed allocation for 1
agents in 42567ns
I0512 23:25:58.969377 8179 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.969393 8179 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.969399 8179 hierarchical.cpp:1434] Performed allocation for 1
agents in 37722ns
I0512 23:25:58.969535 8181 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.969560 8181 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.969570 8181 hierarchical.cpp:1434] Performed allocation for 1
agents in 51703ns
I0512 23:25:58.969686 8180 slave.cpp:6156] Querying resource estimator for
oversubscribable resources
I0512 23:25:58.969722 8178 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.969734 8178 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.969755 8178 hierarchical.cpp:1434] Performed allocation for 1
agents in 48600ns
I0512 23:25:58.969772 8179 slave.cpp:6170] Received oversubscribable resources
{} from the resource estimator
I0512 23:25:58.969936 8177 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.969954 8177 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.969960 8177 hierarchical.cpp:1434] Performed allocation for 1
agents in 36969ns
I0512 23:25:58.970083 8178 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.970100 8178 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.970111 8178 hierarchical.cpp:1434] Performed allocation for 1
agents in 39640ns
I0512 23:25:58.970242 8180 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.970258 8180 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.970270 8180 hierarchical.cpp:1434] Performed allocation for 1
agents in 45805ns
I0512 23:25:58.970427 8176 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.970443 8176 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.970449 8176 hierarchical.cpp:1434] Performed allocation for 1
agents in 36649ns
I0512 23:25:58.970573 8179 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.970590 8179 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.970597 8179 hierarchical.cpp:1434] Performed allocation for 1
agents in 36207ns
I0512 23:25:58.970729 8174 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.970748 8174 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.970759 8174 hierarchical.cpp:1434] Performed allocation for 1
agents in 45900ns
I0512 23:25:58.970901 8175 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.970917 8175 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.970926 8175 hierarchical.cpp:1434] Performed allocation for 1
agents in 39409ns
I0512 23:25:58.971065 8181 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.971087 8181 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.971096 8181 hierarchical.cpp:1434] Performed allocation for 1
agents in 48293ns
I0512 23:25:58.971227 8180 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.971246 8180 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.971257 8180 hierarchical.cpp:1434] Performed allocation for 1
agents in 41714ns
I0512 23:25:58.971393 8179 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.971415 8179 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.971422 8179 hierarchical.cpp:1434] Performed allocation for 1
agents in 46614ns
I0512 23:25:58.971580 8178 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.971598 8178 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.971611 8178 hierarchical.cpp:1434] Performed allocation for 1
agents in 42335ns
I0512 23:25:58.971797 8176 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.971813 8176 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.971820 8176 hierarchical.cpp:1434] Performed allocation for 1
agents in 36584ns
I0512 23:25:58.971968 8175 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.971984 8175 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.971992 8175 hierarchical.cpp:1434] Performed allocation for 1
agents in 40250ns
I0512 23:25:58.972117 8177 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.972132 8177 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.972139 8177 hierarchical.cpp:1434] Performed allocation for 1
agents in 35062ns
I0512 23:25:58.972290 8180 slave.cpp:6156] Querying resource estimator for
oversubscribable resources
I0512 23:25:58.972329 8174 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.972347 8174 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.972359 8174 hierarchical.cpp:1434] Performed allocation for 1
agents in 48190ns
I0512 23:25:58.972401 8176 slave.cpp:6170] Received oversubscribable resources
{} from the resource estimator
I0512 23:25:58.972561 8180 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.972579 8180 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.972591 8180 hierarchical.cpp:1434] Performed allocation for 1
agents in 42192ns
I0512 23:25:58.972754 8178 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.972775 8178 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.972785 8178 hierarchical.cpp:1434] Performed allocation for 1
agents in 46683ns
I0512 23:25:58.972925 8177 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.972945 8177 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.972957 8177 hierarchical.cpp:1434] Performed allocation for 1
agents in 42898ns
I0512 23:25:58.973120 8174 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.973140 8174 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.973151 8174 hierarchical.cpp:1434] Performed allocation for 1
agents in 42850ns
I0512 23:25:58.973294 8179 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.973309 8179 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.973316 8179 hierarchical.cpp:1434] Performed allocation for 1
agents in 35681ns
I0512 23:25:58.973462 8181 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.973481 8181 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.973491 8181 hierarchical.cpp:1434] Performed allocation for 1
agents in 44789ns
I0512 23:25:58.973639 8175 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.973654 8175 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.973662 8175 hierarchical.cpp:1434] Performed allocation for 1
agents in 38414ns
I0512 23:25:58.973799 8176 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.973819 8176 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.973825 8176 hierarchical.cpp:1434] Performed allocation for 1
agents in 45186ns
I0512 23:25:58.973980 8180 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.973996 8180 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.974004 8180 hierarchical.cpp:1434] Performed allocation for 1
agents in 36252ns
I0512 23:25:58.974254 8177 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.974269 8177 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.974277 8177 hierarchical.cpp:1434] Performed allocation for 1
agents in 41784ns
I0512 23:25:58.974413 8178 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.974434 8178 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.974443 8178 hierarchical.cpp:1434] Performed allocation for 1
agents in 47949ns
I0512 23:25:58.974612 8179 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.974630 8179 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.974637 8179 hierarchical.cpp:1434] Performed allocation for 1
agents in 44274ns
I0512 23:25:58.974772 8174 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.974794 8174 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.974807 8174 hierarchical.cpp:1434] Performed allocation for 1
agents in 45547ns
I0512 23:25:58.974987 8181 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.975008 8181 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.975018 8181 hierarchical.cpp:1434] Performed allocation for 1
agents in 46835ns
I0512 23:25:58.975152 8180 slave.cpp:6156] Querying resource estimator for
oversubscribable resources
I0512 23:25:58.975210 8176 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.975227 8176 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.975239 8176 hierarchical.cpp:1434] Performed allocation for 1
agents in 46164ns
I0512 23:25:58.975252 8181 slave.cpp:6170] Received oversubscribable resources
{} from the resource estimator
I0512 23:25:58.975396 8175 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.975419 8175 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.975431 8175 hierarchical.cpp:1434] Performed allocation for 1
agents in 45790ns
I0512 23:25:58.975582 8177 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.975602 8177 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.975615 8177 hierarchical.cpp:1434] Performed allocation for 1
agents in 43623ns
I0512 23:25:58.975744 8178 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.975762 8178 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.975774 8178 hierarchical.cpp:1434] Performed allocation for 1
agents in 41712ns
I0512 23:25:58.975929 8180 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.975945 8180 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.975952 8180 hierarchical.cpp:1434] Performed allocation for 1
agents in 36788ns
I0512 23:25:58.976109 8179 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.976125 8179 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.976131 8179 hierarchical.cpp:1434] Performed allocation for 1
agents in 35498ns
I0512 23:25:58.976305 8176 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.976322 8176 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.976335 8176 hierarchical.cpp:1434] Performed allocation for 1
agents in 45447ns
I0512 23:25:58.976503 8175 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.976521 8175 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.976532 8175 hierarchical.cpp:1434] Performed allocation for 1
agents in 40457ns
I0512 23:25:58.976677 8178 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.976692 8178 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.976699 8178 hierarchical.cpp:1434] Performed allocation for 1
agents in 34712ns
I0512 23:25:58.976842 8181 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.976862 8181 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.976871 8181 hierarchical.cpp:1434] Performed allocation for 1
agents in 45977ns
I0512 23:25:58.977023 8174 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.977039 8174 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.977047 8174 hierarchical.cpp:1434] Performed allocation for 1
agents in 37102ns
I0512 23:25:58.977176 8179 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.977197 8179 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.977210 8179 hierarchical.cpp:1434] Performed allocation for 1
agents in 44985ns
I0512 23:25:58.977439 8177 slave.cpp:5670] Current disk usage 33.89%. Max
allowed age: 3.927899994090174days
I0512 23:25:58.977478 8176 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.977494 8176 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.977506 8176 hierarchical.cpp:1434] Performed allocation for 1
agents in 47866ns
I0512 23:25:58.977689 8177 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.977710 8177 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.977721 8177 hierarchical.cpp:1434] Performed allocation for 1
agents in 49154ns
I0512 23:25:58.977874 8174 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.977890 8174 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.977897 8174 hierarchical.cpp:1434] Performed allocation for 1
agents in 40275ns
I0512 23:25:58.978008 8176 slave.cpp:6156] Querying resource estimator for
oversubscribable resources
E0512 23:25:58.978363 8177 slave.cpp:5150] Termination of executor
'054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 failed: Failed to kill all processes
in the container: Timed out after 1mins
I0512 23:25:58.978395 8177 slave.cpp:4219] Handling status update TASK_LOST
(UUID: 34640a19-75fd-4f89-8e20-a3417b24c190) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 from @0.0.0.0:0
I0512 23:25:58.978430 8178 hierarchical.cpp:1850] No allocations performed
I0512 23:25:58.978451 8178 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.978452 8177 slave.cpp:6170] Received oversubscribable resources
{} from the resource estimator
I0512 23:25:58.978464 8178 hierarchical.cpp:1434] Performed allocation for 1
agents in 55888ns
W0512 23:25:58.978775 8176 containerizer.cpp:2171] Skipping status for
container d506edec-a057-46d8-9233-2faa42d9bc9f because: Container does not exist
W0512 23:25:58.978981 8176 containerizer.cpp:2040] Ignoring update for
currently being destroyed container d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.979127 8178 status_update_manager.cpp:323] Received status
update TASK_LOST (UUID: 34640a19-75fd-4f89-8e20-a3417b24c190) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.979156 8178 status_update_manager.cpp:834] Checkpointing UPDATE
for status update TASK_LOST (UUID: 34640a19-75fd-4f89-8e20-a3417b24c190) for
task 054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.979233 8178 status_update_manager.cpp:377] Forwarding update
TASK_LOST (UUID: 34640a19-75fd-4f89-8e20-a3417b24c190) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 to the agent
I0512 23:25:58.979342 8175 slave.cpp:4659] Forwarding the update TASK_LOST
(UUID: 34640a19-75fd-4f89-8e20-a3417b24c190) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 to master@172.16.10.226:36307
I0512 23:25:58.979462 8175 slave.cpp:4553] Status update manager successfully
handled status update TASK_LOST (UUID: 34640a19-75fd-4f89-8e20-a3417b24c190)
for task 054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.979472 8180 master.cpp:6469] Status update TASK_LOST (UUID:
34640a19-75fd-4f89-8e20-a3417b24c190) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 from agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(471)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal)
I0512 23:25:58.979506 8180 master.cpp:6537] Forwarding status update TASK_LOST
(UUID: 34640a19-75fd-4f89-8e20-a3417b24c190) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.979552 8180 master.cpp:8568] Updating the state of task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 (latest state: TASK_LOST, status
update state: TASK_LOST)
I0512 23:25:58.979651 8177 sched.cpp:1041] Scheduler::statusUpdate took 33952ns
I0512 23:25:58.979787 8179 hierarchical.cpp:1114] 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
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 from framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.979822 8180 master.cpp:5194] Processing ACKNOWLEDGE call
34640a19-75fd-4f89-8e20-a3417b24c190 for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 (default) at
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307 on agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0
I0512 23:25:58.979848 8180 master.cpp:8662] Removing task
054afbcd-fbed-4291-b53f-a15d7cf035a1 with resources cpus(*)(allocated: *):2;
mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated:
*):[31000-32000] of framework 7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 on
agent 7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 at slave(471)@172.16.10.226:36307
(ip-172-16-10-226.ec2.internal)
I0512 23:25:58.979969 8180 status_update_manager.cpp:395] Received status
update acknowledgement (UUID: 34640a19-75fd-4f89-8e20-a3417b24c190) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.980016 8180 status_update_manager.cpp:834] Checkpointing ACK
for status update TASK_LOST (UUID: 34640a19-75fd-4f89-8e20-a3417b24c190) for
task 054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.980051 8180 status_update_manager.cpp:531] Cleaning up status
update stream for task 054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.980128 8180 slave.cpp:3508] Status update manager successfully
handled status update acknowledgement (UUID:
34640a19-75fd-4f89-8e20-a3417b24c190) for task
054afbcd-fbed-4291-b53f-a15d7cf035a1 of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.980142 8180 slave.cpp:7277] Completing task
054afbcd-fbed-4291-b53f-a15d7cf035a1
I0512 23:25:58.980149 8180 slave.cpp:5272] Cleaning up executor
'054afbcd-fbed-4291-b53f-a15d7cf035a1' of framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 at executor(1)@172.16.10.226:48301
I0512 23:25:58.980295 8181 gc.cpp:55] Scheduling
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1/runs/d506edec-a057-46d8-9233-2faa42d9bc9f'
for gc 6.99998897739556days in the future
I0512 23:25:58.980340 8181 gc.cpp:55] Scheduling
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1'
for gc 6.99998897739556days in the future
I0512 23:25:58.980342 8180 slave.cpp:5360] Cleaning up framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.980358 8181 gc.cpp:55] Scheduling
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1/runs/d506edec-a057-46d8-9233-2faa42d9bc9f'
for gc 6.99998897739556days in the future
I0512 23:25:58.980372 8181 gc.cpp:55] Scheduling
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000/executors/054afbcd-fbed-4291-b53f-a15d7cf035a1'
for gc 6.99998897739556days in the future
I0512 23:25:58.980396 8177 status_update_manager.cpp:285] Closing status
update streams for framework 7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.980423 8179 gc.cpp:55] Scheduling
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000'
for gc 6.99998897739556days in the future
I0512 23:25:58.980470 8179 gc.cpp:55] Scheduling
'/tmp/SlaveRecoveryTest_0_RecoverTerminatedExecutor_JRXEDE/meta/slaves/7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0/frameworks/7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000'
for gc 6.99998897739556days in the future
I0512 23:25:58.980772 8176 hierarchical.cpp:1940] No inverse offers to send
out!
I0512 23:25:58.980792 8176 hierarchical.cpp:1434] Performed allocation for 1
agents in 162980ns
I0512 23:25:58.980875 8180 master.cpp:7305] Sending 1 offers to framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 (default) at
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307
I0512 23:25:58.981000 8180 sched.cpp:933] Scheduler::resourceOffers took
18890ns
I0512 23:25:58.981148 8155 sched.cpp:2021] Asked to stop the driver
I0512 23:25:58.981215 8178 sched.cpp:1203] Stopping framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.981304 8176 master.cpp:7988] Processing TEARDOWN call for
framework 7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 (default) at
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307
I0512 23:25:58.981329 8176 master.cpp:8000] Removing framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 (default) at
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307
I0512 23:25:58.981343 8176 master.cpp:3160] Deactivating framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 (default) at
scheduler-7146c507-c1d6-4b40-a173-df9b5b8fab98@172.16.10.226:36307
I0512 23:25:58.981395 8177 hierarchical.cpp:374] Deactivated framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.981516 8181 slave.cpp:3061] Asked to shut down framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000 by master@172.16.10.226:36307
I0512 23:25:58.981533 8181 slave.cpp:3076] Cannot shut down unknown framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.981606 8177 hierarchical.cpp:1114] 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
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0 from framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
I0512 23:25:58.981878 8177 hierarchical.cpp:325] Removed framework
7828d6d3-abb5-4098-9a87-a8e48cd951b3-0000
../../src/tests/cluster.cpp:580: Failure
Value of: containers->empty()
Actual: false
Expected: true
Failed to destroy containers: { d506edec-a057-46d8-9233-2faa42d9bc9f }
I0512 23:25:58.982250 8155 slave.cpp:794] Agent terminating
I0512 23:25:58.984313 8155 master.cpp:1155] Master terminating
I0512 23:25:58.984474 8174 hierarchical.cpp:558] Removed agent
7828d6d3-abb5-4098-9a87-a8e48cd951b3-S0
I0512 23:25:58.992247 8175 cgroups.cpp:2692] Freezing cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.993209 8175 cgroups.cpp:1405] Successfully froze cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f
after 899072ns
I0512 23:25:58.994115 8176 cgroups.cpp:2710] Thawing cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f
I0512 23:25:58.994982 8176 cgroups.cpp:1434] Successfully thawed cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64/d506edec-a057-46d8-9233-2faa42d9bc9f
after 841984ns
I0512 23:25:58.996920 8179 cgroups.cpp:2692] Freezing cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64
I0512 23:25:59.099524 8181 cgroups.cpp:1405] Successfully froze cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64 after
102.572032ms
I0512 23:25:59.100488 8174 cgroups.cpp:2710] Thawing cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64
I0512 23:25:59.101331 8181 cgroups.cpp:1434] Successfully thawed cgroup
/sys/fs/cgroup/freezer/mesos_test_98e5188e-c334-4482-b108-4df9b0548a64 after
816896ns
[ FAILED ] SlaveRecoveryTest/0.RecoverTerminatedExecutor, where TypeParam =
mesos::internal::slave::MesosContainerizer (376 ms)
{noformat}
> Multiple tests leave orphan containers.
> ---------------------------------------
>
> Key: MESOS-7506
> URL: https://issues.apache.org/jira/browse/MESOS-7506
> Project: Mesos
> Issue Type: Bug
> Components: containerization
> Reporter: Alexander Rukletsov
> Labels: containerizer, flaky-test, mesosphere
>
> I've observed a number of flaky tests that leave orphan containers upon
> cleanup. A typical log looks like this:
> {noformat}
> ../../src/tests/cluster.cpp:580: Failure
> Value of: containers->empty()
> Actual: false
> Expected: true
> Failed to destroy containers: { da3e8aa8-98e7-4e72-a8fd-5d0bae960014 }
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
