[
https://issues.apache.org/jira/browse/MESOS-7742?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Alexander Rukletsov updated MESOS-7742:
---------------------------------------
Description:
Observed this on ASF CI and internal Mesosphere CI. Affected tests:
AgentAPIStreamingTest.AttachInputToNestedContainerSession
AgentAPITest.LaunchNestedContainerSession
{code}
[ RUN ]
ContentType/AgentAPIStreamingTest.AttachInputToNestedContainerSession/0
I0629 05:49:33.180673 25301 cluster.cpp:162] Creating default 'local' authorizer
I0629 05:49:33.182234 25306 master.cpp:436] Master
90ea1640-bdf3-49ba-b78f-b2ba7ea30077 (296af9b598c3) started on 172.17.0.3:45726
I0629 05:49:33.182289 25306 master.cpp:438] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1secs" -
-allocator="HierarchicalDRF" --authenticate_agents="true"
--authenticate_frameworks="true" --authenticate_http_frameworks="true"
--authenticate_http_readonly="true" --au
thenticate_http_readwrite="true" --authenticators="crammd5"
--authorizers="local" --credentials="/tmp/a5h5J3/credentials"
--framework_sorter="drf" --help="false" --hostn
ame_lookup="true" --http_authenticators="basic"
--http_framework_authenticators="basic" --initialize_driver_logging="true"
--log_auto_initialize="true" --logbufsecs="0"
--logging_level="INFO" --max_agent_ping_timeouts="5"
--max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
--max_unreachable_tasks_per_framework="10
00" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%"
--registry="in_memory" --registry_fetch_timeout="1mins"
--registry_gc_interval="15mins" --registr
y_max_agent_age="2weeks" --registry_max_agent_count="102400"
--registry_store_timeout="100secs" --registry_strict="false"
--root_submissions="true" --user_sorter="drf" -
-version="false" --webui_dir="/usr/local/share/mesos/webui"
--work_dir="/tmp/a5h5J3/master" --zk_session_timeout="10secs"
I0629 05:49:33.182561 25306 master.cpp:488] Master only allowing authenticated
frameworks to register
I0629 05:49:33.182610 25306 master.cpp:502] Master only allowing authenticated
agents to register
I0629 05:49:33.182636 25306 master.cpp:515] Master only allowing authenticated
HTTP frameworks to register
I0629 05:49:33.182656 25306 credentials.hpp:37] Loading credentials for
authentication from '/tmp/a5h5J3/credentials'
I0629 05:49:33.182915 25306 master.cpp:560] Using default 'crammd5'
authenticator
I0629 05:49:33.183009 25306 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
I0629 05:49:33.183151 25306 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
I0629 05:49:33.183218 25306 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
I0629 05:49:33.183284 25306 master.cpp:640] Authorization enabled
I0629 05:49:33.183462 25309 hierarchical.cpp:158] Initialized hierarchical
allocator process
I0629 05:49:33.183504 25309 whitelist_watcher.cpp:77] No whitelist given
I0629 05:49:33.184311 25308 master.cpp:2161] Elected as the leading master!
I0629 05:49:33.184341 25308 master.cpp:1700] Recovering from registrar
I0629 05:49:33.184404 25308 registrar.cpp:345] Recovering registrar
I0629 05:49:33.184622 25308 registrar.cpp:389] Successfully fetched the
registry (0B) in 183040ns
I0629 05:49:33.184687 25308 registrar.cpp:493] Applied 1 operations in 6441ns;
attempting to update the registry
I0629 05:49:33.184885 25304 registrar.cpp:550] Successfully updated the
registry in 147200ns
I0629 05:49:33.184993 25304 registrar.cpp:422] Successfully recovered registrar
I0629 05:49:33.185148 25308 master.cpp:1799] Recovered 0 agents from the
registry (129B); allowing 10mins for agents to re-register
I0629 05:49:33.185161 25302 hierarchical.cpp:185] Skipping recovery of
hierarchical allocator: nothing to recover
I0629 05:49:33.186769 25301 containerizer.cpp:221] Using isolation:
posix/cpu,posix/mem,filesystem/posix,network/cni
W0629 05:49:33.187232 25301 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
W0629 05:49:33.187363 25301 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
I0629 05:49:33.187396 25301 provisioner.cpp:249] Using default backend 'copy'
I0629 05:49:33.189133 25301 cluster.cpp:448] Creating default 'local' authorizer
I0629 05:49:33.189707 25306 slave.cpp:231] Mesos agent started on
(644)@172.17.0.3:45726
I0629 05:49:33.189741 25306 slave.cpp:232] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authenticatee="crammd5"
--authentication_backoff_factor="1secs" --authorizer="local"
--cgroups_cpu_enable_pids_and_tids_count="false" --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/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/credential"
--default_role="*" --disk_watch_interval="1mins" --docker="docker"
--docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io";
--docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock"
--docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker"
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volu:
me" --enforce_container_disk_quota="false"
--executor_registration_timeout="1mins"
--executor_reregistration_timeout="2secs"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/fetch"
--fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks"
--gc_disk_headroom="0.1" --hadoop_home="" --help="false"
--hostname_lookup="true" --http_command_executor="false"
--http_credentials="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="posix"
--launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150"
--oversubscribed_resources_interval="15secs" --perf_duration="10secs"
--perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns"
--quiet="false" --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_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ"
--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_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw"
I0629 05:49:33.190001 25306 credentials.hpp:86] Loading credential for
authentication from
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/credential'
I0629 05:49:33.190135 25306 slave.cpp:264] Agent using credential for:
test-principal
I0629 05:49:33.190228 25306 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/http_credentials'
I0629 05:49:33.190445 25306 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
I0629 05:49:33.190563 25306 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0629 05:49:33.191004 25301 sched.cpp:232] Version: 1.3.0
I0629 05:49:33.191077 25306 slave.cpp:531] Agent resources: cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0629 05:49:33.191150 25306 slave.cpp:539] Agent attributes: [ ]
I0629 05:49:33.191172 25306 slave.cpp:544] Agent hostname: 296af9b598c3
I0629 05:49:33.191313 25302 sched.cpp:336] New master detected at
master@172.17.0.3:45726
I0629 05:49:33.191349 25302 sched.cpp:407] Authenticating with master
master@172.17.0.3:45726
I0629 05:49:33.191433 25302 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0629 05:49:33.191622 25302 authenticatee.cpp:121] Creating new client SASL
connection
I0629 05:49:33.191917 25302 master.cpp:7475] Authenticating
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.192019 25302 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1229)@172.17.0.3:45726
I0629 05:49:33.192194 25302 authenticator.cpp:98] Creating new server SASL
connection
I0629 05:49:33.192387 25302 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0629 05:49:33.192411 25302 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0629 05:49:33.192445 25302 authenticator.cpp:204] Received SASL authentication
start
I0629 05:49:33.192512 25302 authenticator.cpp:326] Authentication requires more
steps
I0629 05:49:33.192553 25302 authenticatee.cpp:259] Received SASL authentication
step
I0629 05:49:33.192591 25302 authenticator.cpp:232] Received SASL authentication
step
I0629 05:49:33.192699 25302 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0629 05:49:33.192715 25302 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0629 05:49:33.192823 25302 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0629 05:49:33.192849 25302 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0629 05:49:33.192932 25302 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0629 05:49:33.192996 25302 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0629 05:49:33.193013 25302 authenticator.cpp:318] Authentication success
I0629 05:49:33.193075 25308 authenticatee.cpp:299] Authentication success
I0629 05:49:33.193120 25307 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1229)@172.17.0.3:45726
I0629 05:49:33.193137 25308 status_update_manager.cpp:177] Pausing sending
status updates
I0629 05:49:33.193213 25302 master.cpp:7505] Successfully authenticated
principal 'test-principal' at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.193248 25308 sched.cpp:513] Successfully authenticated with
master master@172.17.0.3:45726
I0629 05:49:33.193265 25308 sched.cpp:836] Sending SUBSCRIBE call to
master@172.17.0.3:45726
I0629 05:49:33.193306 25308 sched.cpp:869] Will retry registration in
250.898986ms if necessary
I0629 05:49:33.193398 25308 master.cpp:2813] Received SUBSCRIBE call for
framework 'default' at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.193424 25308 master.cpp:2197] Authorizing framework principal
'test-principal' to receive offers for roles '{ * }'
I0629 05:49:33.193763 25305 state.cpp:62] Recovering state from
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/meta'
I0629 05:49:33.193764 25306 master.cpp:2890] Subscribing framework default with
checkpointing disabled and capabilities [ ]
I0629 05:49:33.194470 25309 status_update_manager.cpp:203] Recovering status
update manager
I0629 05:49:33.194608 25306 sched.cpp:759] Framework registered with
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.194656 25306 sched.cpp:773] Scheduler::registered took 13886ns
I0629 05:49:33.194751 25307 hierarchical.cpp:273] Added framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.194782 25308 containerizer.cpp:608] Recovering containerizer
I0629 05:49:33.194805 25307 hierarchical.cpp:1850] No allocations performed
I0629 05:49:33.194825 25307 hierarchical.cpp:1940] No inverse offers to send
out!
I0629 05:49:33.194835 25307 hierarchical.cpp:1434] Performed allocation for 0
agents in 37750ns
I0629 05:49:33.195451 25302 provisioner.cpp:410] Provisioner recovery complete
I0629 05:49:33.195629 25302 slave.cpp:6075] Finished recovery
I0629 05:49:33.196087 25302 slave.cpp:6257] Querying resource estimator for
oversubscribable resources
I0629 05:49:33.196205 25307 slave.cpp:6271] Received oversubscribable resources
{} from the resource estimator
I0629 05:49:33.196358 25302 slave.cpp:924] New master detected at
master@172.17.0.3:45726
I0629 05:49:33.196447 25308 status_update_manager.cpp:177] Pausing sending
status updates
I0629 05:49:33.196465 25302 slave.cpp:959] Detecting new master
I0629 05:49:33.200856 25302 slave.cpp:986] Authenticating with master
master@172.17.0.3:45726
I0629 05:49:33.200942 25302 slave.cpp:997] Using default CRAM-MD5 authenticatee
I0629 05:49:33.201126 25309 authenticatee.cpp:121] Creating new client SASL
connection
I0629 05:49:33.201560 25309 master.cpp:7475] Authenticating
slave(644)@172.17.0.3:45726
I0629 05:49:33.201704 25309 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1230)@172.17.0.3:45726
I0629 05:49:33.201792 25302 authenticator.cpp:98] Creating new server SASL
connection
I0629 05:49:33.202373 25302 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0629 05:49:33.202396 25302 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0629 05:49:33.202430 25302 authenticator.cpp:204] Received SASL authentication
start
I0629 05:49:33.202487 25302 authenticator.cpp:326] Authentication requires more
steps
I0629 05:49:33.202584 25302 authenticatee.cpp:259] Received SASL authentication
step
I0629 05:49:33.202633 25302 authenticator.cpp:232] Received SASL authentication
step
I0629 05:49:33.202648 25302 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0629 05:49:33.202656 25302 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0629 05:49:33.202678 25302 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0629 05:49:33.202693 25302 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
SASL_AUXPROP_VERIF:
Y_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0629 05:49:33.202698 25302 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0629 05:49:33.202702 25302 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0629 05:49:33.202713 25302 authenticator.cpp:318] Authentication success
I0629 05:49:33.202810 25308 master.cpp:7505] Successfully authenticated
principal 'test-principal' at slave(644)@172.17.0.3:45726
I0629 05:49:33.202847 25307 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1230)@172.17.0.3:45726
I0629 05:49:33.202766 25302 authenticatee.cpp:299] Authentication success
I0629 05:49:33.202999 25302 slave.cpp:1081] Successfully authenticated with
master master@172.17.0.3:45726
I0629 05:49:33.203225 25302 slave.cpp:1509] Will retry registration in
6.854069ms if necessary
I0629 05:49:33.203373 25309 master.cpp:5429] Received register agent message
from slave(644)@172.17.0.3:45726 (296af9b598c3)
I0629 05:49:33.203433 25309 master.cpp:3659] Authorizing agent with principal
'test-principal'
I0629 05:49:33.203737 25306 master.cpp:5564] Registering agent at
slave(644)@172.17.0.3:45726 (296af9b598c3) with id
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
I0629 05:49:33.204012 25308 registrar.cpp:493] Applied 1 operations in 28157ns;
attempting to update the registry
I0629 05:49:33.204355 25303 registrar.cpp:550] Successfully updated the
registry in 277248ns
I0629 05:49:33.204691 25303 master.cpp:5639] Registered agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0629 05:49:33.204764 25303 slave.cpp:4794] Received ping from
slave-observer(589)@172.17.0.3:45726
I0629 05:49:33.204795 25308 hierarchical.cpp:525] Added agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 (296af9b598c3) with cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I0629 05:49:33.204876 25303 slave.cpp:1127] Registered with master
master@172.17.0.3:45726; given agent ID 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
I0629 05:49:33.204895 25303 fetcher.cpp:94] Clearing fetcher cache
I0629 05:49:33.205031 25309 status_update_manager.cpp:184] Resuming sending
status updates
I0629 05:49:33.205252 25303 slave.cpp:1155] Checkpointing SlaveInfo to
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/meta/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/slave.info'
I0629 05:49:33.205269 25308 hierarchical.cpp:1940] No inverse offers to send
out!
I0629 05:49:33.205291 25308 hierarchical.cpp:1434] Performed allocation for 1
agents in 251549ns
I0629 05:49:33.205541 25309 master.cpp:7305] Sending 1 offers to framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.205585 25303 slave.cpp:1193] Forwarding total oversubscribed
resources {}
I0629 05:49:33.205760 25309 master.cpp:6324] Received update of agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3) with total oversubscribed resources {}
I0629 05:49:33.205921 25308 sched.cpp:933] Scheduler::resourceOffers took
54996ns
I0629 05:49:33.206763 25304 master.cpp:3875] Processing ACCEPT call for offers:
[ 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-O0 ] on agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3) for framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
(default) at scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.206811 25304 master.cpp:3426] Authorizing framework principal
'test-principal' to launch task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b
I0629 05:49:33.207425 25304 master.cpp:9320] Adding task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b with resources cpus(*)(allocated: *):2;
mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated:
*):[31000-32000] on agent 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at
slave(644)@172.17.0.3:45726 (296af9b598c3)
I0629 05:49:33.207504 25304 master.cpp:4531] Launching task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 with resources
cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024;
ports(*)(allocated: *):[31000-32000] on agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3)
I0629 05:49:33.207877 25302 slave.cpp:1619] Got assigned task
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.208356 25304 hierarchical.cpp:850] Updated allocation of
framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 on agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077:
-S0 from cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated:
*):1024; ports(*)(allocated: *):[31000-32000] to cpus(*)(allocated: *):2;
mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated:
*):[31000-32000]
I0629 05:49:33.208642 25302 slave.cpp:1900] Authorizing task
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.208668 25302 slave.cpp:6694] Authorizing framework principal
'test-principal' to launch task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b
I0629 05:49:33.208978 25302 slave.cpp:2087] Launching task
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.209475 25302 paths.cpp:573] Trying to chown
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
to user 'mesos'
I0629 05:49:33.209678 25302 slave.cpp:7038] Launching executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 with resources cpus(*)(allocated:
*):0.1; mem(*)(allocated: *):32 in work directory
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
I0629 05:49:33.210337 25302 slave.cpp:2316] Queued task
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.210480 25304 containerizer.cpp:1001] Starting container
b36e964b-c357-4f62-a767-029668d71ff6 for executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.212021 25304 containerizer.cpp:1531] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.3:45726"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw\/slaves\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0\/frameworks\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000\/executors\/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b\/runs\/b36e964b-c357-4f62-a767-029668d71ff6"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"ee05c102-e5cb-4cc2-9fb4-41fe1e06446b"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(644)@172.17.0.3:45726"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw\/slaves\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0\/frameworks\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000\/executors\/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b\/runs\/b36e964b-c357-4f62-a767-029668d71ff6"}]},"user":"mesos","working_directory":"\/tmp\/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw\/slaves\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0\/frameworks\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000\/executors\/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b\/runs\/b36e964b-c357-4f62-a767-029668d71ff6"}"
--pipe_read="8" --pipe_write="9"
--runtime_directory="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/containers/b36e964b-c357-4f62-a767-029668d71ff6"
--unshare_namespace_mnt="false"'
I0629 05:49:33.212301 25302 slave.cpp:877] Successfully attached file
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
I0629 05:49:33.214748 25304 launcher.cpp:140] Forked child with pid '28869' for
container 'b36e964b-c357-4f62-a767-029668d71ff6'
I0629 05:49:33.219424 25305 fetcher.cpp:353] Starting to fetch URIs for
container: b36e964b-c357-4f62-a767-029668d71ff6, directory:
/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6
I0629 05:49:33.335734 25303 slave.cpp:3790] Got registration for executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 from executor(1)@172.17.0.3:40357
I0629 05:49:33.337357 25306 slave.cpp:2529] Sending queued task
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' to executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 at executor(1)@172.17.0.3:40357
I0629 05:49:33.344734 25305 slave.cpp:4264] Handling status update TASK_RUNNING
(UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 from executor(1)@172.17.0.3:40357
I0629 05:49:33.346091 25306 status_update_manager.cpp:323] Received status
update TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9:
fb4-41fe1e06446b of framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.346123 25306 status_update_manager.cpp:500] Creating
StatusUpdate stream for task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.346360 25306 status_update_manager.cpp:377] Forwarding update
TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 to the agent
I0629 05:49:33.346629 25306 slave.cpp:4704] Forwarding the update TASK_RUNNING
(UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 to master@172.17.0.3:45726
I0629 05:49:33.346786 25306 slave.cpp:4598] Status update manager successfully
handled status update TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07)
for task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.346828 25306 slave.cpp:4614] Sending acknowledgement for status
update TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 to executor(1)@172.17.0.3:40357
I0629 05:49:33.347121 25307 master.cpp:6469] Status update TASK_RUNNING (UUID:
3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 from agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3)
I0629 05:49:33.347162 25307 master.cpp:6537] Forwarding status update
TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.347309 25307 master.cpp:8568] Updating the state of task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
I0629 05:49:33.347633 25304 sched.cpp:1041] Scheduler::statusUpdate took 82630ns
I0629 05:49:33.347909 25309 master.cpp:5194] Processing ACKNOWLEDGE call
3aa0c8c0-c78f-4c72-a638-ef2adf1eae07 for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 on agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
I0629 05:49:33.348162 25307 status_update_manager.cpp:395] Received status
update acknowledgement (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.348284 25307 slave.cpp:3510] Status update manager successfully
handled status update acknowledgement (UUID:
3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.349153 25307 process.cpp:3731] Handling HTTP event for process
'slave(644)' with path: '/slave(644)/api/v1'
I0629 05:49:33.349717 25305 http.cpp:1115] HTTP POST for /slave(644)/api/v1
from 172.17.0.3:38460
I0629 05:49:33.350256 25305 http.cpp:527] Processing call
LAUNCH_NESTED_CONTAINER_SESSION
I0629 05:49:33.350522 25303 containerizer.cpp:1798] Starting nested container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.351016 25303 containerizer.cpp:1822] Trying to chown
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b'
to user 'mesos'
I0629 05:49:33.352535 25309 switchboard.cpp:545] Launching
'mesos-io-switchboard' with flags '--heartbeat_interval="30secs" --help="false"
--socket_address="/tmp/mesos-io-switchboard-8a787e7f-51e0-4f96-a310-73423d54dbd5"
--stderr_from_fd="16" --stderr_to_fd="2" --stdin_to_fd="13"
--stdout_from_fd="14" --stdout_to_fd="1" --tty="false"
--wait_for_connection="true"' for container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.355439 25309 switchboard.cpp:575] Created I/O switchboard server
(pid: 28881) listening on socket file
'/tmp/mesos-io-switchboard-8a787e7f-51e0-4f96-a310-73423d54dbd5' for container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.356899 25309 containerizer.cpp:1531] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"shell":true,"value":"cat"},"environment":{},"user":"mesos"}"
--pipe_read="13" --pipe_write="14"
--runtime_directory="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/containers/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b"
--unshare_namespace_mnt="false"'
I0629 05:49:33.358389 25309 launcher.cpp:140] Forked child with pid '28882' for
container
'b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b'
I0629 05:49:33.362704 25308 fetcher.cpp:353] Starting to fetch URIs for
container:
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b,
directory:
/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.419852 25302 process.cpp:3731] Handling HTTP event for process
'slave(644)' with path: '/slave(644)/api/v1'
I0629 05:49:33.420730 25302 http.cpp:1115] HTTP POST for /slave(644)/api/v1
from 172.17.0.3:38462
I0629 05:49:33.421162 25308 http.cpp:527] Processing call ATTACH_CONTAINER_INPUT
I0629 05:49:33.643208 25302 http.cpp:2808] Received EOF attach response for
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.643333 25302 containerizer.cpp:2109] Destroying container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b in
RUNNING state
W0629 05:49:33.643411 25306 http.cpp:2823] Launch nested container session
connection for container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b closed
I0629 05:49:33.643589 25302 launcher.cpp:156] Asked to destroy container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.656733 25305 process.cpp:3788] Failed to process request for
'/slave(644)/api/v1': Disconnected
I0629 05:49:33.656764 25306 process.cpp:1477] Returning '500 Internal Server
Error' for '/slave(644)/api/v1' (Disconnected)
/mesos/src/tests/api_tests.cpp:5487: Failure
Value of: (response).get().status
Actual: "500 Internal Server Error"
Expected: http::OK().status
Which is: "200 OK"
I0629 05:49:33.683780 25306 master.cpp:1430] Framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 disconnected
I0629 05:49:33.683836 25306 master.cpp:3160] Deactivating framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.683857 25306 master.cpp:3137] Disconnecting framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.683899 25306 master.cpp:1445] Giving framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 0ns to failover
I0629 05:49:33.684054 25305 hierarchical.cpp:374] Deactivated framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.684756 25306 containerizer.cpp:2109] Destroying container
b36e964b-c357-4f62-a767-029668d71ff6 in RUNNING state
I0629 05:49:33.685206 25305 master.cpp:7146] Framework failover timeout,
removing framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.685257 25305 master.cpp:8000] Removing framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.685344 25305 master.cpp:8568] Updating the state of task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (latest state: TASK_KILLED, status
update state: TASK_KILLED)
I0629 05:49:33.685416 25302 slave.cpp:3063] Asked to shut down framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 by master@172.17.0.3:45726
I0629 05:49:33.685462 25302 slave.cpp:3088] Shutting down framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.685477 25302 slave.cpp:5531] Shutting down executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 at executor(1)@172.17.0.3:40357
I0629 05:49:33.685734 25305 master.cpp:8662] Removing task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b with resources cpus(*)(allocated: *):2;
mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated:
*):[31000-32000] of framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 on
agent 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3)
I0629 05:49:33.685771 25302 hierarchical.cpp:1114] Recovered cpus(*)(allocated:
*):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024;
ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 from framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.686462 25307 hierarchical.cpp:325] Removed framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.721328 25305 switchboard.cpp:888] I/O switchboard server process
for container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b h:
as terminated (status=0)
I0629 05:49:33.721588 25302 containerizer.cpp:2515] Container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b has
exited
I0629 05:49:33.722765 25308 provisioner.cpp:484] Ignoring destroy request for
unknown container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.722827 25308 containerizer.cpp:2388] Checkpointing termination
state to nested container's runtime directory
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/containers/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b/termination'
I0629 05:49:33.723461 25308 launcher.cpp:156] Asked to destroy container
b36e964b-c357-4f62-a767-029668d71ff6
I0629 05:49:33.731124 25308 slave.cpp:4836] Got exited event for
executor(1)@172.17.0.3:40357
I0629 05:49:33.822432 25305 containerizer.cpp:2515] Container
b36e964b-c357-4f62-a767-029668d71ff6 has exited
I0629 05:49:33.823519 25306 provisioner.cpp:484] Ignoring destroy request for
unknown container b36e964b-c357-4f62-a767-029668d71ff6
I0629 05:49:33.824609 25307 slave.cpp:5217] Executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 terminated with signal Killed
I0629 05:49:33.824664 25307 slave.cpp:5317] Cleaning up executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 at executor(1)@172.17.0.3:40357
W0629 05:49:33.824992 25303 containerizer.cpp:2097] Attempted to destroy
unknown container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.825323 25303 gc.cpp:55] Scheduling
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
for gc 6.99999044942222days in the future
I0629 05:49:33.825505 25307 slave.cpp:5405] Cleaning up framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.825548 25305 gc.cpp:55] Scheduling
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b'
for gc 6.99999044592593days in the future
I0629 05:49:33.825690 25305 status_update_manager.cpp:285] Closing status
update streams for framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.825729 25305 status_update_manager.cpp:531] Cleaning up status
update stream for task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.825898 25307 slave.cpp:796] Agent terminating
I0629 05:49:33.826009 25305 gc.cpp:55] Scheduling
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000'
for gc 6.99999044129778days in the future
I0629 05:49:33.826244 25308 master.cpp:1313] Agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3) disconnected
I0629 05:49:33.826398 25308 master.cpp:3197] Disconnecting agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3)
I0629 05:49:33.826576 25308 master.cpp:3216] Deactivating agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3)
I0629 05:49:33.826901 25302 hierarchical.cpp:653] Agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 deactivated
I0629 05:49:33.828503 25301 master.cpp:1155] Master terminating
I0629 05:49:33.828763 25306 hierarchical.cpp:558] Removed agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
[ FAILED ]
ContentType/AgentAPIStreamingTest.AttachInputToNestedContainerSession/0, where
GetParam() = application/x-protobuf (656 ms)
{code}
was:
Observed this on ASF CI and internal Mesosphere CI. Affected tests:
AgentAPIStreamingTest.AttachInputToNestedContainerSession
{code}
[ RUN ]
ContentType/AgentAPIStreamingTest.AttachInputToNestedContainerSession/0
I0629 05:49:33.180673 25301 cluster.cpp:162] Creating default 'local' authorizer
I0629 05:49:33.182234 25306 master.cpp:436] Master
90ea1640-bdf3-49ba-b78f-b2ba7ea30077 (296af9b598c3) started on 172.17.0.3:45726
I0629 05:49:33.182289 25306 master.cpp:438] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1secs" -
-allocator="HierarchicalDRF" --authenticate_agents="true"
--authenticate_frameworks="true" --authenticate_http_frameworks="true"
--authenticate_http_readonly="true" --au
thenticate_http_readwrite="true" --authenticators="crammd5"
--authorizers="local" --credentials="/tmp/a5h5J3/credentials"
--framework_sorter="drf" --help="false" --hostn
ame_lookup="true" --http_authenticators="basic"
--http_framework_authenticators="basic" --initialize_driver_logging="true"
--log_auto_initialize="true" --logbufsecs="0"
--logging_level="INFO" --max_agent_ping_timeouts="5"
--max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
--max_unreachable_tasks_per_framework="10
00" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%"
--registry="in_memory" --registry_fetch_timeout="1mins"
--registry_gc_interval="15mins" --registr
y_max_agent_age="2weeks" --registry_max_agent_count="102400"
--registry_store_timeout="100secs" --registry_strict="false"
--root_submissions="true" --user_sorter="drf" -
-version="false" --webui_dir="/usr/local/share/mesos/webui"
--work_dir="/tmp/a5h5J3/master" --zk_session_timeout="10secs"
I0629 05:49:33.182561 25306 master.cpp:488] Master only allowing authenticated
frameworks to register
I0629 05:49:33.182610 25306 master.cpp:502] Master only allowing authenticated
agents to register
I0629 05:49:33.182636 25306 master.cpp:515] Master only allowing authenticated
HTTP frameworks to register
I0629 05:49:33.182656 25306 credentials.hpp:37] Loading credentials for
authentication from '/tmp/a5h5J3/credentials'
I0629 05:49:33.182915 25306 master.cpp:560] Using default 'crammd5'
authenticator
I0629 05:49:33.183009 25306 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
I0629 05:49:33.183151 25306 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
I0629 05:49:33.183218 25306 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
I0629 05:49:33.183284 25306 master.cpp:640] Authorization enabled
I0629 05:49:33.183462 25309 hierarchical.cpp:158] Initialized hierarchical
allocator process
I0629 05:49:33.183504 25309 whitelist_watcher.cpp:77] No whitelist given
I0629 05:49:33.184311 25308 master.cpp:2161] Elected as the leading master!
I0629 05:49:33.184341 25308 master.cpp:1700] Recovering from registrar
I0629 05:49:33.184404 25308 registrar.cpp:345] Recovering registrar
I0629 05:49:33.184622 25308 registrar.cpp:389] Successfully fetched the
registry (0B) in 183040ns
I0629 05:49:33.184687 25308 registrar.cpp:493] Applied 1 operations in 6441ns;
attempting to update the registry
I0629 05:49:33.184885 25304 registrar.cpp:550] Successfully updated the
registry in 147200ns
I0629 05:49:33.184993 25304 registrar.cpp:422] Successfully recovered registrar
I0629 05:49:33.185148 25308 master.cpp:1799] Recovered 0 agents from the
registry (129B); allowing 10mins for agents to re-register
I0629 05:49:33.185161 25302 hierarchical.cpp:185] Skipping recovery of
hierarchical allocator: nothing to recover
I0629 05:49:33.186769 25301 containerizer.cpp:221] Using isolation:
posix/cpu,posix/mem,filesystem/posix,network/cni
W0629 05:49:33.187232 25301 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
W0629 05:49:33.187363 25301 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
I0629 05:49:33.187396 25301 provisioner.cpp:249] Using default backend 'copy'
I0629 05:49:33.189133 25301 cluster.cpp:448] Creating default 'local' authorizer
I0629 05:49:33.189707 25306 slave.cpp:231] Mesos agent started on
(644)@172.17.0.3:45726
I0629 05:49:33.189741 25306 slave.cpp:232] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authenticatee="crammd5"
--authentication_backoff_factor="1secs" --authorizer="local"
--cgroups_cpu_enable_pids_and_tids_count="false" --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/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/credential"
--default_role="*" --disk_watch_interval="1mins" --docker="docker"
--docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io";
--docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock"
--docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker"
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volu:
me" --enforce_container_disk_quota="false"
--executor_registration_timeout="1mins"
--executor_reregistration_timeout="2secs"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/fetch"
--fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks"
--gc_disk_headroom="0.1" --hadoop_home="" --help="false"
--hostname_lookup="true" --http_command_executor="false"
--http_credentials="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="posix"
--launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150"
--oversubscribed_resources_interval="15secs" --perf_duration="10secs"
--perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns"
--quiet="false" --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_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ"
--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_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw"
I0629 05:49:33.190001 25306 credentials.hpp:86] Loading credential for
authentication from
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/credential'
I0629 05:49:33.190135 25306 slave.cpp:264] Agent using credential for:
test-principal
I0629 05:49:33.190228 25306 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/http_credentials'
I0629 05:49:33.190445 25306 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
I0629 05:49:33.190563 25306 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
I0629 05:49:33.191004 25301 sched.cpp:232] Version: 1.3.0
I0629 05:49:33.191077 25306 slave.cpp:531] Agent resources: cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0629 05:49:33.191150 25306 slave.cpp:539] Agent attributes: [ ]
I0629 05:49:33.191172 25306 slave.cpp:544] Agent hostname: 296af9b598c3
I0629 05:49:33.191313 25302 sched.cpp:336] New master detected at
master@172.17.0.3:45726
I0629 05:49:33.191349 25302 sched.cpp:407] Authenticating with master
master@172.17.0.3:45726
I0629 05:49:33.191433 25302 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0629 05:49:33.191622 25302 authenticatee.cpp:121] Creating new client SASL
connection
I0629 05:49:33.191917 25302 master.cpp:7475] Authenticating
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.192019 25302 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1229)@172.17.0.3:45726
I0629 05:49:33.192194 25302 authenticator.cpp:98] Creating new server SASL
connection
I0629 05:49:33.192387 25302 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0629 05:49:33.192411 25302 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0629 05:49:33.192445 25302 authenticator.cpp:204] Received SASL authentication
start
I0629 05:49:33.192512 25302 authenticator.cpp:326] Authentication requires more
steps
I0629 05:49:33.192553 25302 authenticatee.cpp:259] Received SASL authentication
step
I0629 05:49:33.192591 25302 authenticator.cpp:232] Received SASL authentication
step
I0629 05:49:33.192699 25302 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0629 05:49:33.192715 25302 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0629 05:49:33.192823 25302 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0629 05:49:33.192849 25302 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0629 05:49:33.192932 25302 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0629 05:49:33.192996 25302 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0629 05:49:33.193013 25302 authenticator.cpp:318] Authentication success
I0629 05:49:33.193075 25308 authenticatee.cpp:299] Authentication success
I0629 05:49:33.193120 25307 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1229)@172.17.0.3:45726
I0629 05:49:33.193137 25308 status_update_manager.cpp:177] Pausing sending
status updates
I0629 05:49:33.193213 25302 master.cpp:7505] Successfully authenticated
principal 'test-principal' at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.193248 25308 sched.cpp:513] Successfully authenticated with
master master@172.17.0.3:45726
I0629 05:49:33.193265 25308 sched.cpp:836] Sending SUBSCRIBE call to
master@172.17.0.3:45726
I0629 05:49:33.193306 25308 sched.cpp:869] Will retry registration in
250.898986ms if necessary
I0629 05:49:33.193398 25308 master.cpp:2813] Received SUBSCRIBE call for
framework 'default' at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.193424 25308 master.cpp:2197] Authorizing framework principal
'test-principal' to receive offers for roles '{ * }'
I0629 05:49:33.193763 25305 state.cpp:62] Recovering state from
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/meta'
I0629 05:49:33.193764 25306 master.cpp:2890] Subscribing framework default with
checkpointing disabled and capabilities [ ]
I0629 05:49:33.194470 25309 status_update_manager.cpp:203] Recovering status
update manager
I0629 05:49:33.194608 25306 sched.cpp:759] Framework registered with
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.194656 25306 sched.cpp:773] Scheduler::registered took 13886ns
I0629 05:49:33.194751 25307 hierarchical.cpp:273] Added framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.194782 25308 containerizer.cpp:608] Recovering containerizer
I0629 05:49:33.194805 25307 hierarchical.cpp:1850] No allocations performed
I0629 05:49:33.194825 25307 hierarchical.cpp:1940] No inverse offers to send
out!
I0629 05:49:33.194835 25307 hierarchical.cpp:1434] Performed allocation for 0
agents in 37750ns
I0629 05:49:33.195451 25302 provisioner.cpp:410] Provisioner recovery complete
I0629 05:49:33.195629 25302 slave.cpp:6075] Finished recovery
I0629 05:49:33.196087 25302 slave.cpp:6257] Querying resource estimator for
oversubscribable resources
I0629 05:49:33.196205 25307 slave.cpp:6271] Received oversubscribable resources
{} from the resource estimator
I0629 05:49:33.196358 25302 slave.cpp:924] New master detected at
master@172.17.0.3:45726
I0629 05:49:33.196447 25308 status_update_manager.cpp:177] Pausing sending
status updates
I0629 05:49:33.196465 25302 slave.cpp:959] Detecting new master
I0629 05:49:33.200856 25302 slave.cpp:986] Authenticating with master
master@172.17.0.3:45726
I0629 05:49:33.200942 25302 slave.cpp:997] Using default CRAM-MD5 authenticatee
I0629 05:49:33.201126 25309 authenticatee.cpp:121] Creating new client SASL
connection
I0629 05:49:33.201560 25309 master.cpp:7475] Authenticating
slave(644)@172.17.0.3:45726
I0629 05:49:33.201704 25309 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1230)@172.17.0.3:45726
I0629 05:49:33.201792 25302 authenticator.cpp:98] Creating new server SASL
connection
I0629 05:49:33.202373 25302 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I0629 05:49:33.202396 25302 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0629 05:49:33.202430 25302 authenticator.cpp:204] Received SASL authentication
start
I0629 05:49:33.202487 25302 authenticator.cpp:326] Authentication requires more
steps
I0629 05:49:33.202584 25302 authenticatee.cpp:259] Received SASL authentication
step
I0629 05:49:33.202633 25302 authenticator.cpp:232] Received SASL authentication
step
I0629 05:49:33.202648 25302 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0629 05:49:33.202656 25302 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I0629 05:49:33.202678 25302 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0629 05:49:33.202693 25302 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
SASL_AUXPROP_VERIF:
Y_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0629 05:49:33.202698 25302 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0629 05:49:33.202702 25302 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0629 05:49:33.202713 25302 authenticator.cpp:318] Authentication success
I0629 05:49:33.202810 25308 master.cpp:7505] Successfully authenticated
principal 'test-principal' at slave(644)@172.17.0.3:45726
I0629 05:49:33.202847 25307 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1230)@172.17.0.3:45726
I0629 05:49:33.202766 25302 authenticatee.cpp:299] Authentication success
I0629 05:49:33.202999 25302 slave.cpp:1081] Successfully authenticated with
master master@172.17.0.3:45726
I0629 05:49:33.203225 25302 slave.cpp:1509] Will retry registration in
6.854069ms if necessary
I0629 05:49:33.203373 25309 master.cpp:5429] Received register agent message
from slave(644)@172.17.0.3:45726 (296af9b598c3)
I0629 05:49:33.203433 25309 master.cpp:3659] Authorizing agent with principal
'test-principal'
I0629 05:49:33.203737 25306 master.cpp:5564] Registering agent at
slave(644)@172.17.0.3:45726 (296af9b598c3) with id
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
I0629 05:49:33.204012 25308 registrar.cpp:493] Applied 1 operations in 28157ns;
attempting to update the registry
I0629 05:49:33.204355 25303 registrar.cpp:550] Successfully updated the
registry in 277248ns
I0629 05:49:33.204691 25303 master.cpp:5639] Registered agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0629 05:49:33.204764 25303 slave.cpp:4794] Received ping from
slave-observer(589)@172.17.0.3:45726
I0629 05:49:33.204795 25308 hierarchical.cpp:525] Added agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 (296af9b598c3) with cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I0629 05:49:33.204876 25303 slave.cpp:1127] Registered with master
master@172.17.0.3:45726; given agent ID 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
I0629 05:49:33.204895 25303 fetcher.cpp:94] Clearing fetcher cache
I0629 05:49:33.205031 25309 status_update_manager.cpp:184] Resuming sending
status updates
I0629 05:49:33.205252 25303 slave.cpp:1155] Checkpointing SlaveInfo to
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/meta/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/slave.info'
I0629 05:49:33.205269 25308 hierarchical.cpp:1940] No inverse offers to send
out!
I0629 05:49:33.205291 25308 hierarchical.cpp:1434] Performed allocation for 1
agents in 251549ns
I0629 05:49:33.205541 25309 master.cpp:7305] Sending 1 offers to framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.205585 25303 slave.cpp:1193] Forwarding total oversubscribed
resources {}
I0629 05:49:33.205760 25309 master.cpp:6324] Received update of agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3) with total oversubscribed resources {}
I0629 05:49:33.205921 25308 sched.cpp:933] Scheduler::resourceOffers took
54996ns
I0629 05:49:33.206763 25304 master.cpp:3875] Processing ACCEPT call for offers:
[ 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-O0 ] on agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3) for framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
(default) at scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.206811 25304 master.cpp:3426] Authorizing framework principal
'test-principal' to launch task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b
I0629 05:49:33.207425 25304 master.cpp:9320] Adding task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b with resources cpus(*)(allocated: *):2;
mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated:
*):[31000-32000] on agent 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at
slave(644)@172.17.0.3:45726 (296af9b598c3)
I0629 05:49:33.207504 25304 master.cpp:4531] Launching task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 with resources
cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024;
ports(*)(allocated: *):[31000-32000] on agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3)
I0629 05:49:33.207877 25302 slave.cpp:1619] Got assigned task
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.208356 25304 hierarchical.cpp:850] Updated allocation of
framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 on agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077:
-S0 from cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated:
*):1024; ports(*)(allocated: *):[31000-32000] to cpus(*)(allocated: *):2;
mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated:
*):[31000-32000]
I0629 05:49:33.208642 25302 slave.cpp:1900] Authorizing task
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.208668 25302 slave.cpp:6694] Authorizing framework principal
'test-principal' to launch task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b
I0629 05:49:33.208978 25302 slave.cpp:2087] Launching task
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.209475 25302 paths.cpp:573] Trying to chown
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
to user 'mesos'
I0629 05:49:33.209678 25302 slave.cpp:7038] Launching executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 with resources cpus(*)(allocated:
*):0.1; mem(*)(allocated: *):32 in work directory
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
I0629 05:49:33.210337 25302 slave.cpp:2316] Queued task
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.210480 25304 containerizer.cpp:1001] Starting container
b36e964b-c357-4f62-a767-029668d71ff6 for executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.212021 25304 containerizer.cpp:1531] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.3:45726"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw\/slaves\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0\/frameworks\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000\/executors\/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b\/runs\/b36e964b-c357-4f62-a767-029668d71ff6"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"ee05c102-e5cb-4cc2-9fb4-41fe1e06446b"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(644)@172.17.0.3:45726"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw\/slaves\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0\/frameworks\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000\/executors\/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b\/runs\/b36e964b-c357-4f62-a767-029668d71ff6"}]},"user":"mesos","working_directory":"\/tmp\/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw\/slaves\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0\/frameworks\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000\/executors\/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b\/runs\/b36e964b-c357-4f62-a767-029668d71ff6"}"
--pipe_read="8" --pipe_write="9"
--runtime_directory="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/containers/b36e964b-c357-4f62-a767-029668d71ff6"
--unshare_namespace_mnt="false"'
I0629 05:49:33.212301 25302 slave.cpp:877] Successfully attached file
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
I0629 05:49:33.214748 25304 launcher.cpp:140] Forked child with pid '28869' for
container 'b36e964b-c357-4f62-a767-029668d71ff6'
I0629 05:49:33.219424 25305 fetcher.cpp:353] Starting to fetch URIs for
container: b36e964b-c357-4f62-a767-029668d71ff6, directory:
/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6
I0629 05:49:33.335734 25303 slave.cpp:3790] Got registration for executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 from executor(1)@172.17.0.3:40357
I0629 05:49:33.337357 25306 slave.cpp:2529] Sending queued task
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' to executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 at executor(1)@172.17.0.3:40357
I0629 05:49:33.344734 25305 slave.cpp:4264] Handling status update TASK_RUNNING
(UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 from executor(1)@172.17.0.3:40357
I0629 05:49:33.346091 25306 status_update_manager.cpp:323] Received status
update TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9:
fb4-41fe1e06446b of framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.346123 25306 status_update_manager.cpp:500] Creating
StatusUpdate stream for task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.346360 25306 status_update_manager.cpp:377] Forwarding update
TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 to the agent
I0629 05:49:33.346629 25306 slave.cpp:4704] Forwarding the update TASK_RUNNING
(UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 to master@172.17.0.3:45726
I0629 05:49:33.346786 25306 slave.cpp:4598] Status update manager successfully
handled status update TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07)
for task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.346828 25306 slave.cpp:4614] Sending acknowledgement for status
update TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 to executor(1)@172.17.0.3:40357
I0629 05:49:33.347121 25307 master.cpp:6469] Status update TASK_RUNNING (UUID:
3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 from agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3)
I0629 05:49:33.347162 25307 master.cpp:6537] Forwarding status update
TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.347309 25307 master.cpp:8568] Updating the state of task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
I0629 05:49:33.347633 25304 sched.cpp:1041] Scheduler::statusUpdate took 82630ns
I0629 05:49:33.347909 25309 master.cpp:5194] Processing ACKNOWLEDGE call
3aa0c8c0-c78f-4c72-a638-ef2adf1eae07 for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 on agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
I0629 05:49:33.348162 25307 status_update_manager.cpp:395] Received status
update acknowledgement (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.348284 25307 slave.cpp:3510] Status update manager successfully
handled status update acknowledgement (UUID:
3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.349153 25307 process.cpp:3731] Handling HTTP event for process
'slave(644)' with path: '/slave(644)/api/v1'
I0629 05:49:33.349717 25305 http.cpp:1115] HTTP POST for /slave(644)/api/v1
from 172.17.0.3:38460
I0629 05:49:33.350256 25305 http.cpp:527] Processing call
LAUNCH_NESTED_CONTAINER_SESSION
I0629 05:49:33.350522 25303 containerizer.cpp:1798] Starting nested container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.351016 25303 containerizer.cpp:1822] Trying to chown
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b'
to user 'mesos'
I0629 05:49:33.352535 25309 switchboard.cpp:545] Launching
'mesos-io-switchboard' with flags '--heartbeat_interval="30secs" --help="false"
--socket_address="/tmp/mesos-io-switchboard-8a787e7f-51e0-4f96-a310-73423d54dbd5"
--stderr_from_fd="16" --stderr_to_fd="2" --stdin_to_fd="13"
--stdout_from_fd="14" --stdout_to_fd="1" --tty="false"
--wait_for_connection="true"' for container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.355439 25309 switchboard.cpp:575] Created I/O switchboard server
(pid: 28881) listening on socket file
'/tmp/mesos-io-switchboard-8a787e7f-51e0-4f96-a310-73423d54dbd5' for container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.356899 25309 containerizer.cpp:1531] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"shell":true,"value":"cat"},"environment":{},"user":"mesos"}"
--pipe_read="13" --pipe_write="14"
--runtime_directory="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/containers/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b"
--unshare_namespace_mnt="false"'
I0629 05:49:33.358389 25309 launcher.cpp:140] Forked child with pid '28882' for
container
'b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b'
I0629 05:49:33.362704 25308 fetcher.cpp:353] Starting to fetch URIs for
container:
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b,
directory:
/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.419852 25302 process.cpp:3731] Handling HTTP event for process
'slave(644)' with path: '/slave(644)/api/v1'
I0629 05:49:33.420730 25302 http.cpp:1115] HTTP POST for /slave(644)/api/v1
from 172.17.0.3:38462
I0629 05:49:33.421162 25308 http.cpp:527] Processing call ATTACH_CONTAINER_INPUT
I0629 05:49:33.643208 25302 http.cpp:2808] Received EOF attach response for
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.643333 25302 containerizer.cpp:2109] Destroying container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b in
RUNNING state
W0629 05:49:33.643411 25306 http.cpp:2823] Launch nested container session
connection for container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b closed
I0629 05:49:33.643589 25302 launcher.cpp:156] Asked to destroy container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.656733 25305 process.cpp:3788] Failed to process request for
'/slave(644)/api/v1': Disconnected
I0629 05:49:33.656764 25306 process.cpp:1477] Returning '500 Internal Server
Error' for '/slave(644)/api/v1' (Disconnected)
/mesos/src/tests/api_tests.cpp:5487: Failure
Value of: (response).get().status
Actual: "500 Internal Server Error"
Expected: http::OK().status
Which is: "200 OK"
I0629 05:49:33.683780 25306 master.cpp:1430] Framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 disconnected
I0629 05:49:33.683836 25306 master.cpp:3160] Deactivating framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.683857 25306 master.cpp:3137] Disconnecting framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.683899 25306 master.cpp:1445] Giving framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 0ns to failover
I0629 05:49:33.684054 25305 hierarchical.cpp:374] Deactivated framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.684756 25306 containerizer.cpp:2109] Destroying container
b36e964b-c357-4f62-a767-029668d71ff6 in RUNNING state
I0629 05:49:33.685206 25305 master.cpp:7146] Framework failover timeout,
removing framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.685257 25305 master.cpp:8000] Removing framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
I0629 05:49:33.685344 25305 master.cpp:8568] Updating the state of task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (latest state: TASK_KILLED, status
update state: TASK_KILLED)
I0629 05:49:33.685416 25302 slave.cpp:3063] Asked to shut down framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 by master@172.17.0.3:45726
I0629 05:49:33.685462 25302 slave.cpp:3088] Shutting down framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.685477 25302 slave.cpp:5531] Shutting down executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 at executor(1)@172.17.0.3:40357
I0629 05:49:33.685734 25305 master.cpp:8662] Removing task
ee05c102-e5cb-4cc2-9fb4-41fe1e06446b with resources cpus(*)(allocated: *):2;
mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated:
*):[31000-32000] of framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 on
agent 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3)
I0629 05:49:33.685771 25302 hierarchical.cpp:1114] Recovered cpus(*)(allocated:
*):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024;
ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 from framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.686462 25307 hierarchical.cpp:325] Removed framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.721328 25305 switchboard.cpp:888] I/O switchboard server process
for container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b h:
as terminated (status=0)
I0629 05:49:33.721588 25302 containerizer.cpp:2515] Container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b has
exited
I0629 05:49:33.722765 25308 provisioner.cpp:484] Ignoring destroy request for
unknown container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.722827 25308 containerizer.cpp:2388] Checkpointing termination
state to nested container's runtime directory
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/containers/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b/termination'
I0629 05:49:33.723461 25308 launcher.cpp:156] Asked to destroy container
b36e964b-c357-4f62-a767-029668d71ff6
I0629 05:49:33.731124 25308 slave.cpp:4836] Got exited event for
executor(1)@172.17.0.3:40357
I0629 05:49:33.822432 25305 containerizer.cpp:2515] Container
b36e964b-c357-4f62-a767-029668d71ff6 has exited
I0629 05:49:33.823519 25306 provisioner.cpp:484] Ignoring destroy request for
unknown container b36e964b-c357-4f62-a767-029668d71ff6
I0629 05:49:33.824609 25307 slave.cpp:5217] Executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 terminated with signal Killed
I0629 05:49:33.824664 25307 slave.cpp:5317] Cleaning up executor
'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 at executor(1)@172.17.0.3:40357
W0629 05:49:33.824992 25303 containerizer.cpp:2097] Attempted to destroy
unknown container
b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
I0629 05:49:33.825323 25303 gc.cpp:55] Scheduling
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
for gc 6.99999044942222days in the future
I0629 05:49:33.825505 25307 slave.cpp:5405] Cleaning up framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.825548 25305 gc.cpp:55] Scheduling
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b'
for gc 6.99999044592593days in the future
I0629 05:49:33.825690 25305 status_update_manager.cpp:285] Closing status
update streams for framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.825729 25305 status_update_manager.cpp:531] Cleaning up status
update stream for task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
I0629 05:49:33.825898 25307 slave.cpp:796] Agent terminating
I0629 05:49:33.826009 25305 gc.cpp:55] Scheduling
'/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000'
for gc 6.99999044129778days in the future
I0629 05:49:33.826244 25308 master.cpp:1313] Agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3) disconnected
I0629 05:49:33.826398 25308 master.cpp:3197] Disconnecting agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3)
I0629 05:49:33.826576 25308 master.cpp:3216] Deactivating agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
(296af9b598c3)
I0629 05:49:33.826901 25302 hierarchical.cpp:653] Agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 deactivated
I0629 05:49:33.828503 25301 master.cpp:1155] Master terminating
I0629 05:49:33.828763 25306 hierarchical.cpp:558] Removed agent
90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
[ FAILED ]
ContentType/AgentAPIStreamingTest.AttachInputToNestedContainerSession/0, where
GetParam() = application/x-protobuf (656 ms)
{code}
> ContentType/AgentAPIStreamingTest.AttachInputToNestedContainerSession is flaky
> ------------------------------------------------------------------------------
>
> Key: MESOS-7742
> URL: https://issues.apache.org/jira/browse/MESOS-7742
> Project: Mesos
> Issue Type: Bug
> Reporter: Vinod Kone
> Assignee: Gastón Kleiman
> Labels: flaky-test, mesosphere-oncall
> Attachments: AgentAPITest.LaunchNestedContainerSession-badrun.txt
>
>
> Observed this on ASF CI and internal Mesosphere CI. Affected tests:
> AgentAPIStreamingTest.AttachInputToNestedContainerSession
> AgentAPITest.LaunchNestedContainerSession
> {code}
> [ RUN ]
> ContentType/AgentAPIStreamingTest.AttachInputToNestedContainerSession/0
> I0629 05:49:33.180673 25301 cluster.cpp:162] Creating default 'local'
> authorizer
> I0629 05:49:33.182234 25306 master.cpp:436] Master
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077 (296af9b598c3) started on
> 172.17.0.3:45726
> I0629 05:49:33.182289 25306 master.cpp:438] Flags at startup: --acls=""
> --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
> --allocation_interval="1secs" -
> -allocator="HierarchicalDRF" --authenticate_agents="true"
> --authenticate_frameworks="true" --authenticate_http_frameworks="true"
> --authenticate_http_readonly="true" --au
> thenticate_http_readwrite="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/a5h5J3/credentials"
> --framework_sorter="drf" --help="false" --hostn
> ame_lookup="true" --http_authenticators="basic"
> --http_framework_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0"
> --logging_level="INFO" --max_agent_ping_timeouts="5"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_unreachable_tasks_per_framework="10
> 00" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%"
> --registry="in_memory" --registry_fetch_timeout="1mins"
> --registry_gc_interval="15mins" --registr
> y_max_agent_age="2weeks" --registry_max_agent_count="102400"
> --registry_store_timeout="100secs" --registry_strict="false"
> --root_submissions="true" --user_sorter="drf" -
> -version="false" --webui_dir="/usr/local/share/mesos/webui"
> --work_dir="/tmp/a5h5J3/master" --zk_session_timeout="10secs"
> I0629 05:49:33.182561 25306 master.cpp:488] Master only allowing
> authenticated frameworks to register
> I0629 05:49:33.182610 25306 master.cpp:502] Master only allowing
> authenticated agents to register
> I0629 05:49:33.182636 25306 master.cpp:515] Master only allowing
> authenticated HTTP frameworks to register
> I0629 05:49:33.182656 25306 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/a5h5J3/credentials'
> I0629 05:49:33.182915 25306 master.cpp:560] Using default 'crammd5'
> authenticator
> I0629 05:49:33.183009 25306 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-readonly'
> I0629 05:49:33.183151 25306 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-readwrite'
> I0629 05:49:33.183218 25306 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-scheduler'
> I0629 05:49:33.183284 25306 master.cpp:640] Authorization enabled
> I0629 05:49:33.183462 25309 hierarchical.cpp:158] Initialized hierarchical
> allocator process
> I0629 05:49:33.183504 25309 whitelist_watcher.cpp:77] No whitelist given
> I0629 05:49:33.184311 25308 master.cpp:2161] Elected as the leading master!
> I0629 05:49:33.184341 25308 master.cpp:1700] Recovering from registrar
> I0629 05:49:33.184404 25308 registrar.cpp:345] Recovering registrar
> I0629 05:49:33.184622 25308 registrar.cpp:389] Successfully fetched the
> registry (0B) in 183040ns
> I0629 05:49:33.184687 25308 registrar.cpp:493] Applied 1 operations in
> 6441ns; attempting to update the registry
> I0629 05:49:33.184885 25304 registrar.cpp:550] Successfully updated the
> registry in 147200ns
> I0629 05:49:33.184993 25304 registrar.cpp:422] Successfully recovered
> registrar
> I0629 05:49:33.185148 25308 master.cpp:1799] Recovered 0 agents from the
> registry (129B); allowing 10mins for agents to re-register
> I0629 05:49:33.185161 25302 hierarchical.cpp:185] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0629 05:49:33.186769 25301 containerizer.cpp:221] Using isolation:
> posix/cpu,posix/mem,filesystem/posix,network/cni
> W0629 05:49:33.187232 25301 backend.cpp:76] Failed to create 'aufs' backend:
> AufsBackend requires root privileges
> W0629 05:49:33.187363 25301 backend.cpp:76] Failed to create 'bind' backend:
> BindBackend requires root privileges
> I0629 05:49:33.187396 25301 provisioner.cpp:249] Using default backend 'copy'
> I0629 05:49:33.189133 25301 cluster.cpp:448] Creating default 'local'
> authorizer
> I0629 05:49:33.189707 25306 slave.cpp:231] Mesos agent started on
> (644)@172.17.0.3:45726
> I0629 05:49:33.189741 25306 slave.cpp:232] Flags at startup: --acls=""
> --appc_simple_discovery_uri_prefix="http://";
> --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_readonly="true"
> --authenticate_http_readwrite="true" --authenticatee="crammd5"
> --authentication_backoff_factor="1secs" --authorizer="local"
> --cgroups_cpu_enable_pids_and_tids_count="false" --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/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/credential"
> --default_role="*" --disk_watch_interval="1mins" --docker="docker"
> --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io";
> --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock"
> --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker"
> --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volu:
> me" --enforce_container_disk_quota="false"
> --executor_registration_timeout="1mins"
> --executor_reregistration_timeout="2secs"
> --executor_shutdown_grace_period="5secs"
> --fetcher_cache_dir="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/fetch"
> --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks"
> --gc_disk_headroom="0.1" --hadoop_home="" --help="false"
> --hostname_lookup="true" --http_command_executor="false"
> --http_credentials="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/http_credentials"
> --http_heartbeat_interval="30secs" --initialize_driver_logging="true"
> --isolation="posix/cpu,posix/mem" --launcher="posix"
> --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO"
> --max_completed_executors_per_framework="150"
> --oversubscribed_resources_interval="15secs" --perf_duration="10secs"
> --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns"
> --quiet="false" --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_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ"
> --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_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw"
> I0629 05:49:33.190001 25306 credentials.hpp:86] Loading credential for
> authentication from
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/credential'
> I0629 05:49:33.190135 25306 slave.cpp:264] Agent using credential for:
> test-principal
> I0629 05:49:33.190228 25306 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/http_credentials'
> I0629 05:49:33.190445 25306 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-agent-readonly'
> I0629 05:49:33.190563 25306 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-agent-readwrite'
> I0629 05:49:33.191004 25301 sched.cpp:232] Version: 1.3.0
> I0629 05:49:33.191077 25306 slave.cpp:531] Agent resources: cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0629 05:49:33.191150 25306 slave.cpp:539] Agent attributes: [ ]
> I0629 05:49:33.191172 25306 slave.cpp:544] Agent hostname: 296af9b598c3
> I0629 05:49:33.191313 25302 sched.cpp:336] New master detected at
> master@172.17.0.3:45726
> I0629 05:49:33.191349 25302 sched.cpp:407] Authenticating with master
> master@172.17.0.3:45726
> I0629 05:49:33.191433 25302 sched.cpp:414] Using default CRAM-MD5
> authenticatee
> I0629 05:49:33.191622 25302 authenticatee.cpp:121] Creating new client SASL
> connection
> I0629 05:49:33.191917 25302 master.cpp:7475] Authenticating
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
> I0629 05:49:33.192019 25302 authenticator.cpp:414] Starting authentication
> session for crammd5-authenticatee(1229)@172.17.0.3:45726
> I0629 05:49:33.192194 25302 authenticator.cpp:98] Creating new server SASL
> connection
> I0629 05:49:33.192387 25302 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0629 05:49:33.192411 25302 authenticatee.cpp:239] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0629 05:49:33.192445 25302 authenticator.cpp:204] Received SASL
> authentication start
> I0629 05:49:33.192512 25302 authenticator.cpp:326] Authentication requires
> more steps
> I0629 05:49:33.192553 25302 authenticatee.cpp:259] Received SASL
> authentication step
> I0629 05:49:33.192591 25302 authenticator.cpp:232] Received SASL
> authentication step
> I0629 05:49:33.192699 25302 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0629 05:49:33.192715 25302 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0629 05:49:33.192823 25302 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0629 05:49:33.192849 25302 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> I0629 05:49:33.192932 25302 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0629 05:49:33.192996 25302 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0629 05:49:33.193013 25302 authenticator.cpp:318] Authentication success
> I0629 05:49:33.193075 25308 authenticatee.cpp:299] Authentication success
> I0629 05:49:33.193120 25307 authenticator.cpp:432] Authentication session
> cleanup for crammd5-authenticatee(1229)@172.17.0.3:45726
> I0629 05:49:33.193137 25308 status_update_manager.cpp:177] Pausing sending
> status updates
> I0629 05:49:33.193213 25302 master.cpp:7505] Successfully authenticated
> principal 'test-principal' at
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
> I0629 05:49:33.193248 25308 sched.cpp:513] Successfully authenticated with
> master master@172.17.0.3:45726
> I0629 05:49:33.193265 25308 sched.cpp:836] Sending SUBSCRIBE call to
> master@172.17.0.3:45726
> I0629 05:49:33.193306 25308 sched.cpp:869] Will retry registration in
> 250.898986ms if necessary
> I0629 05:49:33.193398 25308 master.cpp:2813] Received SUBSCRIBE call for
> framework 'default' at
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
> I0629 05:49:33.193424 25308 master.cpp:2197] Authorizing framework principal
> 'test-principal' to receive offers for roles '{ * }'
> I0629 05:49:33.193763 25305 state.cpp:62] Recovering state from
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/meta'
> I0629 05:49:33.193764 25306 master.cpp:2890] Subscribing framework default
> with checkpointing disabled and capabilities [ ]
> I0629 05:49:33.194470 25309 status_update_manager.cpp:203] Recovering status
> update manager
> I0629 05:49:33.194608 25306 sched.cpp:759] Framework registered with
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.194656 25306 sched.cpp:773] Scheduler::registered took 13886ns
> I0629 05:49:33.194751 25307 hierarchical.cpp:273] Added framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.194782 25308 containerizer.cpp:608] Recovering containerizer
> I0629 05:49:33.194805 25307 hierarchical.cpp:1850] No allocations performed
> I0629 05:49:33.194825 25307 hierarchical.cpp:1940] No inverse offers to send
> out!
> I0629 05:49:33.194835 25307 hierarchical.cpp:1434] Performed allocation for 0
> agents in 37750ns
> I0629 05:49:33.195451 25302 provisioner.cpp:410] Provisioner recovery complete
> I0629 05:49:33.195629 25302 slave.cpp:6075] Finished recovery
> I0629 05:49:33.196087 25302 slave.cpp:6257] Querying resource estimator for
> oversubscribable resources
> I0629 05:49:33.196205 25307 slave.cpp:6271] Received oversubscribable
> resources {} from the resource estimator
> I0629 05:49:33.196358 25302 slave.cpp:924] New master detected at
> master@172.17.0.3:45726
> I0629 05:49:33.196447 25308 status_update_manager.cpp:177] Pausing sending
> status updates
> I0629 05:49:33.196465 25302 slave.cpp:959] Detecting new master
> I0629 05:49:33.200856 25302 slave.cpp:986] Authenticating with master
> master@172.17.0.3:45726
> I0629 05:49:33.200942 25302 slave.cpp:997] Using default CRAM-MD5
> authenticatee
> I0629 05:49:33.201126 25309 authenticatee.cpp:121] Creating new client SASL
> connection
> I0629 05:49:33.201560 25309 master.cpp:7475] Authenticating
> slave(644)@172.17.0.3:45726
> I0629 05:49:33.201704 25309 authenticator.cpp:414] Starting authentication
> session for crammd5-authenticatee(1230)@172.17.0.3:45726
> I0629 05:49:33.201792 25302 authenticator.cpp:98] Creating new server SASL
> connection
> I0629 05:49:33.202373 25302 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0629 05:49:33.202396 25302 authenticatee.cpp:239] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0629 05:49:33.202430 25302 authenticator.cpp:204] Received SASL
> authentication start
> I0629 05:49:33.202487 25302 authenticator.cpp:326] Authentication requires
> more steps
> I0629 05:49:33.202584 25302 authenticatee.cpp:259] Received SASL
> authentication step
> I0629 05:49:33.202633 25302 authenticator.cpp:232] Received SASL
> authentication step
> I0629 05:49:33.202648 25302 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0629 05:49:33.202656 25302 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0629 05:49:33.202678 25302 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0629 05:49:33.202693 25302 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: '296af9b598c3' server FQDN: '296af9b598c3'
> SASL_AUXPROP_VERIF:
> Y_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0629 05:49:33.202698 25302 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0629 05:49:33.202702 25302 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0629 05:49:33.202713 25302 authenticator.cpp:318] Authentication success
> I0629 05:49:33.202810 25308 master.cpp:7505] Successfully authenticated
> principal 'test-principal' at slave(644)@172.17.0.3:45726
> I0629 05:49:33.202847 25307 authenticator.cpp:432] Authentication session
> cleanup for crammd5-authenticatee(1230)@172.17.0.3:45726
> I0629 05:49:33.202766 25302 authenticatee.cpp:299] Authentication success
> I0629 05:49:33.202999 25302 slave.cpp:1081] Successfully authenticated with
> master master@172.17.0.3:45726
> I0629 05:49:33.203225 25302 slave.cpp:1509] Will retry registration in
> 6.854069ms if necessary
> I0629 05:49:33.203373 25309 master.cpp:5429] Received register agent message
> from slave(644)@172.17.0.3:45726 (296af9b598c3)
> I0629 05:49:33.203433 25309 master.cpp:3659] Authorizing agent with principal
> 'test-principal'
> I0629 05:49:33.203737 25306 master.cpp:5564] Registering agent at
> slave(644)@172.17.0.3:45726 (296af9b598c3) with id
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
> I0629 05:49:33.204012 25308 registrar.cpp:493] Applied 1 operations in
> 28157ns; attempting to update the registry
> I0629 05:49:33.204355 25303 registrar.cpp:550] Successfully updated the
> registry in 277248ns
> I0629 05:49:33.204691 25303 master.cpp:5639] Registered agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
> (296af9b598c3) with cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000]
> I0629 05:49:33.204764 25303 slave.cpp:4794] Received ping from
> slave-observer(589)@172.17.0.3:45726
> I0629 05:49:33.204795 25308 hierarchical.cpp:525] Added agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 (296af9b598c3) with cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
> I0629 05:49:33.204876 25303 slave.cpp:1127] Registered with master
> master@172.17.0.3:45726; given agent ID
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
> I0629 05:49:33.204895 25303 fetcher.cpp:94] Clearing fetcher cache
> I0629 05:49:33.205031 25309 status_update_manager.cpp:184] Resuming sending
> status updates
> I0629 05:49:33.205252 25303 slave.cpp:1155] Checkpointing SlaveInfo to
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/meta/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/slave.info'
> I0629 05:49:33.205269 25308 hierarchical.cpp:1940] No inverse offers to send
> out!
> I0629 05:49:33.205291 25308 hierarchical.cpp:1434] Performed allocation for 1
> agents in 251549ns
> I0629 05:49:33.205541 25309 master.cpp:7305] Sending 1 offers to framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
> I0629 05:49:33.205585 25303 slave.cpp:1193] Forwarding total oversubscribed
> resources {}
> I0629 05:49:33.205760 25309 master.cpp:6324] Received update of agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
> (296af9b598c3) with total oversubscribed resources {}
> I0629 05:49:33.205921 25308 sched.cpp:933] Scheduler::resourceOffers took
> 54996ns
> I0629 05:49:33.206763 25304 master.cpp:3875] Processing ACCEPT call for
> offers: [ 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-O0 ] on agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
> (296af9b598c3) for framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> (default) at scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
> I0629 05:49:33.206811 25304 master.cpp:3426] Authorizing framework principal
> 'test-principal' to launch task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b
> I0629 05:49:33.207425 25304 master.cpp:9320] Adding task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b with resources cpus(*)(allocated: *):2;
> mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated:
> *):[31000-32000] on agent 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at
> slave(644)@172.17.0.3:45726 (296af9b598c3)
> I0629 05:49:33.207504 25304 master.cpp:4531] Launching task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 with
> resources cpus(*)(allocated: *):2; mem(*)(allocated: *):1024;
> disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] on agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
> (296af9b598c3)
> I0629 05:49:33.207877 25302 slave.cpp:1619] Got assigned task
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.208356 25304 hierarchical.cpp:850] Updated allocation of
> framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 on agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077:
> -S0 from cpus(*)(allocated: *):2; mem(*)(allocated: *):1024;
> disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] to
> cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated:
> *):1024; ports(*)(allocated: *):[31000-32000]
> I0629 05:49:33.208642 25302 slave.cpp:1900] Authorizing task
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.208668 25302 slave.cpp:6694] Authorizing framework principal
> 'test-principal' to launch task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b
> I0629 05:49:33.208978 25302 slave.cpp:2087] Launching task
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.209475 25302 paths.cpp:573] Trying to chown
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
> to user 'mesos'
> I0629 05:49:33.209678 25302 slave.cpp:7038] Launching executor
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 with resources cpus(*)(allocated:
> *):0.1; mem(*)(allocated: *):32 in work directory
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
> I0629 05:49:33.210337 25302 slave.cpp:2316] Queued task
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' for executor
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.210480 25304 containerizer.cpp:1001] Starting container
> b36e964b-c357-4f62-a767-029668d71ff6 for executor
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.212021 25304 containerizer.cpp:1531] Launching
> 'mesos-containerizer' with flags '--help="false"
> --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.3:45726"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw\/slaves\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0\/frameworks\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000\/executors\/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b\/runs\/b36e964b-c357-4f62-a767-029668d71ff6"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"ee05c102-e5cb-4cc2-9fb4-41fe1e06446b"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(644)@172.17.0.3:45726"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw\/slaves\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0\/frameworks\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000\/executors\/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b\/runs\/b36e964b-c357-4f62-a767-029668d71ff6"}]},"user":"mesos","working_directory":"\/tmp\/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw\/slaves\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0\/frameworks\/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000\/executors\/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b\/runs\/b36e964b-c357-4f62-a767-029668d71ff6"}"
> --pipe_read="8" --pipe_write="9"
> --runtime_directory="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/containers/b36e964b-c357-4f62-a767-029668d71ff6"
> --unshare_namespace_mnt="false"'
> I0629 05:49:33.212301 25302 slave.cpp:877] Successfully attached file
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
> I0629 05:49:33.214748 25304 launcher.cpp:140] Forked child with pid '28869'
> for container 'b36e964b-c357-4f62-a767-029668d71ff6'
> I0629 05:49:33.219424 25305 fetcher.cpp:353] Starting to fetch URIs for
> container: b36e964b-c357-4f62-a767-029668d71ff6, directory:
> /tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6
> I0629 05:49:33.335734 25303 slave.cpp:3790] Got registration for executor
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 from executor(1)@172.17.0.3:40357
> I0629 05:49:33.337357 25306 slave.cpp:2529] Sending queued task
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' to executor
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 at executor(1)@172.17.0.3:40357
> I0629 05:49:33.344734 25305 slave.cpp:4264] Handling status update
> TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 from executor(1)@172.17.0.3:40357
> I0629 05:49:33.346091 25306 status_update_manager.cpp:323] Received status
> update TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
> ee05c102-e5cb-4cc2-9:
> fb4-41fe1e06446b of framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.346123 25306 status_update_manager.cpp:500] Creating
> StatusUpdate stream for task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of
> framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.346360 25306 status_update_manager.cpp:377] Forwarding update
> TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 to the agent
> I0629 05:49:33.346629 25306 slave.cpp:4704] Forwarding the update
> TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 to master@172.17.0.3:45726
> I0629 05:49:33.346786 25306 slave.cpp:4598] Status update manager
> successfully handled status update TASK_RUNNING (UUID:
> 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.346828 25306 slave.cpp:4614] Sending acknowledgement for
> status update TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for
> task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 to executor(1)@172.17.0.3:40357
> I0629 05:49:33.347121 25307 master.cpp:6469] Status update TASK_RUNNING
> (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 from agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
> (296af9b598c3)
> I0629 05:49:33.347162 25307 master.cpp:6537] Forwarding status update
> TASK_RUNNING (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.347309 25307 master.cpp:8568] Updating the state of task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (latest state: TASK_RUNNING, status
> update state: TASK_RUNNING)
> I0629 05:49:33.347633 25304 sched.cpp:1041] Scheduler::statusUpdate took
> 82630ns
> I0629 05:49:33.347909 25309 master.cpp:5194] Processing ACKNOWLEDGE call
> 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07 for task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 on agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
> I0629 05:49:33.348162 25307 status_update_manager.cpp:395] Received status
> update acknowledgement (UUID: 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.348284 25307 slave.cpp:3510] Status update manager
> successfully handled status update acknowledgement (UUID:
> 3aa0c8c0-c78f-4c72-a638-ef2adf1eae07) for task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.349153 25307 process.cpp:3731] Handling HTTP event for process
> 'slave(644)' with path: '/slave(644)/api/v1'
> I0629 05:49:33.349717 25305 http.cpp:1115] HTTP POST for /slave(644)/api/v1
> from 172.17.0.3:38460
> I0629 05:49:33.350256 25305 http.cpp:527] Processing call
> LAUNCH_NESTED_CONTAINER_SESSION
> I0629 05:49:33.350522 25303 containerizer.cpp:1798] Starting nested container
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
> I0629 05:49:33.351016 25303 containerizer.cpp:1822] Trying to chown
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b'
> to user 'mesos'
> I0629 05:49:33.352535 25309 switchboard.cpp:545] Launching
> 'mesos-io-switchboard' with flags '--heartbeat_interval="30secs"
> --help="false"
> --socket_address="/tmp/mesos-io-switchboard-8a787e7f-51e0-4f96-a310-73423d54dbd5"
> --stderr_from_fd="16" --stderr_to_fd="2" --stdin_to_fd="13"
> --stdout_from_fd="14" --stdout_to_fd="1" --tty="false"
> --wait_for_connection="true"' for container
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
> I0629 05:49:33.355439 25309 switchboard.cpp:575] Created I/O switchboard
> server (pid: 28881) listening on socket file
> '/tmp/mesos-io-switchboard-8a787e7f-51e0-4f96-a310-73423d54dbd5' for
> container
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
> I0629 05:49:33.356899 25309 containerizer.cpp:1531] Launching
> 'mesos-containerizer' with flags '--help="false"
> --launch_info="{"command":{"shell":true,"value":"cat"},"environment":{},"user":"mesos"}"
> --pipe_read="13" --pipe_write="14"
> --runtime_directory="/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/containers/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b"
> --unshare_namespace_mnt="false"'
> I0629 05:49:33.358389 25309 launcher.cpp:140] Forked child with pid '28882'
> for container
> 'b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b'
> I0629 05:49:33.362704 25308 fetcher.cpp:353] Starting to fetch URIs for
> container:
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b,
> directory:
> /tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b
> I0629 05:49:33.419852 25302 process.cpp:3731] Handling HTTP event for process
> 'slave(644)' with path: '/slave(644)/api/v1'
> I0629 05:49:33.420730 25302 http.cpp:1115] HTTP POST for /slave(644)/api/v1
> from 172.17.0.3:38462
> I0629 05:49:33.421162 25308 http.cpp:527] Processing call
> ATTACH_CONTAINER_INPUT
> I0629 05:49:33.643208 25302 http.cpp:2808] Received EOF attach response for
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
> I0629 05:49:33.643333 25302 containerizer.cpp:2109] Destroying container
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b in
> RUNNING state
> W0629 05:49:33.643411 25306 http.cpp:2823] Launch nested container session
> connection for container
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
> closed
> I0629 05:49:33.643589 25302 launcher.cpp:156] Asked to destroy container
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
> I0629 05:49:33.656733 25305 process.cpp:3788] Failed to process request for
> '/slave(644)/api/v1': Disconnected
> I0629 05:49:33.656764 25306 process.cpp:1477] Returning '500 Internal Server
> Error' for '/slave(644)/api/v1' (Disconnected)
> /mesos/src/tests/api_tests.cpp:5487: Failure
> Value of: (response).get().status
> Actual: "500 Internal Server Error"
> Expected: http::OK().status
> Which is: "200 OK"
> I0629 05:49:33.683780 25306 master.cpp:1430] Framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 disconnected
> I0629 05:49:33.683836 25306 master.cpp:3160] Deactivating framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
> I0629 05:49:33.683857 25306 master.cpp:3137] Disconnecting framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
> I0629 05:49:33.683899 25306 master.cpp:1445] Giving framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726 0ns to
> failover
> I0629 05:49:33.684054 25305 hierarchical.cpp:374] Deactivated framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.684756 25306 containerizer.cpp:2109] Destroying container
> b36e964b-c357-4f62-a767-029668d71ff6 in RUNNING state
> I0629 05:49:33.685206 25305 master.cpp:7146] Framework failover timeout,
> removing framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
> I0629 05:49:33.685257 25305 master.cpp:8000] Removing framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (default) at
> scheduler-824cb0a6-7a56-4d6a-9e4d-4d302f0cfe06@172.17.0.3:45726
> I0629 05:49:33.685344 25305 master.cpp:8568] Updating the state of task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 (latest state: TASK_KILLED, status
> update state: TASK_KILLED)
> I0629 05:49:33.685416 25302 slave.cpp:3063] Asked to shut down framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 by master@172.17.0.3:45726
> I0629 05:49:33.685462 25302 slave.cpp:3088] Shutting down framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.685477 25302 slave.cpp:5531] Shutting down executor
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 at executor(1)@172.17.0.3:40357
> I0629 05:49:33.685734 25305 master.cpp:8662] Removing task
> ee05c102-e5cb-4cc2-9fb4-41fe1e06446b with resources cpus(*)(allocated: *):2;
> mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated:
> *):[31000-32000] of framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 on
> agent 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
> (296af9b598c3)
> I0629 05:49:33.685771 25302 hierarchical.cpp:1114] Recovered
> cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated:
> *):1024; ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024;
> disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 from framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.686462 25307 hierarchical.cpp:325] Removed framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.721328 25305 switchboard.cpp:888] I/O switchboard server
> process for container
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b h:
> as terminated (status=0)
> I0629 05:49:33.721588 25302 containerizer.cpp:2515] Container
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b has
> exited
> I0629 05:49:33.722765 25308 provisioner.cpp:484] Ignoring destroy request for
> unknown container
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
> I0629 05:49:33.722827 25308 containerizer.cpp:2388] Checkpointing termination
> state to nested container's runtime directory
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_AZGweZ/containers/b36e964b-c357-4f62-a767-029668d71ff6/containers/5bfa5b67-abd8-401d-a18e-7c800362d76b/termination'
> I0629 05:49:33.723461 25308 launcher.cpp:156] Asked to destroy container
> b36e964b-c357-4f62-a767-029668d71ff6
> I0629 05:49:33.731124 25308 slave.cpp:4836] Got exited event for
> executor(1)@172.17.0.3:40357
> I0629 05:49:33.822432 25305 containerizer.cpp:2515] Container
> b36e964b-c357-4f62-a767-029668d71ff6 has exited
> I0629 05:49:33.823519 25306 provisioner.cpp:484] Ignoring destroy request for
> unknown container b36e964b-c357-4f62-a767-029668d71ff6
> I0629 05:49:33.824609 25307 slave.cpp:5217] Executor
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 terminated with signal Killed
> I0629 05:49:33.824664 25307 slave.cpp:5317] Cleaning up executor
> 'ee05c102-e5cb-4cc2-9fb4-41fe1e06446b' of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000 at executor(1)@172.17.0.3:40357
> W0629 05:49:33.824992 25303 containerizer.cpp:2097] Attempted to destroy
> unknown container
> b36e964b-c357-4f62-a767-029668d71ff6.5bfa5b67-abd8-401d-a18e-7c800362d76b
> I0629 05:49:33.825323 25303 gc.cpp:55] Scheduling
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b/runs/b36e964b-c357-4f62-a767-029668d71ff6'
> for gc 6.99999044942222days in the future
> I0629 05:49:33.825505 25307 slave.cpp:5405] Cleaning up framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.825548 25305 gc.cpp:55] Scheduling
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000/executors/ee05c102-e5cb-4cc2-9fb4-41fe1e06446b'
> for gc 6.99999044592593days in the future
> I0629 05:49:33.825690 25305 status_update_manager.cpp:285] Closing status
> update streams for framework 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.825729 25305 status_update_manager.cpp:531] Cleaning up status
> update stream for task ee05c102-e5cb-4cc2-9fb4-41fe1e06446b of framework
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000
> I0629 05:49:33.825898 25307 slave.cpp:796] Agent terminating
> I0629 05:49:33.826009 25305 gc.cpp:55] Scheduling
> '/tmp/ContentType_AgentAPIStreamingTest_AttachInputToNestedContainerSession_0_2eciuw/slaves/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0/frameworks/90ea1640-bdf3-49ba-b78f-b2ba7ea30077-0000'
> for gc 6.99999044129778days in the future
> I0629 05:49:33.826244 25308 master.cpp:1313] Agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
> (296af9b598c3) disconnected
> I0629 05:49:33.826398 25308 master.cpp:3197] Disconnecting agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
> (296af9b598c3)
> I0629 05:49:33.826576 25308 master.cpp:3216] Deactivating agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 at slave(644)@172.17.0.3:45726
> (296af9b598c3)
> I0629 05:49:33.826901 25302 hierarchical.cpp:653] Agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0 deactivated
> I0629 05:49:33.828503 25301 master.cpp:1155] Master terminating
> I0629 05:49:33.828763 25306 hierarchical.cpp:558] Removed agent
> 90ea1640-bdf3-49ba-b78f-b2ba7ea30077-S0
> [ FAILED ]
> ContentType/AgentAPIStreamingTest.AttachInputToNestedContainerSession/0,
> where GetParam() = application/x-protobuf (656 ms)
> {code}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
