Till Toenshoff created MESOS-9217:
-------------------------------------
Summary: LongLivedDefaultExecutorRestart is flaky on Ubuntu.
Key: MESOS-9217
URL: https://issues.apache.org/jira/browse/MESOS-9217
Project: Mesos
Issue Type: Bug
Components: test
Affects Versions: 1.8.0
Environment: Ubuntu 14.04, 16.04
Reporter: Till Toenshoff
{noformat}
03:52:07 [ RUN ]
GarbageCollectorIntegrationTest.LongLivedDefaultExecutorRestart
03:52:07 I0907 03:52:07.699676 2350 cluster.cpp:173] Creating default 'local'
authorizer
03:52:07 I0907 03:52:07.700664 2374 master.cpp:413] Master
8e9d97f6-4dc4-490b-81f6-d2033e2109d3 (ip-172-16-10-27.ec2.internal) started on
172.16.10.27:45074
03:52:07 I0907 03:52:07.700690 2374 master.cpp:416] Flags at startup:
--acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1secs" --allocator="hierarchical"
--authenticate_agents="true" --authenticate_frameworks="true"
--authenticate_http_frameworks="true" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authentication_v0_timeout="15secs"
--authenticators="crammd5" --authorizers="local"
--credentials="/tmp/cuUPYo/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" --memory_profiling="false"
--min_allocatable_resources="cpus:0.01|mem:32" --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"
--require_agent_domain="false" --role_sorter="drf" --root_submissions="true"
--version="false" --webui_dir="/usr/local/share/mesos/webui"
--work_dir="/tmp/cuUPYo/master" --zk_session_timeout="10secs"
03:52:07 I0907 03:52:07.700857 2374 master.cpp:465] Master only allowing
authenticated frameworks to register
03:52:07 I0907 03:52:07.700870 2374 master.cpp:471] Master only allowing
authenticated agents to register
03:52:07 I0907 03:52:07.700947 2374 master.cpp:477] Master only allowing
authenticated HTTP frameworks to register
03:52:07 I0907 03:52:07.700958 2374 credentials.hpp:37] Loading credentials
for authentication from '/tmp/cuUPYo/credentials'
03:52:07 I0907 03:52:07.701068 2374 master.cpp:521] Using default 'crammd5'
authenticator
03:52:07 I0907 03:52:07.701151 2374 http.cpp:1037] Creating default 'basic'
HTTP authenticator for realm 'mesos-master-readonly'
03:52:07 I0907 03:52:07.701254 2374 http.cpp:1037] Creating default 'basic'
HTTP authenticator for realm 'mesos-master-readwrite'
03:52:07 I0907 03:52:07.701352 2374 http.cpp:1037] Creating default 'basic'
HTTP authenticator for realm 'mesos-master-scheduler'
03:52:07 I0907 03:52:07.701445 2374 master.cpp:602] Authorization enabled
03:52:07 I0907 03:52:07.701566 2370 whitelist_watcher.cpp:77] No whitelist
given
03:52:07 I0907 03:52:07.701695 2376 hierarchical.cpp:182] Initialized
hierarchical allocator process
03:52:07 I0907 03:52:07.702237 2374 master.cpp:2083] Elected as the leading
master!
03:52:07 I0907 03:52:07.702255 2374 master.cpp:1638] Recovering from registrar
03:52:07 I0907 03:52:07.702293 2375 registrar.cpp:339] Recovering registrar
03:52:07 I0907 03:52:07.706190 2375 registrar.cpp:383] Successfully fetched
the registry (0B) in 3.884032ms
03:52:07 I0907 03:52:07.706233 2375 registrar.cpp:487] Applied 1 operations
in 7967ns; attempting to update the registry
03:52:07 I0907 03:52:07.706378 2375 registrar.cpp:544] Successfully updated
the registry in 126976ns
03:52:07 I0907 03:52:07.706413 2375 registrar.cpp:416] Successfully recovered
registrar
03:52:07 I0907 03:52:07.706507 2375 master.cpp:1752] Recovered 0 agents from
the registry (172B); allowing 10mins for agents to reregister
03:52:07 I0907 03:52:07.706548 2375 hierarchical.cpp:220] Skipping recovery
of hierarchical allocator: nothing to recover
03:52:07 W0907 03:52:07.708107 2350 process.cpp:2810] Attempted to spawn
already running process [email protected]:45074
03:52:07 I0907 03:52:07.708500 2350 containerizer.cpp:305] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
03:52:07 I0907 03:52:07.710343 2350 linux_launcher.cpp:144] Using
/sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
03:52:07 I0907 03:52:07.710748 2350 provisioner.cpp:298] Using default
backend 'overlay'
03:52:07 I0907 03:52:07.711236 2350 cluster.cpp:485] Creating default 'local'
authorizer
03:52:07 I0907 03:52:07.711629 2376 slave.cpp:267] Mesos agent started on
(90)@172.16.10.27:45074
03:52:07 I0907 03:52:07.711647 2376 slave.cpp:268] Flags at startup:
--acls="" --appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/store/appc"
--authenticate_http_executors="true" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authenticatee="crammd5"
--authentication_backoff_factor="1secs" --authentication_timeout_max="1mins"
--authentication_timeout_min="5secs" --authorizer="local"
--cgroups_cpu_enable_pids_and_tids_count="false"
--cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false"
--cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false"
--cgroups_root="mesos" --container_disk_watch_interval="15secs"
--containerizers="mesos"
--credential="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/credential"
--default_role="*" --disallow_sharing_agent_pid_namespace="false"
--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/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/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_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/fetch"
--fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins"
--frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1"
--gc_non_executor_container_sandboxes="true" --help="false"
--hostname_lookup="true" --http_command_executor="false"
--http_credentials="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem"
--jwt_secret_key="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/jwt_secret_key"
--launcher="linux"
--launcher_dir="/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-ubuntu-16.04/mesos/build/src"
--logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150" --memory_profiling="false"
--network_cni_metrics="true" --oversubscribed_resources_interval="15secs"
--perf_duration="10secs" --perf_interval="1mins" --port="5051"
--qos_correction_interval_min="0ns" --quiet="false"
--reconfiguration_policy="equal" --recover="reconnect"
--recovery_timeout="15mins" --registration_backoff_factor="10ms"
--resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]"
--revocable_cpu_low_priority="true"
--runtime_dir="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB"
--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/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv"
--zk_session_timeout="10secs"
03:52:07 I0907 03:52:07.711815 2376 credentials.hpp:86] Loading credential
for authentication from
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/credential'
03:52:07 I0907 03:52:07.711861 2376 slave.cpp:300] Agent using credential
for: test-principal
03:52:07 I0907 03:52:07.711872 2376 credentials.hpp:37] Loading credentials
for authentication from
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/http_credentials'
03:52:07 I0907 03:52:07.711936 2376 http.cpp:1037] Creating default 'basic'
HTTP authenticator for realm 'mesos-agent-executor'
03:52:07 I0907 03:52:07.711989 2376 http.cpp:1058] Creating default 'jwt'
HTTP authenticator for realm 'mesos-agent-executor'
03:52:07 I0907 03:52:07.712060 2376 http.cpp:1037] Creating default 'basic'
HTTP authenticator for realm 'mesos-agent-readonly'
03:52:07 I0907 03:52:07.712100 2376 http.cpp:1058] Creating default 'jwt'
HTTP authenticator for realm 'mesos-agent-readonly'
03:52:07 I0907 03:52:07.712137 2376 http.cpp:1037] Creating default 'basic'
HTTP authenticator for realm 'mesos-agent-readwrite'
03:52:07 I0907 03:52:07.712158 2376 http.cpp:1058] Creating default 'jwt'
HTTP authenticator for realm 'mesos-agent-readwrite'
03:52:07 I0907 03:52:07.712229 2376 disk_profile_adaptor.cpp:80] Creating
default disk profile adaptor module
03:52:07 I0907 03:52:07.712790 2376 slave.cpp:615] Agent resources:
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
03:52:07 I0907 03:52:07.712839 2376 slave.cpp:623] Agent attributes: [ ]
03:52:07 I0907 03:52:07.712848 2376 slave.cpp:632] Agent hostname:
ip-172-16-10-27.ec2.internal
03:52:07 I0907 03:52:07.712952 2370 task_status_update_manager.cpp:181]
Pausing sending task status updates
03:52:07 I0907 03:52:07.713099 2350 scheduler.cpp:189] Version: 1.8.0
03:52:07 I0907 03:52:07.713196 2376 state.cpp:66] Recovering state from
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta'
03:52:07 I0907 03:52:07.713269 2373 slave.cpp:6909] Finished recovering
checkpointed state from
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta',
beginning agent recovery
03:52:07 I0907 03:52:07.713306 2373 task_status_update_manager.cpp:207]
Recovering task status update manager
03:52:07 I0907 03:52:07.713399 2373 containerizer.cpp:727] Recovering Mesos
containers
03:52:07 I0907 03:52:07.713490 2373 linux_launcher.cpp:286] Recovering Linux
launcher
03:52:07 I0907 03:52:07.713629 2373 containerizer.cpp:1053] Recovering
isolators
03:52:07 I0907 03:52:07.713811 2374 scheduler.cpp:355] Using default 'basic'
HTTP authenticatee
03:52:07 I0907 03:52:07.713838 2372 containerizer.cpp:1092] Recovering
provisioner
03:52:07 I0907 03:52:07.713896 2374 scheduler.cpp:538] New master detected at
[email protected]:45074
03:52:07 I0907 03:52:07.713909 2374 scheduler.cpp:547] Waiting for 0ns before
initiating a re-(connection) attempt with the master
03:52:07 I0907 03:52:07.713941 2372 provisioner.cpp:494] Provisioner recovery
complete
03:52:07 I0907 03:52:07.714123 2371 composing.cpp:339] Finished recovering
all containerizers
03:52:07 I0907 03:52:07.714171 2371 slave.cpp:7138] Recovering executors
03:52:07 I0907 03:52:07.714198 2371 slave.cpp:7291] Finished recovery
03:52:07 I0907 03:52:07.714467 2371 slave.cpp:1254] New master detected at
[email protected]:45074
03:52:07 I0907 03:52:07.714491 2371 slave.cpp:1319] Detecting new master
03:52:07 I0907 03:52:07.714519 2371 task_status_update_manager.cpp:181]
Pausing sending task status updates
03:52:07 I0907 03:52:07.714651 2373 scheduler.cpp:429] Connected with the
master at http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.714872 2373 scheduler.cpp:248] Sending SUBSCRIBE call
to http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.715217 2376 process.cpp:3569] Handling HTTP event for
process 'master' with path: '/master/api/v1/scheduler'
03:52:07 I0907 03:52:07.715551 2374 http.cpp:1177] HTTP POST for
/master/api/v1/scheduler from 172.16.10.27:41612
03:52:07 I0907 03:52:07.715626 2374 master.cpp:2502] Received subscription
request for HTTP framework 'default'
03:52:07 I0907 03:52:07.715656 2374 master.cpp:2155] Authorizing framework
principal 'test-principal' to receive offers for roles '{ * }'
03:52:07 I0907 03:52:07.715811 2372 master.cpp:2637] Subscribing framework
'default' with checkpointing enabled and capabilities [ MULTI_ROLE,
RESERVATION_REFINEMENT ]
03:52:07 I0907 03:52:07.716225 2372 master.cpp:9883] Adding framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default) with roles { } suppressed
03:52:07 I0907 03:52:07.716414 2374 hierarchical.cpp:306] Added framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.716454 2374 hierarchical.cpp:1564] Performed
allocation for 0 agents in 6701ns
03:52:07 I0907 03:52:07.716715 2375 scheduler.cpp:845] Enqueuing event
SUBSCRIBED received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.716856 2373 scheduler.cpp:845] Enqueuing event
HEARTBEAT received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.719863 2373 slave.cpp:1346] Authenticating with
master [email protected]:45074
03:52:07 I0907 03:52:07.719892 2373 slave.cpp:1355] Using default CRAM-MD5
authenticatee
03:52:07 I0907 03:52:07.719959 2375 authenticatee.cpp:121] Creating new
client SASL connection
03:52:07 I0907 03:52:07.720403 2375 master.cpp:9653] Authenticating
slave(90)@172.16.10.27:45074
03:52:07 I0907 03:52:07.720453 2375 authenticator.cpp:414] Starting
authentication session for crammd5-authenticatee(200)@172.16.10.27:45074
03:52:07 I0907 03:52:07.720512 2375 authenticator.cpp:98] Creating new server
SASL connection
03:52:07 I0907 03:52:07.720927 2375 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
03:52:07 I0907 03:52:07.720947 2375 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
03:52:07 I0907 03:52:07.720979 2375 authenticator.cpp:204] Received SASL
authentication start
03:52:07 I0907 03:52:07.721015 2375 authenticator.cpp:326] Authentication
requires more steps
03:52:07 I0907 03:52:07.721052 2375 authenticatee.cpp:259] Received SASL
authentication step
03:52:07 I0907 03:52:07.721097 2375 authenticator.cpp:232] Received SASL
authentication step
03:52:07 I0907 03:52:07.721117 2375 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-27.ec2.internal'
server FQDN: 'ip-172-16-10-27.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
03:52:07 I0907 03:52:07.721127 2375 auxprop.cpp:181] Looking up auxiliary
property '*userPassword'
03:52:07 I0907 03:52:07.721137 2375 auxprop.cpp:181] Looking up auxiliary
property '*cmusaslsecretCRAM-MD5'
03:52:07 I0907 03:52:07.721144 2375 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-27.ec2.internal'
server FQDN: 'ip-172-16-10-27.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
03:52:07 I0907 03:52:07.721151 2375 auxprop.cpp:131] Skipping auxiliary
property '*userPassword' since SASL_AUXPROP_AUTHZID == true
03:52:07 I0907 03:52:07.721158 2375 auxprop.cpp:131] Skipping auxiliary
property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
03:52:07 I0907 03:52:07.721169 2375 authenticator.cpp:318] Authentication
success
03:52:07 I0907 03:52:07.721215 2370 authenticatee.cpp:299] Authentication
success
03:52:07 I0907 03:52:07.721282 2370 slave.cpp:1446] Successfully
authenticated with master [email protected]:45074
03:52:07 I0907 03:52:07.721366 2370 slave.cpp:1877] Will retry registration
in 14.537761ms if necessary
03:52:07 I0907 03:52:07.721418 2375 master.cpp:9685] Successfully
authenticated principal 'test-principal' at slave(90)@172.16.10.27:45074
03:52:07 I0907 03:52:07.721427 2374 authenticator.cpp:432] Authentication
session cleanup for crammd5-authenticatee(200)@172.16.10.27:45074
03:52:07 I0907 03:52:07.721469 2375 master.cpp:6605] Received register agent
message from slave(90)@172.16.10.27:45074 (ip-172-16-10-27.ec2.internal)
03:52:07 I0907 03:52:07.721518 2375 master.cpp:3964] Authorizing agent
providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with
principal 'test-principal'
03:52:07 I0907 03:52:07.721632 2373 master.cpp:6672] Authorized registration
of agent at slave(90)@172.16.10.27:45074 (ip-172-16-10-27.ec2.internal)
03:52:07 I0907 03:52:07.721666 2373 master.cpp:6787] Registering agent at
slave(90)@172.16.10.27:45074 (ip-172-16-10-27.ec2.internal) with id
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0
03:52:07 I0907 03:52:07.721783 2373 registrar.cpp:487] Applied 1 operations
in 28796ns; attempting to update the registry
03:52:07 I0907 03:52:07.721932 2370 registrar.cpp:544] Successfully updated
the registry in 124928ns
03:52:07 I0907 03:52:07.721992 2370 master.cpp:6835] Admitted agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:07 I0907 03:52:07.722132 2370 master.cpp:6880] Registered agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal) with cpus:2; mem:1024; disk:1024;
ports:[31000-32000]
03:52:07 I0907 03:52:07.722203 2374 hierarchical.cpp:601] Added agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 (ip-172-16-10-27.ec2.internal) with
cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
03:52:07 I0907 03:52:07.722205 2370 slave.cpp:1479] Registered with master
[email protected]:45074; given agent ID
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0
03:52:07 I0907 03:52:07.722396 2370 slave.cpp:1499] Checkpointing SlaveInfo
to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/slave.info'
03:52:07 I0907 03:52:07.722447 2374 hierarchical.cpp:1564] Performed
allocation for 1 agents in 173395ns
03:52:07 I0907 03:52:07.722482 2374 task_status_update_manager.cpp:188]
Resuming sending task status updates
03:52:07 I0907 03:52:07.722573 2374 master.cpp:9468] Sending offers [
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-O0 ] to framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default)
03:52:07 I0907 03:52:07.722651 2370 slave.cpp:1548] Forwarding agent update
{"operations":{},"resource_version_uuid":{"value":"V1oIFlhHRv2xxYxsF9hCkQ=="},"slave_id":{"value":"8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0"},"update_oversubscribed_resources":false}
03:52:07 I0907 03:52:07.722790 2374 master.cpp:7939] Ignoring update on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal) as it reports no changes
03:52:07 I0907 03:52:07.723096 2375 scheduler.cpp:845] Enqueuing event OFFERS
received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.723731 2369 scheduler.cpp:248] Sending ACCEPT call to
http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.724097 2371 process.cpp:3569] Handling HTTP event for
process 'master' with path: '/master/api/v1/scheduler'
03:52:07 I0907 03:52:07.724397 2372 http.cpp:1177] HTTP POST for
/master/api/v1/scheduler from 172.16.10.27:41610
03:52:07 I0907 03:52:07.724557 2372 master.cpp:11462] Removing offer
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-O0
03:52:07 I0907 03:52:07.724704 2372 master.cpp:4467] Processing ACCEPT call
for offers: [ 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-O0 ] on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal) for framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default)
03:52:07 I0907 03:52:07.724750 2372 master.cpp:3541] Authorizing framework
principal 'test-principal' to launch task 2e8c13b6-fa45-4e3c-89cd-398a5abc192f
03:52:07 I0907 03:52:07.724932 2372 master.cpp:3541] Authorizing framework
principal 'test-principal' to launch task c6c81339-65c6-4f86-b0ab-c5be60ea5fbd
03:52:07 I0907 03:52:07.725594 2373 master.cpp:12209] Adding task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f with resources cpus(allocated: *):0.1;
mem(allocated: *):32; disk(allocated: *):32 on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:07 I0907 03:52:07.725653 2373 master.cpp:5663] Launching task group {
2e8c13b6-fa45-4e3c-89cd-398a5abc192f } of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default) with resources
cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):32 on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal) on new executor
03:52:07 I0907 03:52:07.725885 2374 slave.cpp:2014] Got assigned task group
containing tasks [ 2e8c13b6-fa45-4e3c-89cd-398a5abc192f ] for framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.725953 2374 slave.cpp:8908] Checkpointing
FrameworkInfo to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/framework.info'
03:52:07 I0907 03:52:07.726119 2373 master.cpp:12209] Adding task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd with resources cpus(allocated: *):0.1;
mem(allocated: *):32; disk(allocated: *):32 on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:07 I0907 03:52:07.726174 2373 master.cpp:5663] Launching task group {
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd } of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default) with resources
cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):32 on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal) on existing executor
03:52:07 I0907 03:52:07.726406 2372 hierarchical.cpp:1236] Recovered
cpus(allocated: *):1.7; mem(allocated: *):928; disk(allocated: *):928;
ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024;
ports:[31000-32000], allocated: cpus(allocated: *):0.3; mem(allocated: *):96;
disk(allocated: *):96) on agent 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 from
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.726444 2372 hierarchical.cpp:1282] Framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 filtered agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 for 5secs
03:52:07 I0907 03:52:07.726583 2374 slave.cpp:8919] Checkpointing framework
pid '@0.0.0.0:0' to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/framework.pid'
03:52:07 I0907 03:52:07.727038 2374 slave.cpp:2014] Got assigned task group
containing tasks [ c6c81339-65c6-4f86-b0ab-c5be60ea5fbd ] for framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.727283 2374 slave.cpp:2388] Authorizing task group
containing tasks [ 2e8c13b6-fa45-4e3c-89cd-398a5abc192f ] for framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.727318 2374 slave.cpp:8466] Authorizing framework
principal 'test-principal' to launch task 2e8c13b6-fa45-4e3c-89cd-398a5abc192f
03:52:07 I0907 03:52:07.727609 2374 slave.cpp:2388] Authorizing task group
containing tasks [ c6c81339-65c6-4f86-b0ab-c5be60ea5fbd ] for framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.727641 2374 slave.cpp:8466] Authorizing framework
principal 'test-principal' to launch task c6c81339-65c6-4f86-b0ab-c5be60ea5fbd
03:52:07 I0907 03:52:07.728116 2374 slave.cpp:2831] Launching task group
containing tasks [ 2e8c13b6-fa45-4e3c-89cd-398a5abc192f ] for framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.728165 2374 paths.cpp:752] Creating sandbox
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f'
for user 'root'
03:52:07 I0907 03:52:07.728693 2374 slave.cpp:9694] Checkpointing
ExecutorInfo to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/executor.info'
03:52:07 I0907 03:52:07.728947 2374 paths.cpp:755] Creating sandbox
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f'
03:52:07 I0907 03:52:07.729185 2374 slave.cpp:8994] Launching executor
'default' of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 with resources
[{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":32.0},"type":"SCALAR"}]
in work directory
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f'
03:52:07 I0907 03:52:07.729526 2374 slave.cpp:9725] Checkpointing TaskInfo to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/tasks/2e8c13b6-fa45-4e3c-89cd-398a5abc192f/task.info'
03:52:07 I0907 03:52:07.731062 2374 slave.cpp:3028] Queued task group
containing tasks [ 2e8c13b6-fa45-4e3c-89cd-398a5abc192f ] for executor
'default' of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.731325 2374 slave.cpp:988] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f'
to virtual path
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/latest'
03:52:07 I0907 03:52:07.731355 2374 slave.cpp:988] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f'
to virtual path
'/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/latest'
03:52:07 I0907 03:52:07.731370 2374 slave.cpp:988] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f'
to virtual path
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f'
03:52:07 I0907 03:52:07.731529 2374 slave.cpp:3509] Launching container
dbe02af2-3122-4f2e-9747-0c4343627c2f for executor 'default' of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.731864 2374 slave.cpp:2831] Launching task group
containing tasks [ c6c81339-65c6-4f86-b0ab-c5be60ea5fbd ] for framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.731918 2374 slave.cpp:9725] Checkpointing TaskInfo to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/tasks/c6c81339-65c6-4f86-b0ab-c5be60ea5fbd/task.info'
03:52:07 I0907 03:52:07.733171 2374 slave.cpp:3028] Queued task group
containing tasks [ c6c81339-65c6-4f86-b0ab-c5be60ea5fbd ] for executor
'default' of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.733458 2373 containerizer.cpp:1280] Starting
container dbe02af2-3122-4f2e-9747-0c4343627c2f
03:52:07 I0907 03:52:07.733788 2373 containerizer.cpp:1446] Checkpointed
ContainerConfig at
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/containers/dbe02af2-3122-4f2e-9747-0c4343627c2f/config'
03:52:07 I0907 03:52:07.733808 2373 containerizer.cpp:3118] Transitioning the
state of container dbe02af2-3122-4f2e-9747-0c4343627c2f from PROVISIONING to
PREPARING
03:52:07 I0907 03:52:07.734777 2369 containerizer.cpp:1939] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"arguments":["mesos-default-executor","--launcher_dir=/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-ubuntu-16.04/mesos/build/src"],"shell":false,"value":"/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-ubuntu-16.04/mesos/build/src/mesos-default-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.27:45074"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiJkYmUwMmFmMi0zMTIyLTRmMmUtOTc0Ny0wYzQzNDM2MjdjMmYiLCJlaWQiOiJkZWZhdWx0IiwiZmlkIjoiOGU5ZDk3ZjYtNGRjNC00OTBiLTgxZjYtZDIwMzNlMjEwOWQzLTAwMDAifQ.Ww__Iwo_c3fJl_ruqYdi_EePl81IKoIQJv74nq6pHl8"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"default"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"8e9d97f6-4dc4-490b-81f6-d2033e2109d3-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":"8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(90)@172.16.10.27:45074"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"2secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f"}]},"task_environment":{},"user":"root","working_directory":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f"}"
--pipe_read="15" --pipe_write="18"
--runtime_directory="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/containers/dbe02af2-3122-4f2e-9747-0c4343627c2f"
--unshare_namespace_mnt="false"'
03:52:07 I0907 03:52:07.734957 2376 linux_launcher.cpp:492] Launching
container dbe02af2-3122-4f2e-9747-0c4343627c2f and cloning with namespaces
03:52:07 I0907 03:52:07.754221 2369 containerizer.cpp:2044] Checkpointing
container's forked pid 10086 to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/pids/forked.pid'
03:52:07 I0907 03:52:07.754623 2369 containerizer.cpp:3118] Transitioning the
state of container dbe02af2-3122-4f2e-9747-0c4343627c2f from PREPARING to
ISOLATING
03:52:07 I0907 03:52:07.755056 2369 containerizer.cpp:3118] Transitioning the
state of container dbe02af2-3122-4f2e-9747-0c4343627c2f from ISOLATING to
FETCHING
03:52:07 I0907 03:52:07.755112 2369 fetcher.cpp:369] Starting to fetch URIs
for container: dbe02af2-3122-4f2e-9747-0c4343627c2f, directory:
/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f
03:52:07 I0907 03:52:07.755334 2369 containerizer.cpp:3118] Transitioning the
state of container dbe02af2-3122-4f2e-9747-0c4343627c2f from FETCHING to RUNNING
03:52:07 I0907 03:52:07.856390 10100 executor.cpp:201] Version: 1.8.0
03:52:07 I0907 03:52:07.858984 2374 process.cpp:3569] Handling HTTP event for
process 'slave(90)' with path: '/slave(90)/api/v1/executor'
03:52:07 I0907 03:52:07.859725 2373 http.cpp:1177] HTTP POST for
/slave(90)/api/v1/executor from 172.16.10.27:41614
03:52:07 I0907 03:52:07.859807 2373 slave.cpp:4607] Received Subscribe
request for HTTP executor 'default' of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.859856 2373 slave.cpp:4670] Creating a marker file
for HTTP based executor 'default' of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (via HTTP) at path
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/http.marker'
03:52:07 I0907 03:52:07.860514 2373 slave.cpp:3282] Sending queued task group
containing tasks [ 2e8c13b6-fa45-4e3c-89cd-398a5abc192f ] to executor 'default'
of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (via HTTP)
03:52:07 I0907 03:52:07.860643 2373 slave.cpp:3282] Sending queued task group
containing tasks [ c6c81339-65c6-4f86-b0ab-c5be60ea5fbd ] to executor 'default'
of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (via HTTP)
03:52:07 I0907 03:52:07.861613 10117 default_executor.cpp:204] Received
SUBSCRIBED event
03:52:07 I0907 03:52:07.861932 10117 default_executor.cpp:208] Subscribed
executor on ip-172-16-10-27.ec2.internal
03:52:07 I0907 03:52:07.862021 10117 default_executor.cpp:204] Received
LAUNCH_GROUP event
03:52:07 I0907 03:52:07.862232 10117 default_executor.cpp:204] Received
LAUNCH_GROUP event
03:52:07 I0907 03:52:07.862555 10119 default_executor.cpp:428] Setting
'MESOS_CONTAINER_IP' to: 172.16.10.27
03:52:07 I0907 03:52:07.863678 2373 process.cpp:3569] Handling HTTP event for
process 'slave(90)' with path: '/slave(90)/api/v1/executor'
03:52:07 I0907 03:52:07.863754 2373 process.cpp:3569] Handling HTTP event for
process 'slave(90)' with path: '/slave(90)/api/v1'
03:52:07 I0907 03:52:07.864528 2373 http.cpp:1177] HTTP POST for
/slave(90)/api/v1 from 172.16.10.27:41618
03:52:07 I0907 03:52:07.864616 2373 http.cpp:1177] HTTP POST for
/slave(90)/api/v1/executor from 172.16.10.27:41616
03:52:07 I0907 03:52:07.864670 10121 default_executor.cpp:428] Setting
'MESOS_CONTAINER_IP' to: 172.16.10.27
03:52:07 I0907 03:52:07.864679 2373 slave.cpp:5269] Handling status update
TASK_STARTING (Status UUID: e10442b0-02ac-4479-9810-b270714ce3c9) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.864825 2373 http.cpp:2444] Processing
LAUNCH_NESTED_CONTAINER call for container
'dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc'
03:52:07 I0907 03:52:07.865089 2376 task_status_update_manager.cpp:328]
Received task status update TASK_STARTING (Status UUID:
e10442b0-02ac-4479-9810-b270714ce3c9) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.865116 2376 task_status_update_manager.cpp:507]
Creating StatusUpdate stream for task 2e8c13b6-fa45-4e3c-89cd-398a5abc192f of
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.865145 2373 containerizer.cpp:1242] Creating sandbox
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/dbc72eae-9465-4bf7-a082-0bf8a055fecc'
for user 'root'
03:52:07 I0907 03:52:07.865350 2373 containerizer.cpp:1280] Starting
container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc
03:52:07 I0907 03:52:07.865348 2376 task_status_update_manager.cpp:842]
Checkpointing UPDATE for task status update TASK_STARTING (Status UUID:
e10442b0-02ac-4479-9810-b270714ce3c9) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.865442 2376 task_status_update_manager.cpp:383]
Forwarding task status update TASK_STARTING (Status UUID:
e10442b0-02ac-4479-9810-b270714ce3c9) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to the agent
03:52:07 I0907 03:52:07.865520 2376 slave.cpp:5761] Forwarding the update
TASK_STARTING (Status UUID: e10442b0-02ac-4479-9810-b270714ce3c9) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to [email protected]:45074
03:52:07 I0907 03:52:07.865600 2376 slave.cpp:5654] Task status update
manager successfully handled status update TASK_STARTING (Status UUID:
e10442b0-02ac-4479-9810-b270714ce3c9) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.865655 2369 master.cpp:8375] Status update
TASK_STARTING (Status UUID: e10442b0-02ac-4479-9810-b270714ce3c9) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 from agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:07 I0907 03:52:07.865679 2369 master.cpp:8432] Forwarding status update
TASK_STARTING (Status UUID: e10442b0-02ac-4479-9810-b270714ce3c9) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.865785 2369 master.cpp:10932] Updating the state of
task 2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (latest state: TASK_STARTING, status
update state: TASK_STARTING)
03:52:07 I0907 03:52:07.866125 2372 scheduler.cpp:845] Enqueuing event UPDATE
received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.866276 2373 containerizer.cpp:1446] Checkpointed
ContainerConfig at
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/containers/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/dbc72eae-9465-4bf7-a082-0bf8a055fecc/config'
03:52:07 I0907 03:52:07.866367 2375 scheduler.cpp:248] Sending ACKNOWLEDGE
call to http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.866674 2372 process.cpp:3569] Handling HTTP event for
process 'master' with path: '/master/api/v1/scheduler'
03:52:07 I0907 03:52:07.866292 2373 containerizer.cpp:3118] Transitioning the
state of container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc from
PROVISIONING to PREPARING
03:52:07 I0907 03:52:07.867278 2375 containerizer.cpp:1939] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"shell":true,"value":"sleep
1000"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/dbc72eae-9465-4bf7-a082-0bf8a055fecc"},{"name":"MESOS_CONTAINER_IP","type":"VALUE","value":"172.16.10.27"}]},"task_environment":{},"user":"root","working_directory":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/dbc72eae-9465-4bf7-a082-0bf8a055fecc"}"
--pipe_read="22" --pipe_write="23"
--runtime_directory="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/containers/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/dbc72eae-9465-4bf7-a082-0bf8a055fecc"
--unshare_namespace_mnt="false"'
03:52:07 I0907 03:52:07.867460 2374 linux_launcher.cpp:492] Launching nested
container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc and
cloning with namespaces
03:52:07 I0907 03:52:07.869093 10119 default_executor.cpp:204] Received
ACKNOWLEDGED event
03:52:07 I0907 03:52:07.869769 2373 process.cpp:3569] Handling HTTP event for
process 'slave(90)' with path: '/slave(90)/api/v1'
03:52:07 I0907 03:52:07.869877 2373 process.cpp:3569] Handling HTTP event for
process 'slave(90)' with path: '/slave(90)/api/v1/executor'
03:52:07 I0907 03:52:07.870610 2370 http.cpp:1177] HTTP POST for
/slave(90)/api/v1 from 172.16.10.27:41620
03:52:07 I0907 03:52:07.870734 2370 http.cpp:2444] Processing
LAUNCH_NESTED_CONTAINER call for container
'dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c'
03:52:07 I0907 03:52:07.886466 2375 containerizer.cpp:3118] Transitioning the
state of container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc from
PREPARING to ISOLATING
03:52:07 I0907 03:52:07.886638 2375 containerizer.cpp:1242] Creating sandbox
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c'
for user 'root'
03:52:07 I0907 03:52:07.886797 2375 containerizer.cpp:1280] Starting
container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c
03:52:07 I0907 03:52:07.887120 2375 containerizer.cpp:1446] Checkpointed
ContainerConfig at
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/containers/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c/config'
03:52:07 I0907 03:52:07.887145 2375 containerizer.cpp:3118] Transitioning the
state of container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c from
PROVISIONING to PREPARING
03:52:07 I0907 03:52:07.887554 2375 containerizer.cpp:3118] Transitioning the
state of container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc from
ISOLATING to FETCHING
03:52:07 I0907 03:52:07.887653 2375 fetcher.cpp:369] Starting to fetch URIs
for container:
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc,
directory:
/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/dbc72eae-9465-4bf7-a082-0bf8a055fecc
03:52:07 I0907 03:52:07.888100 2375 containerizer.cpp:1939] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"shell":true,"value":"exit
0"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c"},{"name":"MESOS_CONTAINER_IP","type":"VALUE","value":"172.16.10.27"}]},"task_environment":{},"user":"root","working_directory":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c"}"
--pipe_read="24" --pipe_write="25"
--runtime_directory="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/containers/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c"
--unshare_namespace_mnt="false"'
03:52:07 I0907 03:52:07.888273 2371 linux_launcher.cpp:492] Launching nested
container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c and
cloning with namespaces
03:52:07 I0907 03:52:07.893172 2375 containerizer.cpp:3118] Transitioning the
state of container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c from
PREPARING to ISOLATING
03:52:07 I0907 03:52:07.893383 2375 containerizer.cpp:3118] Transitioning the
state of container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc from
FETCHING to RUNNING
03:52:07 I0907 03:52:07.893857 2375 containerizer.cpp:3118] Transitioning the
state of container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c from
ISOLATING to FETCHING
03:52:07 I0907 03:52:07.894094 2375 fetcher.cpp:369] Starting to fetch URIs
for container:
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c,
directory:
/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c
03:52:07 I0907 03:52:07.894352 2375 containerizer.cpp:3118] Transitioning the
state of container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c from
FETCHING to RUNNING
03:52:07 I0907 03:52:07.896064 10116 default_executor.cpp:663] Finished
launching tasks [ 2e8c13b6-fa45-4e3c-89cd-398a5abc192f ] in child containers [
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc ]
03:52:07 I0907 03:52:07.896095 10116 default_executor.cpp:687] Waiting on
child containers of tasks [ 2e8c13b6-fa45-4e3c-89cd-398a5abc192f ]
03:52:07 I0907 03:52:07.896347 10116 default_executor.cpp:663] Finished
launching tasks [ c6c81339-65c6-4f86-b0ab-c5be60ea5fbd ] in child containers [
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c ]
03:52:07 I0907 03:52:07.896368 10116 default_executor.cpp:687] Waiting on
child containers of tasks [ c6c81339-65c6-4f86-b0ab-c5be60ea5fbd ]
03:52:07 I0907 03:52:07.896908 10118 default_executor.cpp:748] Waiting for
child container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc of
task '2e8c13b6-fa45-4e3c-89cd-398a5abc192f'
03:52:07 I0907 03:52:07.896988 10118 default_executor.cpp:748] Waiting for
child container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c of
task 'c6c81339-65c6-4f86-b0ab-c5be60ea5fbd'
03:52:07 I0907 03:52:07.897475 2374 process.cpp:3569] Handling HTTP event for
process 'slave(90)' with path: '/slave(90)/api/v1'
03:52:07 I0907 03:52:07.897568 2374 process.cpp:3569] Handling HTTP event for
process 'slave(90)' with path: '/slave(90)/api/v1'
03:52:07 I0907 03:52:07.898296 2374 http.cpp:1177] HTTP POST for
/slave(90)/api/v1 from 172.16.10.27:41622
03:52:07 I0907 03:52:07.898389 2374 http.cpp:1177] HTTP POST for
/slave(90)/api/v1 from 172.16.10.27:41624
03:52:07 I0907 03:52:07.898488 2374 http.cpp:2679] Processing
WAIT_NESTED_CONTAINER call for container
'dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc'
03:52:07 I0907 03:52:07.898587 2374 http.cpp:2679] Processing
WAIT_NESTED_CONTAINER call for container
'dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c'
03:52:07 I0907 03:52:07.906261 2374 process.cpp:3569] Handling HTTP event for
process 'slave(90)' with path: '/slave(90)/api/v1/executor'
03:52:07 I0907 03:52:07.906337 2374 process.cpp:3569] Handling HTTP event for
process 'slave(90)' with path: '/slave(90)/api/v1/executor'
03:52:07 I0907 03:52:07.906690 2374 http.cpp:1177] HTTP POST for
/master/api/v1/scheduler from 172.16.10.27:41610
03:52:07 I0907 03:52:07.906752 2374 master.cpp:6241] Processing ACKNOWLEDGE
call for status e10442b0-02ac-4479-9810-b270714ce3c9 for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default) on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0
03:52:07 I0907 03:52:07.906955 2374 task_status_update_manager.cpp:401]
Received task status update acknowledgement (UUID:
e10442b0-02ac-4479-9810-b270714ce3c9) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.906989 2374 task_status_update_manager.cpp:842]
Checkpointing ACK for task status update TASK_STARTING (Status UUID:
e10442b0-02ac-4479-9810-b270714ce3c9) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.907456 2374 slave.cpp:4505] Task status update
manager successfully handled status update acknowledgement (UUID:
e10442b0-02ac-4479-9810-b270714ce3c9) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.908149 2376 http.cpp:1177] HTTP POST for
/slave(90)/api/v1/executor from 172.16.10.27:41616
03:52:07 I0907 03:52:07.908223 2376 slave.cpp:5269] Handling status update
TASK_STARTING (Status UUID: 8dc5aae0-605b-42a0-a597-014404ae1bde) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.908481 2376 http.cpp:1177] HTTP POST for
/slave(90)/api/v1/executor from 172.16.10.27:41616
03:52:07 I0907 03:52:07.908550 2376 slave.cpp:5269] Handling status update
TASK_RUNNING (Status UUID: 898e5c8a-fb6a-47e6-8732-9c088c8986ea) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.908641 2376 http.cpp:1177] HTTP POST for
/slave(90)/api/v1/executor from 172.16.10.27:41616
03:52:07 I0907 03:52:07.908699 2376 slave.cpp:5269] Handling status update
TASK_RUNNING (Status UUID: fa82b142-8506-416c-9f9a-5d5a0b0f5906) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.909559 2376 task_status_update_manager.cpp:328]
Received task status update TASK_STARTING (Status UUID:
8dc5aae0-605b-42a0-a597-014404ae1bde) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.909593 2376 task_status_update_manager.cpp:507]
Creating StatusUpdate stream for task c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.909816 2376 task_status_update_manager.cpp:842]
Checkpointing UPDATE for task status update TASK_STARTING (Status UUID:
8dc5aae0-605b-42a0-a597-014404ae1bde) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.909917 2376 task_status_update_manager.cpp:383]
Forwarding task status update TASK_STARTING (Status UUID:
8dc5aae0-605b-42a0-a597-014404ae1bde) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to the agent
03:52:07 I0907 03:52:07.910491 2369 task_status_update_manager.cpp:328]
Received task status update TASK_RUNNING (Status UUID:
898e5c8a-fb6a-47e6-8732-9c088c8986ea) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.910521 2369 task_status_update_manager.cpp:842]
Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID:
898e5c8a-fb6a-47e6-8732-9c088c8986ea) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.910598 2369 task_status_update_manager.cpp:383]
Forwarding task status update TASK_RUNNING (Status UUID:
898e5c8a-fb6a-47e6-8732-9c088c8986ea) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to the agent
03:52:07 I0907 03:52:07.910706 2373 task_status_update_manager.cpp:328]
Received task status update TASK_RUNNING (Status UUID:
fa82b142-8506-416c-9f9a-5d5a0b0f5906) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.910732 2373 task_status_update_manager.cpp:842]
Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID:
fa82b142-8506-416c-9f9a-5d5a0b0f5906) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.910827 2376 slave.cpp:5761] Forwarding the update
TASK_STARTING (Status UUID: 8dc5aae0-605b-42a0-a597-014404ae1bde) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to [email protected]:45074
03:52:07 I0907 03:52:07.910946 2372 master.cpp:8375] Status update
TASK_STARTING (Status UUID: 8dc5aae0-605b-42a0-a597-014404ae1bde) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 from agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:07 I0907 03:52:07.910979 2372 master.cpp:8432] Forwarding status update
TASK_STARTING (Status UUID: 8dc5aae0-605b-42a0-a597-014404ae1bde) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.911111 2372 master.cpp:10932] Updating the state of
task c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (latest state: TASK_RUNNING, status
update state: TASK_STARTING)
03:52:07 I0907 03:52:07.911465 2375 scheduler.cpp:845] Enqueuing event UPDATE
received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.911682 2375 scheduler.cpp:248] Sending ACKNOWLEDGE
call to http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.912065 2371 process.cpp:3569] Handling HTTP event for
process 'master' with path: '/master/api/v1/scheduler'
03:52:07 I0907 03:52:07.912154 2376 slave.cpp:5654] Task status update
manager successfully handled status update TASK_STARTING (Status UUID:
8dc5aae0-605b-42a0-a597-014404ae1bde) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.912531 10119 default_executor.cpp:204] Received
ACKNOWLEDGED event
03:52:07 I0907 03:52:07.912585 2376 slave.cpp:5761] Forwarding the update
TASK_RUNNING (Status UUID: 898e5c8a-fb6a-47e6-8732-9c088c8986ea) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to [email protected]:45074
03:52:07 I0907 03:52:07.912716 2373 master.cpp:8375] Status update
TASK_RUNNING (Status UUID: 898e5c8a-fb6a-47e6-8732-9c088c8986ea) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 from agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:07 I0907 03:52:07.912746 2373 master.cpp:8432] Forwarding status update
TASK_RUNNING (Status UUID: 898e5c8a-fb6a-47e6-8732-9c088c8986ea) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.912868 2373 master.cpp:10932] Updating the state of
task 2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
03:52:07 I0907 03:52:07.913197 2370 scheduler.cpp:845] Enqueuing event UPDATE
received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.913413 2370 scheduler.cpp:248] Sending ACKNOWLEDGE
call to http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.913676 2376 slave.cpp:5654] Task status update
manager successfully handled status update TASK_RUNNING (Status UUID:
898e5c8a-fb6a-47e6-8732-9c088c8986ea) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.914064 10119 default_executor.cpp:204] Received
ACKNOWLEDGED event
03:52:07 I0907 03:52:07.914105 2376 slave.cpp:5654] Task status update
manager successfully handled status update TASK_RUNNING (Status UUID:
fa82b142-8506-416c-9f9a-5d5a0b0f5906) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.914460 10120 default_executor.cpp:204] Received
ACKNOWLEDGED event
03:52:07 I0907 03:52:07.950346 2371 process.cpp:3569] Handling HTTP event for
process 'master' with path: '/master/api/v1/scheduler'
03:52:07 I0907 03:52:07.950747 2371 http.cpp:1177] HTTP POST for
/master/api/v1/scheduler from 172.16.10.27:41610
03:52:07 I0907 03:52:07.950814 2371 master.cpp:6241] Processing ACKNOWLEDGE
call for status 8dc5aae0-605b-42a0-a597-014404ae1bde for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default) on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0
03:52:07 I0907 03:52:07.950927 2371 http.cpp:1177] HTTP POST for
/master/api/v1/scheduler from 172.16.10.27:41610
03:52:07 I0907 03:52:07.950971 2371 master.cpp:6241] Processing ACKNOWLEDGE
call for status 898e5c8a-fb6a-47e6-8732-9c088c8986ea for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default) on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0
03:52:07 I0907 03:52:07.951253 2371 task_status_update_manager.cpp:401]
Received task status update acknowledgement (UUID:
8dc5aae0-605b-42a0-a597-014404ae1bde) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.951315 2371 task_status_update_manager.cpp:842]
Checkpointing ACK for task status update TASK_STARTING (Status UUID:
8dc5aae0-605b-42a0-a597-014404ae1bde) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.951396 2371 task_status_update_manager.cpp:383]
Forwarding task status update TASK_RUNNING (Status UUID:
fa82b142-8506-416c-9f9a-5d5a0b0f5906) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to the agent
03:52:07 I0907 03:52:07.951472 2371 task_status_update_manager.cpp:401]
Received task status update acknowledgement (UUID:
898e5c8a-fb6a-47e6-8732-9c088c8986ea) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.951519 2371 task_status_update_manager.cpp:842]
Checkpointing ACK for task status update TASK_RUNNING (Status UUID:
898e5c8a-fb6a-47e6-8732-9c088c8986ea) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.951596 2371 slave.cpp:5761] Forwarding the update
TASK_RUNNING (Status UUID: fa82b142-8506-416c-9f9a-5d5a0b0f5906) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to [email protected]:45074
03:52:07 I0907 03:52:07.951683 2371 slave.cpp:4505] Task status update
manager successfully handled status update acknowledgement (UUID:
8dc5aae0-605b-42a0-a597-014404ae1bde) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.951723 2371 slave.cpp:4505] Task status update
manager successfully handled status update acknowledgement (UUID:
898e5c8a-fb6a-47e6-8732-9c088c8986ea) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.951797 2371 master.cpp:8375] Status update
TASK_RUNNING (Status UUID: fa82b142-8506-416c-9f9a-5d5a0b0f5906) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 from agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:07 I0907 03:52:07.951818 2371 master.cpp:8432] Forwarding status update
TASK_RUNNING (Status UUID: fa82b142-8506-416c-9f9a-5d5a0b0f5906) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:07 I0907 03:52:07.951963 2371 master.cpp:10932] Updating the state of
task c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
03:52:07 I0907 03:52:07.952499 2372 scheduler.cpp:845] Enqueuing event UPDATE
received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.952716 2372 scheduler.cpp:248] Sending ACKNOWLEDGE
call to http://172.16.10.27:45074/master/api/v1/scheduler
03:52:07 I0907 03:52:07.953107 2369 process.cpp:3569] Handling HTTP event for
process 'master' with path: '/master/api/v1/scheduler'
03:52:08 I0907 03:52:07.990520 2371 http.cpp:1177] HTTP POST for
/master/api/v1/scheduler from 172.16.10.27:41610
03:52:08 I0907 03:52:07.990584 2371 master.cpp:6241] Processing ACKNOWLEDGE
call for status fa82b142-8506-416c-9f9a-5d5a0b0f5906 for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default) on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0
03:52:08 I0907 03:52:07.990727 2374 task_status_update_manager.cpp:401]
Received task status update acknowledgement (UUID:
fa82b142-8506-416c-9f9a-5d5a0b0f5906) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:07.990777 2374 task_status_update_manager.cpp:842]
Checkpointing ACK for task status update TASK_RUNNING (Status UUID:
fa82b142-8506-416c-9f9a-5d5a0b0f5906) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:07.990979 2373 slave.cpp:4505] Task status update
manager successfully handled status update acknowledgement (UUID:
fa82b142-8506-416c-9f9a-5d5a0b0f5906) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.056339 2371 containerizer.cpp:2957] Container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c has
exited
03:52:08 I0907 03:52:08.056361 2371 containerizer.cpp:2455] Destroying
container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c in
RUNNING state
03:52:08 I0907 03:52:08.056371 2371 containerizer.cpp:3118] Transitioning the
state of container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c from
RUNNING to DESTROYING
03:52:08 I0907 03:52:08.056445 2371 linux_launcher.cpp:580] Asked to destroy
container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c
03:52:08 I0907 03:52:08.056494 2371 linux_launcher.cpp:622] Destroying cgroup
'/sys/fs/cgroup/freezer/mesos/dbe02af2-3122-4f2e-9747-0c4343627c2f/mesos/05a1238c-5190-476a-945f-4d8f1225e45c'
03:52:08 I0907 03:52:08.056720 2373 cgroups.cpp:2838] Freezing cgroup
/sys/fs/cgroup/freezer/mesos/dbe02af2-3122-4f2e-9747-0c4343627c2f/mesos/05a1238c-5190-476a-945f-4d8f1225e45c
03:52:08 I0907 03:52:08.056849 2373 cgroups.cpp:1229] Successfully froze
cgroup
/sys/fs/cgroup/freezer/mesos/dbe02af2-3122-4f2e-9747-0c4343627c2f/mesos/05a1238c-5190-476a-945f-4d8f1225e45c
after 104192ns
03:52:08 I0907 03:52:08.056985 2374 cgroups.cpp:2856] Thawing cgroup
/sys/fs/cgroup/freezer/mesos/dbe02af2-3122-4f2e-9747-0c4343627c2f/mesos/05a1238c-5190-476a-945f-4d8f1225e45c
03:52:08 I0907 03:52:08.057072 2374 cgroups.cpp:1258] Successfully thawed
cgroup
/sys/fs/cgroup/freezer/mesos/dbe02af2-3122-4f2e-9747-0c4343627c2f/mesos/05a1238c-5190-476a-945f-4d8f1225e45c
after 59136ns
03:52:08 I0907 03:52:08.057595 2375 provisioner.cpp:597] Ignoring destroy
request for unknown container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c
03:52:08 I0907 03:52:08.057662 2375 containerizer.cpp:2747] Checkpointing
termination state to nested container's runtime directory
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/containers/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c/termination'
03:52:08 I0907 03:52:08.057904 2376 gc.cpp:95] Scheduling
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c'
for gc 6.99998775645926days in the future
03:52:08 I0907 03:52:08.058738 2369 process.cpp:3569] Handling HTTP event for
process 'slave(90)' with path: '/slave(90)/api/v1/executor'
03:52:08 I0907 03:52:08.060922 10121 default_executor.cpp:955] Child container
dbe02af2-3122-4f2e-9747-0c4343627c2f.05a1238c-5190-476a-945f-4d8f1225e45c of
task 'c6c81339-65c6-4f86-b0ab-c5be60ea5fbd' completed in state TASK_FINISHED:
Command exited with status 0
03:52:08 I0907 03:52:08.098583 2371 http.cpp:1177] HTTP POST for
/slave(90)/api/v1/executor from 172.16.10.27:41616
03:52:08 I0907 03:52:08.098664 2371 slave.cpp:5269] Handling status update
TASK_FINISHED (Status UUID: 7459155f-590d-4e56-ad85-9cd2c2f4ba40) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.099135 2373 task_status_update_manager.cpp:328]
Received task status update TASK_FINISHED (Status UUID:
7459155f-590d-4e56-ad85-9cd2c2f4ba40) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.099171 2373 task_status_update_manager.cpp:842]
Checkpointing UPDATE for task status update TASK_FINISHED (Status UUID:
7459155f-590d-4e56-ad85-9cd2c2f4ba40) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.099236 2373 task_status_update_manager.cpp:383]
Forwarding task status update TASK_FINISHED (Status UUID:
7459155f-590d-4e56-ad85-9cd2c2f4ba40) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to the agent
03:52:08 I0907 03:52:08.099304 2373 slave.cpp:5761] Forwarding the update
TASK_FINISHED (Status UUID: 7459155f-590d-4e56-ad85-9cd2c2f4ba40) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to [email protected]:45074
03:52:08 I0907 03:52:08.099382 2373 slave.cpp:5654] Task status update
manager successfully handled status update TASK_FINISHED (Status UUID:
7459155f-590d-4e56-ad85-9cd2c2f4ba40) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.099511 2373 master.cpp:8375] Status update
TASK_FINISHED (Status UUID: 7459155f-590d-4e56-ad85-9cd2c2f4ba40) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 from agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:08 I0907 03:52:08.099537 2373 master.cpp:8432] Forwarding status update
TASK_FINISHED (Status UUID: 7459155f-590d-4e56-ad85-9cd2c2f4ba40) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.099639 2373 master.cpp:10932] Updating the state of
task c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (latest state: TASK_FINISHED, status
update state: TASK_FINISHED)
03:52:08 I0907 03:52:08.099834 2373 hierarchical.cpp:1236] Recovered
cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):32 (total:
cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated:
*):0.2; mem(allocated: *):64; disk(allocated: *):64) on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 from framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.100028 10119 default_executor.cpp:204] Received
ACKNOWLEDGED event
03:52:08 I0907 03:52:08.100237 2369 scheduler.cpp:845] Enqueuing event UPDATE
received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:08 I0907 03:52:08.100456 2370 scheduler.cpp:248] Sending ACKNOWLEDGE
call to http://172.16.10.27:45074/master/api/v1/scheduler
03:52:08 I0907 03:52:08.100777 2369 process.cpp:3569] Handling HTTP event for
process 'master' with path: '/master/api/v1/scheduler'
03:52:08 I0907 03:52:08.138344 2370 http.cpp:1177] HTTP POST for
/master/api/v1/scheduler from 172.16.10.27:41610
03:52:08 I0907 03:52:08.138397 2370 master.cpp:6241] Processing ACKNOWLEDGE
call for status 7459155f-590d-4e56-ad85-9cd2c2f4ba40 for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default) on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0
03:52:08 I0907 03:52:08.138432 2370 master.cpp:11030] Removing task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd with resources cpus(allocated: *):0.1;
mem(allocated: *):32; disk(allocated: *):32 of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:08 I0907 03:52:08.138602 2369 task_status_update_manager.cpp:401]
Received task status update acknowledgement (UUID:
7459155f-590d-4e56-ad85-9cd2c2f4ba40) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.138638 2369 task_status_update_manager.cpp:842]
Checkpointing ACK for task status update TASK_FINISHED (Status UUID:
7459155f-590d-4e56-ad85-9cd2c2f4ba40) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.138676 2369 task_status_update_manager.cpp:538]
Cleaning up status update stream for task c6c81339-65c6-4f86-b0ab-c5be60ea5fbd
of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.138803 2369 slave.cpp:4505] Task status update
manager successfully handled status update acknowledgement (UUID:
7459155f-590d-4e56-ad85-9cd2c2f4ba40) for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.138820 2369 slave.cpp:9651] Completing task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd
03:52:08 I0907 03:52:08.138900 2369 gc.cpp:95] Scheduling
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/tasks/c6c81339-65c6-4f86-b0ab-c5be60ea5fbd'
for gc 6.99998681873778days in the future
03:52:08 I0907 03:52:08.139261 2350 slave.cpp:909] Agent terminating
03:52:08 I0907 03:52:08.139454 2371 master.cpp:1251] Agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal) disconnected
03:52:08 I0907 03:52:08.139475 2371 master.cpp:3267] Disconnecting agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:08 I0907 03:52:08.139492 2371 master.cpp:3286] Deactivating agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(90)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:08 I0907 03:52:08.139536 2371 hierarchical.cpp:795] Agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 deactivated
03:52:08 W0907 03:52:08.140225 2350 process.cpp:2810] Attempted to spawn
already running process [email protected]:45074
03:52:08 I0907 03:52:08.140589 2350 containerizer.cpp:305] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
03:52:08 I0907 03:52:08.142592 2350 linux_launcher.cpp:144] Using
/sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
03:52:08 I0907 03:52:08.143028 2350 provisioner.cpp:298] Using default
backend 'overlay'
03:52:08 I0907 03:52:08.143687 2350 cluster.cpp:485] Creating default 'local'
authorizer
03:52:08 I0907 03:52:08.144181 2370 slave.cpp:267] Mesos agent started on
(91)@172.16.10.27:45074
03:52:08 I0907 03:52:08.144197 2370 slave.cpp:268] Flags at startup:
--acls="" --appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/store/appc"
--authenticate_http_executors="true" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authenticatee="crammd5"
--authentication_backoff_factor="1secs" --authentication_timeout_max="1mins"
--authentication_timeout_min="5secs" --authorizer="local"
--cgroups_cpu_enable_pids_and_tids_count="false"
--cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false"
--cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false"
--cgroups_root="mesos" --container_disk_watch_interval="15secs"
--containerizers="mesos"
--credential="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/credential"
--default_role="*" --disallow_sharing_agent_pid_namespace="false"
--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/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/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_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/fetch"
--fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins"
--frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1"
--gc_non_executor_container_sandboxes="true" --help="false"
--hostname_lookup="true" --http_command_executor="false"
--http_credentials="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem"
--jwt_secret_key="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/jwt_secret_key"
--launcher="linux"
--launcher_dir="/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-ubuntu-16.04/mesos/build/src"
--logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150" --memory_profiling="false"
--network_cni_metrics="true" --oversubscribed_resources_interval="15secs"
--perf_duration="10secs" --perf_interval="1mins" --port="5051"
--qos_correction_interval_min="0ns" --quiet="false"
--reconfiguration_policy="equal" --recover="reconnect"
--recovery_timeout="15mins" --registration_backoff_factor="10ms"
--resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]"
--revocable_cpu_low_priority="true"
--runtime_dir="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB"
--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/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv"
--zk_session_timeout="10secs"
03:52:08 I0907 03:52:08.144366 2370 credentials.hpp:86] Loading credential
for authentication from
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/credential'
03:52:08 I0907 03:52:08.144414 2370 slave.cpp:300] Agent using credential
for: test-principal
03:52:08 I0907 03:52:08.144425 2370 credentials.hpp:37] Loading credentials
for authentication from
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_thYmJB/http_credentials'
03:52:08 I0907 03:52:08.144500 2370 http.cpp:1037] Creating default 'basic'
HTTP authenticator for realm 'mesos-agent-executor'
03:52:08 I0907 03:52:08.144552 2370 http.cpp:1058] Creating default 'jwt'
HTTP authenticator for realm 'mesos-agent-executor'
03:52:08 I0907 03:52:08.144613 2370 http.cpp:1037] Creating default 'basic'
HTTP authenticator for realm 'mesos-agent-readonly'
03:52:08 I0907 03:52:08.144652 2370 http.cpp:1058] Creating default 'jwt'
HTTP authenticator for realm 'mesos-agent-readonly'
03:52:08 I0907 03:52:08.144690 2370 http.cpp:1037] Creating default 'basic'
HTTP authenticator for realm 'mesos-agent-readwrite'
03:52:08 I0907 03:52:08.144726 2370 http.cpp:1058] Creating default 'jwt'
HTTP authenticator for realm 'mesos-agent-readwrite'
03:52:08 I0907 03:52:08.144798 2370 disk_profile_adaptor.cpp:80] Creating
default disk profile adaptor module
03:52:08 I0907 03:52:08.145326 2370 slave.cpp:615] Agent resources:
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
03:52:08 I0907 03:52:08.145390 2370 slave.cpp:623] Agent attributes: [ ]
03:52:08 I0907 03:52:08.145401 2370 slave.cpp:632] Agent hostname:
ip-172-16-10-27.ec2.internal
03:52:08 I0907 03:52:08.145444 2373 task_status_update_manager.cpp:181]
Pausing sending task status updates
03:52:08 I0907 03:52:08.145632 2370 state.cpp:66] Recovering state from
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta'
03:52:08 I0907 03:52:08.145664 2370 state.cpp:711] No committed checkpointed
resources found at
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/resources/resources.info'
03:52:08 E0907 03:52:08.145715 10118 executor.cpp:714] End-Of-File received
from agent. The agent closed the event stream
03:52:08 I0907 03:52:08.147001 10118 default_executor.cpp:176] Disconnected
from agent
03:52:08 I0907 03:52:08.147406 2370 slave.cpp:6909] Finished recovering
checkpointed state from
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta',
beginning agent recovery
03:52:08 I0907 03:52:08.147666 2370 slave.cpp:7388] Recovering framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.147833 2370 slave.cpp:9112] Recovering executor
'default' of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.148141 2370 slave.cpp:9651] Completing task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd
03:52:08 I0907 03:52:08.148406 2376 gc.cpp:95] Scheduling
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/tasks/c6c81339-65c6-4f86-b0ab-c5be60ea5fbd'
for gc 6.99998670912days in the future
03:52:08 I0907 03:52:08.148608 2373 task_status_update_manager.cpp:207]
Recovering task status update manager
03:52:08 I0907 03:52:08.148630 2373 task_status_update_manager.cpp:215]
Recovering executor 'default' of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.148672 2373 task_status_update_manager.cpp:507]
Creating StatusUpdate stream for task 2e8c13b6-fa45-4e3c-89cd-398a5abc192f of
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.148811 2370 slave.cpp:988] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f'
to virtual path
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/latest'
03:52:08 I0907 03:52:08.148908 2373 task_status_update_manager.cpp:818]
Replaying task status update stream for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f
03:52:08 I0907 03:52:08.148990 2373 task_status_update_manager.cpp:507]
Creating StatusUpdate stream for task c6c81339-65c6-4f86-b0ab-c5be60ea5fbd of
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.148998 2377 process.cpp:2735] Returning '404 Not
Found' for '/slave(90)/api/v1/executor'
03:52:08 I0907 03:52:08.149178 2373 task_status_update_manager.cpp:818]
Replaying task status update stream for task
c6c81339-65c6-4f86-b0ab-c5be60ea5fbd
03:52:08 I0907 03:52:08.149216 2373 task_status_update_manager.cpp:538]
Cleaning up status update stream for task c6c81339-65c6-4f86-b0ab-c5be60ea5fbd
of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.149478 2370 slave.cpp:988] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f'
to virtual path
'/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/latest'
03:52:08 I0907 03:52:08.149642 2370 slave.cpp:988] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f'
to virtual path
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f'
03:52:08 W0907 03:52:08.149492 10114 executor.cpp:666] Received '404 Not
Found' () for SUBSCRIBE
03:52:08 I0907 03:52:08.149968 2370 containerizer.cpp:727] Recovering Mesos
containers
03:52:08 I0907 03:52:08.150168 2370 containerizer.cpp:784] Recovering
container dbe02af2-3122-4f2e-9747-0c4343627c2f for executor 'default' of
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:08 I0907 03:52:08.154752 2370 gc.cpp:95] Scheduling
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c'
for gc 6.99998663851852days in the future
03:52:08 I0907 03:52:08.154945 2370 linux_launcher.cpp:286] Recovering Linux
launcher
03:52:08 I0907 03:52:08.155302 2370 linux_launcher.cpp:343] Recovered
container dbe02af2-3122-4f2e-9747-0c4343627c2f
03:52:08 I0907 03:52:08.155437 2370 linux_launcher.cpp:331] Not recovering
cgroup mesos/dbe02af2-3122-4f2e-9747-0c4343627c2f/mesos
03:52:08 I0907 03:52:08.155575 2370 linux_launcher.cpp:343] Recovered
container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc
03:52:08 I0907 03:52:08.155746 2370 containerizer.cpp:1053] Recovering
isolators
03:52:08 I0907 03:52:08.157411 2370 containerizer.cpp:1092] Recovering
provisioner
03:52:08 I0907 03:52:08.162133 2376 provisioner.cpp:494] Provisioner recovery
complete
03:52:08 I0907 03:52:08.162586 2371 composing.cpp:339] Finished recovering
all containerizers
03:52:08 I0907 03:52:08.162637 2376 slave.cpp:7138] Recovering executors
03:52:08 I0907 03:52:08.162654 2376 slave.cpp:7225] Waiting for executor
'default' of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (via HTTP) to
subscribe
03:52:08 I0907 03:52:08.702880 2370 hierarchical.cpp:1564] Performed
allocation for 1 agents in 31079ns
03:52:08 I0907 03:52:08.859201 2377 process.cpp:2735] Returning '404 Not
Found' for '/slave(90)/api/v1/executor'
03:52:08 W0907 03:52:08.859589 10114 executor.cpp:666] Received '404 Not
Found' () for SUBSCRIBE
03:52:09 I0907 03:52:09.149554 2377 process.cpp:2735] Returning '404 Not
Found' for '/slave(90)/api/v1/executor'
03:52:09 W0907 03:52:09.149917 10114 executor.cpp:666] Received '404 Not
Found' () for SUBSCRIBE
03:52:09 I0907 03:52:09.703336 2376 hierarchical.cpp:1564] Performed
allocation for 1 agents in 30173ns
03:52:09 I0907 03:52:09.859925 2377 process.cpp:2735] Returning '404 Not
Found' for '/slave(90)/api/v1/executor'
03:52:09 W0907 03:52:09.860404 10117 executor.cpp:666] Received '404 Not
Found' () for SUBSCRIBE
03:52:10 I0907 03:52:10.150609 2377 process.cpp:2735] Returning '404 Not
Found' for '/slave(90)/api/v1/executor'
03:52:10 W0907 03:52:10.151021 10121 executor.cpp:666] Received '404 Not
Found' () for SUBSCRIBE
03:52:10 I0907 03:52:10.162950 2373 slave.cpp:5197] Cleaning up
un-reregistered executors
03:52:10 I0907 03:52:10.162973 2373 slave.cpp:5215] Killing un-reregistered
executor 'default' of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (via
HTTP)
03:52:10 I0907 03:52:10.163033 2373 slave.cpp:7291] Finished recovery
03:52:10 I0907 03:52:10.163075 2371 containerizer.cpp:2455] Destroying
container dbe02af2-3122-4f2e-9747-0c4343627c2f in RUNNING state
03:52:10 I0907 03:52:10.163096 2371 containerizer.cpp:3118] Transitioning the
state of container dbe02af2-3122-4f2e-9747-0c4343627c2f from RUNNING to
DESTROYING
03:52:10 I0907 03:52:10.163106 2371 containerizer.cpp:2455] Destroying
container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc in
RUNNING state
03:52:10 I0907 03:52:10.163115 2371 containerizer.cpp:3118] Transitioning the
state of container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc from
RUNNING to DESTROYING
03:52:10 I0907 03:52:10.163275 2374 linux_launcher.cpp:580] Asked to destroy
container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc
03:52:10 I0907 03:52:10.163326 2374 linux_launcher.cpp:622] Destroying cgroup
'/sys/fs/cgroup/freezer/mesos/dbe02af2-3122-4f2e-9747-0c4343627c2f/mesos/dbc72eae-9465-4bf7-a082-0bf8a055fecc'
03:52:10 I0907 03:52:10.163509 2374 cgroups.cpp:2838] Freezing cgroup
/sys/fs/cgroup/freezer/mesos/dbe02af2-3122-4f2e-9747-0c4343627c2f/mesos/dbc72eae-9465-4bf7-a082-0bf8a055fecc
03:52:10 I0907 03:52:10.164005 2373 slave.cpp:1254] New master detected at
[email protected]:45074
03:52:10 I0907 03:52:10.164031 2373 slave.cpp:1319] Detecting new master
03:52:10 I0907 03:52:10.164106 2371 task_status_update_manager.cpp:181]
Pausing sending task status updates
03:52:10 I0907 03:52:10.165093 2372 slave.cpp:1346] Authenticating with
master [email protected]:45074
03:52:10 I0907 03:52:10.165128 2372 slave.cpp:1355] Using default CRAM-MD5
authenticatee
03:52:10 I0907 03:52:10.165200 2376 authenticatee.cpp:121] Creating new
client SASL connection
03:52:10 I0907 03:52:10.165675 2376 master.cpp:9653] Authenticating
slave(91)@172.16.10.27:45074
03:52:10 I0907 03:52:10.165731 2376 authenticator.cpp:414] Starting
authentication session for crammd5-authenticatee(201)@172.16.10.27:45074
03:52:10 I0907 03:52:10.165791 2376 authenticator.cpp:98] Creating new server
SASL connection
03:52:10 I0907 03:52:10.166316 2376 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
03:52:10 I0907 03:52:10.166338 2376 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
03:52:10 I0907 03:52:10.166371 2376 authenticator.cpp:204] Received SASL
authentication start
03:52:10 I0907 03:52:10.166407 2376 authenticator.cpp:326] Authentication
requires more steps
03:52:10 I0907 03:52:10.166440 2376 authenticatee.cpp:259] Received SASL
authentication step
03:52:10 I0907 03:52:10.166481 2376 authenticator.cpp:232] Received SASL
authentication step
03:52:10 I0907 03:52:10.166496 2376 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-27.ec2.internal'
server FQDN: 'ip-172-16-10-27.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
03:52:10 I0907 03:52:10.166505 2376 auxprop.cpp:181] Looking up auxiliary
property '*userPassword'
03:52:10 I0907 03:52:10.166515 2376 auxprop.cpp:181] Looking up auxiliary
property '*cmusaslsecretCRAM-MD5'
03:52:10 I0907 03:52:10.166524 2376 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-27.ec2.internal'
server FQDN: 'ip-172-16-10-27.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
03:52:10 I0907 03:52:10.166532 2376 auxprop.cpp:131] Skipping auxiliary
property '*userPassword' since SASL_AUXPROP_AUTHZID == true
03:52:10 I0907 03:52:10.166538 2376 auxprop.cpp:131] Skipping auxiliary
property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
03:52:10 I0907 03:52:10.166549 2376 authenticator.cpp:318] Authentication
success
03:52:10 I0907 03:52:10.166592 2376 authenticatee.cpp:299] Authentication
success
03:52:10 I0907 03:52:10.166638 2376 master.cpp:9685] Successfully
authenticated principal 'test-principal' at slave(91)@172.16.10.27:45074
03:52:10 I0907 03:52:10.166651 2371 authenticator.cpp:432] Authentication
session cleanup for crammd5-authenticatee(201)@172.16.10.27:45074
03:52:10 I0907 03:52:10.166708 2376 slave.cpp:1446] Successfully
authenticated with master [email protected]:45074
03:52:10 I0907 03:52:10.166925 2376 slave.cpp:1877] Will retry registration
in 4.802199ms if necessary
03:52:10 I0907 03:52:10.167089 2371 master.cpp:6959] Received reregister
agent message from agent 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at
slave(91)@172.16.10.27:45074 (ip-172-16-10-27.ec2.internal)
03:52:10 I0907 03:52:10.167194 2371 master.cpp:3964] Authorizing agent
providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with
principal 'test-principal'
03:52:10 I0907 03:52:10.167399 2372 master.cpp:7051] Authorized
re-registration of agent 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at
slave(91)@172.16.10.27:45074 (ip-172-16-10-27.ec2.internal)
03:52:10 I0907 03:52:10.167444 2372 master.cpp:7135] Agent is already marked
as registered: 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at
slave(91)@172.16.10.27:45074 (ip-172-16-10-27.ec2.internal)
03:52:10 I0907 03:52:10.167487 2372 master.cpp:7503] Registry updated for
slave 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at
slave(91)@172.16.10.27:45074(ip-172-16-10-27.ec2.internal)
03:52:10 I0907 03:52:10.167649 2376 hierarchical.cpp:697] Agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 (ip-172-16-10-27.ec2.internal) updated
with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
03:52:10 I0907 03:52:10.167691 2376 hierarchical.cpp:783] Agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 reactivated
03:52:10 I0907 03:52:10.167817 2372 slave.cpp:1585] Re-registered with master
[email protected]:45074
03:52:10 I0907 03:52:10.168326 2371 hierarchical.cpp:1564] Performed
allocation for 1 agents in 170435ns
03:52:10 I0907 03:52:10.170323 2376 task_status_update_manager.cpp:188]
Resuming sending task status updates
03:52:10 I0907 03:52:10.170390 2372 slave.cpp:1630] Forwarding agent update
{"operations":{},"resource_version_uuid":{"value":"j4ZjLDA/StuRQkYO2dDq+A=="},"slave_id":{"value":"8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0"},"update_oversubscribed_resources":false}
03:52:10 I0907 03:52:10.170478 2372 slave.cpp:4067] Updating info for
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:10 I0907 03:52:10.170260 2369 scheduler.cpp:845] Enqueuing event
HEARTBEAT received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:10 I0907 03:52:10.168475 2370 cgroups.cpp:2856] Thawing cgroup
/sys/fs/cgroup/freezer/mesos/dbe02af2-3122-4f2e-9747-0c4343627c2f/mesos/dbc72eae-9465-4bf7-a082-0bf8a055fecc
03:52:10 I0907 03:52:10.168576 2375 master.cpp:1827] Skipping periodic
registry garbage collection: no agents qualify for removal
03:52:10 I0907 03:52:10.170827 2369 cgroups.cpp:1258] Successfully thawed
cgroup
/sys/fs/cgroup/freezer/mesos/dbe02af2-3122-4f2e-9747-0c4343627c2f/mesos/dbc72eae-9465-4bf7-a082-0bf8a055fecc
after 0ns
03:52:10 I0907 03:52:10.170676 2372 slave.cpp:8908] Checkpointing
FrameworkInfo to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/framework.info'
03:52:10 I0907 03:52:10.173640 2375 master.cpp:9468] Sending offers [
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-O1 ] to framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default)
03:52:10 I0907 03:52:10.169373 2373 gc.cpp:272] Deleting
/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/tasks/c6c81339-65c6-4f86-b0ab-c5be60ea5fbd
03:52:10 I0907 03:52:10.174196 2369 scheduler.cpp:845] Enqueuing event OFFERS
received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:10 I0907 03:52:10.174222 2375 master.cpp:7939] Ignoring update on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(91)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal) as it reports no changes
03:52:10 I0907 03:52:10.269464 2372 slave.cpp:8919] Checkpointing framework
pid '@0.0.0.0:0' to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/framework.pid'
03:52:10 E0907 03:52:10.269704 2372 slave.cpp:6267] Termination of executor
'default' of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 failed: Failed
to destroy nested containers: Failed to kill all processes in the container:
Timed out after 1mins
03:52:10 I0907 03:52:10.269757 2372 slave.cpp:5269] Handling status update
TASK_LOST (Status UUID: f5a0fab7-ad86-4d4d-94a7-8894f15521fd) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 from @0.0.0.0:0
03:52:10 I0907 03:52:10.269884 2372 slave.cpp:6824] Current disk usage
44.82%. Max allowed age: 3.162545109095440days
03:52:10 I0907 03:52:10.269927 2372 task_status_update_manager.cpp:188]
Resuming sending task status updates
03:52:10 I0907 03:52:10.270087 2369 gc.cpp:331] Pruning directories with
remaining removal time 0ns
03:52:10 I0907 03:52:10.270102 2369 gc.cpp:331] Pruning directories with
remaining removal time 0ns
03:52:10 I0907 03:52:10.270117 2369 gc.cpp:188] Skipping deletion of
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/tasks/c6c81339-65c6-4f86-b0ab-c5be60ea5fbd'
as it is already in progress
03:52:10 E0907 03:52:10.270146 2369 slave.cpp:5600] Failed to update
resources for container dbe02af2-3122-4f2e-9747-0c4343627c2f of executor
'default' running task 2e8c13b6-fa45-4e3c-89cd-398a5abc192f on status update
for terminal task, destroying container: Container not found
03:52:10 W0907 03:52:10.270192 2369 composing.cpp:609] Attempted to destroy
unknown container dbe02af2-3122-4f2e-9747-0c4343627c2f
03:52:10 I0907 03:52:10.270216 2369 task_status_update_manager.cpp:328]
Received task status update TASK_LOST (Status UUID:
f5a0fab7-ad86-4d4d-94a7-8894f15521fd) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:10 I0907 03:52:10.270236 2369 task_status_update_manager.cpp:842]
Checkpointing UPDATE for task status update TASK_LOST (Status UUID:
f5a0fab7-ad86-4d4d-94a7-8894f15521fd) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:10 I0907 03:52:10.270299 2369 task_status_update_manager.cpp:383]
Forwarding task status update TASK_LOST (Status UUID:
f5a0fab7-ad86-4d4d-94a7-8894f15521fd) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to the agent
03:52:10 I0907 03:52:10.270349 2369 slave.cpp:5761] Forwarding the update
TASK_LOST (Status UUID: f5a0fab7-ad86-4d4d-94a7-8894f15521fd) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 to [email protected]:45074
03:52:10 I0907 03:52:10.270387 2369 slave.cpp:5654] Task status update
manager successfully handled status update TASK_LOST (Status UUID:
f5a0fab7-ad86-4d4d-94a7-8894f15521fd) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:10 I0907 03:52:10.270020 2372 master.cpp:8618] Executor 'default' of
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(91)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal): wait status -1
03:52:10 I0907 03:52:10.270433 2372 master.cpp:11061] Removing executor
'default' with resources
[{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":32.0},"type":"SCALAR"}]
of framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(91)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:10 I0907 03:52:10.270642 2372 master.cpp:8375] Status update TASK_LOST
(Status UUID: f5a0fab7-ad86-4d4d-94a7-8894f15521fd) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 from agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(91)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:10 I0907 03:52:10.270660 2372 master.cpp:8432] Forwarding status update
TASK_LOST (Status UUID: f5a0fab7-ad86-4d4d-94a7-8894f15521fd) for task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:10 I0907 03:52:10.270738 2372 master.cpp:10932] Updating the state of
task 2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (latest state: TASK_LOST, status
update state: TASK_LOST)
03:52:10 I0907 03:52:10.270931 2372 hierarchical.cpp:1236] Recovered
cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):32 (total:
cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated:
*):1.9; mem(allocated: *):992; disk(allocated: *):992; ports(allocated:
*):[31000-32000]) on agent 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 from
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:10 I0907 03:52:10.271028 2372 hierarchical.cpp:1236] Recovered
cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):32 (total:
cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated:
*):1.8; mem(allocated: *):960; disk(allocated: *):960; ports(allocated:
*):[31000-32000]) on agent 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 from
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:10 I0907 03:52:10.271473 2371 scheduler.cpp:845] Enqueuing event
FAILURE received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:10
03:52:10 GMOCK WARNING:
03:52:10 Uninteresting mock function call - returning directly.
03:52:10 Function call: failure(0x7ffcee44e920, @0x7ff40001de70 48-byte
object <88-43 53-2C F4-7F 00-00 00-00 00-00 00-00 00-00 07-00 00-00 00-00 00-00
70-0A 00-00 F4-7F 00-00 30-FF 00-00 F4-7F 00-00 FF-FF FF-FF F4-7F 00-00>)
03:52:10 NOTE: You can safely ignore the above warning unless this call should
not happen. Do not suppress it by blindly adding an EXPECT_CALL() if you don't
mean to enforce the call. See
https://github.com/google/googletest/blob/master/googlemock/docs/CookBook.md#knowing-when-to-expect
for details.
03:52:10 I0907 03:52:10.271648 2371 scheduler.cpp:845] Enqueuing event UPDATE
received from http://172.16.10.27:45074/master/api/v1/scheduler
03:52:10 unknown file: Failure
03:52:10
03:52:10 Unexpected mock function call - returning directly.
03:52:10 Function call: update(0x7ffcee44e920, @0x7ff4000015a0 TASK_LOST
(Status UUID: f5a0fab7-ad86-4d4d-94a7-8894f15521fd) Source: SOURCE_AGENT
Reason: REASON_EXECUTOR_REREGISTRATION_TIMEOUT Message: 'Executor did not
reregister within 2secs; Abnormal executor termination: Failed to destroy
nested containers: Failed to kill all processes in the container: Timed out
after 1mins' for task '2e8c13b6-fa45-4e3c-89cd-398a5abc192f' on agent:
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0)
03:52:10 Google Mock tried the following 5 expectations, but none matched:
03:52:10
03:52:10 ../../src/tests/gc_tests.cpp:986: tried expectation #0:
EXPECT_CALL(*scheduler, update(_, AllOf(
TaskStatusUpdateTaskIdEq(longLivedTaskInfo),
TaskStatusUpdateStateEq(v1::TASK_STARTING))))...
03:52:10 Expected: the expectation is active
03:52:10 Actual: it is retired
03:52:10 Expected: to be called once
03:52:10 Actual: called once - saturated and retired
03:52:10 ../../src/tests/gc_tests.cpp:996: tried expectation #1:
EXPECT_CALL(*scheduler, update(_, AllOf(
TaskStatusUpdateTaskIdEq(longLivedTaskInfo),
TaskStatusUpdateStateEq(v1::TASK_RUNNING))))...
03:52:10 Expected arg #1: (task status update task id eq name: "test-task"
03:52:10 task_id {
03:52:10 value: "2e8c13b6-fa45-4e3c-89cd-398a5abc192f"
03:52:10 }
03:52:10 agent_id {
03:52:10 value: "8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0"
03:52:10 }
03:52:10 resources {
03:52:10 name: "cpus"
03:52:10 type: SCALAR
03:52:10 scalar {
03:52:10 value: 0.1
03:52:10 }
03:52:10 }
03:52:10 resources {
03:52:10 name: "mem"
03:52:10 type: SCALAR
03:52:10 scalar {
03:52:10 value: 32
03:52:10 }
03:52:10 }
03:52:10 resources {
03:52:10 name: "disk"
03:52:10 type: SCALAR
03:52:10 scalar {
03:52:10 value: 32
03:52:10 }
03:52:10 }
03:52:10 command {
03:52:10 value: "sleep 1000"
03:52:10 }
03:52:10 ) and (task status update state eq TASK_RUNNING)
03:52:10 Actual: TASK_LOST (Status UUID:
f5a0fab7-ad86-4d4d-94a7-8894f15521fd) Source: SOURCE_AGENT Reason:
REASON_EXECUTOR_REREGISTRATION_TIMEOUT Message: 'Executor did not reregister
within 2secs; Abnormal executor termination: Failed to destroy nested
containers: Failed to kill all processes in the container: Timed out after
1mins' for task '2e8c13b6-fa45-4e3c-89cd-398a5abc192f' on agent:
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0
03:52:10 Expected: to be called once
03:52:10 Actual: called once - saturated and active
03:52:10 ../../src/tests/gc_tests.cpp:1011: tried expectation #2:
EXPECT_CALL(*scheduler, update(_, AllOf(
TaskStatusUpdateTaskIdEq(shortLivedTaskInfo),
TaskStatusUpdateStateEq(v1::TASK_STARTING))))...
03:52:10 Expected: the expectation is active
03:52:10 Actual: it is retired
03:52:10 Expected: to be called once
03:52:10 Actual: called once - saturated and retired
03:52:10 ../../src/tests/gc_tests.cpp:1021: tried expectation #3:
EXPECT_CALL(*scheduler, update(_, AllOf(
TaskStatusUpdateTaskIdEq(shortLivedTaskInfo),
TaskStatusUpdateStateEq(v1::TASK_RUNNING))))...
03:52:10 Expected: the expectation is active
03:52:10 Actual: it is retired
03:52:10 Expected: to be called once
03:52:10 Actual: called once - saturated and retired
03:52:10 ../../src/tests/gc_tests.cpp:1031: tried expectation #4:
EXPECT_CALL(*scheduler, update(_, AllOf(
TaskStatusUpdateTaskIdEq(shortLivedTaskInfo),
TaskStatusUpdateStateEq(v1::TASK_FINISHED))))...
03:52:10 Expected arg #1: (task status update task id eq name: "test-task"
03:52:10 task_id {
03:52:10 value: "c6c81339-65c6-4f86-b0ab-c5be60ea5fbd"
03:52:10 }
03:52:10 agent_id {
03:52:10 value: "8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0"
03:52:10 }
03:52:10 resources {
03:52:10 name: "cpus"
03:52:10 type: SCALAR
03:52:10 scalar {
03:52:10 value: 0.1
03:52:10 }
03:52:10 }
03:52:10 resources {
03:52:10 name: "mem"
03:52:10 type: SCALAR
03:52:10 scalar {
03:52:10 value: 32
03:52:10 }
03:52:10 }
03:52:10 resources {
03:52:10 name: "disk"
03:52:10 type: SCALAR
03:52:10 scalar {
03:52:10 value: 32
03:52:10 }
03:52:10 }
03:52:10 command {
03:52:10 value: "exit 0"
03:52:10 }
03:52:10 ) and (task status update state eq TASK_FINISHED)
03:52:10 Actual: TASK_LOST (Status UUID:
f5a0fab7-ad86-4d4d-94a7-8894f15521fd) Source: SOURCE_AGENT Reason:
REASON_EXECUTOR_REREGISTRATION_TIMEOUT Message: 'Executor did not reregister
within 2secs; Abnormal executor termination: Failed to destroy nested
containers: Failed to kill all processes in the container: Timed out after
1mins' for task '2e8c13b6-fa45-4e3c-89cd-398a5abc192f' on agent:
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0
03:52:10 Expected: to be called once
03:52:10 Actual: called once - saturated and active
03:52:10 I0907 03:52:10.327615 2373 gc.cpp:288] Deleted
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/meta/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/tasks/c6c81339-65c6-4f86-b0ab-c5be60ea5fbd'
03:52:10 I0907 03:52:10.327862 2370 gc.cpp:188] Skipping deletion of
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c'
as it is already in progress
03:52:10 I0907 03:52:10.328534 2369 gc.cpp:188] Skipping deletion of
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c'
as it is already in progress
03:52:10 I0907 03:52:10.329061 2373 gc.cpp:272] Deleting
/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c
03:52:10 I0907 03:52:10.329295 2373 gc.cpp:288] Deleted
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutorRestart_X4h6lv/slaves/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0/frameworks/8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000/executors/default/runs/dbe02af2-3122-4f2e-9747-0c4343627c2f/containers/05a1238c-5190-476a-945f-4d8f1225e45c'
03:52:10 I0907 03:52:10.860333 2377 process.cpp:2735] Returning '404 Not
Found' for '/slave(90)/api/v1/executor'
03:52:10 W0907 03:52:10.860883 10114 executor.cpp:666] Received '404 Not
Found' () for SUBSCRIBE
03:52:11 I0907 03:52:11.151208 2377 process.cpp:2735] Returning '404 Not
Found' for '/slave(90)/api/v1/executor'
03:52:11 W0907 03:52:11.151674 10114 executor.cpp:666] Received '404 Not
Found' () for SUBSCRIBE
03:52:11 I0907 03:52:11.213229 2371 hierarchical.cpp:1564] Performed
allocation for 1 agents in 188978ns
03:52:11 I0907 03:52:11.213379 2371 containerizer.cpp:2957] Container
dbe02af2-3122-4f2e-9747-0c4343627c2f.dbc72eae-9465-4bf7-a082-0bf8a055fecc has
exited
03:52:11 I0907 03:52:11.213652 2371 master.cpp:9468] Sending offers [
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-O2 ] to framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default)
03:52:11 I0907 03:52:11.214164 2350 slave.cpp:909] Agent terminating
03:52:11 I0907 03:52:11.214273 2369 master.cpp:1366] Framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default) disconnected
03:52:11 I0907 03:52:11.214293 2369 master.cpp:3230] Deactivating framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default)
03:52:11 W0907 03:52:11.214360 2369 master.hpp:2605] Unable to send event to
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default): connection closed
03:52:11 I0907 03:52:11.214375 2369 master.cpp:11462] Removing offer
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-O2
03:52:11 W0907 03:52:11.214435 2369 master.hpp:2605] Unable to send event to
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default): connection closed
03:52:11 I0907 03:52:11.214445 2369 master.cpp:11462] Removing offer
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-O1
03:52:11 I0907 03:52:11.214455 2369 master.cpp:3207] Disconnecting framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default)
03:52:11 I0907 03:52:11.214462 2369 master.cpp:1381] Giving framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default) 0ns to failover
03:52:11 I0907 03:52:11.214606 2370 hierarchical.cpp:420] Deactivated
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:11 I0907 03:52:11.214704 2370 hierarchical.cpp:1236] Recovered
cpus(allocated: *):0.2; mem(allocated: *):64; disk(allocated: *):64 (total:
cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated:
*):1.8; mem(allocated: *):960; disk(allocated: *):960; ports(allocated:
*):[31000-32000]) on agent 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 from
framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:11 I0907 03:52:11.214819 2370 hierarchical.cpp:1236] Recovered
cpus(allocated: *):1.8; mem(allocated: *):960; disk(allocated: *):960;
ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024;
ports:[31000-32000], allocated: {}) on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 from framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:11 I0907 03:52:11.214895 2369 master.cpp:9261] Framework failover
timeout, removing framework 8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default)
03:52:11 I0907 03:52:11.214910 2369 master.cpp:10197] Removing framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (default)
03:52:11 I0907 03:52:11.214947 2369 master.cpp:10932] Updating the state of
task 2e8c13b6-fa45-4e3c-89cd-398a5abc192f of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 (latest state: TASK_LOST, status
update state: TASK_KILLED)
03:52:11 I0907 03:52:11.214964 2369 master.cpp:11030] Removing task
2e8c13b6-fa45-4e3c-89cd-398a5abc192f with resources cpus(allocated: *):0.1;
mem(allocated: *):32; disk(allocated: *):32 of framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000 on agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0 at slave(91)@172.16.10.27:45074
(ip-172-16-10-27.ec2.internal)
03:52:11 I0907 03:52:11.215090 2369 hierarchical.cpp:359] Removed framework
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-0000
03:52:11 I0907 03:52:11.217375 2350 master.cpp:1093] Master terminating
03:52:11 I0907 03:52:11.217579 2375 hierarchical.cpp:637] Removed agent
8e9d97f6-4dc4-490b-81f6-d2033e2109d3-S0
03:52:11 [ FAILED ]
GarbageCollectorIntegrationTest.LongLivedDefaultExecutorRestart (3519 ms)
{noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
