[ https://issues.apache.org/jira/browse/MESOS-9217?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16632200#comment-16632200 ]
Joseph Wu commented on MESOS-9217: ---------------------------------- Temporarily disabled: {code} commit 698c1498c20585089db9fca98c35bbab8da46c04 Author: Joseph Wu <josep...@apache.org> Date: Fri Sep 28 11:09:19 2018 -0700 Disabled flaky LongLivedDefaultExecutorRestart test. This flaky test is tracked here: https://issues.apache.org/jira/browse/MESOS-9217 {code} > LongLivedDefaultExecutorRestart is flaky. > ----------------------------------------- > > Key: MESOS-9217 > URL: https://issues.apache.org/jira/browse/MESOS-9217 > Project: Mesos > Issue Type: Bug > Components: test > Affects Versions: 1.7.0, 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 files@172.16.10.27: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 master@172.16.10.27: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 > master@172.16.10.27: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 master@172.16.10.27: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 master@172.16.10.27: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 > master@172.16.10.27: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 master@172.16.10.27: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 master@172.16.10.27: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 master@172.16.10.27: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 master@172.16.10.27: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 master@172.16.10.27: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 files@172.16.10.27: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 > master@172.16.10.27: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 master@172.16.10.27: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 master@172.16.10.27: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 master@172.16.10.27: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 master@172.16.10.27: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)