Andrei Sekretenko created MESOS-9924:
----------------------------------------
Summary: GarbageCollectorIntegrationTest.LongLivedDefaultExecutor
is flaky
Key: MESOS-9924
URL: https://issues.apache.org/jira/browse/MESOS-9924
Project: Mesos
Issue Type: Bug
Environment: centos 6
Reporter: Andrei Sekretenko
Observed in internal CI on centos 6, SSL build:
{code}
[ RUN ] GarbageCollectorIntegrationTest.LongLivedDefaultExecutor
I0801 21:37:55.515724 25986 cluster.cpp:177] Creating default 'local' authorizer
I0801 21:37:55.517258 25994 master.cpp:440] Master
98570ef6-2391-4957-8781-7dc1977897c5 (ip-172-16-10-175.ec2.internal) started on
172.16.10.175:36936
I0801 21:37:55.517282 25994 master.cpp:443] 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/4683ej/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_operator_event_stream_subscribers="1000"
--max_unreachable_tasks_per_framework="1000" --memory_profiling="false"
--min_allocatable_resources="cpus:0.01|mem:32" --port="5050"
--publish_per_framework_metrics="true" --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/4683ej/master" --zk_session_timeout="10secs"
I0801 21:37:55.517568 25994 master.cpp:492] Master only allowing authenticated
frameworks to register
I0801 21:37:55.517596 25994 master.cpp:498] Master only allowing authenticated
agents to register
I0801 21:37:55.517603 25994 master.cpp:504] Master only allowing authenticated
HTTP frameworks to register
I0801 21:37:55.517879 25994 credentials.hpp:37] Loading credentials for
authentication from '/tmp/4683ej/credentials'
I0801 21:37:55.518239 25994 master.cpp:548] Using default 'crammd5'
authenticator
I0801 21:37:55.518290 25994 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
I0801 21:37:55.518703 25994 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
I0801 21:37:55.518743 25994 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
I0801 21:37:55.519242 25994 master.cpp:629] Authorization enabled
I0801 21:37:55.519382 25988 hierarchical.cpp:241] Initialized hierarchical
allocator process
I0801 21:37:55.519675 25988 whitelist_watcher.cpp:77] No whitelist given
I0801 21:37:55.520395 25988 master.cpp:2168] Elected as the leading master!
I0801 21:37:55.520418 25988 master.cpp:1664] Recovering from registrar
I0801 21:37:55.520458 25988 registrar.cpp:339] Recovering registrar
I0801 21:37:55.520639 25988 registrar.cpp:383] Successfully fetched the
registry (0B) in 167168ns
I0801 21:37:55.520673 25988 registrar.cpp:487] Applied 1 operations in 8039ns;
attempting to update the registry
I0801 21:37:55.520794 25988 registrar.cpp:544] Successfully updated the
registry in 104960ns
I0801 21:37:55.520824 25988 registrar.cpp:416] Successfully recovered registrar
I0801 21:37:55.520900 25988 master.cpp:1817] Recovered 0 agents from the
registry (184B); allowing 10mins for agents to reregister
I0801 21:37:55.520944 25988 hierarchical.cpp:280] Skipping recovery of
hierarchical allocator: nothing to recover
W0801 21:37:55.522819 25986 process.cpp:2877] Attempted to spawn already
running process files@172.16.10.175:36936
I0801 21:37:55.523217 25986 containerizer.cpp:318] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I0801 21:37:55.525137 25986 linux_launcher.cpp:144] Using /cgroup/freezer as
the freezer hierarchy for the Linux launcher
I0801 21:37:55.525547 25986 provisioner.cpp:300] Using default backend 'copy'
I0801 21:37:55.526152 25986 cluster.cpp:518] Creating default 'local' authorizer
I0801 21:37:55.526631 25994 slave.cpp:267] Mesos agent started on
(92)@172.16.10.175:36936
I0801 21:37:55.526648 25994 slave.cpp:268] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/4683ej/nETR4f/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/4683ej/nETR4f/credential"
--default_role="*" --disallow_sharing_agent_ipc_namespace="false"
--disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins"
--docker="docker" --docker_ignore_runtime="false" --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/4683ej/nETR4f/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/4683ej/nETR4f/fetch" --fetcher_cache_size="2GB"
--fetcher_stall_timeout="1mins"
--frameworks_home="/tmp/4683ej/nETR4f/frameworks" --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/4683ej/nETR4f/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem"
--jwt_secret_key="/tmp/4683ej/nETR4f/jwt_secret_key" --launcher="linux"
--launcher_dir="/home/centos/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-centos-6/mesos/build/src"
--logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150" --memory_profiling="false"
--network_cni_metrics="true" --network_cni_root_dir_persist="false"
--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_LongLivedDefaultExecutor_pC9f8g"
--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_LongLivedDefaultExecutor_a3REbi"
--zk_session_timeout="10secs"
I0801 21:37:55.526834 25994 credentials.hpp:86] Loading credential for
authentication from '/tmp/4683ej/nETR4f/credential'
I0801 21:37:55.526895 25994 slave.cpp:300] Agent using credential for:
test-principal
I0801 21:37:55.526906 25994 credentials.hpp:37] Loading credentials for
authentication from '/tmp/4683ej/nETR4f/http_credentials'
I0801 21:37:55.526986 25994 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-executor'
I0801 21:37:55.526986 25986 scheduler.cpp:189] Version: 1.9.0
I0801 21:37:55.527030 25994 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-executor'
I0801 21:37:55.527073 25994 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
I0801 21:37:55.527102 25994 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readonly'
I0801 21:37:55.527130 25994 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0801 21:37:55.527154 25994 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0801 21:37:55.527235 25994 disk_profile_adaptor.cpp:78] Creating default disk
profile adaptor module
I0801 21:37:55.527447 25990 scheduler.cpp:342] Using default 'basic' HTTP
authenticatee
I0801 21:37:55.527802 25994 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"}]
I0801 21:37:55.527882 25994 slave.cpp:623] Agent attributes: [ ]
I0801 21:37:55.527892 25994 slave.cpp:632] Agent hostname:
ip-172-16-10-175.ec2.internal
I0801 21:37:55.528424 25991 state.cpp:67] Recovering state from
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta'
I0801 21:37:55.528486 25991 slave.cpp:7444] Finished recovering checkpointed
state from
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta',
beginning agent recovery
I0801 21:37:55.528623 25990 scheduler.cpp:525] New master detected at
master@172.16.10.175:36936
I0801 21:37:55.528638 25990 scheduler.cpp:534] Waiting for 0ns before
initiating a re-(connection) attempt with the master
I0801 21:37:55.528754 25987 task_status_update_manager.cpp:181] Pausing sending
task status updates
I0801 21:37:55.528771 25987 task_status_update_manager.cpp:207] Recovering task
status update manager
I0801 21:37:55.529124 25987 containerizer.cpp:821] Recovering Mesos containers
I0801 21:37:55.529181 25987 linux_launcher.cpp:286] Recovering Linux launcher
I0801 21:37:55.529312 25987 containerizer.cpp:1147] Recovering isolators
I0801 21:37:55.529563 25987 containerizer.cpp:1186] Recovering provisioner
I0801 21:37:55.529700 25987 provisioner.cpp:500] Provisioner recovery complete
I0801 21:37:55.529855 25987 composing.cpp:339] Finished recovering all
containerizers
I0801 21:37:55.529922 25987 slave.cpp:7908] Recovering executors
I0801 21:37:55.529950 25987 slave.cpp:8061] Finished recovery
I0801 21:37:55.530313 25987 slave.cpp:1351] New master detected at
master@172.16.10.175:36936
I0801 21:37:55.530347 25987 slave.cpp:1416] Detecting new master
I0801 21:37:55.530375 25987 task_status_update_manager.cpp:181] Pausing sending
task status updates
I0801 21:37:55.530818 25990 scheduler.cpp:416] Connected with the master at
http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.531023 25990 scheduler.cpp:246] Adding authentication headers to
SUBSCRIBE call to http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.531123 25990 scheduler.cpp:600] Sending SUBSCRIBE call to
http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.531486 25991 process.cpp:3671] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0801 21:37:55.531806 25991 http.cpp:1115] HTTP POST for
/master/api/v1/scheduler from 172.16.10.175:39526
I0801 21:37:55.531886 25991 master.cpp:2668] Received subscription request for
HTTP framework 'default'
I0801 21:37:55.531909 25991 master.cpp:2240] Authorizing framework principal
'test-principal' to receive offers for roles '{ * }'
I0801 21:37:55.532183 25991 master.cpp:2740] Subscribing framework 'default'
with checkpointing enabled and capabilities [ MULTI_ROLE,
RESERVATION_REFINEMENT ]
I0801 21:37:55.532656 25991 master.cpp:10808] Adding framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) with roles { } suppressed
I0801 21:37:55.532878 25991 hierarchical.cpp:368] Added framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.532943 25991 hierarchical.cpp:1508] Performed allocation for 0
agents in 21194ns
I0801 21:37:55.533437 25990 scheduler.cpp:847] Enqueuing event SUBSCRIBED
received from http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.533617 25990 scheduler.cpp:847] Enqueuing event HEARTBEAT
received from http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.533802 25994 status_update_manager_process.hpp:379] Pausing
operation status update manager
I0801 21:37:55.533819 25994 status_update_manager_process.hpp:379] Pausing
operation status update manager
I0801 21:37:55.538949 25994 slave.cpp:1443] Authenticating with master
master@172.16.10.175:36936
I0801 21:37:55.538980 25994 slave.cpp:1452] Using default CRAM-MD5 authenticatee
I0801 21:37:55.539049 25994 authenticatee.cpp:121] Creating new client SASL
connection
I0801 21:37:55.539208 25991 master.cpp:10578] Authenticating
slave(92)@172.16.10.175:36936
I0801 21:37:55.539263 25991 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(211)@172.16.10.175:36936
I0801 21:37:55.539314 25991 authenticator.cpp:98] Creating new server SASL
connection
I0801 21:37:55.539368 25991 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0801 21:37:55.539379 25991 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0801 21:37:55.539409 25991 authenticator.cpp:204] Received SASL authentication
start
I0801 21:37:55.539443 25991 authenticator.cpp:326] Authentication requires more
steps
I0801 21:37:55.539476 25991 authenticatee.cpp:259] Received SASL authentication
step
I0801 21:37:55.539515 25991 authenticator.cpp:232] Received SASL authentication
step
I0801 21:37:55.539530 25991 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-175' server FQDN:
'ip-172-16-10-175' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0801 21:37:55.539535 25991 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0801 21:37:55.539542 25991 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0801 21:37:55.539548 25991 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-175' server FQDN:
'ip-172-16-10-175' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0801 21:37:55.539552 25991 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0801 21:37:55.539556 25991 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0801 21:37:55.539564 25991 authenticator.cpp:318] Authentication success
I0801 21:37:55.539614 25987 authenticatee.cpp:299] Authentication success
I0801 21:37:55.539619 25991 master.cpp:10610] Successfully authenticated
principal 'test-principal' at slave(92)@172.16.10.175:36936
I0801 21:37:55.539640 25991 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(211)@172.16.10.175:36936
I0801 21:37:55.539692 25987 slave.cpp:1543] Successfully authenticated with
master master@172.16.10.175:36936
I0801 21:37:55.539772 25987 slave.cpp:1993] Will retry registration in
8.161868ms if necessary
I0801 21:37:55.539815 25991 master.cpp:7086] Received register agent message
from slave(92)@172.16.10.175:36936 (ip-172-16-10-175.ec2.internal)
I0801 21:37:55.540143 25991 master.cpp:4202] Authorizing agent providing
resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal
'test-principal'
I0801 21:37:55.540642 25992 master.cpp:7153] Authorized registration of agent
at slave(92)@172.16.10.175:36936 (ip-172-16-10-175.ec2.internal)
I0801 21:37:55.540686 25992 master.cpp:7265] Registering agent at
slave(92)@172.16.10.175:36936 (ip-172-16-10-175.ec2.internal) with id
98570ef6-2391-4957-8781-7dc1977897c5-S0
I0801 21:37:55.540985 25987 registrar.cpp:487] Applied 1 operations in 33235ns;
attempting to update the registry
I0801 21:37:55.541126 25989 registrar.cpp:544] Successfully updated the
registry in 98048ns
I0801 21:37:55.541298 25989 master.cpp:7313] Admitted agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.541551 25989 master.cpp:7358] Registered agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal) with cpus:2; mem:1024; disk:1024;
ports:[31000-32000]
I0801 21:37:55.541628 25989 slave.cpp:1576] Registered with master
master@172.16.10.175:36936; given agent ID
98570ef6-2391-4957-8781-7dc1977897c5-S0
I0801 21:37:55.541628 25994 hierarchical.cpp:617] Added agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 (ip-172-16-10-175.ec2.internal) with
cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I0801 21:37:55.541779 25994 hierarchical.cpp:1508] Performed allocation for 1
agents in 105067ns
I0801 21:37:55.541805 25994 task_status_update_manager.cpp:188] Resuming
sending task status updates
I0801 21:37:55.541846 25989 slave.cpp:1611] Checkpointing SlaveInfo to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/slave.info'
I0801 21:37:55.541900 25994 master.cpp:10393] Sending offers [
98570ef6-2391-4957-8781-7dc1977897c5-O0 ] to framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default)
I0801 21:37:55.542023 25994 status_update_manager_process.hpp:385] Resuming
operation status update manager
I0801 21:37:55.542153 25989 slave.cpp:1663] Forwarding agent update
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"mDDTPFT7QY6fB5hE9hSuIw=="},"slave_id":{"value":"98570ef6-2391-4957-8781-7dc1977897c5-S0"},"update_oversubscribed_resources":false}
I0801 21:37:55.542376 25989 master.cpp:8457] Ignoring update on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal) as it reports no changes
I0801 21:37:55.542764 25991 scheduler.cpp:847] Enqueuing event OFFERS received
from http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.543794 25987 scheduler.cpp:246] Adding authentication headers to
ACCEPT call to http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.543936 25987 scheduler.cpp:600] Sending ACCEPT call to
http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.544349 25987 process.cpp:3671] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0801 21:37:55.544860 25987 http.cpp:1115] HTTP POST for
/master/api/v1/scheduler from 172.16.10.175:39524
I0801 21:37:55.545277 25987 master.cpp:12685] Removing offer
98570ef6-2391-4957-8781-7dc1977897c5-O0
I0801 21:37:55.545550 25987 master.cpp:4739] Processing ACCEPT call for offers:
[ 98570ef6-2391-4957-8781-7dc1977897c5-O0 ] on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal) for framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default)
I0801 21:37:55.545617 25987 master.cpp:3756] Authorizing framework principal
'test-principal' to launch task feb351d3-1bc1-4fde-b10d-f3a9375ffa73
I0801 21:37:55.545809 25987 master.cpp:3756] Authorizing framework principal
'test-principal' to launch task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc
I0801 21:37:55.546689 25987 master.cpp:4274] Adding executor 'default' with
resources cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):32
of framework 98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.546770 25987 master.cpp:4300] Adding task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 with resources cpus(allocated: *):0.1;
mem(allocated: *):32; disk(allocated: *):32 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.546835 25987 master.cpp:5941] Launching task group {
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 } of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) with resources
cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):32 on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal) on new executor
I0801 21:37:55.547273 25990 slave.cpp:2130] Got assigned task group containing
tasks [ feb351d3-1bc1-4fde-b10d-f3a9375ffa73 ] for framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.547363 25990 slave.cpp:9852] Checkpointing FrameworkInfo to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/framework.info'
I0801 21:37:55.547888 25990 slave.cpp:9863] Checkpointing framework pid
'@0.0.0.0:0' to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/framework.pid'
I0801 21:37:55.548380 25987 master.cpp:4300] Adding task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc with resources cpus(allocated: *):0.1;
mem(allocated: *):32; disk(allocated: *):32 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.548454 25987 master.cpp:5941] Launching task group {
8e6a0158-8860-45c6-aa1f-389a95ebb0cc } of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) with resources
cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):32 on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal) on existing executor
I0801 21:37:55.548563 25987 hierarchical.cpp:1432] Allocation paused
I0801 21:37:55.548815 25987 hierarchical.cpp:1218] 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 98570ef6-2391-4957-8781-7dc1977897c5-S0 from framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.548912 25987 hierarchical.cpp:1264] Framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 filtered agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 for 5secs
I0801 21:37:55.549626 25987 hierarchical.cpp:1442] Allocation resumed
I0801 21:37:55.549926 25990 slave.cpp:2130] Got assigned task group containing
tasks [ 8e6a0158-8860-45c6-aa1f-389a95ebb0cc ] for framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.550469 25990 slave.cpp:2504] Authorizing task group containing
tasks [ feb351d3-1bc1-4fde-b10d-f3a9375ffa73 ] for framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.550503 25990 slave.cpp:9400] Authorizing framework principal
'test-principal' to launch task feb351d3-1bc1-4fde-b10d-f3a9375ffa73
I0801 21:37:55.551146 25990 slave.cpp:2504] Authorizing task group containing
tasks [ 8e6a0158-8860-45c6-aa1f-389a95ebb0cc ] for framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.551182 25990 slave.cpp:9400] Authorizing framework principal
'test-principal' to launch task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc
I0801 21:37:55.551954 25990 slave.cpp:2977] Launching task group containing
tasks [ feb351d3-1bc1-4fde-b10d-f3a9375ffa73 ] for framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.552012 25990 paths.cpp:810] Creating sandbox
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b'
for user 'root'
I0801 21:37:55.552757 25990 slave.cpp:10650] Checkpointing ExecutorInfo to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/executor.info'
I0801 21:37:55.554229 25990 paths.cpp:813] Creating sandbox
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b'
I0801 21:37:55.554572 25990 slave.cpp:9938] Launching executor 'default' of
framework 98570ef6-2391-4957-8781-7dc1977897c5-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_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b'
I0801 21:37:55.555160 25990 slave.cpp:10681] Checkpointing TaskInfo to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/tasks/feb351d3-1bc1-4fde-b10d-f3a9375ffa73/task.info'
I0801 21:37:55.555701 25990 slave.cpp:3203] Queued task group containing tasks
[ feb351d3-1bc1-4fde-b10d-f3a9375ffa73 ] for executor 'default' of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.556010 25990 slave.cpp:1084] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b'
to virtual path
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/latest'
I0801 21:37:55.556038 25990 slave.cpp:1084] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b'
to virtual path
'/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/latest'
I0801 21:37:55.556412 25990 slave.cpp:1084] Successfully attached
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b'
to virtual path
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b'
I0801 21:37:55.556664 25990 slave.cpp:2977] Launching task group containing
tasks [ 8e6a0158-8860-45c6-aa1f-389a95ebb0cc ] for framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.556756 25990 slave.cpp:10681] Checkpointing TaskInfo to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/tasks/8e6a0158-8860-45c6-aa1f-389a95ebb0cc/task.info'
I0801 21:37:55.557281 25990 slave.cpp:3203] Queued task group containing tasks
[ 8e6a0158-8860-45c6-aa1f-389a95ebb0cc ] for executor 'default' of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.557426 25990 slave.cpp:3651] Launching container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b for executor 'default' of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.557739 25987 containerizer.cpp:1382] Starting container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b
I0801 21:37:55.558279 25987 containerizer.cpp:1554] Checkpointed
ContainerConfig at
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_pC9f8g/containers/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/config'
I0801 21:37:55.558301 25987 containerizer.cpp:3302] Transitioning the state of
container 742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b from PROVISIONING to PREPARING
I0801 21:37:55.559485 25987 containerizer.cpp:2080] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"arguments":["mesos-default-executor","--launcher_dir=/home/centos/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-centos-6/mesos/build/src"],"shell":false,"value":"/home/centos/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-centos-6/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.175:36936"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"1"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiI3NDJkY2Y2Yi1jYTJkLTRkYzMtOWIwZC0xMDRmYjE4ODJiOGIiLCJlaWQiOiJkZWZhdWx0IiwiZmlkIjoiOTg1NzBlZjYtMjM5MS00OTU3LTg3ODEtN2RjMTk3Nzg5N2M1LTAwMDAifQ.toGtvTFOTdTB9_aER4dVe5f24o3BS8BRNv7ZD8WYcZs"},{"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":"98570ef6-2391-4957-8781-7dc1977897c5-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":"98570ef6-2391-4957-8781-7dc1977897c5-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(92)@172.16.10.175:36936"},{"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","type":"VALUE","value":"2secs"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b"}]},"task_environment":{},"user":"root","working_directory":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b"}"
--pipe_read="14" --pipe_write="17"
--runtime_directory="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_pC9f8g/containers/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b"
--unshare_namespace_mnt="false"'
I0801 21:37:55.559799 25994 linux_launcher.cpp:492] Launching container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b and cloning with namespaces
I0801 21:37:55.569988 25987 containerizer.cpp:2189] Checkpointing container's
forked pid 28455 to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/pids/forked.pid'
I0801 21:37:55.570873 25987 containerizer.cpp:3302] Transitioning the state of
container 742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b from PREPARING to ISOLATING
I0801 21:37:55.572144 25987 containerizer.cpp:3302] Transitioning the state of
container 742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b from ISOLATING to FETCHING
I0801 21:37:55.572192 25994 fetcher.cpp:369] Starting to fetch URIs for
container: 742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b, directory:
/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b
I0801 21:37:55.572919 25987 containerizer.cpp:3302] Transitioning the state of
container 742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b from FETCHING to RUNNING
I0801 21:37:55.683789 28460 executor.cpp:206] Version: 1.9.0
I0801 21:37:55.686751 25988 process.cpp:3671] Handling HTTP event for process
'slave(92)' with path: '/slave(92)/api/v1/executor'
I0801 21:37:55.687532 25990 http.cpp:1115] HTTP POST for
/slave(92)/api/v1/executor from 172.16.10.175:39528
I0801 21:37:55.687651 25990 slave.cpp:4994] Received Subscribe request for HTTP
executor 'default' of framework 98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.687755 25990 slave.cpp:5069] Creating a marker file for HTTP
based executor 'default' of framework 98570ef6-2391-4957-8781-7dc1977897c5-0000
(via HTTP) at path
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/http.marker'
I0801 21:37:55.689358 28458 default_executor.cpp:205] Received SUBSCRIBED event
I0801 21:37:55.689805 28458 default_executor.cpp:209] Subscribed executor on
ip-172-16-10-175.ec2.internal
I0801 21:37:55.690657 25988 slave.cpp:3462] Sending queued task group
containing tasks [ feb351d3-1bc1-4fde-b10d-f3a9375ffa73 ] to executor 'default'
of framework 98570ef6-2391-4957-8781-7dc1977897c5-0000 (via HTTP)
I0801 21:37:55.690798 25988 slave.cpp:3462] Sending queued task group
containing tasks [ 8e6a0158-8860-45c6-aa1f-389a95ebb0cc ] to executor 'default'
of framework 98570ef6-2391-4957-8781-7dc1977897c5-0000 (via HTTP)
I0801 21:37:55.691330 28458 default_executor.cpp:205] Received LAUNCH_GROUP
event
I0801 21:37:55.691540 28458 default_executor.cpp:205] Received LAUNCH_GROUP
event
I0801 21:37:55.691843 28464 default_executor.cpp:433] Setting
'MESOS_CONTAINER_IP' to: 172.16.10.175
I0801 21:37:55.692850 28464 default_executor.cpp:433] Setting
'MESOS_CONTAINER_IP' to: 172.16.10.175
I0801 21:37:55.696983 25989 process.cpp:3671] Handling HTTP event for process
'slave(92)' with path: '/slave(92)/api/v1'
I0801 21:37:55.697165 25989 process.cpp:3671] Handling HTTP event for process
'slave(92)' with path: '/slave(92)/api/v1/executor'
I0801 21:37:55.697237 25989 process.cpp:3671] Handling HTTP event for process
'slave(92)' with path: '/slave(92)/api/v1/executor'
I0801 21:37:55.697324 25989 process.cpp:3671] Handling HTTP event for process
'slave(92)' with path: '/slave(92)/api/v1'
I0801 21:37:55.698529 25987 http.cpp:1115] HTTP POST for /slave(92)/api/v1 from
172.16.10.175:39532
I0801 21:37:55.698822 25987 http.cpp:1115] HTTP POST for
/slave(92)/api/v1/executor from 172.16.10.175:39530
I0801 21:37:55.699077 25987 slave.cpp:5703] Handling status update
TASK_STARTING (Status UUID: feca5d1f-be6b-41be-8a0e-46a0d1830963) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.699430 25987 http.cpp:1115] HTTP POST for /slave(92)/api/v1 from
172.16.10.175:39534
I0801 21:37:55.699514 25987 http.cpp:1115] HTTP POST for
/slave(92)/api/v1/executor from 172.16.10.175:39530
I0801 21:37:55.699687 25987 slave.cpp:5703] Handling status update
TASK_STARTING (Status UUID: e2e887c5-6b22-4e4d-9cd1-fb4b918398f7) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.699923 25987 http.cpp:2574] Processing LAUNCH_NESTED_CONTAINER
call for container
'742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d'
I0801 21:37:55.700187 25994 task_status_update_manager.cpp:328] Received task
status update TASK_STARTING (Status UUID: feca5d1f-be6b-41be-8a0e-46a0d1830963)
for task feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.700209 25994 task_status_update_manager.cpp:507] Creating
StatusUpdate stream for task feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.700675 25994 task_status_update_manager.cpp:842] Checkpointing
UPDATE for task status update TASK_STARTING (Status UUID:
feca5d1f-be6b-41be-8a0e-46a0d1830963) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.700752 25994 task_status_update_manager.cpp:383] Forwarding task
status update TASK_STARTING (Status UUID: feca5d1f-be6b-41be-8a0e-46a0d1830963)
for task feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 to the agent
I0801 21:37:55.700208 25987 http.cpp:2574] Processing LAUNCH_NESTED_CONTAINER
call for container
'742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883'
I0801 21:37:55.701331 25994 task_status_update_manager.cpp:328] Received task
status update TASK_STARTING (Status UUID: e2e887c5-6b22-4e4d-9cd1-fb4b918398f7)
for task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.701356 25994 task_status_update_manager.cpp:507] Creating
StatusUpdate stream for task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.701400 25989 containerizer.cpp:1344] Creating sandbox
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/fce506dd-afb9-4013-9731-f0094b96657d'
for user 'root'
I0801 21:37:55.701557 25994 task_status_update_manager.cpp:842] Checkpointing
UPDATE for task status update TASK_STARTING (Status UUID:
e2e887c5-6b22-4e4d-9cd1-fb4b918398f7) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.701669 25994 task_status_update_manager.cpp:383] Forwarding task
status update TASK_STARTING (Status UUID: e2e887c5-6b22-4e4d-9cd1-fb4b918398f7)
for task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 to the agent
I0801 21:37:55.701804 25987 slave.cpp:6229] Forwarding the update TASK_STARTING
(Status UUID: feca5d1f-be6b-41be-8a0e-46a0d1830963) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 to master@172.16.10.175:36936
I0801 21:37:55.701879 25987 slave.cpp:6122] Task status update manager
successfully handled status update TASK_STARTING (Status UUID:
feca5d1f-be6b-41be-8a0e-46a0d1830963) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.701676 25989 containerizer.cpp:1382] Starting container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d
I0801 21:37:55.701982 25992 master.cpp:8946] Status update TASK_STARTING
(Status UUID: feca5d1f-be6b-41be-8a0e-46a0d1830963) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 from agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.702005 25992 master.cpp:9003] Forwarding status update
TASK_STARTING (Status UUID: feca5d1f-be6b-41be-8a0e-46a0d1830963) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.702109 25992 master.cpp:12034] Updating the state of task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (latest state: TASK_STARTING, status
update state: TASK_STARTING)
I0801 21:37:55.702421 28459 default_executor.cpp:205] Received ACKNOWLEDGED
event
I0801 21:37:55.702739 25994 scheduler.cpp:847] Enqueuing event UPDATE received
from http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.702960 25994 scheduler.cpp:246] Adding authentication headers to
ACKNOWLEDGE call to http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.703380 25987 slave.cpp:6229] Forwarding the update TASK_STARTING
(Status UUID: e2e887c5-6b22-4e4d-9cd1-fb4b918398f7) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 to master@172.16.10.175:36936
I0801 21:37:55.703444 25987 slave.cpp:6122] Task status update manager
successfully handled status update TASK_STARTING (Status UUID:
e2e887c5-6b22-4e4d-9cd1-fb4b918398f7) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.703491 25988 master.cpp:8946] Status update TASK_STARTING
(Status UUID: e2e887c5-6b22-4e4d-9cd1-fb4b918398f7) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 from agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.703514 25988 master.cpp:9003] Forwarding status update
TASK_STARTING (Status UUID: e2e887c5-6b22-4e4d-9cd1-fb4b918398f7) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.703748 25988 master.cpp:12034] Updating the state of task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (latest state: TASK_STARTING, status
update state: TASK_STARTING)
I0801 21:37:55.703791 28464 default_executor.cpp:205] Received ACKNOWLEDGED
event
I0801 21:37:55.703049 25994 scheduler.cpp:600] Sending ACKNOWLEDGE call to
http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.704535 25993 process.cpp:3671] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0801 21:37:55.704571 25994 scheduler.cpp:847] Enqueuing event UPDATE received
from http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.704881 25989 containerizer.cpp:1554] Checkpointed
ContainerConfig at
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_pC9f8g/containers/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/fce506dd-afb9-4013-9731-f0094b96657d/config'
I0801 21:37:55.704900 25989 containerizer.cpp:3302] Transitioning the state of
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d from
PROVISIONING to PREPARING
I0801 21:37:55.704962 25992 scheduler.cpp:246] Adding authentication headers to
ACKNOWLEDGE call to http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.705060 25989 containerizer.cpp:1344] Creating sandbox
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/a610a63f-303a-4640-854a-b04fdfdb8883'
for user 'root'
I0801 21:37:55.705225 25992 scheduler.cpp:600] Sending ACKNOWLEDGE call to
http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.705268 25989 containerizer.cpp:1382] Starting container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883
I0801 21:37:55.705816 25989 containerizer.cpp:1554] Checkpointed
ContainerConfig at
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_pC9f8g/containers/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/a610a63f-303a-4640-854a-b04fdfdb8883/config'
I0801 21:37:55.705839 25989 containerizer.cpp:3302] Transitioning the state of
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883 from
PROVISIONING to PREPARING
I0801 21:37:55.706636 25987 containerizer.cpp:2080] 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_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/fce506dd-afb9-4013-9731-f0094b96657d"},{"name":"MESOS_CONTAINER_IP","type":"VALUE","value":"172.16.10.175"},{"name":"MESOS_ALLOCATION_ROLE","type":"VALUE","value":"*"}]},"task_environment":{},"user":"root","working_directory":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/fce506dd-afb9-4013-9731-f0094b96657d"}"
--pipe_read="22" --pipe_write="23"
--runtime_directory="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_pC9f8g/containers/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/fce506dd-afb9-4013-9731-f0094b96657d"
--unshare_namespace_mnt="false"'
I0801 21:37:55.707046 25993 linux_launcher.cpp:492] Launching nested container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d and
cloning with namespaces
I0801 21:37:55.717864 25987 containerizer.cpp:3302] Transitioning the state of
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d from
PREPARING to ISOLATING
I0801 21:37:55.718379 25987 containerizer.cpp:2080] 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_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/a610a63f-303a-4640-854a-b04fdfdb8883"},{"name":"MESOS_CONTAINER_IP","type":"VALUE","value":"172.16.10.175"},{"name":"MESOS_ALLOCATION_ROLE","type":"VALUE","value":"*"}]},"task_environment":{},"user":"root","working_directory":"/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/a610a63f-303a-4640-854a-b04fdfdb8883"}"
--pipe_read="24" --pipe_write="25"
--runtime_directory="/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_pC9f8g/containers/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/a610a63f-303a-4640-854a-b04fdfdb8883"
--unshare_namespace_mnt="false"'
I0801 21:37:55.718852 25990 linux_launcher.cpp:492] Launching nested container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883 and
cloning with namespaces
I0801 21:37:55.728068 25987 containerizer.cpp:3302] Transitioning the state of
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883 from
PREPARING to ISOLATING
I0801 21:37:55.728339 25987 containerizer.cpp:3302] Transitioning the state of
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d from
ISOLATING to FETCHING
I0801 21:37:55.728528 25987 fetcher.cpp:369] Starting to fetch URIs for
container:
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d,
directory:
/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/fce506dd-afb9-4013-9731-f0094b96657d
I0801 21:37:55.728716 25988 containerizer.cpp:3302] Transitioning the state of
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883 from
ISOLATING to FETCHING
I0801 21:37:55.729420 25987 fetcher.cpp:369] Starting to fetch URIs for
container:
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883,
directory:
/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/a610a63f-303a-4640-854a-b04fdfdb8883
I0801 21:37:55.729719 25987 containerizer.cpp:3302] Transitioning the state of
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d from
FETCHING to RUNNING
I0801 21:37:55.729809 25987 containerizer.cpp:3302] Transitioning the state of
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883 from
FETCHING to RUNNING
I0801 21:37:55.731778 28461 default_executor.cpp:679] Finished launching tasks
[ feb351d3-1bc1-4fde-b10d-f3a9375ffa73 ] in child containers [
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d ]
I0801 21:37:55.731797 28461 default_executor.cpp:703] Waiting on child
containers of tasks [ feb351d3-1bc1-4fde-b10d-f3a9375ffa73 ]
I0801 21:37:55.737150 25994 process.cpp:3671] Handling HTTP event for process
'slave(92)' with path: '/slave(92)/api/v1/executor'
I0801 21:37:55.739617 28457 default_executor.cpp:764] Waiting for child
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d of
task 'feb351d3-1bc1-4fde-b10d-f3a9375ffa73'
I0801 21:37:55.743896 25989 process.cpp:3671] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0801 21:37:55.744273 25989 http.cpp:1115] HTTP POST for
/master/api/v1/scheduler from 172.16.10.175:39524
I0801 21:37:55.744351 25989 master.cpp:6693] Processing ACKNOWLEDGE call for
status feca5d1f-be6b-41be-8a0e-46a0d1830963 for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0
I0801 21:37:55.744441 25989 http.cpp:1115] HTTP POST for
/master/api/v1/scheduler from 172.16.10.175:39524
I0801 21:37:55.744472 25989 master.cpp:6693] Processing ACKNOWLEDGE call for
status e2e887c5-6b22-4e4d-9cd1-fb4b918398f7 for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0
I0801 21:37:55.744761 25989 task_status_update_manager.cpp:401] Received task
status update acknowledgement (UUID: feca5d1f-be6b-41be-8a0e-46a0d1830963) for
task feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.744791 25989 task_status_update_manager.cpp:842] Checkpointing
ACK for task status update TASK_STARTING (Status UUID:
feca5d1f-be6b-41be-8a0e-46a0d1830963) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.744879 25989 task_status_update_manager.cpp:401] Received task
status update acknowledgement (UUID: e2e887c5-6b22-4e4d-9cd1-fb4b918398f7) for
task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.744894 25989 task_status_update_manager.cpp:842] Checkpointing
ACK for task status update TASK_STARTING (Status UUID:
e2e887c5-6b22-4e4d-9cd1-fb4b918398f7) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.744944 25989 slave.cpp:4832] Task status update manager
successfully handled status update acknowledgement (UUID:
feca5d1f-be6b-41be-8a0e-46a0d1830963) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.744967 25989 slave.cpp:4832] Task status update manager
successfully handled status update acknowledgement (UUID:
e2e887c5-6b22-4e4d-9cd1-fb4b918398f7) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.748919 25991 process.cpp:3671] Handling HTTP event for process
'slave(92)' with path: '/slave(92)/api/v1'
I0801 21:37:55.749392 25991 http.cpp:1115] HTTP POST for /slave(92)/api/v1 from
172.16.10.175:39536
I0801 21:37:55.749930 25991 http.cpp:2797] Processing WAIT_NESTED_CONTAINER
call for container
'742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d'
I0801 21:37:55.751909 28459 default_executor.cpp:679] Finished launching tasks
[ 8e6a0158-8860-45c6-aa1f-389a95ebb0cc ] in child containers [
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883 ]
I0801 21:37:55.752337 28459 default_executor.cpp:703] Waiting on child
containers of tasks [ 8e6a0158-8860-45c6-aa1f-389a95ebb0cc ]
I0801 21:37:55.760607 28460 default_executor.cpp:764] Waiting for child
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883 of
task '8e6a0158-8860-45c6-aa1f-389a95ebb0cc'
I0801 21:37:55.762915 25992 process.cpp:3671] Handling HTTP event for process
'slave(92)' with path: '/slave(92)/api/v1'
I0801 21:37:55.763423 25992 http.cpp:1115] HTTP POST for /slave(92)/api/v1 from
172.16.10.175:39538
I0801 21:37:55.764036 25992 http.cpp:2797] Processing WAIT_NESTED_CONTAINER
call for container
'742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883'
I0801 21:37:55.771829 25992 process.cpp:3671] Handling HTTP event for process
'slave(92)' with path: '/slave(92)/api/v1/executor'
I0801 21:37:55.772873 25992 http.cpp:1115] HTTP POST for
/slave(92)/api/v1/executor from 172.16.10.175:39530
I0801 21:37:55.772972 25992 slave.cpp:5703] Handling status update TASK_RUNNING
(Status UUID: c4e85dcd-9fe9-4eb6-856d-f741882e879a) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.773119 25992 http.cpp:1115] HTTP POST for
/slave(92)/api/v1/executor from 172.16.10.175:39530
I0801 21:37:55.773172 25992 slave.cpp:5703] Handling status update TASK_RUNNING
(Status UUID: d9157b98-30ad-4178-ba6f-884eb0d1930c) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.774336 25993 task_status_update_manager.cpp:328] Received task
status update TASK_RUNNING (Status UUID: c4e85dcd-9fe9-4eb6-856d-f741882e879a)
for task feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.774366 25993 task_status_update_manager.cpp:842] Checkpointing
UPDATE for task status update TASK_RUNNING (Status UUID:
c4e85dcd-9fe9-4eb6-856d-f741882e879a) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.774452 25993 task_status_update_manager.cpp:383] Forwarding task
status update TASK_RUNNING (Status UUID: c4e85dcd-9fe9-4eb6-856d-f741882e879a)
for task feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 to the agent
I0801 21:37:55.774544 25993 slave.cpp:6229] Forwarding the update TASK_RUNNING
(Status UUID: c4e85dcd-9fe9-4eb6-856d-f741882e879a) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 to master@172.16.10.175:36936
I0801 21:37:55.774931 25993 slave.cpp:6122] Task status update manager
successfully handled status update TASK_RUNNING (Status UUID:
c4e85dcd-9fe9-4eb6-856d-f741882e879a) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.775048 25993 master.cpp:8946] Status update TASK_RUNNING (Status
UUID: c4e85dcd-9fe9-4eb6-856d-f741882e879a) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 from agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.775070 25993 master.cpp:9003] Forwarding status update
TASK_RUNNING (Status UUID: c4e85dcd-9fe9-4eb6-856d-f741882e879a) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.775211 25993 master.cpp:12034] Updating the state of task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
I0801 21:37:55.775813 28463 default_executor.cpp:205] Received ACKNOWLEDGED
event
I0801 21:37:55.777043 25993 scheduler.cpp:847] Enqueuing event UPDATE received
from http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.777279 25993 scheduler.cpp:246] Adding authentication headers to
ACKNOWLEDGE call to http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.777374 25993 scheduler.cpp:600] Sending ACKNOWLEDGE call to
http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.778156 25988 process.cpp:3671] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0801 21:37:55.779270 25994 task_status_update_manager.cpp:328] Received task
status update TASK_RUNNING (Status UUID: d9157b98-30ad-4178-ba6f-884eb0d1930c)
for task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.779299 25994 task_status_update_manager.cpp:842] Checkpointing
UPDATE for task status update TASK_RUNNING (Status UUID:
d9157b98-30ad-4178-ba6f-884eb0d1930c) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.779367 25994 task_status_update_manager.cpp:383] Forwarding task
status update TASK_RUNNING (Status UUID: d9157b98-30ad-4178-ba6f-884eb0d1930c)
for task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 to the agent
I0801 21:37:55.780814 25992 slave.cpp:6229] Forwarding the update TASK_RUNNING
(Status UUID: d9157b98-30ad-4178-ba6f-884eb0d1930c) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 to master@172.16.10.175:36936
I0801 21:37:55.780913 25988 master.cpp:8946] Status update TASK_RUNNING (Status
UUID: d9157b98-30ad-4178-ba6f-884eb0d1930c) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 from agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.780933 25988 master.cpp:9003] Forwarding status update
TASK_RUNNING (Status UUID: d9157b98-30ad-4178-ba6f-884eb0d1930c) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.781031 25988 master.cpp:12034] Updating the state of task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
I0801 21:37:55.781883 25991 scheduler.cpp:847] Enqueuing event UPDATE received
from http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.782073 25991 scheduler.cpp:246] Adding authentication headers to
ACKNOWLEDGE call to http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.782145 25991 scheduler.cpp:600] Sending ACKNOWLEDGE call to
http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.783354 25992 slave.cpp:6122] Task status update manager
successfully handled status update TASK_RUNNING (Status UUID:
d9157b98-30ad-4178-ba6f-884eb0d1930c) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.783654 28463 default_executor.cpp:205] Received ACKNOWLEDGED
event
I0801 21:37:55.817020 25994 process.cpp:3671] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0801 21:37:55.817453 25994 http.cpp:1115] HTTP POST for
/master/api/v1/scheduler from 172.16.10.175:39524
I0801 21:37:55.817521 25994 master.cpp:6693] Processing ACKNOWLEDGE call for
status c4e85dcd-9fe9-4eb6-856d-f741882e879a for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0
I0801 21:37:55.817631 25994 http.cpp:1115] HTTP POST for
/master/api/v1/scheduler from 172.16.10.175:39524
I0801 21:37:55.817668 25994 master.cpp:6693] Processing ACKNOWLEDGE call for
status d9157b98-30ad-4178-ba6f-884eb0d1930c for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0
I0801 21:37:55.817957 25994 task_status_update_manager.cpp:401] Received task
status update acknowledgement (UUID: c4e85dcd-9fe9-4eb6-856d-f741882e879a) for
task feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.817993 25994 task_status_update_manager.cpp:842] Checkpointing
ACK for task status update TASK_RUNNING (Status UUID:
c4e85dcd-9fe9-4eb6-856d-f741882e879a) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.818084 25994 task_status_update_manager.cpp:401] Received task
status update acknowledgement (UUID: d9157b98-30ad-4178-ba6f-884eb0d1930c) for
task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.818106 25994 task_status_update_manager.cpp:842] Checkpointing
ACK for task status update TASK_RUNNING (Status UUID:
d9157b98-30ad-4178-ba6f-884eb0d1930c) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.818157 25994 slave.cpp:4832] Task status update manager
successfully handled status update acknowledgement (UUID:
c4e85dcd-9fe9-4eb6-856d-f741882e879a) for task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.818183 25994 slave.cpp:4832] Task status update manager
successfully handled status update acknowledgement (UUID:
d9157b98-30ad-4178-ba6f-884eb0d1930c) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.882627 25989 containerizer.cpp:3141] Container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883 has
exited
I0801 21:37:55.882659 25989 containerizer.cpp:2600] Destroying container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883 in
RUNNING state
I0801 21:37:55.882669 25989 containerizer.cpp:3302] Transitioning the state of
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883 from
RUNNING to DESTROYING
I0801 21:37:55.882900 25989 linux_launcher.cpp:576] Asked to destroy container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883
I0801 21:37:55.882946 25989 linux_launcher.cpp:618] Destroying cgroup
'/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos/a610a63f-303a-4640-854a-b04fdfdb8883'
I0801 21:37:55.883277 25994 cgroups.cpp:2854] Freezing cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos/a610a63f-303a-4640-854a-b04fdfdb8883
I0801 21:37:55.883522 25991 cgroups.cpp:1242] Successfully froze cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos/a610a63f-303a-4640-854a-b04fdfdb8883
after 215808ns
I0801 21:37:55.883823 25994 cgroups.cpp:2872] Thawing cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos/a610a63f-303a-4640-854a-b04fdfdb8883
I0801 21:37:55.884065 25994 cgroups.cpp:1271] Successfully thawed cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos/a610a63f-303a-4640-854a-b04fdfdb8883
after 207872ns
I0801 21:37:55.884776 25993 provisioner.cpp:611] Ignoring destroy request for
unknown container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883
I0801 21:37:55.884990 25993 containerizer.cpp:2927] Checkpointing termination
state to nested container's runtime directory
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_pC9f8g/containers/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/a610a63f-303a-4640-854a-b04fdfdb8883/termination'
I0801 21:37:55.885506 25988 gc.cpp:95] Scheduling
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/a610a63f-303a-4640-854a-b04fdfdb8883'
for gc 6.99998975193185days in the future
I0801 21:37:55.886494 25993 process.cpp:3671] Handling HTTP event for process
'slave(92)' with path: '/slave(92)/api/v1/executor'
I0801 21:37:55.889855 28461 default_executor.cpp:971] Child container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.a610a63f-303a-4640-854a-b04fdfdb8883 of
task '8e6a0158-8860-45c6-aa1f-389a95ebb0cc' completed in state TASK_FINISHED:
Command exited with status 0
I0801 21:37:55.926250 25994 http.cpp:1115] HTTP POST for
/slave(92)/api/v1/executor from 172.16.10.175:39530
I0801 21:37:55.926360 25994 slave.cpp:5703] Handling status update
TASK_FINISHED (Status UUID: 5d1ce366-9ddf-433e-beb3-a5a385bdf173) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.927376 25988 task_status_update_manager.cpp:328] Received task
status update TASK_FINISHED (Status UUID: 5d1ce366-9ddf-433e-beb3-a5a385bdf173)
for task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.927405 25988 task_status_update_manager.cpp:842] Checkpointing
UPDATE for task status update TASK_FINISHED (Status UUID:
5d1ce366-9ddf-433e-beb3-a5a385bdf173) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.927490 25988 task_status_update_manager.cpp:383] Forwarding task
status update TASK_FINISHED (Status UUID: 5d1ce366-9ddf-433e-beb3-a5a385bdf173)
for task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 to the agent
I0801 21:37:55.927556 25988 slave.cpp:6229] Forwarding the update TASK_FINISHED
(Status UUID: 5d1ce366-9ddf-433e-beb3-a5a385bdf173) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 to master@172.16.10.175:36936
I0801 21:37:55.927639 25988 slave.cpp:6122] Task status update manager
successfully handled status update TASK_FINISHED (Status UUID:
5d1ce366-9ddf-433e-beb3-a5a385bdf173) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.927772 25990 master.cpp:8946] Status update TASK_FINISHED
(Status UUID: 5d1ce366-9ddf-433e-beb3-a5a385bdf173) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 from agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.927798 25990 master.cpp:9003] Forwarding status update
TASK_FINISHED (Status UUID: 5d1ce366-9ddf-433e-beb3-a5a385bdf173) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.927909 25990 master.cpp:12034] Updating the state of task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (latest state: TASK_FINISHED, status
update state: TASK_FINISHED)
I0801 21:37:55.928131 28462 default_executor.cpp:205] Received ACKNOWLEDGED
event
I0801 21:37:55.928277 25988 hierarchical.cpp:1218] 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
98570ef6-2391-4957-8781-7dc1977897c5-S0 from framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.928402 25988 scheduler.cpp:847] Enqueuing event UPDATE received
from http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.928728 25988 scheduler.cpp:246] Adding authentication headers to
ACKNOWLEDGE call to http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.928823 25988 scheduler.cpp:600] Sending ACKNOWLEDGE call to
http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.929107 25987 process.cpp:3671] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0801 21:37:55.969033 25994 http.cpp:1115] HTTP POST for
/master/api/v1/scheduler from 172.16.10.175:39524
I0801 21:37:55.969105 25994 master.cpp:6693] Processing ACKNOWLEDGE call for
status 5d1ce366-9ddf-433e-beb3-a5a385bdf173 for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0
I0801 21:37:55.969142 25994 master.cpp:12132] Removing task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc with resources cpus(allocated: *):0.1;
mem(allocated: *):32; disk(allocated: *):32 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.969627 25987 task_status_update_manager.cpp:401] Received task
status update acknowledgement (UUID: 5d1ce366-9ddf-433e-beb3-a5a385bdf173) for
task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.969660 25987 task_status_update_manager.cpp:842] Checkpointing
ACK for task status update TASK_FINISHED (Status UUID:
5d1ce366-9ddf-433e-beb3-a5a385bdf173) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.969717 25987 task_status_update_manager.cpp:538] Cleaning up
status update stream for task 8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.969907 25993 slave.cpp:4832] Task status update manager
successfully handled status update acknowledgement (UUID:
5d1ce366-9ddf-433e-beb3-a5a385bdf173) for task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.969926 25993 slave.cpp:10607] Completing task
8e6a0158-8860-45c6-aa1f-389a95ebb0cc
I0801 21:37:55.970984 25990 hierarchical.cpp:1508] Performed allocation for 1
agents in 127233ns
I0801 21:37:55.971112 25990 master.cpp:1892] Skipping periodic registry garbage
collection: no agents qualify for removal
I0801 21:37:55.971221 25990 master.cpp:10393] Sending offers [
98570ef6-2391-4957-8781-7dc1977897c5-O1 ] to framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default)
I0801 21:37:55.971416 25990 slave.cpp:6399] No pings from master received
within 75secs
I0801 21:37:55.971472 25990 slave.cpp:7359] Current disk usage 35.73%. Max
allowed age: 3.798752844032697days
I0801 21:37:55.971853 25987 slave.cpp:1340] Re-detecting master
I0801 21:37:55.971868 25987 slave.cpp:1416] Detecting new master
I0801 21:37:55.971889 25987 task_status_update_manager.cpp:181] Pausing sending
task status updates
I0801 21:37:55.971904 25987 status_update_manager_process.hpp:379] Pausing
operation status update manager
I0801 21:37:55.971995 28463 default_executor.cpp:205] Received HEARTBEAT event
I0801 21:37:55.972034 25987 slave.cpp:1351] New master detected at
master@172.16.10.175:36936
I0801 21:37:55.972052 25987 slave.cpp:1416] Detecting new master
I0801 21:37:55.972077 25987 task_status_update_manager.cpp:181] Pausing sending
task status updates
I0801 21:37:55.972090 25987 status_update_manager_process.hpp:379] Pausing
operation status update manager
I0801 21:37:55.972450 25987 scheduler.cpp:847] Enqueuing event OFFERS received
from http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.972643 25987 scheduler.cpp:847] Enqueuing event HEARTBEAT
received from http://172.16.10.175:36936/master/api/v1/scheduler
I0801 21:37:55.970028 25993 gc.cpp:95] Scheduling
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/tasks/8e6a0158-8860-45c6-aa1f-389a95ebb0cc'
for gc 6.99998877325333days in the future
I0801 21:37:55.975688 25993 gc.cpp:331] Pruning directories with remaining
removal time 0ns
I0801 21:37:55.975705 25993 gc.cpp:188] Skipping deletion of
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/a610a63f-303a-4640-854a-b04fdfdb8883'
as it is already in progress
I0801 21:37:55.976153 25993 gc.cpp:272] Deleting
/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/a610a63f-303a-4640-854a-b04fdfdb8883
I0801 21:37:55.976296 25993 gc.cpp:288] Deleted
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/a610a63f-303a-4640-854a-b04fdfdb8883'
../../src/tests/gc_tests.cpp:858: Failure
Value of: os::exists(shortLivedTaskPath)
Actual: true
IExpected: false
0801 21:37:55.976774 25990 slave.cpp:1443] Authenticating with master
master@172.16.10.175:36936
I0801 21:37:55.976795 25990 slave.cpp:1452] Using default CRAM-MD5 authenticatee
I0801 21:37:55.976881 25991 authenticatee.cpp:121] Creating new client SASL
connection
I0801 21:37:55.976958 25991 master.cpp:10578] Authenticating
slave(92)@172.16.10.175:36936; clearing previous authentication
I0801 21:37:55.977005 25991 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(212)@172.16.10.175:36936
I0801 21:37:55.977283 25991 authenticator.cpp:98] Creating new server SASL
connection
I0801 21:37:55.977471 25991 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0801 21:37:55.977545 25991 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0801 21:37:55.977615 25991 authenticator.cpp:204] Received SASL authentication
start
I0801 21:37:55.977728 25991 authenticator.cpp:326] Authentication requires more
steps
I0801 21:37:55.977959 25991 authenticatee.cpp:259] Received SASL authentication
step
I0801 21:37:55.978006 25991 authenticator.cpp:232] Received SASL authentication
step
I0801 21:37:55.978090 25991 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-175' server FQDN:
'ip-172-16-10-175' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0801 21:37:55.978161 25991 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0801 21:37:55.978174 25991 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0801 21:37:55.978184 25991 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-175' server FQDN:
'ip-172-16-10-175' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0801 21:37:55.978190 25991 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0801 21:37:55.978196 25991 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0801 21:37:55.978209 25991 authenticator.cpp:318] Authentication success
I0801 21:37:55.978333 25994 authenticatee.cpp:299] Authentication success
I0801 21:37:55.978376 25991 master.cpp:10610] Successfully authenticated
principal 'test-principal' at slave(92)@172.16.10.175:36936
I0801 21:37:55.978381 25987 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(212)@172.16.10.175:36936
I0801 21:37:55.978432 25994 slave.cpp:1543] Successfully authenticated with
master master@172.16.10.175:36936
I0801 21:37:55.978672 25994 slave.cpp:1993] Will retry registration in
7.418259ms if necessary
I0801 21:37:55.978822 25994 master.cpp:7437] Received reregister agent message
from agent 98570ef6-2391-4957-8781-7dc1977897c5-S0 at
slave(92)@172.16.10.175:36936 (ip-172-16-10-175.ec2.internal)
I0801 21:37:55.978911 25994 master.cpp:4202] Authorizing agent providing
resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal
'test-principal'
I0801 21:37:55.979671 25994 master.cpp:1410] Framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) disconnected
I0801 21:37:55.979689 25994 master.cpp:3360] Deactivating framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default)
I0801 21:37:55.979755 25988 hierarchical.cpp:475] Deactivated framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
W0801 21:37:55.979791 25994 master.hpp:2708] Unable to send message to
framework 98570ef6-2391-4957-8781-7dc1977897c5-0000 (default): connection closed
I0801 21:37:55.979805 25994 master.cpp:12685] Removing offer
98570ef6-2391-4957-8781-7dc1977897c5-O1
I0801 21:37:55.979820 25994 master.cpp:3337] Disconnecting framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default)
I0801 21:37:55.979830 25994 master.cpp:1425] Giving framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default) 0ns to failover
I0801 21:37:55.979851 25988 hierarchical.cpp:1218] 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: cpus(allocated: *):0.2; mem(allocated: *):64; disk(allocated: *):64)
on agent 98570ef6-2391-4957-8781-7dc1977897c5-S0 from framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.979871 25994 master.cpp:7529] Authorized re-registration of
agent 98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.979900 25994 master.cpp:7613] Agent is already marked as
registered: 98570ef6-2391-4957-8781-7dc1977897c5-S0 at
slave(92)@172.16.10.175:36936 (ip-172-16-10-175.ec2.internal)
I0801 21:37:55.979939 25994 master.cpp:8000] Registry updated for slave
98570ef6-2391-4957-8781-7dc1977897c5-S0 at
slave(92)@172.16.10.175:36936(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.980049 25993 hierarchical.cpp:710] Agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 (ip-172-16-10-175.ec2.internal) updated
with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0801 21:37:55.980093 25993 slave.cpp:1700] Re-registered with master
master@172.16.10.175:36936
I0801 21:37:55.980151 25994 master.cpp:10185] Framework failover timeout,
removing framework 98570ef6-2391-4957-8781-7dc1977897c5-0000 (default)
I0801 21:37:55.980163 25994 master.cpp:11184] Removing framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (default)
I0801 21:37:55.980159 25993 slave.cpp:1746] Forwarding agent update
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"mDDTPFT7QY6fB5hE9hSuIw=="},"slave_id":{"value":"98570ef6-2391-4957-8781-7dc1977897c5-S0"},"update_oversubscribed_resources":false}
I0801 21:37:55.980196 25994 master.cpp:12034] Updating the state of task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 (latest state: TASK_KILLED, status
update state: TASK_KILLED)
I0801 21:37:55.980222 25993 slave.cpp:4227] Updating info for framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.980257 25993 slave.cpp:9852] Checkpointing FrameworkInfo to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/framework.info'
I0801 21:37:55.980270 25994 master.cpp:12132] Removing task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 with resources cpus(allocated: *):0.1;
mem(allocated: *):32; disk(allocated: *):32 of framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.980352 25994 master.cpp:12172] Removing executor 'default' with
resources cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):32
of framework 98570ef6-2391-4957-8781-7dc1977897c5-0000 on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.980531 25994 master.cpp:8457] Ignoring update on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal) as it reports no changes
I0801 21:37:55.980554 25993 slave.cpp:9863] Checkpointing framework pid
'@0.0.0.0:0' to
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/meta/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/framework.pid'
I0801 21:37:55.980562 25994 task_status_update_manager.cpp:188] Resuming
sending task status updates
I0801 21:37:55.980599 25994 status_update_manager_process.hpp:385] Resuming
operation status update manager
I0801 21:37:55.980670 25994 hierarchical.cpp:1218] 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.1;
mem(allocated: *):32; disk(allocated: *):32) on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 from framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.980751 25994 hierarchical.cpp:1218] Recovered cpus(allocated:
*):0.1; mem(allocated: *):32; disk(allocated: *):32 (total: cpus:2; mem:1024;
disk:1024; ports:[31000-32000], allocated: {}) on agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 from framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.980784 25994 hierarchical.cpp:1432] Allocation paused
I0801 21:37:55.980785 25993 slave.cpp:4056] Asked to shut down framework
98570ef6-2391-4957-8781-7dc1977897c5-0000 by master@172.16.10.175:36936
I0801 21:37:55.980798 25993 slave.cpp:4081] Shutting down framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.980809 25993 slave.cpp:7175] Shutting down executor 'default' of
framework 98570ef6-2391-4957-8781-7dc1977897c5-0000 (via HTTP)
I0801 21:37:55.980832 25994 hierarchical.cpp:417] Removed framework
98570ef6-2391-4957-8781-7dc1977897c5-0000
I0801 21:37:55.980854 25994 hierarchical.cpp:1442] Allocation resumed
I0801 21:37:55.980870 25989 task_status_update_manager.cpp:188] Resuming
sending task status updates
I0801 21:37:55.981104 28457 default_executor.cpp:205] Received SHUTDOWN event
I0801 21:37:55.981120 28457 default_executor.cpp:1037] Shutting down
I0801 21:37:55.981128 28457 default_executor.cpp:1142] Killing task
feb351d3-1bc1-4fde-b10d-f3a9375ffa73 running in child container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d with
SIGTERM signal
I0801 21:37:55.981134 28457 default_executor.cpp:1153] Scheduling escalation to
SIGKILL in 3secs from now
I0801 21:37:55.982034 25992 process.cpp:3671] Handling HTTP event for process
'slave(92)' with path: '/slave(92)/api/v1'
I0801 21:37:55.982720 25989 http.cpp:1115] HTTP POST for /slave(92)/api/v1 from
172.16.10.175:39540
I0801 21:37:55.982825 25989 http.cpp:2962] Processing KILL_NESTED_CONTAINER
call for container
'742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d'
I0801 21:37:55.984169 25989 containerizer.cpp:3011] Sending Terminated to
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d in
RUNNING state
I0801 21:37:55.985385 25990 slave.cpp:924] Agent terminating
I0801 21:37:55.987066 25990 master.cpp:1295] Agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal) disconnected
I0801 21:37:55.987087 25990 master.cpp:3397] Disconnecting agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.987102 25990 master.cpp:3416] Deactivating agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 at slave(92)@172.16.10.175:36936
(ip-172-16-10-175.ec2.internal)
I0801 21:37:55.987179 25988 hierarchical.cpp:799] Agent
98570ef6-2391-4957-8781-7dc1977897c5-S0 deactivated
I0801 21:37:55.987635 25988 containerizer.cpp:2600] Destroying container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b in RUNNING state
I0801 21:37:55.987656 25988 containerizer.cpp:3302] Transitioning the state of
container 742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b from RUNNING to DESTROYING
I0801 21:37:55.987664 25988 containerizer.cpp:2600] Destroying container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d in
RUNNING state
I0801 21:37:55.987671 25988 containerizer.cpp:3302] Transitioning the state of
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d from
RUNNING to DESTROYING
I0801 21:37:55.987776 25988 linux_launcher.cpp:576] Asked to destroy container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d
I0801 21:37:55.987956 25988 linux_launcher.cpp:618] Destroying cgroup
'/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos/fce506dd-afb9-4013-9731-f0094b96657d'
I0801 21:37:55.988382 25987 cgroups.cpp:2854] Freezing cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos/fce506dd-afb9-4013-9731-f0094b96657d
I0801 21:37:55.988528 25987 cgroups.cpp:1242] Successfully froze cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos/fce506dd-afb9-4013-9731-f0094b96657d
after 110080ns
I0801 21:37:55.989051 25987 cgroups.cpp:2872] Thawing cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos/fce506dd-afb9-4013-9731-f0094b96657d
I0801 21:37:55.989217 25987 cgroups.cpp:1271] Successfully thawed cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos/fce506dd-afb9-4013-9731-f0094b96657d
after 135936ns
I0801 21:37:56.071333 25991 containerizer.cpp:3141] Container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d has
exited
I0801 21:37:56.071728 25988 provisioner.cpp:611] Ignoring destroy request for
unknown container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d
I0801 21:37:56.071811 25991 containerizer.cpp:2927] Checkpointing termination
state to nested container's runtime directory
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_pC9f8g/containers/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/fce506dd-afb9-4013-9731-f0094b96657d/termination'
I0801 21:37:56.072211 25987 gc.cpp:95] Scheduling
'/tmp/GarbageCollectorIntegrationTest_LongLivedDefaultExecutor_a3REbi/slaves/98570ef6-2391-4957-8781-7dc1977897c5-S0/frameworks/98570ef6-2391-4957-8781-7dc1977897c5-0000/executors/default/runs/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/containers/fce506dd-afb9-4013-9731-f0094b96657d'
for gc 6.99998759089185days in the future
I0801 21:37:56.072463 25991 linux_launcher.cpp:576] Asked to destroy container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b
I0801 21:37:56.072499 25991 linux_launcher.cpp:618] Destroying cgroup
'/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b'
I0801 21:37:56.072760 28460 default_executor.cpp:971] Child container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d of
task 'feb351d3-1bc1-4fde-b10d-f3a9375ffa73' completed in state TASK_KILLED:
Command terminated with signal Terminated
I0801 21:37:56.072808 28460 default_executor.cpp:1093] Terminating after 1secs
I0801 21:37:56.073040 25989 cgroups.cpp:2854] Freezing cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos
I0801 21:37:56.073088 25989 cgroups.cpp:2854] Freezing cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b
I0801 21:37:56.073197 25989 cgroups.cpp:1242] Successfully froze cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos after 136960ns
I0801 21:37:56.073388 25995 process.cpp:2781] Returning '404 Not Found' for
'/slave(92)/api/v1/executor'
I0801 21:37:56.073403 25988 cgroups.cpp:2872] Thawing cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos
I0801 21:37:56.073634 25989 cgroups.cpp:1242] Successfully froze cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b after 528896ns
I0801 21:37:56.073848 25989 cgroups.cpp:2872] Thawing cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b
I0801 21:37:56.074026 25989 cgroups.cpp:1271] Successfully thawed cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b after 153088ns
W0801 21:37:56.076376 25995 process.cpp:846] Failed to recv on socket 17 to
peer 'unknown': Connection reset by peer
I0801 21:37:56.172092 25988 containerizer.cpp:3141] Container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b has exited
I0801 21:37:56.174038 25989 cgroups.cpp:1271] Successfully thawed cgroup
/cgroup/freezer/mesos/742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b/mesos after
100.614912ms
I0801 21:37:56.174957 25987 provisioner.cpp:611] Ignoring destroy request for
unknown container 742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b
W0801 21:37:56.175772 25987 composing.cpp:609] Attempted to destroy unknown
container
742dcf6b-ca2d-4dc3-9b0d-104fb1882b8b.fce506dd-afb9-4013-9731-f0094b96657d
I0801 21:37:56.190009 25986 master.cpp:1135] Master terminating
I0801 21:37:56.190392 25987 hierarchical.cpp:775] Removed all filters for agent
98570ef6-2391-4957-8781-7dc1977897c5-S0
I0801 21:37:56.190415 25987 hierarchical.cpp:650] Removed agent
98570ef6-2391-4957-8781-7dc1977897c5-S0
[ FAILED ] GarbageCollectorIntegrationTest.LongLivedDefaultExecutor (677 ms)
{code}
--
This message was sent by Atlassian JIRA
(v7.6.14#76016)
