[
https://issues.apache.org/jira/browse/MESOS-9923?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16918740#comment-16918740
]
Vinod Kone commented on MESOS-9923:
-----------------------------------
Observed this on ASF CI when testing 1.9.0-rc2
{code}
3: [ RUN ] ContentType/AgentAPITest.GetStateWithNonTerminalCompletedTask/0
3: I0828 21:20:00.647260 17669 cluster.cpp:177] Creating default 'local'
authorizer
3: I0828 21:20:00.655491 17681 master.cpp:440] Master
cff62302-83f2-4586-b6a6-ec603af07f35 (5ca4a76bb68c) started on 172.17.0.3:46115
3: I0828 21:20:00.655534 17681 master.cpp:443] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1000secs" --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/49Bxak/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/49Bxak/master" --zk_session_timeout="10secs"
3: I0828 21:20:00.656090 17681 master.cpp:492] Master only allowing
authenticated frameworks to register
3: I0828 21:20:00.656103 17681 master.cpp:498] Master only allowing
authenticated agents to register
3: I0828 21:20:00.656111 17681 master.cpp:504] Master only allowing
authenticated HTTP frameworks to register
3: I0828 21:20:00.656119 17681 credentials.hpp:37] Loading credentials for
authentication from '/tmp/49Bxak/credentials'
3: I0828 21:20:00.656491 17681 master.cpp:548] Using default 'crammd5'
authenticator
3: I0828 21:20:00.656787 17681 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
3: I0828 21:20:00.657025 17681 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
3: I0828 21:20:00.657196 17681 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
3: I0828 21:20:00.657344 17681 master.cpp:629] Authorization enabled
3: I0828 21:20:00.657789 17676 hierarchical.cpp:474] Initialized hierarchical
allocator process
3: I0828 21:20:00.658103 17677 whitelist_watcher.cpp:77] No whitelist given
3: I0828 21:20:00.664515 17681 master.cpp:2170] Elected as the leading master!
3: I0828 21:20:00.664557 17681 master.cpp:1666] Recovering from registrar
3: I0828 21:20:00.665055 17681 registrar.cpp:339] Recovering registrar
3: I0828 21:20:00.666002 17676 registrar.cpp:383] Successfully fetched the
registry (0B) in 896us
3: I0828 21:20:00.666203 17676 registrar.cpp:487] Applied 1 operations in
62949ns; attempting to update the registry
3: I0828 21:20:00.667132 17676 registrar.cpp:544] Successfully updated the
registry in 852224ns
3: I0828 21:20:00.667313 17676 registrar.cpp:416] Successfully recovered
registrar
3: I0828 21:20:00.667974 17676 master.cpp:1819] Recovered 0 agents from the
registry (143B); allowing 10mins for agents to reregister
3: I0828 21:20:00.668090 17685 hierarchical.cpp:513] Skipping recovery of
hierarchical allocator: nothing to recover
3: W0828 21:20:00.687932 17669 process.cpp:2877] Attempted to spawn already
running process files@172.17.0.3:46115
3: I0828 21:20:00.689092 17669 cluster.cpp:518] Creating default 'local'
authorizer
3: W0828 21:20:00.692358 17669 process.cpp:2877] Attempted to spawn already
running process version@172.17.0.3:46115
3: I0828 21:20:00.692720 17684 slave.cpp:267] Mesos agent started on
(901)@172.17.0.3:46115
3: I0828 21:20:00.692745 17684 slave.cpp:268] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/49Bxak/YlM9y5/store/appc"
--authenticate_http_readonly="true" --authenticate_http_readwrite="false"
--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/49Bxak/YlM9y5/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/49Bxak/YlM9y5/store/docker"
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
--docker_volume_chown="false" --enforce_container_disk_quota="false"
--executor_registration_timeout="1mins"
--executor_reregistration_timeout="2secs"
--executor_shutdown_grace_period="0ns"
--fetcher_cache_dir="/tmp/49Bxak/YlM9y5/fetch" --fetcher_cache_size="2GB"
--fetcher_stall_timeout="1mins"
--frameworks_home="/tmp/49Bxak/YlM9y5/frameworks" --gc_delay="1weeks"
--gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false"
--help="false" --hostname_lookup="true" --http_command_executor="false"
--http_credentials="/tmp/49Bxak/YlM9y5/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="posix"
--launcher_dir="/tmp/SRC/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/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_b0lBLP"
--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/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz"
--zk_session_timeout="10secs"
3: I0828 21:20:00.693759 17684 credentials.hpp:86] Loading credential for
authentication from '/tmp/49Bxak/YlM9y5/credential'
3: I0828 21:20:00.693996 17684 slave.cpp:300] Agent using credential for:
test-principal
3: I0828 21:20:00.694017 17684 credentials.hpp:37] Loading credentials for
authentication from '/tmp/49Bxak/YlM9y5/http_credentials'
3: I0828 21:20:00.694100 17669 sched.cpp:239] Version: 1.9.0
3: I0828 21:20:00.694273 17684 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I0828 21:20:00.695122 17684 disk_profile_adaptor.cpp:78] Creating default
disk profile adaptor module
3: I0828 21:20:00.695171 17673 sched.cpp:343] New master detected at
master@172.17.0.3:46115
3: I0828 21:20:00.695367 17673 sched.cpp:408] Authenticating with master
master@172.17.0.3:46115
3: I0828 21:20:00.695389 17673 sched.cpp:415] Using default CRAM-MD5
authenticatee
3: I0828 21:20:00.696143 17674 authenticatee.cpp:121] Creating new client SASL
connection
3: I0828 21:20:00.696612 17674 master.cpp:10617] Authenticating
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115
3: I0828 21:20:00.696754 17676 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1614)@172.17.0.3:46115
3: I0828 21:20:00.697154 17671 authenticator.cpp:98] Creating new server SASL
connection
3: I0828 21:20:00.697638 17671 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I0828 21:20:00.697670 17671 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I0828 21:20:00.697849 17677 authenticator.cpp:204] Received SASL
authentication start
3: I0828 21:20:00.697926 17677 authenticator.cpp:326] Authentication requires
more steps
3: I0828 21:20:00.698048 17677 authenticatee.cpp:259] Received SASL
authentication step
3: I0828 21:20:00.698153 17677 authenticator.cpp:232] Received SASL
authentication step
3: I0828 21:20:00.698207 17677 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '5ca4a76bb68c' server FQDN: '5ca4a76bb68c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I0828 21:20:00.698220 17677 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I0828 21:20:00.698277 17677 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I0828 21:20:00.698295 17677 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '5ca4a76bb68c' server FQDN: '5ca4a76bb68c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I0828 21:20:00.698304 17677 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I0828 21:20:00.698312 17677 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I0828 21:20:00.698328 17677 authenticator.cpp:318] Authentication success
3: I0828 21:20:00.698451 17679 authenticatee.cpp:299] Authentication success
3: I0828 21:20:00.698629 17677 master.cpp:10649] Successfully authenticated
principal 'test-principal' at
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115
3: I0828 21:20:00.698629 17683 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1614)@172.17.0.3:46115
3: I0828 21:20:00.699429 17684 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"}]
3: I0828 21:20:00.699781 17684 slave.cpp:623] Agent attributes: [ ]
3: I0828 21:20:00.699797 17684 slave.cpp:632] Agent hostname: 5ca4a76bb68c
3: I0828 21:20:00.700057 17674 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I0828 21:20:00.700110 17674 status_update_manager_process.hpp:379] Pausing
operation status update manager
3: I0828 21:20:00.704396 17673 sched.cpp:520] Successfully authenticated with
master master@172.17.0.3:46115
3: I0828 21:20:00.704417 17676 state.cpp:67] Recovering state from
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta'
3: I0828 21:20:00.705502 17684 slave.cpp:7491] Finished recovering checkpointed
state from
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta',
beginning agent recovery
3: I0828 21:20:00.706600 17684 task_status_update_manager.cpp:207] Recovering
task status update manager
3: I0828 21:20:00.704432 17673 sched.cpp:835] Sending SUBSCRIBE call to
master@172.17.0.3:46115
3: I0828 21:20:00.708032 17673 sched.cpp:870] Will retry registration in
390.398061ms if necessary
3: I0828 21:20:00.708427 17679 master.cpp:2910] Received SUBSCRIBE call for
framework 'default' at
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115
3: I0828 21:20:00.708472 17679 master.cpp:2242] Authorizing framework principal
'test-principal' to receive offers for roles '{ * }'
3: I0828 21:20:00.709172 17674 composing.cpp:339] Finished recovering all
containerizers
3: I0828 21:20:00.709401 17679 master.cpp:2997] Subscribing framework default
with checkpointing enabled and capabilities [ MULTI_ROLE,
RESERVATION_REFINEMENT ]
3: I0828 21:20:00.709642 17674 slave.cpp:7972] Recovering executors
3: I0828 21:20:00.709738 17674 slave.cpp:8125] Finished recovery
3: I0828 21:20:00.711498 17679 master.cpp:10847] Adding framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 (default) at
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115 with roles { }
suppressed
3: I0828 21:20:00.712893 17673 hierarchical.cpp:605] Added framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.716658 17673 hierarchical.cpp:1724] Performed allocation for
0 agents in 216818ns
3: I0828 21:20:00.721011 17683 slave.cpp:1351] New master detected at
master@172.17.0.3:46115
3: I0828 21:20:00.721177 17671 sched.cpp:751] Framework registered with
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.721222 17683 slave.cpp:1416] Detecting new master
3: I0828 21:20:00.721266 17671 sched.cpp:770] Scheduler::registered took 53397ns
3: I0828 21:20:00.721359 17671 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I0828 21:20:00.721449 17679 status_update_manager_process.hpp:379] Pausing
operation status update manager
3: I0828 21:20:00.736454 17676 slave.cpp:1443] Authenticating with master
master@172.17.0.3:46115
3: I0828 21:20:00.736706 17676 slave.cpp:1452] Using default CRAM-MD5
authenticatee
3: I0828 21:20:00.737596 17676 authenticatee.cpp:121] Creating new client SASL
connection
3: I0828 21:20:00.738191 17674 master.cpp:10617] Authenticating
slave(901)@172.17.0.3:46115
3: I0828 21:20:00.738514 17674 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1615)@172.17.0.3:46115
3: I0828 21:20:00.739151 17674 authenticator.cpp:98] Creating new server SASL
connection
3: I0828 21:20:00.739572 17674 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I0828 21:20:00.739603 17674 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I0828 21:20:00.739732 17674 authenticator.cpp:204] Received SASL
authentication start
3: I0828 21:20:00.739794 17674 authenticator.cpp:326] Authentication requires
more steps
3: I0828 21:20:00.739907 17674 authenticatee.cpp:259] Received SASL
authentication step
3: I0828 21:20:00.740059 17673 authenticator.cpp:232] Received SASL
authentication step
3: I0828 21:20:00.740118 17673 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '5ca4a76bb68c' server FQDN: '5ca4a76bb68c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I0828 21:20:00.740131 17673 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I0828 21:20:00.740197 17673 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I0828 21:20:00.740218 17673 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '5ca4a76bb68c' server FQDN: '5ca4a76bb68c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I0828 21:20:00.740227 17673 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I0828 21:20:00.740234 17673 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I0828 21:20:00.740250 17673 authenticator.cpp:318] Authentication success
3: I0828 21:20:00.740542 17673 authenticatee.cpp:299] Authentication success
3: I0828 21:20:00.740803 17679 master.cpp:10649] Successfully authenticated
principal 'test-principal' at slave(901)@172.17.0.3:46115
3: I0828 21:20:00.740849 17673 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1615)@172.17.0.3:46115
3: I0828 21:20:00.748420 17679 slave.cpp:1543] Successfully authenticated with
master master@172.17.0.3:46115
3: I0828 21:20:00.749120 17679 slave.cpp:1993] Will retry registration in
8.559337ms if necessary
3: I0828 21:20:00.749577 17682 master.cpp:7088] Received register agent message
from slave(901)@172.17.0.3:46115 (5ca4a76bb68c)
3: I0828 21:20:00.750394 17682 master.cpp:4204] Authorizing agent providing
resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal
'test-principal'
3: I0828 21:20:00.752676 17682 master.cpp:7155] Authorized registration of
agent at slave(901)@172.17.0.3:46115 (5ca4a76bb68c)
3: I0828 21:20:00.752835 17682 master.cpp:7267] Registering agent at
slave(901)@172.17.0.3:46115 (5ca4a76bb68c) with id
cff62302-83f2-4586-b6a6-ec603af07f35-S0
3: I0828 21:20:00.754045 17680 registrar.cpp:487] Applied 1 operations in
328192ns; attempting to update the registry
3: I0828 21:20:00.755089 17680 registrar.cpp:544] Successfully updated the
registry in 944128ns
3: I0828 21:20:00.755350 17677 master.cpp:7315] Admitted agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:00.756541 17677 master.cpp:7360] Registered agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I0828 21:20:00.756824 17683 hierarchical.cpp:854] Added agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 (5ca4a76bb68c) with cpus:2; mem:1024;
disk:1024; ports:[31000-32000] (allocated: {})
3: I0828 21:20:00.756953 17685 slave.cpp:1576] Registered with master
master@172.17.0.3:46115; given agent ID cff62302-83f2-4586-b6a6-ec603af07f35-S0
3: I0828 21:20:00.757879 17672 task_status_update_manager.cpp:188] Resuming
sending task status updates
3: I0828 21:20:00.757998 17685 slave.cpp:1611] Checkpointing SlaveInfo to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/slave.info'
3: I0828 21:20:00.758330 17683 hierarchical.cpp:1724] Performed allocation for
1 agents in 1.268681ms
3: I0828 21:20:00.758476 17683 status_update_manager_process.hpp:385] Resuming
operation status update manager
3: I0828 21:20:00.759102 17683 master.cpp:10432] Sending offers [
cff62302-83f2-4586-b6a6-ec603af07f35-O0 ] to framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 (default) at
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115
3: I0828 21:20:00.760170 17671 sched.cpp:934] Scheduler::resourceOffers took
127537ns
3: I0828 21:20:00.761273 17685 slave.cpp:1663] Forwarding agent update
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"27pkOK6pRz+yfEwDry/+Cw=="},"slave_id":{"value":"cff62302-83f2-4586-b6a6-ec603af07f35-S0"},"update_oversubscribed_resources":false}
3: I0828 21:20:00.762323 17685 master.cpp:8487] Ignoring update on agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c) as it reports no changes
3: I0828 21:20:00.763523 17685 master.cpp:12724] Removing offer
cff62302-83f2-4586-b6a6-ec603af07f35-O0
3: I0828 21:20:00.764124 17685 master.cpp:4741] Processing ACCEPT call for
offers: [ cff62302-83f2-4586-b6a6-ec603af07f35-O0 ] on agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c) for framework cff62302-83f2-4586-b6a6-ec603af07f35-0000
(default) at scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115
3: I0828 21:20:00.764309 17685 master.cpp:3758] Authorizing framework principal
'test-principal' to launch task 72adc257-b17a-4ac7-a824-7c22940f01cb
3: W0828 21:20:00.767088 17672 validation.cpp:1640] Executor 'default' for task
'72adc257-b17a-4ac7-a824-7c22940f01cb' uses less CPUs (None) than the minimum
required (0.01). Please update your executor, as this will be mandatory in
future releases.
3: W0828 21:20:00.767141 17672 validation.cpp:1652] Executor 'default' for task
'72adc257-b17a-4ac7-a824-7c22940f01cb' uses less memory (None) than the minimum
required (32MB). Please update your executor, as this will be mandatory in
future releases.
3: I0828 21:20:00.767653 17672 master.cpp:4276] Adding executor 'default' with
resources {} of framework cff62302-83f2-4586-b6a6-ec603af07f35-0000 (default)
at scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115 on agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:00.767931 17672 master.cpp:4302] Adding task
72adc257-b17a-4ac7-a824-7c22940f01cb with resources ports(allocated:
*):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated:
*):1024 of framework cff62302-83f2-4586-b6a6-ec603af07f35-0000 (default) at
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115 on agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:00.768788 17672 master.cpp:5720] Launching task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 (default) at
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115 with resources
[{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"},{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"}]
on agent cff62302-83f2-4586-b6a6-ec603af07f35-S0 at
slave(901)@172.17.0.3:46115 (5ca4a76bb68c) on new executor
3: I0828 21:20:00.769490 17672 hierarchical.cpp:1648] Allocation paused
3: I0828 21:20:00.769522 17672 hierarchical.cpp:1658] Allocation resumed
3: I0828 21:20:00.770387 17677 slave.cpp:2130] Got assigned task
'72adc257-b17a-4ac7-a824-7c22940f01cb' for framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.770648 17677 slave.cpp:9916] Checkpointing FrameworkInfo to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/framework.info'
3: I0828 21:20:00.771387 17677 slave.cpp:9927] Checkpointing framework pid
'scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115' to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/framework.pid'
3: I0828 21:20:00.774060 17677 slave.cpp:2504] Authorizing task
'72adc257-b17a-4ac7-a824-7c22940f01cb' for framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.774165 17677 slave.cpp:9464] Authorizing framework principal
'test-principal' to launch task 72adc257-b17a-4ac7-a824-7c22940f01cb
3: I0828 21:20:00.777487 17680 slave.cpp:2977] Launching task
'72adc257-b17a-4ac7-a824-7c22940f01cb' for framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.777626 17680 paths.cpp:817] Creating sandbox
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
for user 'mesos'
3: I0828 21:20:00.783429 17680 slave.cpp:10714] Checkpointing ExecutorInfo to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/executor.info'
3: I0828 21:20:00.784216 17680 paths.cpp:820] Creating sandbox
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
3: I0828 21:20:00.784524 17680 slave.cpp:10002] Launching executor 'default' of
framework cff62302-83f2-4586-b6a6-ec603af07f35-0000 with resources [] in work
directory
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
3: I0828 21:20:00.785908 17680 slave.cpp:10745] Checkpointing TaskInfo to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a/tasks/72adc257-b17a-4ac7-a824-7c22940f01cb/task.info'
3: I0828 21:20:00.786914 17680 slave.cpp:3209] Queued task
'72adc257-b17a-4ac7-a824-7c22940f01cb' for executor 'default' of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.787521 17680 slave.cpp:1084] Successfully attached
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
to virtual path
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/latest'
3: I0828 21:20:00.787569 17680 slave.cpp:1084] Successfully attached
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
to virtual path
'/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/latest'
3: I0828 21:20:00.787595 17680 slave.cpp:1084] Successfully attached
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
to virtual path
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
3: I0828 21:20:00.787915 17680 slave.cpp:3657] Launching container
d9091939-7dce-4de7-8460-1137fadac15a for executor 'default' of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: W0828 21:20:00.789808 17682 process.cpp:2877] Attempted to spawn already
running process version@172.17.0.3:46115
3: I0828 21:20:00.790206 17682 exec.cpp:164] Version: 1.9.0
3: I0828 21:20:00.790638 17675 exec.cpp:213] Executor started at:
executor(200)@172.17.0.3:46115 with pid 17669
3: I0828 21:20:00.791011 17675 slave.cpp:5256] Got registration for executor
'default' of framework cff62302-83f2-4586-b6a6-ec603af07f35-0000 from
executor(200)@172.17.0.3:46115
3: I0828 21:20:00.791232 17675 slave.cpp:5342] Checkpointing executor pid
'executor(200)@172.17.0.3:46115' to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a/pids/libprocess.pid'
3: I0828 21:20:00.792021 17682 exec.cpp:237] Executor registered on agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0
3: I0828 21:20:00.792083 17682 exec.cpp:249] Executor::registered took 34194ns
3: I0828 21:20:00.794234 17675 slave.cpp:3427] Sending queued task
'72adc257-b17a-4ac7-a824-7c22940f01cb' to executor 'default' of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 at executor(200)@172.17.0.3:46115
3: I0828 21:20:00.794965 17674 exec.cpp:331] Executor asked to run task
'72adc257-b17a-4ac7-a824-7c22940f01cb'
3: I0828 21:20:00.795089 17674 exec.cpp:340] Executor::launchTask took 92284ns
3: I0828 21:20:00.795241 17674 exec.cpp:595] Executor sending status update
TASK_RUNNING (Status UUID: 885438b5-ebd8-4fd7-93b6-1e7eba00b580) for task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.795639 17674 slave.cpp:5737] Handling status update
TASK_RUNNING (Status UUID: 885438b5-ebd8-4fd7-93b6-1e7eba00b580) for task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 from executor(200)@172.17.0.3:46115
3: I0828 21:20:00.797763 17677 task_status_update_manager.cpp:328] Received
task status update TASK_RUNNING (Status UUID:
885438b5-ebd8-4fd7-93b6-1e7eba00b580) for task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.797837 17677 task_status_update_manager.cpp:507] Creating
StatusUpdate stream for task 72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.798887 17677 task_status_update_manager.cpp:842]
Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID:
885438b5-ebd8-4fd7-93b6-1e7eba00b580) for task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.799352 17677 task_status_update_manager.cpp:383] Forwarding
task status update TASK_RUNNING (Status UUID:
885438b5-ebd8-4fd7-93b6-1e7eba00b580) for task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 to the agent
3: I0828 21:20:00.799827 17677 slave.cpp:6276] Forwarding the update
TASK_RUNNING (Status UUID: 885438b5-ebd8-4fd7-93b6-1e7eba00b580) for task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 to master@172.17.0.3:46115
3: I0828 21:20:00.800076 17677 slave.cpp:6160] Task status update manager
successfully handled status update TASK_RUNNING (Status UUID:
885438b5-ebd8-4fd7-93b6-1e7eba00b580) for task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.800251 17677 slave.cpp:6187] Sending acknowledgement for
status update TASK_RUNNING (Status UUID: 885438b5-ebd8-4fd7-93b6-1e7eba00b580)
for task 72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 to executor(200)@172.17.0.3:46115
3: I0828 21:20:00.801174 17677 exec.cpp:412] Executor received status update
acknowledgement 885438b5-ebd8-4fd7-93b6-1e7eba00b580 for task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.800359 17681 master.cpp:8985] Status update TASK_RUNNING
(Status UUID: 885438b5-ebd8-4fd7-93b6-1e7eba00b580) for task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 from agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:00.802294 17681 master.cpp:9042] Forwarding status update
TASK_RUNNING (Status UUID: 885438b5-ebd8-4fd7-93b6-1e7eba00b580) for task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.802668 17681 master.cpp:12073] Updating the state of task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
3: I0828 21:20:00.803084 17681 sched.cpp:1042] Scheduler::statusUpdate took
94249ns
3: I0828 21:20:00.803665 17684 master.cpp:6695] Processing ACKNOWLEDGE call for
status 885438b5-ebd8-4fd7-93b6-1e7eba00b580 for task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 (default) at
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115 on agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0
3: I0828 21:20:00.803866 17669 slave.cpp:965] Unregistering and shutting down
3: I0828 21:20:00.803994 17669 slave.cpp:4062] Asked to shut down framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 by @0.0.0.0:0
3: I0828 21:20:00.804029 17669 slave.cpp:4087] Shutting down framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.804095 17669 slave.cpp:7222] Shutting down executor 'default'
of framework cff62302-83f2-4586-b6a6-ec603af07f35-0000 at
executor(200)@172.17.0.3:46115
3: W0828 21:20:00.804396 17669 slave.cpp:4823] Dropping status update
acknowledgement message for cff62302-83f2-4586-b6a6-ec603af07f35-0000 because
the agent is in TERMINATING state
3: I0828 21:20:00.804558 17678 exec.cpp:459] Executor asked to shutdown
3: I0828 21:20:00.804602 17678 exec.cpp:474] Executor::shutdown took 24633ns
3: I0828 21:20:00.805426 17674 slave.cpp:6456] Got exited event for
executor(200)@172.17.0.3:46115
3: I0828 21:20:00.806154 17684 master.cpp:11638] Removing agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c): the agent unregistered
3: I0828 21:20:00.806224 17679 slave.cpp:7295] Killing executor 'default' of
framework cff62302-83f2-4586-b6a6-ec603af07f35-0000 at
executor(200)@172.17.0.3:46115
3: I0828 21:20:00.807256 17677 registrar.cpp:487] Applied 1 operations in
168972ns; attempting to update the registry
3: I0828 21:20:00.807751 17679 slave.cpp:6856] Executor 'default' of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 exited with status 0
3: I0828 21:20:00.808068 17679 slave.cpp:6967] Cleaning up executor 'default'
of framework cff62302-83f2-4586-b6a6-ec603af07f35-0000 at
executor(200)@172.17.0.3:46115
3: I0828 21:20:00.808847 17684 master.cpp:9322] Executor 'default' of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 on agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c): exited with status 0
3: I0828 21:20:00.808974 17670 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
for gc 6.99999064202667days in the future
3: I0828 21:20:00.809089 17674 registrar.cpp:544] Successfully updated the
registry in 1.735936ms
3: I0828 21:20:00.809499 17684 master.cpp:12211] Removing executor 'default'
with resources {} of framework cff62302-83f2-4586-b6a6-ec603af07f35-0000 on
agent cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:00.809962 17679 slave.cpp:7096] Cleaning up framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.810075 17683 task_status_update_manager.cpp:289] Closing task
status update streams for framework cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.810163 17683 task_status_update_manager.cpp:538] Cleaning up
status update stream for task 72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.810647 17679 slave.cpp:924] Agent terminating
3: I0828 21:20:00.811619 17684 master.cpp:11680] Removed agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c): the agent unregistered
3: I0828 21:20:00.811619 17670 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default'
for gc 6.99999063903704days in the future
3: I0828 21:20:00.812463 17684 master.cpp:12073] Updating the state of task
72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 (latest state: TASK_LOST, status
update state: TASK_LOST)
3: I0828 21:20:00.816376 17670 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
for gc 6.99999063771852days in the future
3: I0828 21:20:00.816573 17670 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default'
for gc 6.99999063690074days in the future
3: I0828 21:20:00.816578 17677 hierarchical.cpp:1013] Removed all filters for
agent cff62302-83f2-4586-b6a6-ec603af07f35-S0
3: I0828 21:20:00.816642 17677 hierarchical.cpp:890] Removed agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0
3: I0828 21:20:00.816716 17670 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000'
for gc 6.99999062221037days in the future
3: I0828 21:20:00.816833 17670 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000'
for gc 6.99999061951407days in the future
3: I0828 21:20:00.818025 17674 sched.cpp:1144] Executor default on agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 exited with status 0
3:
3: GMOCK WARNING:
3: Uninteresting mock function call - returning directly.
3: Function call: executorLost(0x7ffe5550d790, @0x7f56a8030220 default,
@0x7f56a8022fc0 cff62302-83f2-4586-b6a6-ec603af07f35-S0, 0)
3: 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.
3: I0828 21:20:00.818130 17674 sched.cpp:1155] Scheduler::executorLost took
75632ns
3: I0828 21:20:00.819655 17684 master.cpp:12171] Removing task
72adc257-b17a-4ac7-a824-7c22940f01cb with resources ports(allocated:
*):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated:
*):1024 of framework cff62302-83f2-4586-b6a6-ec603af07f35-0000 on agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(901)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:00.820025 17684 master.cpp:9037] Sending status update TASK_LOST
for task 72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 'Agent 5ca4a76bb68c removed: the
agent unregistered'
3: I0828 21:20:00.820904 17684 master.cpp:2087] Notifying framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 (default) at
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115 of lost agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 (5ca4a76bb68c)
3: I0828 21:20:00.821516 17684 sched.cpp:1042] Scheduler::statusUpdate took
95110ns
3: I0828 21:20:00.821672 17684 sched.cpp:1104] Lost agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0
3: I0828 21:20:00.821750 17684 sched.cpp:1115] Scheduler::slaveLost took 24907ns
3: W0828 21:20:00.825289 17669 process.cpp:2877] Attempted to spawn already
running process files@172.17.0.3:46115
3: I0828 21:20:00.827280 17669 containerizer.cpp:318] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W0828 21:20:00.828303 17669 backend.cpp:76] Failed to create 'overlay'
backend: OverlayBackend requires root privileges
3: W0828 21:20:00.828416 17669 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
3: W0828 21:20:00.828495 17669 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
3: I0828 21:20:00.828673 17669 provisioner.cpp:300] Using default backend 'copy'
3: I0828 21:20:00.831893 17669 cluster.cpp:518] Creating default 'local'
authorizer
3: I0828 21:20:00.836628 17679 slave.cpp:267] Mesos agent started on
(902)@172.17.0.3:46115
3: I0828 21:20:00.836655 17679 slave.cpp:268] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/49Bxak/YlM9y5/store/appc"
--authenticate_http_readonly="true" --authenticate_http_readwrite="false"
--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/49Bxak/YlM9y5/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/49Bxak/YlM9y5/store/docker"
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
--docker_volume_chown="false" --enforce_container_disk_quota="false"
--executor_registration_timeout="1mins"
--executor_reregistration_timeout="2secs"
--executor_shutdown_grace_period="0ns"
--fetcher_cache_dir="/tmp/49Bxak/YlM9y5/fetch" --fetcher_cache_size="2GB"
--fetcher_stall_timeout="1mins"
--frameworks_home="/tmp/49Bxak/YlM9y5/frameworks" --gc_delay="1weeks"
--gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false"
--help="false" --hostname_lookup="true" --http_command_executor="false"
--http_credentials="/tmp/49Bxak/YlM9y5/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="posix"
--launcher_dir="/tmp/SRC/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/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_b0lBLP"
--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/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz"
--zk_session_timeout="10secs"
3: I0828 21:20:00.837268 17679 credentials.hpp:86] Loading credential for
authentication from '/tmp/49Bxak/YlM9y5/credential'
3: I0828 21:20:00.837498 17679 slave.cpp:300] Agent using credential for:
test-principal
3: I0828 21:20:00.837518 17679 credentials.hpp:37] Loading credentials for
authentication from '/tmp/49Bxak/YlM9y5/http_credentials'
3: I0828 21:20:00.837777 17679 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I0828 21:20:00.838425 17679 disk_profile_adaptor.cpp:78] Creating default
disk profile adaptor module
3: I0828 21:20:00.840155 17679 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"}]
3: I0828 21:20:00.840524 17679 slave.cpp:623] Agent attributes: [ ]
3: I0828 21:20:00.840600 17679 slave.cpp:632] Agent hostname: 5ca4a76bb68c
3: I0828 21:20:00.841472 17672 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I0828 21:20:00.841532 17672 status_update_manager_process.hpp:379] Pausing
operation status update manager
3: I0828 21:20:00.875303 17679 state.cpp:67] Recovering state from
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta'
3: I0828 21:20:00.875573 17679 state.cpp:874] No committed checkpointed
resources and operations found at
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/resources/resources_and_operations.state'
3: I0828 21:20:00.875677 17679 state.cpp:880] No committed checkpointed
resources found at
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/resources/resources.info'
3: I0828 21:20:00.881279 17682 slave.cpp:7491] Finished recovering checkpointed
state from
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta',
beginning agent recovery
3: I0828 21:20:00.884348 17682 slave.cpp:8222] Recovering framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.884665 17682 slave.cpp:10120] Recovering executor 'default'
of framework cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.886436 17682 slave.cpp:7096] Cleaning up framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.886677 17671 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
for gc 6.99998974745481days in the future
3: I0828 21:20:00.886727 17674 task_status_update_manager.cpp:289] Closing task
status update streams for framework cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.886947 17671 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
for gc 6.99998974403852days in the future
3: I0828 21:20:00.887156 17671 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default'
for gc 6.99998974264days in the future
3: I0828 21:20:00.887290 17671 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default'
for gc 6.99998974170074days in the future
3: I0828 21:20:00.887646 17681 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000'
for gc 6.99998972747556days in the future
3: I0828 21:20:00.888135 17680 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/meta/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000'
for gc 6.9999897217837days in the future
3: I0828 21:20:00.889597 17682 slave.cpp:1084] Successfully attached
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
to virtual path
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/latest'
3: I0828 21:20:00.889762 17682 slave.cpp:1084] Successfully attached
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
to virtual path
'/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/latest'
3: I0828 21:20:00.889886 17682 slave.cpp:1084] Successfully attached
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
to virtual path
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_U4F3Xz/slaves/cff62302-83f2-4586-b6a6-ec603af07f35-S0/frameworks/cff62302-83f2-4586-b6a6-ec603af07f35-0000/executors/default/runs/d9091939-7dce-4de7-8460-1137fadac15a'
3: I0828 21:20:00.890296 17677 task_status_update_manager.cpp:207] Recovering
task status update manager
3: I0828 21:20:00.890336 17677 task_status_update_manager.cpp:215] Recovering
executor 'default' of framework cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.890420 17677 task_status_update_manager.cpp:240] Skipping
recovering task status updates of executor 'default' of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 because its latest run
d9091939-7dce-4de7-8460-1137fadac15a is completed
3: I0828 21:20:00.892587 17676 containerizer.cpp:821] Recovering Mesos
containers
3: I0828 21:20:00.892704 17676 containerizer.cpp:859] Skipping recovery of
executor 'default' of framework cff62302-83f2-4586-b6a6-ec603af07f35-0000
because its latest run d9091939-7dce-4de7-8460-1137fadac15a is completed
3: I0828 21:20:00.893245 17676 containerizer.cpp:1161] Recovering isolators
3: I0828 21:20:00.894448 17678 containerizer.cpp:1200] Recovering provisioner
3: I0828 21:20:00.895294 17674 provisioner.cpp:500] Provisioner recovery
complete
3: I0828 21:20:00.912823 17680 composing.cpp:339] Finished recovering all
containerizers
3: I0828 21:20:00.914355 17677 status_update_manager_process.hpp:314]
Recovering operation status update manager
3: I0828 21:20:00.914963 17684 slave.cpp:7972] Recovering executors
3: I0828 21:20:00.915092 17684 slave.cpp:8125] Finished recovery
3: I0828 21:20:00.916378 17683 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I0828 21:20:00.916420 17684 slave.cpp:1351] New master detected at
master@172.17.0.3:46115
3: I0828 21:20:00.916617 17684 slave.cpp:1416] Detecting new master
3: I0828 21:20:00.917773 17673 status_update_manager_process.hpp:379] Pausing
operation status update manager
3: I0828 21:20:00.932415 17670 slave.cpp:1443] Authenticating with master
master@172.17.0.3:46115
3: I0828 21:20:00.932458 17669 sched.cpp:2166] Asked to stop the driver
3: I0828 21:20:00.932626 17670 slave.cpp:1452] Using default CRAM-MD5
authenticatee
3: I0828 21:20:00.932941 17682 sched.cpp:1204] Stopping framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.934958 17675 master.cpp:11211] Processing TEARDOWN call for
framework cff62302-83f2-4586-b6a6-ec603af07f35-0000 (default) at
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115
3: I0828 21:20:00.935024 17675 master.cpp:11223] Removing framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 (default) at
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115
3: I0828 21:20:00.935039 17675 master.cpp:3362] Deactivating framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 (default) at
scheduler-ff02b2f4-e01f-4c56-9b08-8da5d17e88ee@172.17.0.3:46115
3: I0828 21:20:00.935732 17678 hierarchical.cpp:711] Deactivated framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.935806 17678 hierarchical.cpp:1648] Allocation paused
3: I0828 21:20:00.936331 17678 hierarchical.cpp:655] Removed framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.936492 17678 hierarchical.cpp:1658] Allocation resumed
3: I0828 21:20:00.936645 17670 authenticatee.cpp:121] Creating new client SASL
connection
3: I0828 21:20:00.937255 17670 master.cpp:10617] Authenticating
slave(902)@172.17.0.3:46115
3: I0828 21:20:00.937510 17676 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1616)@172.17.0.3:46115
3: I0828 21:20:00.938221 17676 authenticator.cpp:98] Creating new server SASL
connection
3: I0828 21:20:00.938597 17680 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I0828 21:20:00.938629 17680 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I0828 21:20:00.938803 17680 authenticator.cpp:204] Received SASL
authentication start
3: I0828 21:20:00.939803 17680 authenticator.cpp:326] Authentication requires
more steps
3: I0828 21:20:00.939972 17680 authenticatee.cpp:259] Received SASL
authentication step
3: I0828 21:20:00.940083 17680 authenticator.cpp:232] Received SASL
authentication step
3: I0828 21:20:00.940145 17680 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '5ca4a76bb68c' server FQDN: '5ca4a76bb68c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I0828 21:20:00.940157 17680 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I0828 21:20:00.940230 17680 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I0828 21:20:00.940251 17680 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '5ca4a76bb68c' server FQDN: '5ca4a76bb68c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I0828 21:20:00.940261 17680 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I0828 21:20:00.940269 17680 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I0828 21:20:00.940323 17680 authenticator.cpp:318] Authentication success
3: I0828 21:20:00.940536 17677 authenticatee.cpp:299] Authentication success
3: I0828 21:20:00.940630 17680 master.cpp:10649] Successfully authenticated
principal 'test-principal' at slave(902)@172.17.0.3:46115
3: I0828 21:20:00.940773 17680 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1616)@172.17.0.3:46115
3: I0828 21:20:00.948400 17681 slave.cpp:1543] Successfully authenticated with
master master@172.17.0.3:46115
3: I0828 21:20:00.948690 17681 slave.cpp:1940] Reregistering completed
framework cff62302-83f2-4586-b6a6-ec603af07f35-0000
3: I0828 21:20:00.949723 17681 slave.cpp:1993] Will retry registration in
19.170173ms if necessary
3: I0828 21:20:00.949954 17681 process.cpp:3671] Handling HTTP event for
process 'slave(902)' with path: '/slave(902)/api/v1'
3: I0828 21:20:00.950223 17674 master.cpp:7439] Received reregister agent
message from agent cff62302-83f2-4586-b6a6-ec603af07f35-S0 at
slave(902)@172.17.0.3:46115 (5ca4a76bb68c)
3: I0828 21:20:00.950856 17674 master.cpp:4204] Authorizing agent providing
resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal
'test-principal'
3: I0828 21:20:00.951555 17681 http.cpp:1115] HTTP POST for /slave(902)/api/v1
from 172.17.0.3:36524
3: I0828 21:20:00.952239 17677 master.cpp:7531] Authorized re-registration of
agent cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(902)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:00.952407 17677 master.cpp:7703] Consulting registry about agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at
slave(902)@172.17.0.3:46115(5ca4a76bb68c)
3: I0828 21:20:00.952658 17681 http.cpp:1925] Processing GET_STATE call
3: W0828 21:20:00.953122 17677 registry_operations.cpp:200] Allowing UNKNOWN
agent to reregister: hostname: "5ca4a76bb68c"
3: resources {
3: name: "cpus"
3: type: SCALAR
3: scalar {
3: value: 2
3: }
3: }
3: resources {
3: name: "mem"
3: type: SCALAR
3: scalar {
3: value: 1024
3: }
3: }
3: resources {
3: name: "disk"
3: type: SCALAR
3: scalar {
3: value: 1024
3: }
3: }
3: resources {
3: name: "ports"
3: type: RANGES
3: ranges {
3: range {
3: begin: 31000
3: end: 32000
3: }
3: }
3: }
3: id {
3: value: "cff62302-83f2-4586-b6a6-ec603af07f35-S0"
3: }
3: checkpoint: true
3: port: 46115
3: I0828 21:20:00.953652 17677 registrar.cpp:487] Applied 1 operations in
637826ns; attempting to update the registry
3: I0828 21:20:00.954844 17677 registrar.cpp:544] Successfully updated the
registry in 1.089024ms
3: I0828 21:20:00.955173 17677 master.cpp:7759] Re-admitted agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(902)@172.17.0.3:46115
(5ca4a76bb68c)
3: W0828 21:20:00.956040 17677 master.cpp:11572] Possibly orphaned completed
task 72adc257-b17a-4ac7-a824-7c22940f01cb of framework
cff62302-83f2-4586-b6a6-ec603af07f35-0000 that ran on agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(902)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:00.956408 17677 master.cpp:7980] Re-registered agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(902)@172.17.0.3:46115
(5ca4a76bb68c) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I0828 21:20:00.956528 17675 slave.cpp:1700] Re-registered with master
master@172.17.0.3:46115
3: I0828 21:20:00.956707 17678 task_status_update_manager.cpp:188] Resuming
sending task status updates
3: I0828 21:20:00.956725 17676 status_update_manager_process.hpp:385] Resuming
operation status update manager
3: I0828 21:20:00.956845 17675 slave.cpp:1746] Forwarding agent update
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"XTlcOZSjS1qMZYQesVKWXQ=="},"slave_id":{"value":"cff62302-83f2-4586-b6a6-ec603af07f35-S0"},"update_oversubscribed_resources":false}
3: I0828 21:20:00.957070 17679 hierarchical.cpp:854] Added agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 (5ca4a76bb68c) with cpus:2; mem:1024;
disk:1024; ports:[31000-32000] (allocated: {})
3: I0828 21:20:00.957600 17679 hierarchical.cpp:1724] Performed allocation for
1 agents in 287045ns
3: I0828 21:20:00.959376 17675 master.cpp:8487] Ignoring update on agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(902)@172.17.0.3:46115
(5ca4a76bb68c) as it reports no changes
3: I0828 21:20:00.960716 17669 slave.cpp:924] Agent terminating
3: I0828 21:20:00.969293 17685 master.cpp:1297] Agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(902)@172.17.0.3:46115
(5ca4a76bb68c) disconnected
3: I0828 21:20:00.969347 17685 master.cpp:3399] Disconnecting agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(902)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:00.969416 17685 master.cpp:3418] Deactivating agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 at slave(902)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:00.969825 17685 hierarchical.cpp:1037] Agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0 deactivated
3: I0828 21:20:01.070354 17669 master.cpp:1137] Master terminating
3: I0828 21:20:01.071156 17673 hierarchical.cpp:1013] Removed all filters for
agent cff62302-83f2-4586-b6a6-ec603af07f35-S0
3: I0828 21:20:01.071195 17673 hierarchical.cpp:890] Removed agent
cff62302-83f2-4586-b6a6-ec603af07f35-S0
3: [ OK ] ContentType/AgentAPITest.GetStateWithNonTerminalCompletedTask/0
(470 ms)
3: [ RUN ] ContentType/AgentAPITest.GetStateWithNonTerminalCompletedTask/1
3: I0828 21:20:01.118296 17669 cluster.cpp:177] Creating default 'local'
authorizer
3: I0828 21:20:01.122467 17671 master.cpp:440] Master
ae7cb5ee-5248-413c-9f32-4da778d2e3b7 (5ca4a76bb68c) started on 172.17.0.3:46115
3: I0828 21:20:01.122501 17671 master.cpp:443] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1000secs" --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/chizWG/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/chizWG/master" --zk_session_timeout="10secs"
3: I0828 21:20:01.122956 17671 master.cpp:492] Master only allowing
authenticated frameworks to register
3: I0828 21:20:01.122967 17671 master.cpp:498] Master only allowing
authenticated agents to register
3: I0828 21:20:01.122974 17671 master.cpp:504] Master only allowing
authenticated HTTP frameworks to register
3: I0828 21:20:01.122982 17671 credentials.hpp:37] Loading credentials for
authentication from '/tmp/chizWG/credentials'
3: I0828 21:20:01.123298 17671 master.cpp:548] Using default 'crammd5'
authenticator
3: I0828 21:20:01.123526 17671 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
3: I0828 21:20:01.123718 17671 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
3: I0828 21:20:01.123833 17671 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
3: I0828 21:20:01.123929 17671 master.cpp:629] Authorization enabled
3: I0828 21:20:01.124461 17678 hierarchical.cpp:474] Initialized hierarchical
allocator process
3: I0828 21:20:01.124614 17678 whitelist_watcher.cpp:77] No whitelist given
3: I0828 21:20:01.127687 17671 master.cpp:2170] Elected as the leading master!
3: I0828 21:20:01.128101 17671 master.cpp:1666] Recovering from registrar
3: I0828 21:20:01.128379 17678 registrar.cpp:339] Recovering registrar
3: I0828 21:20:01.129616 17678 registrar.cpp:383] Successfully fetched the
registry (0B) in 1184us
3: I0828 21:20:01.129810 17678 registrar.cpp:487] Applied 1 operations in
54748ns; attempting to update the registry
3: I0828 21:20:01.131137 17678 registrar.cpp:544] Successfully updated the
registry in 1.25184ms
3: I0828 21:20:01.131323 17678 registrar.cpp:416] Successfully recovered
registrar
3: I0828 21:20:01.132688 17677 hierarchical.cpp:513] Skipping recovery of
hierarchical allocator: nothing to recover
3: I0828 21:20:01.132838 17671 master.cpp:1819] Recovered 0 agents from the
registry (143B); allowing 10mins for agents to reregister
3: W0828 21:20:01.142704 17669 process.cpp:2877] Attempted to spawn already
running process files@172.17.0.3:46115
3: I0828 21:20:01.143836 17669 cluster.cpp:518] Creating default 'local'
authorizer
3: I0828 21:20:01.146584 17671 slave.cpp:267] Mesos agent started on
(903)@172.17.0.3:46115
3: I0828 21:20:01.146698 17671 slave.cpp:268] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/chizWG/Md3FLv/store/appc"
--authenticate_http_readonly="true" --authenticate_http_readwrite="false"
--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/chizWG/Md3FLv/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/chizWG/Md3FLv/store/docker"
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
--docker_volume_chown="false" --enforce_container_disk_quota="false"
--executor_registration_timeout="1mins"
--executor_reregistration_timeout="2secs"
--executor_shutdown_grace_period="0ns"
--fetcher_cache_dir="/tmp/chizWG/Md3FLv/fetch" --fetcher_cache_size="2GB"
--fetcher_stall_timeout="1mins"
--frameworks_home="/tmp/chizWG/Md3FLv/frameworks" --gc_delay="1weeks"
--gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false"
--help="false" --hostname_lookup="true" --http_command_executor="false"
--http_credentials="/tmp/chizWG/Md3FLv/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="posix"
--launcher_dir="/tmp/SRC/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/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_7FuiPe"
--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/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX"
--zk_session_timeout="10secs"
3: I0828 21:20:01.147424 17671 credentials.hpp:86] Loading credential for
authentication from '/tmp/chizWG/Md3FLv/credential'
3: I0828 21:20:01.147752 17671 slave.cpp:300] Agent using credential for:
test-principal
3: I0828 21:20:01.147856 17671 credentials.hpp:37] Loading credentials for
authentication from '/tmp/chizWG/Md3FLv/http_credentials'
3: I0828 21:20:01.148159 17671 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
3: W0828 21:20:01.149713 17669 process.cpp:2877] Attempted to spawn already
running process version@172.17.0.3:46115
3: I0828 21:20:01.149827 17671 disk_profile_adaptor.cpp:78] Creating default
disk profile adaptor module
3: I0828 21:20:01.151438 17671 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"}]
3: I0828 21:20:01.151770 17671 slave.cpp:623] Agent attributes: [ ]
3: I0828 21:20:01.151849 17671 slave.cpp:632] Agent hostname: 5ca4a76bb68c
3: I0828 21:20:01.152137 17680 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I0828 21:20:01.152348 17679 status_update_manager_process.hpp:379] Pausing
operation status update manager
3: I0828 21:20:01.154738 17684 state.cpp:67] Recovering state from
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta'
3: I0828 21:20:01.155251 17675 slave.cpp:7491] Finished recovering checkpointed
state from
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta',
beginning agent recovery
3: I0828 21:20:01.156108 17675 task_status_update_manager.cpp:207] Recovering
task status update manager
3: I0828 21:20:01.157891 17677 composing.cpp:339] Finished recovering all
containerizers
3: I0828 21:20:01.158354 17677 slave.cpp:7972] Recovering executors
3: I0828 21:20:01.158473 17677 slave.cpp:8125] Finished recovery
3: I0828 21:20:01.159694 17685 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I0828 21:20:01.159754 17671 status_update_manager_process.hpp:379] Pausing
operation status update manager
3: I0828 21:20:01.159698 17670 slave.cpp:1351] New master detected at
master@172.17.0.3:46115
3: I0828 21:20:01.159956 17670 slave.cpp:1416] Detecting new master
3: I0828 21:20:01.161885 17669 sched.cpp:239] Version: 1.9.0
3: I0828 21:20:01.162886 17681 sched.cpp:343] New master detected at
master@172.17.0.3:46115
3: I0828 21:20:01.163080 17681 sched.cpp:408] Authenticating with master
master@172.17.0.3:46115
3: I0828 21:20:01.163098 17681 sched.cpp:415] Using default CRAM-MD5
authenticatee
3: I0828 21:20:01.163859 17676 authenticatee.cpp:121] Creating new client SASL
connection
3: I0828 21:20:01.164345 17676 master.cpp:10617] Authenticating
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115
3: I0828 21:20:01.164510 17684 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1617)@172.17.0.3:46115
3: I0828 21:20:01.165109 17684 authenticator.cpp:98] Creating new server SASL
connection
3: I0828 21:20:01.165599 17684 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I0828 21:20:01.165704 17684 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I0828 21:20:01.165877 17670 authenticator.cpp:204] Received SASL
authentication start
3: I0828 21:20:01.166002 17670 authenticator.cpp:326] Authentication requires
more steps
3: I0828 21:20:01.166185 17684 authenticatee.cpp:259] Received SASL
authentication step
3: I0828 21:20:01.166374 17674 authenticator.cpp:232] Received SASL
authentication step
3: I0828 21:20:01.166455 17674 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '5ca4a76bb68c' server FQDN: '5ca4a76bb68c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I0828 21:20:01.166471 17674 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I0828 21:20:01.166532 17674 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I0828 21:20:01.166550 17674 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '5ca4a76bb68c' server FQDN: '5ca4a76bb68c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I0828 21:20:01.166559 17674 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I0828 21:20:01.166566 17674 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I0828 21:20:01.166581 17674 authenticator.cpp:318] Authentication success
3: I0828 21:20:01.166891 17674 master.cpp:10649] Successfully authenticated
principal 'test-principal' at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115
3: I0828 21:20:01.167027 17674 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1617)@172.17.0.3:46115
3: I0828 21:20:01.167546 17680 slave.cpp:1443] Authenticating with master
master@172.17.0.3:46115
3: I0828 21:20:01.167627 17680 slave.cpp:1452] Using default CRAM-MD5
authenticatee
3: I0828 21:20:01.188513 17684 authenticatee.cpp:299] Authentication success
3: I0828 21:20:01.189790 17684 authenticatee.cpp:121] Creating new client SASL
connection
3: I0828 21:20:01.190158 17671 sched.cpp:520] Successfully authenticated with
master master@172.17.0.3:46115
3: I0828 21:20:01.190194 17671 sched.cpp:835] Sending SUBSCRIBE call to
master@172.17.0.3:46115
3: I0828 21:20:01.190279 17673 master.cpp:10617] Authenticating
slave(903)@172.17.0.3:46115
3: I0828 21:20:01.190380 17671 sched.cpp:870] Will retry registration in
1.998323554secs if necessary
3: I0828 21:20:01.190695 17674 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1618)@172.17.0.3:46115
3: I0828 21:20:01.190791 17673 master.cpp:2910] Received SUBSCRIBE call for
framework 'default' at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115
3: I0828 21:20:01.190837 17673 master.cpp:2242] Authorizing framework principal
'test-principal' to receive offers for roles '{ * }'
3: I0828 21:20:01.191356 17672 authenticator.cpp:98] Creating new server SASL
connection
3: I0828 21:20:01.191711 17673 master.cpp:2997] Subscribing framework default
with checkpointing enabled and capabilities [ MULTI_ROLE,
RESERVATION_REFINEMENT ]
3: I0828 21:20:01.191897 17672 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I0828 21:20:01.191922 17672 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I0828 21:20:01.192026 17672 authenticator.cpp:204] Received SASL
authentication start
3: I0828 21:20:01.192085 17672 authenticator.cpp:326] Authentication requires
more steps
3: I0828 21:20:01.193646 17673 master.cpp:10847] Adding framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115 with roles { }
suppressed
3: I0828 21:20:01.194463 17673 sched.cpp:751] Framework registered with
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.194543 17673 sched.cpp:770] Scheduler::registered took 49876ns
3: I0828 21:20:01.194595 17683 authenticatee.cpp:259] Received SASL
authentication step
3: I0828 21:20:01.194768 17670 authenticator.cpp:232] Received SASL
authentication step
3: I0828 21:20:01.194810 17670 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '5ca4a76bb68c' server FQDN: '5ca4a76bb68c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I0828 21:20:01.194823 17670 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I0828 21:20:01.194885 17670 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I0828 21:20:01.194912 17670 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '5ca4a76bb68c' server FQDN: '5ca4a76bb68c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I0828 21:20:01.194922 17670 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I0828 21:20:01.194929 17670 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I0828 21:20:01.194945 17670 authenticator.cpp:318] Authentication success
3: I0828 21:20:01.195214 17682 hierarchical.cpp:605] Added framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.195327 17670 master.cpp:10649] Successfully authenticated
principal 'test-principal' at slave(903)@172.17.0.3:46115
3: I0828 21:20:01.195735 17683 authenticatee.cpp:299] Authentication success
3: I0828 21:20:01.195442 17679 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1618)@172.17.0.3:46115
3: I0828 21:20:01.195972 17682 hierarchical.cpp:1724] Performed allocation for
0 agents in 227224ns
3: I0828 21:20:01.199262 17682 slave.cpp:1543] Successfully authenticated with
master master@172.17.0.3:46115
3: I0828 21:20:01.199843 17682 slave.cpp:1993] Will retry registration in
11.057449ms if necessary
3: I0828 21:20:01.200347 17682 master.cpp:7088] Received register agent message
from slave(903)@172.17.0.3:46115 (5ca4a76bb68c)
3: I0828 21:20:01.200801 17682 master.cpp:4204] Authorizing agent providing
resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal
'test-principal'
3: I0828 21:20:01.202157 17685 master.cpp:7155] Authorized registration of
agent at slave(903)@172.17.0.3:46115 (5ca4a76bb68c)
3: I0828 21:20:01.202271 17685 master.cpp:7267] Registering agent at
slave(903)@172.17.0.3:46115 (5ca4a76bb68c) with id
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0
3: I0828 21:20:01.203125 17673 registrar.cpp:487] Applied 1 operations in
355571ns; attempting to update the registry
3: I0828 21:20:01.204645 17673 registrar.cpp:544] Successfully updated the
registry in 1.338112ms
3: I0828 21:20:01.204949 17679 master.cpp:7315] Admitted agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at slave(903)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:01.206027 17679 master.cpp:7360] Registered agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at slave(903)@172.17.0.3:46115
(5ca4a76bb68c) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I0828 21:20:01.206650 17679 hierarchical.cpp:854] Added agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 (5ca4a76bb68c) with cpus:2; mem:1024;
disk:1024; ports:[31000-32000] (allocated: {})
3: I0828 21:20:01.208184 17679 hierarchical.cpp:1724] Performed allocation for
1 agents in 1.28463ms
3: I0828 21:20:01.208986 17676 master.cpp:10432] Sending offers [
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-O0 ] to framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115
3: I0828 21:20:01.209723 17676 sched.cpp:934] Scheduler::resourceOffers took
118469ns
3: I0828 21:20:01.212617 17670 master.cpp:12724] Removing offer
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-O0
3: I0828 21:20:01.213268 17670 master.cpp:4741] Processing ACCEPT call for
offers: [ ae7cb5ee-5248-413c-9f32-4da778d2e3b7-O0 ] on agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at slave(903)@172.17.0.3:46115
(5ca4a76bb68c) for framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
(default) at scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115
3: I0828 21:20:01.213445 17670 master.cpp:3758] Authorizing framework principal
'test-principal' to launch task f222d2aa-2dd1-48fc-9973-3551d1ae5cf9
3: W0828 21:20:01.216207 17671 validation.cpp:1640] Executor 'default' for task
'f222d2aa-2dd1-48fc-9973-3551d1ae5cf9' uses less CPUs (None) than the minimum
required (0.01). Please update your executor, as this will be mandatory in
future releases.
3: W0828 21:20:01.216251 17671 validation.cpp:1652] Executor 'default' for task
'f222d2aa-2dd1-48fc-9973-3551d1ae5cf9' uses less memory (None) than the minimum
required (32MB). Please update your executor, as this will be mandatory in
future releases.
3: I0828 21:20:01.216780 17671 master.cpp:4276] Adding executor 'default' with
resources {} of framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default)
at scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115 on agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at slave(903)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:01.217046 17671 master.cpp:4302] Adding task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 with resources ports(allocated:
*):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated:
*):1024 of framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115 on agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at slave(903)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:01.217825 17671 master.cpp:5720] Launching task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115 with resources
[{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"},{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"}]
on agent ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at
slave(903)@172.17.0.3:46115 (5ca4a76bb68c) on new executor
3: I0828 21:20:01.218515 17671 hierarchical.cpp:1648] Allocation paused
3: I0828 21:20:01.218551 17671 hierarchical.cpp:1658] Allocation resumed
3: I0828 21:20:01.219192 17679 slave.cpp:1576] Registered with master
master@172.17.0.3:46115; given agent ID ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0
3: I0828 21:20:01.219326 17685 task_status_update_manager.cpp:188] Resuming
sending task status updates
3: I0828 21:20:01.219741 17679 slave.cpp:1611] Checkpointing SlaveInfo to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/slave.info'
3: I0828 21:20:01.220801 17681 status_update_manager_process.hpp:385] Resuming
operation status update manager
3: I0828 21:20:01.222082 17679 slave.cpp:1663] Forwarding agent update
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"3OWVpVedS1izR11SFcbxgg=="},"slave_id":{"value":"ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0"},"update_oversubscribed_resources":false}
3: I0828 21:20:01.223467 17679 slave.cpp:2130] Got assigned task
'f222d2aa-2dd1-48fc-9973-3551d1ae5cf9' for framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.224910 17679 slave.cpp:9916] Checkpointing FrameworkInfo to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/framework.info'
3: I0828 21:20:01.224359 17684 master.cpp:8487] Ignoring update on agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at slave(903)@172.17.0.3:46115
(5ca4a76bb68c) as it reports no changes
3: I0828 21:20:01.226536 17679 slave.cpp:9927] Checkpointing framework pid
'scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115' to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/framework.pid'
3: I0828 21:20:01.229657 17679 slave.cpp:2504] Authorizing task
'f222d2aa-2dd1-48fc-9973-3551d1ae5cf9' for framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.230481 17679 slave.cpp:9464] Authorizing framework principal
'test-principal' to launch task f222d2aa-2dd1-48fc-9973-3551d1ae5cf9
3: I0828 21:20:01.235488 17677 slave.cpp:2977] Launching task
'f222d2aa-2dd1-48fc-9973-3551d1ae5cf9' for framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.235622 17677 paths.cpp:817] Creating sandbox
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/4a2bfc64-27a0-4a61-b9dd-d82ff5a15602'
for user 'mesos'
3: I0828 21:20:01.237385 17677 slave.cpp:10714] Checkpointing ExecutorInfo to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/executor.info'
3: I0828 21:20:01.238138 17677 paths.cpp:820] Creating sandbox
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/4a2bfc64-27a0-4a61-b9dd-d82ff5a15602'
3: I0828 21:20:01.238432 17677 slave.cpp:10002] Launching executor 'default' of
framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 with resources [] in work
directory
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/4a2bfc64-27a0-4a61-b9dd-d82ff5a15602'
3: I0828 21:20:01.239845 17677 slave.cpp:10745] Checkpointing TaskInfo to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/4a2bfc64-27a0-4a61-b9dd-d82ff5a15602/tasks/f222d2aa-2dd1-48fc-9973-3551d1ae5cf9/task.info'
3: I0828 21:20:01.240880 17677 slave.cpp:3209] Queued task
'f222d2aa-2dd1-48fc-9973-3551d1ae5cf9' for executor 'default' of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.241765 17677 slave.cpp:3657] Launching container
4a2bfc64-27a0-4a61-b9dd-d82ff5a15602 for executor 'default' of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.242996 17676 slave.cpp:1084] Successfully attached
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/4a2bfc64-27a0-4a61-b9dd-d82ff5a15602'
to virtual path
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/latest'
3: W0828 21:20:01.243712 17676 process.cpp:2877] Attempted to spawn already
running process version@172.17.0.3:46115
3: I0828 21:20:01.244053 17676 exec.cpp:164] Version: 1.9.0
3: I0828 21:20:01.244758 17684 exec.cpp:213] Executor started at:
executor(201)@172.17.0.3:46115 with pid 17669
3: I0828 21:20:01.245295 17684 slave.cpp:5256] Got registration for executor
'default' of framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 from
executor(201)@172.17.0.3:46115
3: I0828 21:20:01.245501 17684 slave.cpp:5342] Checkpointing executor pid
'executor(201)@172.17.0.3:46115' to
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/4a2bfc64-27a0-4a61-b9dd-d82ff5a15602/pids/libprocess.pid'
3: I0828 21:20:01.250309 17684 slave.cpp:1084] Successfully attached
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/4a2bfc64-27a0-4a61-b9dd-d82ff5a15602'
to virtual path
'/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/latest'
3: I0828 21:20:01.250499 17684 slave.cpp:1084] Successfully attached
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/4a2bfc64-27a0-4a61-b9dd-d82ff5a15602'
to virtual path
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/4a2bfc64-27a0-4a61-b9dd-d82ff5a15602'
3: I0828 21:20:01.251039 17684 exec.cpp:237] Executor registered on agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0
3: I0828 21:20:01.251467 17684 exec.cpp:249] Executor::registered took 31562ns
3: I0828 21:20:01.252501 17670 slave.cpp:3427] Sending queued task
'f222d2aa-2dd1-48fc-9973-3551d1ae5cf9' to executor 'default' of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 at executor(201)@172.17.0.3:46115
3: I0828 21:20:01.253304 17670 exec.cpp:331] Executor asked to run task
'f222d2aa-2dd1-48fc-9973-3551d1ae5cf9'
3: I0828 21:20:01.253532 17670 exec.cpp:340] Executor::launchTask took 108865ns
3: I0828 21:20:01.253772 17670 exec.cpp:595] Executor sending status update
TASK_RUNNING (Status UUID: 33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6) for task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.254266 17670 slave.cpp:5737] Handling status update
TASK_RUNNING (Status UUID: 33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6) for task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 from executor(201)@172.17.0.3:46115
3: I0828 21:20:01.255676 17670 task_status_update_manager.cpp:328] Received
task status update TASK_RUNNING (Status UUID:
33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6) for task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.255820 17670 task_status_update_manager.cpp:507] Creating
StatusUpdate stream for task f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.256709 17670 task_status_update_manager.cpp:842]
Checkpointing UPDATE for task status update TASK_RUNNING (Status UUID:
33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6) for task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.257107 17670 task_status_update_manager.cpp:383] Forwarding
task status update TASK_RUNNING (Status UUID:
33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6) for task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 to the agent
3: I0828 21:20:01.257726 17670 slave.cpp:6276] Forwarding the update
TASK_RUNNING (Status UUID: 33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6) for task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 to master@172.17.0.3:46115
3: I0828 21:20:01.258095 17670 slave.cpp:6160] Task status update manager
successfully handled status update TASK_RUNNING (Status UUID:
33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6) for task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.258384 17670 slave.cpp:6187] Sending acknowledgement for
status update TASK_RUNNING (Status UUID: 33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6)
for task f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 to executor(201)@172.17.0.3:46115
3: I0828 21:20:01.258898 17675 master.cpp:8985] Status update TASK_RUNNING
(Status UUID: 33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6) for task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 from agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at slave(903)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:01.258983 17675 master.cpp:9042] Forwarding status update
TASK_RUNNING (Status UUID: 33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6) for task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.259256 17675 master.cpp:12073] Updating the state of task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
3: I0828 21:20:01.259639 17675 sched.cpp:1042] Scheduler::statusUpdate took
103508ns
3: I0828 21:20:01.260391 17669 slave.cpp:965] Unregistering and shutting down
3: I0828 21:20:01.260511 17669 slave.cpp:4062] Asked to shut down framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 by @0.0.0.0:0
3: I0828 21:20:01.260552 17669 slave.cpp:4087] Shutting down framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.260623 17669 slave.cpp:7222] Shutting down executor 'default'
of framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 at
executor(201)@172.17.0.3:46115
3: I0828 21:20:01.261039 17682 master.cpp:6695] Processing ACKNOWLEDGE call for
status 33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6 for task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115 on agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0
3: I0828 21:20:01.261489 17682 master.cpp:11638] Removing agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at slave(903)@172.17.0.3:46115
(5ca4a76bb68c): the agent unregistered
3: W0828 21:20:01.261924 17682 slave.cpp:4823] Dropping status update
acknowledgement message for ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 because
the agent is in TERMINATING state
3: I0828 21:20:01.262532 17682 registrar.cpp:487] Applied 1 operations in
148270ns; attempting to update the registry
3: I0828 21:20:01.263614 17682 registrar.cpp:544] Successfully updated the
registry in 899072ns
3: I0828 21:20:01.264173 17682 master.cpp:11680] Removed agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at slave(903)@172.17.0.3:46115
(5ca4a76bb68c): the agent unregistered
3: I0828 21:20:01.264600 17682 master.cpp:12073] Updating the state of task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (latest state: TASK_LOST, status
update state: TASK_LOST)
3: I0828 21:20:01.265098 17672 hierarchical.cpp:1013] Removed all filters for
agent ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0
3: I0828 21:20:01.265136 17672 hierarchical.cpp:890] Removed agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0
3: I0828 21:20:01.265350 17680 slave.cpp:7295] Killing executor 'default' of
framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 at
executor(201)@172.17.0.3:46115
3: I0828 21:20:01.265588 17682 master.cpp:12171] Removing task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 with resources ports(allocated:
*):[31000-32000]; cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated:
*):1024 of framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 on agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at slave(903)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:01.265883 17682 master.cpp:9037] Sending status update TASK_LOST
for task f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 'Agent 5ca4a76bb68c removed: the
agent unregistered'
3: I0828 21:20:01.266239 17682 master.cpp:12211] Removing executor 'default'
with resources {} of framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 on
agent ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 at slave(903)@172.17.0.3:46115
(5ca4a76bb68c)
3: I0828 21:20:01.266413 17672 sched.cpp:1042] Scheduler::statusUpdate took
66072ns
3: I0828 21:20:01.267894 17670 exec.cpp:412] Executor received status update
acknowledgement 33e4b1ac-c25b-4d0b-8f89-4b599b32a3d6 for task
f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.268393 17670 slave.cpp:6456] Got exited event for
executor(201)@172.17.0.3:46115
3: I0828 21:20:01.268508 17682 master.cpp:2087] Notifying framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115 of lost agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0 (5ca4a76bb68c)
3: I0828 21:20:01.268739 17685 sched.cpp:1104] Lost agent
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0
3: I0828 21:20:01.268811 17685 sched.cpp:1115] Scheduler::slaveLost took 24639ns
3: I0828 21:20:01.273079 17680 slave.cpp:6856] Executor 'default' of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 exited with status 0
3: I0828 21:20:01.273347 17680 slave.cpp:6967] Cleaning up executor 'default'
of framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 at
executor(201)@172.17.0.3:46115
3: I0828 21:20:01.273896 17683 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/4a2bfc64-27a0-4a61-b9dd-d82ff5a15602'
for gc 6.99999683149333days in the future
3: W0828 21:20:01.274164 17677 master.cpp:9294] Ignoring exited executor
'default' of framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 on removed
agent ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0
3: I0828 21:20:01.274180 17683 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default'
for gc 6.99999682752296days in the future
3: I0828 21:20:01.274376 17683 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default/runs/4a2bfc64-27a0-4a61-b9dd-d82ff5a15602'
for gc 6.9999968261363days in the future
3: I0828 21:20:01.274479 17683 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000/executors/default'
for gc 6.99999682518519days in the future
3: I0828 21:20:01.274515 17680 slave.cpp:7096] Cleaning up framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.274626 17683 task_status_update_manager.cpp:289] Closing task
status update streams for framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.274695 17683 task_status_update_manager.cpp:538] Cleaning up
status update stream for task f222d2aa-2dd1-48fc-9973-3551d1ae5cf9 of framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:01.274818 17673 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000'
for gc 6.99999682032296days in the future
3: I0828 21:20:01.275004 17673 gc.cpp:95] Scheduling
'/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_1_VlgVSX/meta/slaves/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-S0/frameworks/ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000'
for gc 6.99999681912days in the future
3: I0828 21:20:01.280330 17680 slave.cpp:924] Agent terminating
3: /tmp/SRC/src/tests/api_tests.cpp:6735: Failure
3: Failed to wait 15secs for shutdown
3: I0828 21:20:16.287364 17676 master.cpp:1412] Framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115 disconnected
3: I0828 21:20:16.287432 17676 master.cpp:3362] Deactivating framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115
3: I0828 21:20:16.287540 17676 master.cpp:3339] Disconnecting framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115
3: I0828 21:20:16.287602 17676 master.cpp:1427] Giving framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115 0ns to failover
3: I0828 21:20:16.287763 17672 hierarchical.cpp:711] Deactivated framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:16.289182 17677 master.cpp:10224] Framework failover timeout,
removing framework ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115
3: I0828 21:20:16.289222 17677 master.cpp:11223] Removing framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000 (default) at
scheduler-a6f54246-1aab-4e8b-bd9b-73f979c15bb3@172.17.0.3:46115
3: I0828 21:20:16.289757 17679 hierarchical.cpp:1648] Allocation paused
3: I0828 21:20:16.290469 17677 hierarchical.cpp:655] Removed framework
ae7cb5ee-5248-413c-9f32-4da778d2e3b7-0000
3: I0828 21:20:16.290524 17677 hierarchical.cpp:1658] Allocation resumed
3: /tmp/SRC/src/tests/api_tests.cpp:6730: Failure
3: Actual function call count doesn't match EXPECT_CALL(exec, shutdown(_))...
3: Expected: to be called once
3: Actual: never called - unsatisfied and active
3: I0828 21:20:16.296138 17669 master.cpp:1137] Master terminating
3: [ FAILED ]
ContentType/AgentAPITest.GetStateWithNonTerminalCompletedTask/1, where
GetParam() = application/json (15204 ms)
{code}
> AgentAPITest.GetStateWithNonTerminalCompletedTask is flaky
> ----------------------------------------------------------
>
> Key: MESOS-9923
> URL: https://issues.apache.org/jira/browse/MESOS-9923
> Project: Mesos
> Issue Type: Bug
> Reporter: Andrei Sekretenko
> Priority: Major
> Labels: containerization, flaky
>
> Observed in internal CI.
> {code}
> [ RUN ] ContentType/AgentAPITest.GetStateWithNonTerminalCompletedTask/0
> I0801 23:48:09.993656 27650 cluster.cpp:177] Creating default 'local'
> authorizer
> I0801 23:48:09.995075 13632 master.cpp:440] Master
> ba9ed547-f27b-4426-96f7-d93f854c62ae (ip-172-16-10-65.ec2.internal) started
> on 172.16.10.65:59528
> I0801 23:48:09.995096 13632 master.cpp:443] Flags at startup: --acls=""
> --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
> --allocation_interval="1000secs" --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/AhLctl/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/AhLctl/master" --zk_session_timeout="10secs"
> I0801 23:48:09.995235 13632 master.cpp:492] Master only allowing
> authenticated frameworks to register
> I0801 23:48:09.995242 13632 master.cpp:498] Master only allowing
> authenticated agents to register
> I0801 23:48:09.995247 13632 master.cpp:504] Master only allowing
> authenticated HTTP frameworks to register
> I0801 23:48:09.995252 13632 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/AhLctl/credentials'
> I0801 23:48:09.995324 13632 master.cpp:548] Using default 'crammd5'
> authenticator
> I0801 23:48:09.995362 13632 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-readonly'
> I0801 23:48:09.995391 13632 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-readwrite'
> I0801 23:48:09.995409 13632 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-scheduler'
> I0801 23:48:09.995426 13632 master.cpp:629] Authorization enabled
> I0801 23:48:09.995962 13632 hierarchical.cpp:241] Initialized hierarchical
> allocator process
> I0801 23:48:09.995999 13632 whitelist_watcher.cpp:77] No whitelist given
> I0801 23:48:09.996352 13632 master.cpp:2168] Elected as the leading master!
> I0801 23:48:09.996364 13632 master.cpp:1664] Recovering from registrar
> I0801 23:48:09.996434 13636 registrar.cpp:339] Recovering registrar
> I0801 23:48:09.996553 13636 registrar.cpp:383] Successfully fetched the
> registry (0B) in 103168ns
> I0801 23:48:09.996584 13636 registrar.cpp:487] Applied 1 operations in
> 6776ns; attempting to update the registry
> I0801 23:48:09.996692 13636 registrar.cpp:544] Successfully updated the
> registry in 94976ns
> I0801 23:48:09.996717 13636 registrar.cpp:416] Successfully recovered
> registrar
> I0801 23:48:09.996929 13632 master.cpp:1817] Recovered 0 agents from the
> registry (180B); allowing 10mins for agents to reregister
> I0801 23:48:09.996948 13636 hierarchical.cpp:280] Skipping recovery of
> hierarchical allocator: nothing to recover
> W0801 23:48:09.998728 27650 process.cpp:2877] Attempted to spawn already
> running process files@172.16.10.65:59528
> I0801 23:48:09.999023 27650 cluster.cpp:518] Creating default 'local'
> authorizer
> W0801 23:48:09.999817 27650 process.cpp:2877] Attempted to spawn already
> running process version@172.16.10.65:59528
> I0801 23:48:09.999938 13634 slave.cpp:267] Mesos agent started on
> (1122)@172.16.10.65:59528
> I0801 23:48:10.000281 13634 slave.cpp:268] Flags at startup: --acls=""
> --appc_simple_discovery_uri_prefix="http://";
> --appc_store_dir="/tmp/AhLctl/jeVIQy/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/AhLctl/jeVIQy/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/AhLctl/jeVIQy/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="0ns"
> --fetcher_cache_dir="/tmp/AhLctl/jeVIQy/fetch" --fetcher_cache_size="2GB"
> --fetcher_stall_timeout="1mins"
> --frameworks_home="/tmp/AhLctl/jeVIQy/frameworks" --gc_delay="1weeks"
> --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false"
> --help="false" --hostname_lookup="true" --http_command_executor="false"
> --http_credentials="/tmp/AhLctl/jeVIQy/http_credentials"
> --http_heartbeat_interval="30secs" --initialize_driver_logging="true"
> --isolation="posix/cpu,posix/mem"
> --jwt_secret_key="/tmp/AhLctl/jeVIQy/jwt_secret_key" --launcher="linux"
> --launcher_dir="/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-ubuntu-14.04/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/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_z31x3O"
> --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/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5"
> --zk_session_timeout="10secs"
> I0801 23:48:10.000499 13634 credentials.hpp:86] Loading credential for
> authentication from '/tmp/AhLctl/jeVIQy/credential'
> I0801 23:48:10.000691 13634 slave.cpp:300] Agent using credential for:
> test-principal
> I0801 23:48:10.000826 13634 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/AhLctl/jeVIQy/http_credentials'
> I0801 23:48:10.001021 13634 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-agent-executor'
> I0801 23:48:10.001186 13634 http.cpp:996] Creating default 'jwt' HTTP
> authenticator for realm 'mesos-agent-executor'
> I0801 23:48:10.001374 13634 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-agent-readonly'
> I0801 23:48:10.001539 13634 http.cpp:996] Creating default 'jwt' HTTP
> authenticator for realm 'mesos-agent-readonly'
> I0801 23:48:10.001704 13634 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-agent-readwrite'
> I0801 23:48:10.001917 13634 http.cpp:996] Creating default 'jwt' HTTP
> authenticator for realm 'mesos-agent-readwrite'
> I0801 23:48:10.002270 13634 disk_profile_adaptor.cpp:78] Creating default
> disk profile adaptor module
> I0801 23:48:10.002600 27650 sched.cpp:239] Version: 1.9.0
> I0801 23:48:10.002848 13638 sched.cpp:343] New master detected at
> master@172.16.10.65:59528
> I0801 23:48:10.002883 13638 sched.cpp:408] Authenticating with master
> master@172.16.10.65:59528
> I0801 23:48:10.002892 13638 sched.cpp:415] Using default CRAM-MD5
> authenticatee
> I0801 23:48:10.003152 13637 authenticatee.cpp:121] Creating new client SASL
> connection
> I0801 23:48:10.003396 13634 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 23:48:10.003455 13634 slave.cpp:623] Agent attributes: [ ]
> I0801 23:48:10.003463 13634 slave.cpp:632] Agent hostname:
> ip-172-16-10-65.ec2.internal
> I0801 23:48:10.003760 13637 master.cpp:10578] Authenticating
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528
> I0801 23:48:10.003895 13637 authenticator.cpp:414] Starting authentication
> session for crammd5-authenticatee(1977)@172.16.10.65:59528
> I0801 23:48:10.004032 13635 authenticator.cpp:98] Creating new server SASL
> connection
> I0801 23:48:10.004314 13633 task_status_update_manager.cpp:181] Pausing
> sending task status updates
> I0801 23:48:10.004338 13633 status_update_manager_process.hpp:379] Pausing
> operation status update manager
> I0801 23:48:10.004393 13631 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0801 23:48:10.004406 13631 authenticatee.cpp:239] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0801 23:48:10.004542 13634 authenticator.cpp:204] Received SASL
> authentication start
> I0801 23:48:10.004583 13634 authenticator.cpp:326] Authentication requires
> more steps
> I0801 23:48:10.004588 13632 state.cpp:67] Recovering state from
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta'
> I0801 23:48:10.004633 13635 slave.cpp:7444] Finished recovering checkpointed
> state from
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta',
> beginning agent recovery
> I0801 23:48:10.004691 13635 task_status_update_manager.cpp:207] Recovering
> task status update manager
> I0801 23:48:10.004880 13635 composing.cpp:339] Finished recovering all
> containerizers
> I0801 23:48:10.004941 13636 slave.cpp:7908] Recovering executors
> I0801 23:48:10.004967 13636 slave.cpp:8061] Finished recovery
> I0801 23:48:10.005252 13633 task_status_update_manager.cpp:181] Pausing
> sending task status updates
> I0801 23:48:10.005275 13633 status_update_manager_process.hpp:379] Pausing
> operation status update manager
> I0801 23:48:10.005252 13636 slave.cpp:1351] New master detected at
> master@172.16.10.65:59528
> I0801 23:48:10.005313 13636 slave.cpp:1416] Detecting new master
> I0801 23:48:10.004611 13634 authenticatee.cpp:259] Received SASL
> authentication step
> I0801 23:48:10.005597 13633 authenticator.cpp:232] Received SASL
> authentication step
> I0801 23:48:10.005614 13633 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'ip-172-16-10-65.ec2.internal' server FQDN:
> 'ip-172-16-10-65.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0801 23:48:10.005621 13633 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0801 23:48:10.005631 13633 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0801 23:48:10.005640 13633 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'ip-172-16-10-65.ec2.internal' server FQDN:
> 'ip-172-16-10-65.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0801 23:48:10.005646 13633 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0801 23:48:10.005652 13633 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0801 23:48:10.005664 13633 authenticator.cpp:318] Authentication success
> I0801 23:48:10.005718 13633 master.cpp:10610] Successfully authenticated
> principal 'test-principal' at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528
> I0801 23:48:10.005738 13633 authenticator.cpp:432] Authentication session
> cleanup for crammd5-authenticatee(1977)@172.16.10.65:59528
> I0801 23:48:10.007694 13632 slave.cpp:1443] Authenticating with master
> master@172.16.10.65:59528
> I0801 23:48:10.007717 13632 slave.cpp:1452] Using default CRAM-MD5
> authenticatee
> I0801 23:48:10.011816 13634 authenticatee.cpp:299] Authentication success
> I0801 23:48:10.011960 13632 authenticatee.cpp:121] Creating new client SASL
> connection
> I0801 23:48:10.012117 13638 sched.cpp:520] Successfully authenticated with
> master master@172.16.10.65:59528
> I0801 23:48:10.012130 13638 sched.cpp:835] Sending SUBSCRIBE call to
> master@172.16.10.65:59528
> I0801 23:48:10.012174 13638 sched.cpp:870] Will retry registration in
> 1.917744521secs if necessary
> I0801 23:48:10.012262 13635 master.cpp:2908] Received SUBSCRIBE call for
> framework 'default' at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528
> I0801 23:48:10.012281 13635 master.cpp:2240] Authorizing framework principal
> 'test-principal' to receive offers for roles '{ * }'
> I0801 23:48:10.012362 13635 master.cpp:10578] Authenticating
> slave(1122)@172.16.10.65:59528
> I0801 23:48:10.012420 13635 master.cpp:2995] Subscribing framework default
> with checkpointing enabled and capabilities [ MULTI_ROLE,
> RESERVATION_REFINEMENT ]
> I0801 23:48:10.012434 13636 authenticator.cpp:414] Starting authentication
> session for crammd5-authenticatee(1978)@172.16.10.65:59528
> I0801 23:48:10.012485 13636 authenticator.cpp:98] Creating new server SASL
> connection
> I0801 23:48:10.012857 13635 master.cpp:10808] Adding framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528 with roles
> { } suppressed
> I0801 23:48:10.012868 13634 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0801 23:48:10.012878 13634 authenticatee.cpp:239] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0801 23:48:10.012903 13634 authenticator.cpp:204] Received SASL
> authentication start
> I0801 23:48:10.012931 13634 authenticator.cpp:326] Authentication requires
> more steps
> I0801 23:48:10.012974 13634 sched.cpp:751] Framework registered with
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.012996 13634 sched.cpp:770] Scheduler::registered took 12016ns
> I0801 23:48:10.013003 13635 hierarchical.cpp:368] Added framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.013015 13634 authenticatee.cpp:259] Received SASL
> authentication step
> I0801 23:48:10.013042 13634 authenticator.cpp:232] Received SASL
> authentication step
> I0801 23:48:10.013047 13635 hierarchical.cpp:1508] Performed allocation for 0
> agents in 15293ns
> I0801 23:48:10.013053 13634 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'ip-172-16-10-65.ec2.internal' server FQDN:
> 'ip-172-16-10-65.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0801 23:48:10.013059 13634 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0801 23:48:10.013068 13634 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0801 23:48:10.013075 13634 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'ip-172-16-10-65.ec2.internal' server FQDN:
> 'ip-172-16-10-65.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0801 23:48:10.013082 13634 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0801 23:48:10.013087 13634 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0801 23:48:10.013098 13634 authenticator.cpp:318] Authentication success
> I0801 23:48:10.013132 13634 authenticatee.cpp:299] Authentication success
> I0801 23:48:10.013139 13638 master.cpp:10610] Successfully authenticated
> principal 'test-principal' at slave(1122)@172.16.10.65:59528
> I0801 23:48:10.013161 13638 authenticator.cpp:432] Authentication session
> cleanup for crammd5-authenticatee(1978)@172.16.10.65:59528
> I0801 23:48:10.013686 13634 slave.cpp:1543] Successfully authenticated with
> master master@172.16.10.65:59528
> I0801 23:48:10.013890 13631 master.cpp:7086] Received register agent message
> from slave(1122)@172.16.10.65:59528 (ip-172-16-10-65.ec2.internal)
> I0801 23:48:10.013960 13631 master.cpp:4202] Authorizing agent providing
> resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal
> 'test-principal'
> I0801 23:48:10.014089 13631 master.cpp:7153] Authorized registration of agent
> at slave(1122)@172.16.10.65:59528 (ip-172-16-10-65.ec2.internal)
> I0801 23:48:10.014118 13631 master.cpp:7265] Registering agent at
> slave(1122)@172.16.10.65:59528 (ip-172-16-10-65.ec2.internal) with id
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0
> I0801 23:48:10.014231 13631 registrar.cpp:487] Applied 1 operations in
> 35429ns; attempting to update the registry
> I0801 23:48:10.014349 13631 registrar.cpp:544] Successfully updated the
> registry in 101888ns
> I0801 23:48:10.014397 13631 master.cpp:7313] Admitted agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at slave(1122)@172.16.10.65:59528
> (ip-172-16-10-65.ec2.internal)
> I0801 23:48:10.014499 13631 master.cpp:7358] Registered agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at slave(1122)@172.16.10.65:59528
> (ip-172-16-10-65.ec2.internal) with cpus:2; mem:1024; disk:1024;
> ports:[31000-32000]
> I0801 23:48:10.014581 13631 hierarchical.cpp:617] Added agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 (ip-172-16-10-65.ec2.internal) with
> cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
> I0801 23:48:10.014814 13632 master.cpp:10393] Sending offers [
> ba9ed547-f27b-4426-96f7-d93f854c62ae-O0 ] to framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528
> I0801 23:48:10.014950 13632 sched.cpp:934] Scheduler::resourceOffers took
> 22407ns
> I0801 23:48:10.015086 13631 hierarchical.cpp:1508] Performed allocation for 1
> agents in 464279ns
> I0801 23:48:10.015185 13634 slave.cpp:1993] Will retry registration in
> 19.857824ms if necessary
> I0801 23:48:10.015347 13634 slave.cpp:1576] Registered with master
> master@172.16.10.65:59528; given agent ID
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0
> I0801 23:48:10.015393 13632 task_status_update_manager.cpp:188] Resuming
> sending task status updates
> I0801 23:48:10.015497 13634 slave.cpp:1611] Checkpointing SlaveInfo to
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/slave.info'
> I0801 23:48:10.015516 13638 status_update_manager_process.hpp:385] Resuming
> operation status update manager
> I0801 23:48:10.016136 13634 slave.cpp:1663] Forwarding agent update
> {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"izXdb7yjTI+Jt8xfgvVR9Q=="},"slave_id":{"value":"ba9ed547-f27b-4426-96f7-d93f854c62ae-S0"},"update_oversubscribed_resources":false}
> I0801 23:48:10.016438 13631 master.cpp:8457] Ignoring update on agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at slave(1122)@172.16.10.65:59528
> (ip-172-16-10-65.ec2.internal) as it reports no changes
> I0801 23:48:10.016716 13634 master.cpp:12685] Removing offer
> ba9ed547-f27b-4426-96f7-d93f854c62ae-O0
> I0801 23:48:10.016805 13634 master.cpp:4739] Processing ACCEPT call for
> offers: [ ba9ed547-f27b-4426-96f7-d93f854c62ae-O0 ] on agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at slave(1122)@172.16.10.65:59528
> (ip-172-16-10-65.ec2.internal) for framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528
> I0801 23:48:10.016844 13634 master.cpp:3756] Authorizing framework principal
> 'test-principal' to launch task 7ba022e2-a921-445c-90a6-1133bfec7e34
> W0801 23:48:10.017196 13637 validation.cpp:1640] Executor 'default' for task
> '7ba022e2-a921-445c-90a6-1133bfec7e34' uses less CPUs (None) than the minimum
> required (0.01). Please update your executor, as this will be mandatory in
> future releases.
> W0801 23:48:10.017215 13637 validation.cpp:1652] Executor 'default' for task
> '7ba022e2-a921-445c-90a6-1133bfec7e34' uses less memory (None) than the
> minimum required (32MB). Please update your executor, as this will be
> mandatory in future releases.
> I0801 23:48:10.017282 13637 master.cpp:4274] Adding executor 'default' with
> resources {} of framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default)
> at scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528 on agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at slave(1122)@172.16.10.65:59528
> (ip-172-16-10-65.ec2.internal)
> I0801 23:48:10.017313 13637 master.cpp:4300] Adding task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 with resources cpus(allocated: *):2;
> mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated:
> *):[31000-32000] of framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528 on agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at slave(1122)@172.16.10.65:59528
> (ip-172-16-10-65.ec2.internal)
> I0801 23:48:10.017408 13637 master.cpp:5718] Launching task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528 with
> resources
> [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
> on agent ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at
> slave(1122)@172.16.10.65:59528 (ip-172-16-10-65.ec2.internal) on new executor
> I0801 23:48:10.017588 13638 hierarchical.cpp:1432] Allocation paused
> I0801 23:48:10.017607 13638 hierarchical.cpp:1442] Allocation resumed
> I0801 23:48:10.017680 13637 slave.cpp:2130] Got assigned task
> '7ba022e2-a921-445c-90a6-1133bfec7e34' for framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.017745 13637 slave.cpp:9852] Checkpointing FrameworkInfo to
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/framework.info'
> I0801 23:48:10.017951 13637 slave.cpp:9863] Checkpointing framework pid
> 'scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528' to
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/framework.pid'
> I0801 23:48:10.019289 13637 slave.cpp:2504] Authorizing task
> '7ba022e2-a921-445c-90a6-1133bfec7e34' for framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.019320 13637 slave.cpp:9400] Authorizing framework principal
> 'test-principal' to launch task 7ba022e2-a921-445c-90a6-1133bfec7e34
> I0801 23:48:10.019901 13637 slave.cpp:2977] Launching task
> '7ba022e2-a921-445c-90a6-1133bfec7e34' for framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.019950 13637 paths.cpp:810] Creating sandbox
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/7b299798-f257-40fc-8586-9b3653116792'
> for user 'root'
> I0801 23:48:10.020830 13637 slave.cpp:10650] Checkpointing ExecutorInfo to
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/executor.info'
> I0801 23:48:10.021227 13637 paths.cpp:813] Creating sandbox
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/7b299798-f257-40fc-8586-9b3653116792'
> I0801 23:48:10.021468 13637 slave.cpp:9938] Launching executor 'default' of
> framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 with resources [] in work
> directory
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/7b299798-f257-40fc-8586-9b3653116792'
> I0801 23:48:10.021822 13637 slave.cpp:10681] Checkpointing TaskInfo to
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/7b299798-f257-40fc-8586-9b3653116792/tasks/7ba022e2-a921-445c-90a6-1133bfec7e34/task.info'
> I0801 23:48:10.023365 13637 slave.cpp:3203] Queued task
> '7ba022e2-a921-445c-90a6-1133bfec7e34' for executor 'default' of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.023617 13637 slave.cpp:1084] Successfully attached
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/7b299798-f257-40fc-8586-9b3653116792'
> to virtual path
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/latest'
> I0801 23:48:10.023661 13637 slave.cpp:1084] Successfully attached
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/7b299798-f257-40fc-8586-9b3653116792'
> to virtual path
> '/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/latest'
> I0801 23:48:10.023674 13637 slave.cpp:1084] Successfully attached
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/7b299798-f257-40fc-8586-9b3653116792'
> to virtual path
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/7b299798-f257-40fc-8586-9b3653116792'
> I0801 23:48:10.023810 13637 slave.cpp:3651] Launching container
> 7b299798-f257-40fc-8586-9b3653116792 for executor 'default' of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> W0801 23:48:10.024217 13637 process.cpp:2877] Attempted to spawn already
> running process version@172.16.10.65:59528
> I0801 23:48:10.024363 13637 exec.cpp:164] Version: 1.9.0
> I0801 23:48:10.024410 13632 exec.cpp:213] Executor started at:
> executor(204)@172.16.10.65:59528 with pid 27650
> I0801 23:48:10.024456 13632 slave.cpp:5222] Got registration for executor
> 'default' of framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 from
> executor(204)@172.16.10.65:59528
> I0801 23:48:10.024495 13632 slave.cpp:5308] Checkpointing executor pid
> 'executor(204)@172.16.10.65:59528' to
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/7b299798-f257-40fc-8586-9b3653116792/pids/libprocess.pid'
> I0801 23:48:10.025211 13635 exec.cpp:237] Executor registered on agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0
> I0801 23:48:10.025260 13635 exec.cpp:249] Executor::registered took 27772ns
> I0801 23:48:10.025485 13637 slave.cpp:3421] Sending queued task
> '7ba022e2-a921-445c-90a6-1133bfec7e34' to executor 'default' of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 at executor(204)@172.16.10.65:59528
> I0801 23:48:10.025606 13637 exec.cpp:331] Executor asked to run task
> '7ba022e2-a921-445c-90a6-1133bfec7e34'
> I0801 23:48:10.025635 13637 exec.cpp:340] Executor::launchTask took 16382ns
> I0801 23:48:10.025668 13637 exec.cpp:595] Executor sending status update
> TASK_RUNNING (Status UUID: 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.025749 13632 slave.cpp:5703] Handling status update
> TASK_RUNNING (Status UUID: 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 from
> executor(204)@172.16.10.65:59528
> I0801 23:48:10.025915 13631 task_status_update_manager.cpp:328] Received task
> status update TASK_RUNNING (Status UUID:
> 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.025933 13631 task_status_update_manager.cpp:507] Creating
> StatusUpdate stream for task 7ba022e2-a921-445c-90a6-1133bfec7e34 of
> framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.026168 13631 task_status_update_manager.cpp:842] Checkpointing
> UPDATE for task status update TASK_RUNNING (Status UUID:
> 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.026237 13631 task_status_update_manager.cpp:383] Forwarding
> task status update TASK_RUNNING (Status UUID:
> 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 to the agent
> I0801 23:48:10.026294 13631 slave.cpp:6229] Forwarding the update
> TASK_RUNNING (Status UUID: 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 to master@172.16.10.65:59528
> I0801 23:48:10.026373 13638 master.cpp:8946] Status update TASK_RUNNING
> (Status UUID: 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 from agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at slave(1122)@172.16.10.65:59528
> (ip-172-16-10-65.ec2.internal)
> I0801 23:48:10.026391 13638 master.cpp:9003] Forwarding status update
> TASK_RUNNING (Status UUID: 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.026437 13638 master.cpp:12034] Updating the state of task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (latest state: TASK_RUNNING, status
> update state: TASK_RUNNING)
> I0801 23:48:10.026468 13631 slave.cpp:6122] Task status update manager
> successfully handled status update TASK_RUNNING (Status UUID:
> 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.026484 13631 slave.cpp:6138] Sending acknowledgement for
> status update TASK_RUNNING (Status UUID:
> 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 to executor(204)@172.16.10.65:59528
> I0801 23:48:10.026504 13633 sched.cpp:1042] Scheduler::statusUpdate took
> 20738ns
> I0801 23:48:10.026595 13638 master.cpp:6693] Processing ACKNOWLEDGE call for
> status 8c67d57a-2391-4852-b3c7-cdb20efbd303 for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528 on agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0
> I0801 23:48:10.026664 13638 slave.cpp:965] Unregistering and shutting down
> I0801 23:48:10.026677 13638 slave.cpp:4056] Asked to shut down framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 by @0.0.0.0:0
> I0801 23:48:10.026684 13638 slave.cpp:4081] Shutting down framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.026690 13638 slave.cpp:7175] Shutting down executor 'default'
> of framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 at
> executor(204)@172.16.10.65:59528
> I0801 23:48:10.026729 13638 task_status_update_manager.cpp:401] Received task
> status update acknowledgement (UUID: 8c67d57a-2391-4852-b3c7-cdb20efbd303)
> for task 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.026751 13638 task_status_update_manager.cpp:842] Checkpointing
> ACK for task status update TASK_RUNNING (Status UUID:
> 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.026805 13638 master.cpp:11599] Removing agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at slave(1122)@172.16.10.65:59528
> (ip-172-16-10-65.ec2.internal): the agent unregistered
> I0801 23:48:10.026836 13638 slave.cpp:7248] Killing executor 'default' of
> framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 at
> executor(204)@172.16.10.65:59528
> I0801 23:48:10.026850 13638 slave.cpp:4832] Task status update manager
> successfully handled status update acknowledgement (UUID:
> 8c67d57a-2391-4852-b3c7-cdb20efbd303) for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.026890 13638 registrar.cpp:487] Applied 1 operations in
> 15225ns; attempting to update the registry
> I0801 23:48:10.026993 13631 exec.cpp:412] Executor received status update
> acknowledgement 8c67d57a-2391-4852-b3c7-cdb20efbd303 for task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.027046 13631 registrar.cpp:544] Successfully updated the
> registry in 144128ns
> I0801 23:48:10.027114 13631 slave.cpp:6409] Got exited event for
> executor(204)@172.16.10.65:59528
> I0801 23:48:10.027144 13631 slave.cpp:6809] Executor 'default' of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 exited with status 0
> I0801 23:48:10.027161 13638 master.cpp:11641] Removed agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at slave(1122)@172.16.10.65:59528
> (ip-172-16-10-65.ec2.internal): the agent unregistered
> I0801 23:48:10.027170 13631 slave.cpp:6920] Cleaning up executor 'default' of
> framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 at
> executor(204)@172.16.10.65:59528
> I0801 23:48:10.027194 13638 master.cpp:12034] Updating the state of task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (latest state: TASK_LOST, status
> update state: TASK_LOST)
> I0801 23:48:10.027281 13638 master.cpp:12132] Removing task
> 7ba022e2-a921-445c-90a6-1133bfec7e34 with resources cpus(allocated: *):2;
> mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated:
> *):[31000-32000] of framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 on
> agent ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at
> slave(1122)@172.16.10.65:59528 (ip-172-16-10-65.ec2.internal)
> I0801 23:48:10.027335 13638 master.cpp:8998] Sending status update TASK_LOST
> for task 7ba022e2-a921-445c-90a6-1133bfec7e34 of framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 'Agent ip-172-16-10-65.ec2.internal
> removed: the agent unregistered'
> I0801 23:48:10.027374 13638 master.cpp:12172] Removing executor 'default'
> with resources {} of framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 on
> agent ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 at
> slave(1122)@172.16.10.65:59528 (ip-172-16-10-65.ec2.internal)
> I0801 23:48:10.027420 13631 slave.cpp:7049] Cleaning up framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.027460 13638 master.cpp:2085] Notifying framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528 of lost
> agent ba9ed547-f27b-4426-96f7-d93f854c62ae-S0 (ip-172-16-10-65.ec2.internal)
> I0801 23:48:10.027485 13631 slave.cpp:924] Agent terminating
> W0801 23:48:10.027509 13638 master.cpp:9255] Ignoring exited executor
> 'default' of framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 on removed
> agent ba9ed547-f27b-4426-96f7-d93f854c62ae-S0
> I0801 23:48:10.027611 13632 gc.cpp:95] Scheduling
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/7b299798-f257-40fc-8586-9b3653116792'
> for gc 6.9999996843763days in the future
> I0801 23:48:10.027644 13638 hierarchical.cpp:775] Removed all filters for
> agent ba9ed547-f27b-4426-96f7-d93f854c62ae-S0
> I0801 23:48:10.027649 13632 gc.cpp:95] Scheduling
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default'
> for gc 6.99999968364444days in the future
> I0801 23:48:10.027654 13638 hierarchical.cpp:650] Removed agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0
> I0801 23:48:10.027673 13632 gc.cpp:95] Scheduling
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default/runs/7b299798-f257-40fc-8586-9b3653116792'
> for gc 6.99999968328593days in the future
> I0801 23:48:10.027698 13632 gc.cpp:95] Scheduling
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000/executors/default'
> for gc 6.99999968302222days in the future
> I0801 23:48:10.027721 13632 gc.cpp:95] Scheduling
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000'
> for gc 6.99999968223407days in the future
> I0801 23:48:10.027798 13632 gc.cpp:95] Scheduling
> '/tmp/ContentType_AgentAPITest_GetStateWithNonTerminalCompletedTask_0_nNgng5/meta/slaves/ba9ed547-f27b-4426-96f7-d93f854c62ae-S0/frameworks/ba9ed547-f27b-4426-96f7-d93f854c62ae-0000'
> for gc 6.99999968202667days in the future
> I0801 23:48:10.027812 13638 sched.cpp:1042] Scheduler::statusUpdate took
> 9674ns
> I0801 23:48:10.027824 13632 task_status_update_manager.cpp:289] Closing task
> status update streams for framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.027833 13632 task_status_update_manager.cpp:538] Cleaning up
> status update stream for task 7ba022e2-a921-445c-90a6-1133bfec7e34 of
> framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:10.027840 13638 sched.cpp:1104] Lost agent
> ba9ed547-f27b-4426-96f7-d93f854c62ae-S0
> I0801 23:48:10.027856 13638 sched.cpp:1115] Scheduler::slaveLost took 7643ns
> ../../src/tests/api_tests.cpp:7085: Failure
> Failed to wait 15secs for shutdown
> I0801 23:48:25.029498 13635 master.cpp:1410] Framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528 disconnected
> I0801 23:48:25.029528 13635 master.cpp:3360] Deactivating framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528
> I0801 23:48:25.029554 13635 master.cpp:3337] Disconnecting framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528
> I0801 23:48:25.029567 13635 master.cpp:1425] Giving framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528 0ns to
> failover
> I0801 23:48:25.029685 13637 hierarchical.cpp:475] Deactivated framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:25.029685 13636 master.cpp:10185] Framework failover timeout,
> removing framework ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528
> I0801 23:48:25.029711 13636 master.cpp:11184] Removing framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000 (default) at
> scheduler-578a9bfc-813a-4924-ada5-f0f6431f4b0c@172.16.10.65:59528
> I0801 23:48:25.029824 13636 hierarchical.cpp:1432] Allocation paused
> I0801 23:48:25.029880 13636 hierarchical.cpp:417] Removed framework
> ba9ed547-f27b-4426-96f7-d93f854c62ae-0000
> I0801 23:48:25.029903 13636 hierarchical.cpp:1442] Allocation resumed
> ../../src/tests/api_tests.cpp:7080: Failure
> Actual function call count doesn't match EXPECT_CALL(exec, shutdown(_))...
> Expected: to be called once
> Actual: never called - unsatisfied and active
> I0801 23:48:25.032428 27650 master.cpp:1135] Master terminating
> [ FAILED ] ContentType/AgentAPITest.GetStateWithNonTerminalCompletedTask/0,
> where GetParam() = application/x-protobuf (15051 ms)
> {code}
--
This message was sent by Atlassian Jira
(v8.3.2#803003)
