[
https://issues.apache.org/jira/browse/MESOS-9217?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Till Toenshoff reassigned MESOS-9217:
-------------------------------------
Assignee: Joseph Wu
> 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
> Assignee: Joseph Wu
> Priority: Major
> Labels: flaky, flaky-test, test
>
> {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)
