[
https://issues.apache.org/jira/browse/MESOS-5274?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Gilbert Song updated MESOS-5274:
--------------------------------
Sprint: Mesosphere Sprint 37
Labels: filesystem flaky mesosphere (was: flaky mesosphere)
> DockerRuntimeIsolatorTest.ROOT_DockerDefaultEntryptLocalPuller is flaky
> -----------------------------------------------------------------------
>
> Key: MESOS-5274
> URL: https://issues.apache.org/jira/browse/MESOS-5274
> Project: Mesos
> Issue Type: Bug
> Reporter: Neil Conway
> Assignee: haosdent
> Labels: filesystem, flaky, mesosphere
>
> Observed on Mesosphere internal CI:
> {noformat}
> [15:07:02] : [Step 10/10] [ RUN ]
> DockerRuntimeIsolatorTest.ROOT_DockerDefaultEntryptLocalPuller
> [15:07:02]W: [Step 10/10] I0425 15:07:02.166211 32147 cluster.cpp:149]
> Creating default 'local' authorizer
> [15:07:02]W: [Step 10/10] I0425 15:07:02.178527 32147 leveldb.cpp:174]
> Opened db in 12.157082ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.179869 32147 leveldb.cpp:181]
> Compacted db in 1.313946ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.179893 32147 leveldb.cpp:196]
> Created db iterator in 3836ns
> [15:07:02]W: [Step 10/10] I0425 15:07:02.179913 32147 leveldb.cpp:202]
> Seeked to beginning of db in 656ns
> [15:07:02]W: [Step 10/10] I0425 15:07:02.179919 32147 leveldb.cpp:271]
> Iterated through 0 keys in the db in 553ns
> [15:07:02]W: [Step 10/10] I0425 15:07:02.179934 32147 replica.cpp:779]
> Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> [15:07:02]W: [Step 10/10] I0425 15:07:02.180132 32165 recover.cpp:447]
> Starting replica recovery
> [15:07:02]W: [Step 10/10] I0425 15:07:02.180217 32163 recover.cpp:473]
> Replica is in EMPTY status
> [15:07:02]W: [Step 10/10] I0425 15:07:02.180500 32161 replica.cpp:673]
> Replica in EMPTY status received a broadcasted recover request from
> (17793)@172.30.2.13:42326
> [15:07:02]W: [Step 10/10] I0425 15:07:02.180655 32167 recover.cpp:193]
> Received a recover response from a replica in EMPTY status
> [15:07:02]W: [Step 10/10] I0425 15:07:02.180891 32165 recover.cpp:564]
> Updating replica status to STARTING
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181026 32168 master.cpp:382]
> Master f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517 (ip-172-30-2-13.mesosphere.io)
> started on 172.30.2.13:42326
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181040 32168 master.cpp:384] Flags
> at startup: --acls="" --allocation_interval="1secs"
> --allocator="HierarchicalDRF" --authenticate="true"
> --authenticate_http="true" --authenticate_http_frameworks="true"
> --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/G2DxFl/credentials" --framework_sorter="drf"
> --help="false" --hostname_lookup="true" --http_authenticators="basic"
> --http_framework_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="100secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/G2DxFl/master"
> --zk_session_timeout="10secs"
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181165 32168 master.cpp:433]
> Master only allowing authenticated frameworks to register
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181171 32168 master.cpp:439]
> Master only allowing authenticated agents to register
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181175 32168 master.cpp:445]
> Master only allowing authenticated HTTP frameworks to register
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181180 32168 credentials.hpp:37]
> Loading credentials for authentication from '/tmp/G2DxFl/credentials'
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181313 32168 master.cpp:489] Using
> default 'crammd5' authenticator
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181352 32168 master.cpp:560] Using
> default 'basic' HTTP authenticator
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181421 32168 master.cpp:640] Using
> default 'basic' HTTP framework authenticator
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181473 32168 master.cpp:687]
> Authorization enabled
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181556 32162
> whitelist_watcher.cpp:77] No whitelist given
> [15:07:02]W: [Step 10/10] I0425 15:07:02.181576 32163 hierarchical.cpp:142]
> Initialized hierarchical allocator process
> [15:07:02]W: [Step 10/10] I0425 15:07:02.182076 32164 master.cpp:1932] The
> newly elected leader is [email protected]:42326 with id
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517
> [15:07:02]W: [Step 10/10] I0425 15:07:02.182090 32164 master.cpp:1945]
> Elected as the leading master!
> [15:07:02]W: [Step 10/10] I0425 15:07:02.182095 32164 master.cpp:1632]
> Recovering from registrar
> [15:07:02]W: [Step 10/10] I0425 15:07:02.182142 32168 registrar.cpp:331]
> Recovering registrar
> [15:07:02]W: [Step 10/10] I0425 15:07:02.182188 32167 leveldb.cpp:304]
> Persisting metadata (8 bytes) to leveldb took 1.2377ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.182205 32167 replica.cpp:320]
> Persisted replica status to STARTING
> [15:07:02]W: [Step 10/10] I0425 15:07:02.182320 32167 recover.cpp:473]
> Replica is in STARTING status
> [15:07:02]W: [Step 10/10] I0425 15:07:02.182600 32162 replica.cpp:673]
> Replica in STARTING status received a broadcasted recover request from
> (17796)@172.30.2.13:42326
> [15:07:02]W: [Step 10/10] I0425 15:07:02.182705 32165 recover.cpp:193]
> Received a recover response from a replica in STARTING status
> [15:07:02]W: [Step 10/10] I0425 15:07:02.182840 32161 recover.cpp:564]
> Updating replica status to VOTING
> [15:07:02]W: [Step 10/10] I0425 15:07:02.183964 32162 leveldb.cpp:304]
> Persisting metadata (8 bytes) to leveldb took 1.061794ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.183980 32162 replica.cpp:320]
> Persisted replica status to VOTING
> [15:07:02]W: [Step 10/10] I0425 15:07:02.184012 32162 recover.cpp:578]
> Successfully joined the Paxos group
> [15:07:02]W: [Step 10/10] I0425 15:07:02.184056 32162 recover.cpp:462]
> Recover process terminated
> [15:07:02]W: [Step 10/10] I0425 15:07:02.184185 32161 log.cpp:524]
> Attempting to start the writer
> [15:07:02]W: [Step 10/10] I0425 15:07:02.184515 32167 replica.cpp:493]
> Replica received implicit promise request from (17797)@172.30.2.13:42326 with
> proposal 1
> [15:07:02]W: [Step 10/10] I0425 15:07:02.185619 32167 leveldb.cpp:304]
> Persisting metadata (8 bytes) to leveldb took 1.087808ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.185634 32167 replica.cpp:342]
> Persisted promised to 1
> [15:07:02]W: [Step 10/10] I0425 15:07:02.185812 32162 coordinator.cpp:238]
> Coordinator attempting to fill missing positions
> [15:07:02]W: [Step 10/10] I0425 15:07:02.186211 32164 replica.cpp:388]
> Replica received explicit promise request from (17798)@172.30.2.13:42326 for
> position 0 with proposal 2
> [15:07:02]W: [Step 10/10] I0425 15:07:02.187296 32164 leveldb.cpp:341]
> Persisting action (8 bytes) to leveldb took 1.067669ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.187312 32164 replica.cpp:712]
> Persisted action at 0
> [15:07:02]W: [Step 10/10] I0425 15:07:02.187705 32167 replica.cpp:537]
> Replica received write request for position 0 from (17799)@172.30.2.13:42326
> [15:07:02]W: [Step 10/10] I0425 15:07:02.187729 32167 leveldb.cpp:436]
> Reading position from leveldb took 10052ns
> [15:07:02]W: [Step 10/10] I0425 15:07:02.188858 32167 leveldb.cpp:341]
> Persisting action (14 bytes) to leveldb took 1.11514ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.188874 32167 replica.cpp:712]
> Persisted action at 0
> [15:07:02]W: [Step 10/10] I0425 15:07:02.189128 32163 replica.cpp:691]
> Replica received learned notice for position 0 from @0.0.0.0:0
> [15:07:02]W: [Step 10/10] I0425 15:07:02.190341 32163 leveldb.cpp:341]
> Persisting action (16 bytes) to leveldb took 1.197513ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.190356 32163 replica.cpp:712]
> Persisted action at 0
> [15:07:02]W: [Step 10/10] I0425 15:07:02.190362 32163 replica.cpp:697]
> Replica learned NOP action at position 0
> [15:07:02]W: [Step 10/10] I0425 15:07:02.190518 32162 log.cpp:540] Writer
> started with ending position 0
> [15:07:02]W: [Step 10/10] I0425 15:07:02.190822 32165 leveldb.cpp:436]
> Reading position from leveldb took 10027ns
> [15:07:02]W: [Step 10/10] I0425 15:07:02.191026 32163 registrar.cpp:364]
> Successfully fetched the registry (0B) in 8.86912ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.191061 32163 registrar.cpp:463]
> Applied 1 operations in 4130ns; attempting to update the 'registry'
> [15:07:02]W: [Step 10/10] I0425 15:07:02.191259 32166 log.cpp:548]
> Attempting to append 205 bytes to the log
> [15:07:02]W: [Step 10/10] I0425 15:07:02.191301 32166 coordinator.cpp:348]
> Coordinator attempting to write APPEND action at position 1
> [15:07:02]W: [Step 10/10] I0425 15:07:02.191524 32162 replica.cpp:537]
> Replica received write request for position 1 from (17800)@172.30.2.13:42326
> [15:07:02]W: [Step 10/10] I0425 15:07:02.192633 32162 leveldb.cpp:341]
> Persisting action (224 bytes) to leveldb took 1.092846ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.192648 32162 replica.cpp:712]
> Persisted action at 1
> [15:07:02]W: [Step 10/10] I0425 15:07:02.192883 32164 replica.cpp:691]
> Replica received learned notice for position 1 from @0.0.0.0:0
> [15:07:02]W: [Step 10/10] I0425 15:07:02.193985 32164 leveldb.cpp:341]
> Persisting action (226 bytes) to leveldb took 1.08493ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.194001 32164 replica.cpp:712]
> Persisted action at 1
> [15:07:02]W: [Step 10/10] I0425 15:07:02.194006 32164 replica.cpp:697]
> Replica learned APPEND action at position 1
> [15:07:02]W: [Step 10/10] I0425 15:07:02.194190 32165 registrar.cpp:508]
> Successfully updated the 'registry' in 3.108864ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.194236 32165 registrar.cpp:394]
> Successfully recovered registrar
> [15:07:02]W: [Step 10/10] I0425 15:07:02.194283 32168 log.cpp:567]
> Attempting to truncate the log to 1
> [15:07:02]W: [Step 10/10] I0425 15:07:02.194350 32162 master.cpp:1740]
> Recovered 0 agents from the Registry (166B) ; allowing 10mins for agents to
> re-register
> [15:07:02]W: [Step 10/10] I0425 15:07:02.194396 32167 hierarchical.cpp:169]
> Skipping recovery of hierarchical allocator: nothing to recover
> [15:07:02]W: [Step 10/10] I0425 15:07:02.194461 32166 coordinator.cpp:348]
> Coordinator attempting to write TRUNCATE action at position 2
> [15:07:02]W: [Step 10/10] I0425 15:07:02.194767 32163 replica.cpp:537]
> Replica received write request for position 2 from (17801)@172.30.2.13:42326
> [15:07:02]W: [Step 10/10] I0425 15:07:02.195948 32163 leveldb.cpp:341]
> Persisting action (16 bytes) to leveldb took 1.163067ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.195963 32163 replica.cpp:712]
> Persisted action at 2
> [15:07:02]W: [Step 10/10] I0425 15:07:02.196156 32161 replica.cpp:691]
> Replica received learned notice for position 2 from @0.0.0.0:0
> [15:07:02]W: [Step 10/10] I0425 15:07:02.197480 32161 leveldb.cpp:341]
> Persisting action (18 bytes) to leveldb took 1.305359ms
> [15:07:02]W: [Step 10/10] I0425 15:07:02.197509 32161 leveldb.cpp:399]
> Deleting ~1 keys from leveldb took 13719ns
> [15:07:02]W: [Step 10/10] I0425 15:07:02.197516 32161 replica.cpp:712]
> Persisted action at 2
> [15:07:02]W: [Step 10/10] I0425 15:07:02.197521 32161 replica.cpp:697]
> Replica learned TRUNCATE action at position 2
> [15:07:03]W: [Step 10/10] I0425 15:07:03.182390 32167
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:03]W: [Step 10/10] I0425 15:07:03.182428 32167
> hierarchical.cpp:1139] Performed allocation for 0 agents in 69623ns
> [15:07:04]W: [Step 10/10] I0425 15:07:04.182711 32168
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:04]W: [Step 10/10] I0425 15:07:04.182757 32168
> hierarchical.cpp:1139] Performed allocation for 0 agents in 91881ns
> [15:07:05]W: [Step 10/10] I0425 15:07:05.183476 32163
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:05]W: [Step 10/10] I0425 15:07:05.183509 32163
> hierarchical.cpp:1139] Performed allocation for 0 agents in 59724ns
> [15:07:06]W: [Step 10/10] I0425 15:07:06.184595 32168
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:06]W: [Step 10/10] I0425 15:07:06.184630 32168
> hierarchical.cpp:1139] Performed allocation for 0 agents in 51046ns
> [15:07:07]W: [Step 10/10] I0425 15:07:07.184818 32167
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:07]W: [Step 10/10] I0425 15:07:07.184854 32167
> hierarchical.cpp:1139] Performed allocation for 0 agents in 56653ns
> [15:07:08]W: [Step 10/10] I0425 15:07:08.185839 32168
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:08]W: [Step 10/10] I0425 15:07:08.185873 32168
> hierarchical.cpp:1139] Performed allocation for 0 agents in 46112ns
> [15:07:09]W: [Step 10/10] I0425 15:07:09.186439 32167
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:09]W: [Step 10/10] I0425 15:07:09.186473 32167
> hierarchical.cpp:1139] Performed allocation for 0 agents in 54647ns
> [15:07:10]W: [Step 10/10] I0425 15:07:10.186907 32168
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:10]W: [Step 10/10] I0425 15:07:10.186942 32168
> hierarchical.cpp:1139] Performed allocation for 0 agents in 49298ns
> [15:07:11]W: [Step 10/10] I0425 15:07:11.188061 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:11]W: [Step 10/10] I0425 15:07:11.188093 32164
> hierarchical.cpp:1139] Performed allocation for 0 agents in 67195ns
> [15:07:12]W: [Step 10/10] I0425 15:07:12.189275 32161
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:12]W: [Step 10/10] I0425 15:07:12.189311 32161
> hierarchical.cpp:1139] Performed allocation for 0 agents in 68130ns
> [15:07:13]W: [Step 10/10] I0425 15:07:13.190248 32163
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:13]W: [Step 10/10] I0425 15:07:13.190286 32163
> hierarchical.cpp:1139] Performed allocation for 0 agents in 57124ns
> [15:07:14]W: [Step 10/10] I0425 15:07:14.191352 32161
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:14]W: [Step 10/10] I0425 15:07:14.191382 32161
> hierarchical.cpp:1139] Performed allocation for 0 agents in 50249ns
> [15:07:15]W: [Step 10/10] I0425 15:07:15.192203 32166
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:15]W: [Step 10/10] I0425 15:07:15.192237 32166
> hierarchical.cpp:1139] Performed allocation for 0 agents in 75731ns
> [15:07:16]W: [Step 10/10] I0425 15:07:16.192332 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:16]W: [Step 10/10] I0425 15:07:16.192363 32164
> hierarchical.cpp:1139] Performed allocation for 0 agents in 57948ns
> [15:07:17]W: [Step 10/10] I0425 15:07:17.193349 32162
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:17]W: [Step 10/10] I0425 15:07:17.193379 32162
> hierarchical.cpp:1139] Performed allocation for 0 agents in 57275ns
> [15:07:18]W: [Step 10/10] I0425 15:07:18.081517 32147
> containerizer.cpp:178] Using isolation:
> docker/runtime,filesystem/linux,network/cni
> [15:07:18]W: [Step 10/10] I0425 15:07:18.088409 32147
> linux_launcher.cpp:101] Using /sys/fs/cgroup/freezer as the freezer hierarchy
> for the Linux launcher
> [15:07:18]W: [Step 10/10] E0425 15:07:18.093040 32147 shell.hpp:106]
> Command 'hadoop version 2>&1' failed; this is the output:
> [15:07:18]W: [Step 10/10] sh: hadoop: command not found
> [15:07:18]W: [Step 10/10] I0425 15:07:18.093065 32147 fetcher.cpp:59]
> Skipping URI fetcher plugin 'hadoop' as it could not be created: Failed to
> create HDFS client: Failed to execute 'hadoop version 2>&1'; the command was
> either not found or exited with a non-zero exit status: 127
> [15:07:18]W: [Step 10/10] I0425 15:07:18.093106 32147 local_puller.cpp:90]
> Creating local puller with docker registry '/tmp/G2DxFl/archives'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.093937 32147 linux.cpp:81] Making
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S'
> a shared mount
> [15:07:18]W: [Step 10/10] I0425 15:07:18.101300 32164 slave.cpp:202] Agent
> started on 456)@172.30.2.13:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.101318 32164 slave.cpp:203] Flags
> at startup: --appc_simple_discovery_uri_prefix="http://";
> --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http="true"
> --authenticatee="crammd5" --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="/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/credential"
> --default_role="*" --disk_watch_interval="1mins" --docker="docker"
> --docker_kill_orphans="true" --docker_registry="/tmp/G2DxFl/archives"
> --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock"
> --docker_stop_timeout="0ns" --docker_store_dir="/tmp/G2DxFl/store"
> --enforce_container_disk_quota="false"
> --executor_registration_timeout="1mins"
> --executor_shutdown_grace_period="5secs"
> --fetcher_cache_dir="/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/fetch"
> --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks"
> --gc_disk_headroom="0.1" --hadoop_home="" --help="false"
> --hostname_lookup="true" --http_authenticators="basic"
> --http_command_executor="false"
> --http_credentials="/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/http_credentials"
> --image_providers="docker" --image_provisioner_backend="copy"
> --initialize_driver_logging="true"
> --isolation="docker/runtime,filesystem/linux"
> --launcher_dir="/mnt/teamcity/work/4240ba9ddd0997c3/build/src"
> --logbufsecs="0" --logging_level="INFO"
> --oversubscribed_resources_interval="15secs" --perf_duration="10secs"
> --perf_interval="1mins" --qos_correction_interval_min="0ns" --quiet="false"
> --recover="reconnect" --recovery_timeout="15mins"
> --registration_backoff_factor="10ms"
> --resources="cpus:2;mem:1024;disk:1024;ports:[31000-32000]"
> --revocable_cpu_low_priority="true" --sandbox_directory="/mnt/mesos/sandbox"
> --strict="true" --switch_user="true" --systemd_enable_support="true"
> --systemd_runtime_directory="/run/systemd/system" --version="false"
> --work_dir="/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S"
> [15:07:18]W: [Step 10/10] I0425 15:07:18.101650 32164 credentials.hpp:86]
> Loading credential for authentication from
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/credential'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.101753 32164 slave.cpp:340] Agent
> using credential for: test-principal
> [15:07:18]W: [Step 10/10] I0425 15:07:18.101765 32164 credentials.hpp:37]
> Loading credentials for authentication from
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/http_credentials'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.101934 32164 slave.cpp:392] Using
> default 'basic' HTTP authenticator
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102025 32147 sched.cpp:224]
> Version: 0.29.0
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102108 32164 resources.cpp:572]
> Parsing resources as JSON failed:
> cpus:2;mem:1024;disk:1024;ports:[31000-32000]
> [15:07:18]W: [Step 10/10] Trying semicolon-delimited string format instead
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102246 32164 slave.cpp:591] Agent
> resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102258 32168 sched.cpp:328] New
> master detected at [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102270 32164 slave.cpp:599] Agent
> attributes: [ ]
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102288 32164 slave.cpp:604] Agent
> hostname: ip-172-30-2-13.mesosphere.io
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102298 32168 sched.cpp:384]
> Authenticating with master [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102304 32168 sched.cpp:391] Using
> default CRAM-MD5 authenticatee
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102377 32167
> authenticatee.cpp:121] Creating new client SASL connection
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102607 32167 master.cpp:5803]
> Authenticating
> [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102687 32165 state.cpp:57]
> Recovering state from
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/meta'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102716 32168
> authenticator.cpp:413] Starting authentication session for
> crammd5_authenticatee(929)@172.30.2.13:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102793 32166 authenticator.cpp:98]
> Creating new server SASL connection
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102864 32167
> status_update_manager.cpp:200] Recovering status update manager
> [15:07:18]W: [Step 10/10] I0425 15:07:18.102946 32163
> containerizer.cpp:444] Recovering containerizer
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103004 32162
> authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103031 32162
> authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103080 32162
> authenticator.cpp:203] Received SASL authentication start
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103122 32162
> authenticator.cpp:325] Authentication requires more steps
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103206 32162
> authenticatee.cpp:258] Received SASL authentication step
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103269 32162
> authenticator.cpp:231] Received SASL authentication step
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103291 32162 auxprop.cpp:107]
> Request to lookup properties for user: 'test-principal' realm:
> 'ip-172-30-2-13.mesosphere.io' server FQDN: 'ip-172-30-2-13.mesosphere.io'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103302 32162 auxprop.cpp:179]
> Looking up auxiliary property '*userPassword'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103317 32162 auxprop.cpp:179]
> Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103332 32162 auxprop.cpp:107]
> Request to lookup properties for user: 'test-principal' realm:
> 'ip-172-30-2-13.mesosphere.io' server FQDN: 'ip-172-30-2-13.mesosphere.io'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103339 32162 auxprop.cpp:129]
> Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103346 32162 auxprop.cpp:129]
> Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since
> SASL_AUXPROP_AUTHZID == true
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103358 32162
> authenticator.cpp:317] Authentication success
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103404 32166
> authenticatee.cpp:298] Authentication success
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103425 32164 master.cpp:5833]
> Successfully authenticated principal 'test-principal' at
> [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103446 32161
> authenticator.cpp:431] Authentication session cleanup for
> crammd5_authenticatee(929)@172.30.2.13:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103514 32168 sched.cpp:474]
> Successfully authenticated with master [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103528 32168 sched.cpp:783]
> Sending SUBSCRIBE call to [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103580 32168 sched.cpp:816] Will
> retry registration in 628.03409ms if necessary
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103618 32167 master.cpp:2465]
> Received SUBSCRIBE call for framework 'default' at
> [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103634 32167 master.cpp:1971]
> Authorizing framework principal 'test-principal' to receive offers for role
> '*'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103719 32166 master.cpp:2541]
> Subscribing framework default with checkpointing disabled and capabilities [
> ]
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103853 32167 hierarchical.cpp:264]
> Added framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103874 32167
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103884 32167
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103901 32167
> hierarchical.cpp:1139] Performed allocation for 0 agents in 34160ns
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103919 32161 sched.cpp:710]
> Framework registered with f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:07:18]W: [Step 10/10] I0425 15:07:18.103940 32161 sched.cpp:724]
> Scheduler::registered took 8133ns
> [15:07:18]W: [Step 10/10] I0425 15:07:18.104763 32162
> metadata_manager.cpp:192] No images to load from disk. Docker provisioner
> image storage path '/tmp/G2DxFl/store/storedImages' does not exist
> [15:07:18]W: [Step 10/10] I0425 15:07:18.104841 32161 provisioner.cpp:245]
> Provisioner recovery complete
> [15:07:18]W: [Step 10/10] I0425 15:07:18.104950 32162 slave.cpp:4824]
> Finished recovery
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105165 32162 slave.cpp:4996]
> Querying resource estimator for oversubscribable resources
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105257 32168
> status_update_manager.cpp:174] Pausing sending status updates
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105257 32165 slave.cpp:951] New
> master detected at [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105294 32165 slave.cpp:1014]
> Authenticating with master [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105300 32165 slave.cpp:1019] Using
> default CRAM-MD5 authenticatee
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105330 32165 slave.cpp:987]
> Detecting new master
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105345 32161
> authenticatee.cpp:121] Creating new client SASL connection
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105358 32165 slave.cpp:5010]
> Received oversubscribable resources from the resource estimator
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105512 32161 master.cpp:5803]
> Authenticating slave(456)@172.30.2.13:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105566 32166
> authenticator.cpp:413] Starting authentication session for
> crammd5_authenticatee(930)@172.30.2.13:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105621 32166 authenticator.cpp:98]
> Creating new server SASL connection
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105792 32166
> authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105808 32166
> authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105854 32167
> authenticator.cpp:203] Received SASL authentication start
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105885 32167
> authenticator.cpp:325] Authentication requires more steps
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105916 32167
> authenticatee.cpp:258] Received SASL authentication step
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105948 32167
> authenticator.cpp:231] Received SASL authentication step
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105963 32167 auxprop.cpp:107]
> Request to lookup properties for user: 'test-principal' realm:
> 'ip-172-30-2-13.mesosphere.io' server FQDN: 'ip-172-30-2-13.mesosphere.io'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105975 32167 auxprop.cpp:179]
> Looking up auxiliary property '*userPassword'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105986 32167 auxprop.cpp:179]
> Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105993 32167 auxprop.cpp:107]
> Request to lookup properties for user: 'test-principal' realm:
> 'ip-172-30-2-13.mesosphere.io' server FQDN: 'ip-172-30-2-13.mesosphere.io'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> [15:07:18]W: [Step 10/10] I0425 15:07:18.105998 32167 auxprop.cpp:129]
> Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106001 32167 auxprop.cpp:129]
> Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since
> SASL_AUXPROP_AUTHZID == true
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106009 32167
> authenticator.cpp:317] Authentication success
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106045 32167
> authenticatee.cpp:298] Authentication success
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106070 32165
> authenticator.cpp:431] Authentication session cleanup for
> crammd5_authenticatee(930)@172.30.2.13:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106088 32161 master.cpp:5833]
> Successfully authenticated principal 'test-principal' at
> slave(456)@172.30.2.13:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106149 32167 slave.cpp:1084]
> Successfully authenticated with master [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106194 32167 slave.cpp:1480] Will
> retry registration in 3.523044ms if necessary
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106245 32162 master.cpp:4514]
> Registering agent at slave(456)@172.30.2.13:42326
> (ip-172-30-2-13.mesosphere.io) with id f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106359 32165 registrar.cpp:463]
> Applied 1 operations in 13916ns; attempting to update the 'registry'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106518 32161 log.cpp:548]
> Attempting to append 390 bytes to the log
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106564 32161 coordinator.cpp:348]
> Coordinator attempting to write APPEND action at position 3
> [15:07:18]W: [Step 10/10] I0425 15:07:18.106839 32163 replica.cpp:537]
> Replica received write request for position 3 from (17825)@172.30.2.13:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.107951 32163 leveldb.cpp:341]
> Persisting action (409 bytes) to leveldb took 1.089055ms
> [15:07:18]W: [Step 10/10] I0425 15:07:18.107967 32163 replica.cpp:712]
> Persisted action at 3
> [15:07:18]W: [Step 10/10] I0425 15:07:18.108248 32167 replica.cpp:691]
> Replica received learned notice for position 3 from @0.0.0.0:0
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109148 32167 leveldb.cpp:341]
> Persisting action (411 bytes) to leveldb took 880495ns
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109159 32167 replica.cpp:712]
> Persisted action at 3
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109165 32167 replica.cpp:697]
> Replica learned APPEND action at position 3
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109462 32164 registrar.cpp:508]
> Successfully updated the 'registry' in 3.08096ms
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109516 32163 log.cpp:567]
> Attempting to truncate the log to 3
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109577 32163 coordinator.cpp:348]
> Coordinator attempting to write TRUNCATE action at position 4
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109673 32163 slave.cpp:3699]
> Received ping from slave-observer(420)@172.30.2.13:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109658 32161 master.cpp:4582]
> Registered agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 at
> slave(456)@172.30.2.13:42326 (ip-172-30-2-13.mesosphere.io) with cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109694 32166 hierarchical.cpp:473]
> Added agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0
> (ip-172-30-2-13.mesosphere.io) with cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000] (allocated: )
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109729 32163 slave.cpp:1128]
> Registered with master [email protected]:42326; given agent ID
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109738 32163 fetcher.cpp:81]
> Clearing fetcher cache
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109789 32161
> status_update_manager.cpp:181] Resuming sending status updates
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109817 32166
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109843 32166
> hierarchical.cpp:1162] Performed allocation for agent
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 in 122827ns
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109891 32167 replica.cpp:537]
> Replica received write request for position 4 from (17826)@172.30.2.13:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109915 32164 master.cpp:5632]
> Sending 1 offers to framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> (default) at [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.109956 32163 slave.cpp:1151]
> Checkpointing SlaveInfo to
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/meta/slaves/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0/slave.info'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110071 32162 sched.cpp:880]
> Scheduler::resourceOffers took 32262ns
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110090 32163 slave.cpp:1188]
> Forwarding total oversubscribed resources
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110218 32165 master.cpp:4926]
> Received update of agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 at
> slave(456)@172.30.2.13:42326 (ip-172-30-2-13.mesosphere.io) with total
> oversubscribed resources
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110232 32147 resources.cpp:572]
> Parsing resources as JSON failed: cpus:1;mem:128
> [15:07:18]W: [Step 10/10] Trying semicolon-delimited string format instead
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110344 32163 hierarchical.cpp:531]
> Agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 (ip-172-30-2-13.mesosphere.io)
> updated with oversubscribed resources (total: cpus(*):2; mem(*):1024;
> disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024;
> disk(*):1024; ports(*):[31000-32000])
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110394 32163
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110405 32163
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110422 32163
> hierarchical.cpp:1162] Performed allocation for agent
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 in 47476ns
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110503 32163 master.cpp:3412]
> Processing ACCEPT call for offers: [ f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-O0
> ] on agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 at
> slave(456)@172.30.2.13:42326 (ip-172-30-2-13.mesosphere.io) for framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 (default) at
> [email protected]:42326
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110517 32163 master.cpp:3015]
> Authorizing framework principal 'test-principal' to launch task
> 41d96480-fae8-44fe-bd96-7c625ddc6a09 as user 'root'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110780 32161 master.hpp:177]
> Adding task 41d96480-fae8-44fe-bd96-7c625ddc6a09 with resources cpus(*):1;
> mem(*):128 on agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0
> (ip-172-30-2-13.mesosphere.io)
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110822 32167 leveldb.cpp:341]
> Persisting action (16 bytes) to leveldb took 913411ns
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110819 32161 master.cpp:3897]
> Launching task 41d96480-fae8-44fe-bd96-7c625ddc6a09 of framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 (default) at
> [email protected]:42326 with
> resources cpus(*):1; mem(*):128 on agent
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 at slave(456)@172.30.2.13:42326
> (ip-172-30-2-13.mesosphere.io)
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110836 32167 replica.cpp:712]
> Persisted action at 4
> [15:07:18]W: [Step 10/10] I0425 15:07:18.110921 32165 slave.cpp:1520] Got
> assigned task 41d96480-fae8-44fe-bd96-7c625ddc6a09 for framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:07:18]W: [Step 10/10] I0425 15:07:18.111024 32165 resources.cpp:572]
> Parsing resources as JSON failed: cpus:0.1;mem:32
> [15:07:18]W: [Step 10/10] Trying semicolon-delimited string format instead
> [15:07:18]W: [Step 10/10] I0425 15:07:18.111018 32164 hierarchical.cpp:891]
> Recovered cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] (total:
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated:
> cpus(*):1; mem(*):128) on agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 from
> framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:07:18]W: [Step 10/10] I0425 15:07:18.111047 32167 replica.cpp:691]
> Replica received learned notice for position 4 from @0.0.0.0:0
> [15:07:18]W: [Step 10/10] I0425 15:07:18.111050 32164 hierarchical.cpp:928]
> Framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 filtered agent
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 for 5secs
> [15:07:18]W: [Step 10/10] I0425 15:07:18.111176 32165 slave.cpp:1639]
> Launching task 41d96480-fae8-44fe-bd96-7c625ddc6a09 for framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:07:18]W: [Step 10/10] I0425 15:07:18.111212 32165 resources.cpp:572]
> Parsing resources as JSON failed: cpus:0.1;mem:32
> [15:07:18]W: [Step 10/10] Trying semicolon-delimited string format instead
> [15:07:18]W: [Step 10/10] I0425 15:07:18.111510 32165 paths.cpp:528] Trying
> to chown
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/slaves/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0/frameworks/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000/executors/41d96480-fae8-44fe-bd96-7c625ddc6a09/runs/dca2f70c-0fdf-42f6-afba-3cca70f28b01'
> to user 'root'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.112715 32167 leveldb.cpp:341]
> Persisting action (18 bytes) to leveldb took 624784ns
> [15:07:18]W: [Step 10/10] I0425 15:07:18.112800 32167 leveldb.cpp:399]
> Deleting ~2 keys from leveldb took 52809ns
> [15:07:18]W: [Step 10/10] I0425 15:07:18.112815 32167 replica.cpp:712]
> Persisted action at 4
> [15:07:18]W: [Step 10/10] I0425 15:07:18.112823 32167 replica.cpp:697]
> Replica learned TRUNCATE action at position 4
> [15:07:18]W: [Step 10/10] I0425 15:07:18.116066 32165 slave.cpp:5644]
> Launching executor 41d96480-fae8-44fe-bd96-7c625ddc6a09 of framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 with resources cpus(*):0.1;
> mem(*):32 in work directory
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/slaves/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0/frameworks/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000/executors/41d96480-fae8-44fe-bd96-7c625ddc6a09/runs/dca2f70c-0fdf-42f6-afba-3cca70f28b01'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.116205 32167
> containerizer.cpp:703] Starting container
> 'dca2f70c-0fdf-42f6-afba-3cca70f28b01' for executor
> '41d96480-fae8-44fe-bd96-7c625ddc6a09' of framework
> 'f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.116210 32165 slave.cpp:1865]
> Queuing task '41d96480-fae8-44fe-bd96-7c625ddc6a09' for executor
> '41d96480-fae8-44fe-bd96-7c625ddc6a09' of framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:07:18]W: [Step 10/10] I0425 15:07:18.116268 32165 slave.cpp:904]
> Successfully attached file
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/slaves/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0/frameworks/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000/executors/41d96480-fae8-44fe-bd96-7c625ddc6a09/runs/dca2f70c-0fdf-42f6-afba-3cca70f28b01'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.116515 32168
> metadata_manager.cpp:159] Looking for image 'alpine'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.116729 32166 local_puller.cpp:142]
> Untarring image 'alpine' from '/tmp/G2DxFl/archives/alpine.tar' to
> '/tmp/G2DxFl/store/staging/mHBdlv'
> [15:07:18]W: [Step 10/10] I0425 15:07:18.193632 32165
> hierarchical.cpp:1674] Filtered offer with cpus(*):1; mem(*):896;
> disk(*):1024; ports(*):[31000-32000] on agent
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 for framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:07:18]W: [Step 10/10] I0425 15:07:18.193694 32165
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:18]W: [Step 10/10] I0425 15:07:18.193701 32165
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:18]W: [Step 10/10] I0425 15:07:18.193718 32165
> hierarchical.cpp:1139] Performed allocation for 1 agents in 210907ns
> [15:07:19]W: [Step 10/10] I0425 15:07:19.194316 32161
> hierarchical.cpp:1674] Filtered offer with cpus(*):1; mem(*):896;
> disk(*):1024; ports(*):[31000-32000] on agent
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 for framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:07:19]W: [Step 10/10] I0425 15:07:19.194358 32161
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:19]W: [Step 10/10] I0425 15:07:19.194365 32161
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:19]W: [Step 10/10] I0425 15:07:19.194381 32161
> hierarchical.cpp:1139] Performed allocation for 1 agents in 180413ns
> [15:07:19]W: [Step 10/10] I0425 15:07:19.207705 32163 local_puller.cpp:162]
> The repositories JSON file for image 'alpine' is
> '{"alpine":{"latest":"815b809d588c80fd6ddf4d6ac244ad1c01ae4cbe0f91cc7480e306671ee9c346"}}'
> [15:07:19]W: [Step 10/10] I0425 15:07:19.207916 32163 local_puller.cpp:290]
> Extracting layer tar ball
> '/tmp/G2DxFl/store/staging/mHBdlv/815b809d588c80fd6ddf4d6ac244ad1c01ae4cbe0f91cc7480e306671ee9c346/layer.tar
> to rootfs
> '/tmp/G2DxFl/store/staging/mHBdlv/815b809d588c80fd6ddf4d6ac244ad1c01ae4cbe0f91cc7480e306671ee9c346/rootfs'
> [15:07:20]W: [Step 10/10] I0425 15:07:20.195329 32162
> hierarchical.cpp:1674] Filtered offer with cpus(*):1; mem(*):896;
> disk(*):1024; ports(*):[31000-32000] on agent
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 for framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:07:20]W: [Step 10/10] I0425 15:07:20.195376 32162
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:20]W: [Step 10/10] I0425 15:07:20.195384 32162
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:20]W: [Step 10/10] I0425 15:07:20.195400 32162
> hierarchical.cpp:1139] Performed allocation for 1 agents in 219707ns
> [15:07:21]W: [Step 10/10] I0425 15:07:21.196656 32164
> hierarchical.cpp:1674] Filtered offer with cpus(*):1; mem(*):896;
> disk(*):1024; ports(*):[31000-32000] on agent
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 for framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:07:21]W: [Step 10/10] I0425 15:07:21.196715 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:21]W: [Step 10/10] I0425 15:07:21.196722 32164
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:21]W: [Step 10/10] I0425 15:07:21.196737 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 177145ns
> [15:07:22]W: [Step 10/10] I0425 15:07:22.197506 32165
> hierarchical.cpp:1674] Filtered offer with cpus(*):1; mem(*):896;
> disk(*):1024; ports(*):[31000-32000] on agent
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 for framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:07:22]W: [Step 10/10] I0425 15:07:22.197547 32165
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:22]W: [Step 10/10] I0425 15:07:22.197553 32165
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:22]W: [Step 10/10] I0425 15:07:22.197567 32165
> hierarchical.cpp:1139] Performed allocation for 1 agents in 168766ns
> [15:07:23]W: [Step 10/10] I0425 15:07:23.198818 32161
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:23]W: [Step 10/10] I0425 15:07:23.198860 32161
> hierarchical.cpp:1139] Performed allocation for 1 agents in 195868ns
> [15:07:23]W: [Step 10/10] I0425 15:07:23.198932 32166 master.cpp:5632]
> Sending 1 offers to framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> (default) at [email protected]:42326
> [15:07:23]W: [Step 10/10] I0425 15:07:23.199066 32166 sched.cpp:880]
> Scheduler::resourceOffers took 11062ns
> [15:07:24]W: [Step 10/10] I0425 15:07:24.199370 32163
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:24]W: [Step 10/10] I0425 15:07:24.199391 32163
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:24]W: [Step 10/10] I0425 15:07:24.199405 32163
> hierarchical.cpp:1139] Performed allocation for 1 agents in 79072ns
> [15:07:25]W: [Step 10/10] I0425 15:07:25.199781 32167
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:25]W: [Step 10/10] I0425 15:07:25.199800 32167
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:25]W: [Step 10/10] I0425 15:07:25.199812 32167
> hierarchical.cpp:1139] Performed allocation for 1 agents in 85763ns
> [15:07:26]W: [Step 10/10] I0425 15:07:26.200672 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:26]W: [Step 10/10] I0425 15:07:26.200696 32164
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:26]W: [Step 10/10] I0425 15:07:26.200711 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 79524ns
> [15:07:27]W: [Step 10/10] I0425 15:07:27.201580 32161
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:27]W: [Step 10/10] I0425 15:07:27.201609 32161
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:27]W: [Step 10/10] I0425 15:07:27.201627 32161
> hierarchical.cpp:1139] Performed allocation for 1 agents in 94416ns
> [15:07:28]W: [Step 10/10] I0425 15:07:28.202420 32168
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:28]W: [Step 10/10] I0425 15:07:28.202445 32168
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:28]W: [Step 10/10] I0425 15:07:28.202461 32168
> hierarchical.cpp:1139] Performed allocation for 1 agents in 87566ns
> [15:07:29]W: [Step 10/10] I0425 15:07:29.203049 32166
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:29]W: [Step 10/10] I0425 15:07:29.203078 32166
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:29]W: [Step 10/10] I0425 15:07:29.203094 32166
> hierarchical.cpp:1139] Performed allocation for 1 agents in 90535ns
> [15:07:30]W: [Step 10/10] I0425 15:07:30.203680 32165
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:30]W: [Step 10/10] I0425 15:07:30.203696 32165
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:30]W: [Step 10/10] I0425 15:07:30.203707 32165
> hierarchical.cpp:1139] Performed allocation for 1 agents in 52805ns
> [15:07:31]W: [Step 10/10] I0425 15:07:31.204231 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:31]W: [Step 10/10] I0425 15:07:31.204257 32164
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:31]W: [Step 10/10] I0425 15:07:31.204277 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 76532ns
> [15:07:32]W: [Step 10/10] I0425 15:07:32.204854 32163
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:32]W: [Step 10/10] I0425 15:07:32.204867 32163
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:32]W: [Step 10/10] I0425 15:07:32.204877 32163
> hierarchical.cpp:1139] Performed allocation for 1 agents in 45506ns
> [15:07:33]W: [Step 10/10] I0425 15:07:33.106377 32162 slave.cpp:4996]
> Querying resource estimator for oversubscribable resources
> [15:07:33]W: [Step 10/10] I0425 15:07:33.106546 32168 slave.cpp:5010]
> Received oversubscribable resources from the resource estimator
> [15:07:33]W: [Step 10/10] I0425 15:07:33.110666 32161 slave.cpp:3699]
> Received ping from slave-observer(420)@172.30.2.13:42326
> [15:07:33]W: [Step 10/10] I0425 15:07:33.205027 32161
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:33]W: [Step 10/10] I0425 15:07:33.205039 32161
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:33]W: [Step 10/10] I0425 15:07:33.205054 32161
> hierarchical.cpp:1139] Performed allocation for 1 agents in 50604ns
> [15:07:34]W: [Step 10/10] I0425 15:07:34.205543 32167
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:34]W: [Step 10/10] I0425 15:07:34.205574 32167
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:34]W: [Step 10/10] I0425 15:07:34.205590 32167
> hierarchical.cpp:1139] Performed allocation for 1 agents in 65040ns
> [15:07:35]W: [Step 10/10] I0425 15:07:35.206027 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:35]W: [Step 10/10] I0425 15:07:35.206039 32164
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:35]W: [Step 10/10] I0425 15:07:35.206058 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 45986ns
> [15:07:36]W: [Step 10/10] I0425 15:07:36.206652 32165
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:36]W: [Step 10/10] I0425 15:07:36.206677 32165
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:36]W: [Step 10/10] I0425 15:07:36.206696 32165
> hierarchical.cpp:1139] Performed allocation for 1 agents in 85405ns
> [15:07:37]W: [Step 10/10] I0425 15:07:37.207527 32168
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:37]W: [Step 10/10] I0425 15:07:37.207556 32168
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:37]W: [Step 10/10] I0425 15:07:37.207572 32168
> hierarchical.cpp:1139] Performed allocation for 1 agents in 92554ns
> [15:07:38]W: [Step 10/10] I0425 15:07:38.208175 32166
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:38]W: [Step 10/10] I0425 15:07:38.208199 32166
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:38]W: [Step 10/10] I0425 15:07:38.208221 32166
> hierarchical.cpp:1139] Performed allocation for 1 agents in 85233ns
> [15:07:39]W: [Step 10/10] I0425 15:07:39.208797 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:39]W: [Step 10/10] I0425 15:07:39.208813 32164
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:39]W: [Step 10/10] I0425 15:07:39.208825 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 53630ns
> [15:07:40]W: [Step 10/10] I0425 15:07:40.209425 32161
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:40]W: [Step 10/10] I0425 15:07:40.209441 32161
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:40]W: [Step 10/10] I0425 15:07:40.209455 32161
> hierarchical.cpp:1139] Performed allocation for 1 agents in 50178ns
> [15:07:41]W: [Step 10/10] I0425 15:07:41.209555 32163
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:41]W: [Step 10/10] I0425 15:07:41.209573 32163
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:41]W: [Step 10/10] I0425 15:07:41.209589 32163
> hierarchical.cpp:1139] Performed allocation for 1 agents in 53936ns
> [15:07:42]W: [Step 10/10] I0425 15:07:42.210266 32167
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:42]W: [Step 10/10] I0425 15:07:42.210279 32167
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:42]W: [Step 10/10] I0425 15:07:42.210297 32167
> hierarchical.cpp:1139] Performed allocation for 1 agents in 45637ns
> [15:07:43]W: [Step 10/10] I0425 15:07:43.210948 32162
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:43]W: [Step 10/10] I0425 15:07:43.210973 32162
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:43]W: [Step 10/10] I0425 15:07:43.210989 32162
> hierarchical.cpp:1139] Performed allocation for 1 agents in 79689ns
> [15:07:44]W: [Step 10/10] I0425 15:07:44.211794 32165
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:44]W: [Step 10/10] I0425 15:07:44.211822 32165
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:44]W: [Step 10/10] I0425 15:07:44.211841 32165
> hierarchical.cpp:1139] Performed allocation for 1 agents in 87717ns
> [15:07:45]W: [Step 10/10] I0425 15:07:45.212698 32163
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:45]W: [Step 10/10] I0425 15:07:45.212723 32163
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:45]W: [Step 10/10] I0425 15:07:45.212738 32163
> hierarchical.cpp:1139] Performed allocation for 1 agents in 85311ns
> [15:07:46]W: [Step 10/10] I0425 15:07:46.213450 32167
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:46]W: [Step 10/10] I0425 15:07:46.213477 32167
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:46]W: [Step 10/10] I0425 15:07:46.213493 32167
> hierarchical.cpp:1139] Performed allocation for 1 agents in 87031ns
> [15:07:47]W: [Step 10/10] I0425 15:07:47.213908 32161
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:47]W: [Step 10/10] I0425 15:07:47.213935 32161
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:47]W: [Step 10/10] I0425 15:07:47.213951 32161
> hierarchical.cpp:1139] Performed allocation for 1 agents in 92524ns
> [15:07:48]W: [Step 10/10] I0425 15:07:48.107192 32165 slave.cpp:4996]
> Querying resource estimator for oversubscribable resources
> [15:07:48]W: [Step 10/10] I0425 15:07:48.107322 32162 slave.cpp:5010]
> Received oversubscribable resources from the resource estimator
> [15:07:48]W: [Step 10/10] I0425 15:07:48.111474 32165 slave.cpp:3699]
> Received ping from slave-observer(420)@172.30.2.13:42326
> [15:07:48]W: [Step 10/10] I0425 15:07:48.215004 32165
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:48]W: [Step 10/10] I0425 15:07:48.215015 32165
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:48]W: [Step 10/10] I0425 15:07:48.215029 32165
> hierarchical.cpp:1139] Performed allocation for 1 agents in 56982ns
> [15:07:49]W: [Step 10/10] I0425 15:07:49.215823 32163
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:49]W: [Step 10/10] I0425 15:07:49.215852 32163
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:49]W: [Step 10/10] I0425 15:07:49.215867 32163
> hierarchical.cpp:1139] Performed allocation for 1 agents in 91312ns
> [15:07:50]W: [Step 10/10] I0425 15:07:50.216691 32166
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:50]W: [Step 10/10] I0425 15:07:50.216719 32166
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:50]W: [Step 10/10] I0425 15:07:50.216740 32166
> hierarchical.cpp:1139] Performed allocation for 1 agents in 89719ns
> [15:07:51]W: [Step 10/10] I0425 15:07:51.217478 32162
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:51]W: [Step 10/10] I0425 15:07:51.217509 32162
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:51]W: [Step 10/10] I0425 15:07:51.217526 32162
> hierarchical.cpp:1139] Performed allocation for 1 agents in 98430ns
> [15:07:52]W: [Step 10/10] I0425 15:07:52.218420 32163
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:52]W: [Step 10/10] I0425 15:07:52.218444 32163
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:52]W: [Step 10/10] I0425 15:07:52.218459 32163
> hierarchical.cpp:1139] Performed allocation for 1 agents in 83372ns
> [15:07:53]W: [Step 10/10] I0425 15:07:53.219063 32161
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:53]W: [Step 10/10] I0425 15:07:53.219094 32161
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:53]W: [Step 10/10] I0425 15:07:53.219111 32161
> hierarchical.cpp:1139] Performed allocation for 1 agents in 90859ns
> [15:07:54]W: [Step 10/10] I0425 15:07:54.220070 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:54]W: [Step 10/10] I0425 15:07:54.220095 32164
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:54]W: [Step 10/10] I0425 15:07:54.220110 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 87823ns
> [15:07:55]W: [Step 10/10] I0425 15:07:55.221058 32168
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:55]W: [Step 10/10] I0425 15:07:55.221086 32168
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:55]W: [Step 10/10] I0425 15:07:55.221107 32168
> hierarchical.cpp:1139] Performed allocation for 1 agents in 87820ns
> [15:07:56]W: [Step 10/10] I0425 15:07:56.222067 32162
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:56]W: [Step 10/10] I0425 15:07:56.222093 32162
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:56]W: [Step 10/10] I0425 15:07:56.222110 32162
> hierarchical.cpp:1139] Performed allocation for 1 agents in 94072ns
> [15:07:57]W: [Step 10/10] I0425 15:07:57.223033 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:57]W: [Step 10/10] I0425 15:07:57.223064 32164
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:57]W: [Step 10/10] I0425 15:07:57.223090 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 108270ns
> [15:07:58]W: [Step 10/10] I0425 15:07:58.224179 32165
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:58]W: [Step 10/10] I0425 15:07:58.224208 32165
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:58]W: [Step 10/10] I0425 15:07:58.224226 32165
> hierarchical.cpp:1139] Performed allocation for 1 agents in 91758ns
> [15:07:59]W: [Step 10/10] I0425 15:07:59.225424 32166
> hierarchical.cpp:1488] No resources available to allocate!
> [15:07:59]W: [Step 10/10] I0425 15:07:59.225448 32166
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:07:59]W: [Step 10/10] I0425 15:07:59.225464 32166
> hierarchical.cpp:1139] Performed allocation for 1 agents in 83438ns
> [15:08:00]W: [Step 10/10] I0425 15:08:00.226443 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:00]W: [Step 10/10] I0425 15:08:00.226474 32164
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:00]W: [Step 10/10] I0425 15:08:00.226491 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 92391ns
> [15:08:01]W: [Step 10/10] I0425 15:08:01.227365 32167
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:01]W: [Step 10/10] I0425 15:08:01.227387 32167
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:01]W: [Step 10/10] I0425 15:08:01.227402 32167
> hierarchical.cpp:1139] Performed allocation for 1 agents in 76293ns
> [15:08:02]W: [Step 10/10] I0425 15:08:02.228199 32168
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:02]W: [Step 10/10] I0425 15:08:02.228220 32168
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:02]W: [Step 10/10] I0425 15:08:02.228235 32168
> hierarchical.cpp:1139] Performed allocation for 1 agents in 76278ns
> [15:08:03]W: [Step 10/10] I0425 15:08:03.107926 32161 slave.cpp:4996]
> Querying resource estimator for oversubscribable resources
> [15:08:03]W: [Step 10/10] I0425 15:08:03.108036 32168 slave.cpp:5010]
> Received oversubscribable resources from the resource estimator
> [15:08:03]W: [Step 10/10] I0425 15:08:03.112210 32161 slave.cpp:3699]
> Received ping from slave-observer(420)@172.30.2.13:42326
> [15:08:03]W: [Step 10/10] I0425 15:08:03.228732 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:03]W: [Step 10/10] I0425 15:08:03.228742 32164
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:03]W: [Step 10/10] I0425 15:08:03.228757 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 59596ns
> [15:08:04]W: [Step 10/10] I0425 15:08:04.229460 32162
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:04]W: [Step 10/10] I0425 15:08:04.229480 32162
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:04]W: [Step 10/10] I0425 15:08:04.229496 32162
> hierarchical.cpp:1139] Performed allocation for 1 agents in 70740ns
> [15:08:05]W: [Step 10/10] I0425 15:08:05.230406 32161
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:05]W: [Step 10/10] I0425 15:08:05.230443 32161
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:05]W: [Step 10/10] I0425 15:08:05.230460 32161
> hierarchical.cpp:1139] Performed allocation for 1 agents in 98097ns
> [15:08:06]W: [Step 10/10] I0425 15:08:06.231168 32166
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:06]W: [Step 10/10] I0425 15:08:06.231191 32166
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:06]W: [Step 10/10] I0425 15:08:06.231206 32166
> hierarchical.cpp:1139] Performed allocation for 1 agents in 80804ns
> [15:08:07]W: [Step 10/10] I0425 15:08:07.232044 32167
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:07]W: [Step 10/10] I0425 15:08:07.232074 32167
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:07]W: [Step 10/10] I0425 15:08:07.232094 32167
> hierarchical.cpp:1139] Performed allocation for 1 agents in 95337ns
> [15:08:08]W: [Step 10/10] I0425 15:08:08.232728 32163
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:08]W: [Step 10/10] I0425 15:08:08.232741 32163
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:08]W: [Step 10/10] I0425 15:08:08.232753 32163
> hierarchical.cpp:1139] Performed allocation for 1 agents in 45537ns
> [15:08:09]W: [Step 10/10] I0425 15:08:09.233428 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:09]W: [Step 10/10] I0425 15:08:09.233448 32164
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:09]W: [Step 10/10] I0425 15:08:09.233464 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 73905ns
> [15:08:10]W: [Step 10/10] I0425 15:08:10.233937 32168
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:10]W: [Step 10/10] I0425 15:08:10.233947 32168
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:10]W: [Step 10/10] I0425 15:08:10.233958 32168
> hierarchical.cpp:1139] Performed allocation for 1 agents in 38090ns
> [15:08:10]W: [Step 10/10] I0425 15:08:10.972741 32167
> metadata_manager.cpp:148] Successfully cached image 'alpine'
> [15:08:10]W: [Step 10/10] I0425 15:08:10.973219 32161 provisioner.cpp:285]
> Provisioning image rootfs
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/provisioner/containers/dca2f70c-0fdf-42f6-afba-3cca70f28b01/backends/copy/rootfses/f7583759-ea67-4cf2-aa56-edcf3fdcb207'
> for container dca2f70c-0fdf-42f6-afba-3cca70f28b01
> [15:08:10]W: [Step 10/10] I0425 15:08:10.973554 32167 copy.cpp:128] Copying
> layer path
> '/tmp/G2DxFl/store/layers/815b809d588c80fd6ddf4d6ac244ad1c01ae4cbe0f91cc7480e306671ee9c346/rootfs'
> to rootfs
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/provisioner/containers/dca2f70c-0fdf-42f6-afba-3cca70f28b01/backends/copy/rootfses/f7583759-ea67-4cf2-aa56-edcf3fdcb207'
> [15:08:11]W: [Step 10/10] I0425 15:08:11.234539 32165
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:11]W: [Step 10/10] I0425 15:08:11.234566 32165
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:11]W: [Step 10/10] I0425 15:08:11.234586 32165
> hierarchical.cpp:1139] Performed allocation for 1 agents in 120592ns
> [15:08:12]W: [Step 10/10] I0425 15:08:12.235381 32168
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:12]W: [Step 10/10] I0425 15:08:12.235411 32168
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:12]W: [Step 10/10] I0425 15:08:12.235432 32168
> hierarchical.cpp:1139] Performed allocation for 1 agents in 103935ns
> [15:08:13]W: [Step 10/10] I0425 15:08:13.235791 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:13]W: [Step 10/10] I0425 15:08:13.235815 32164
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:13]W: [Step 10/10] I0425 15:08:13.235831 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 89328ns
> [15:08:14]W: [Step 10/10] I0425 15:08:14.235991 32167
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:15]W: [Step 10/10] I0425 15:08:14.236016 32167
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:15]W: [Step 10/10] I0425 15:08:14.236029 32167
> hierarchical.cpp:1139] Performed allocation for 1 agents in 86883ns
> [15:08:15]W: [Step 10/10] I0425 15:08:15.236173 32165
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:15]W: [Step 10/10] I0425 15:08:15.236201 32165
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:15]W: [Step 10/10] I0425 15:08:15.236222 32165
> hierarchical.cpp:1139] Performed allocation for 1 agents in 90786ns
> [15:08:16]W: [Step 10/10] I0425 15:08:16.237462 32162
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:17]W: [Step 10/10] I0425 15:08:16.237489 32162
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:18] : [Step 10/10]
> ../../src/tests/containerizer/runtime_isolator_tests.cpp:231: Failure
> [15:08:21]W: [Step 10/10] I0425 15:08:16.237507 32162
> hierarchical.cpp:1139] Performed allocation for 1 agents in 109476ns
> [15:08:21] : [Step 10/10] Failed to wait 1mins for statusRunning
> [15:08:21] : [Step 10/10]
> ../../src/tests/containerizer/runtime_isolator_tests.cpp:225: Failure
> [15:08:21]W: [Step 10/10] I0425 15:08:17.238730 32161
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:21] : [Step 10/10] Actual function call count doesn't match
> EXPECT_CALL(sched, statusUpdate(&driver, _))...
> [15:08:21]W: [Step 10/10] I0425 15:08:17.238755 32161
> hierarchical.cpp:1583] No inverse offers to send out!
> [15:08:21] : [Step 10/10] Expected: to be called twice
> [15:08:21] : [Step 10/10] Actual: never called - unsatisfied and
> active
> [15:08:21]W: [Step 10/10] I0425 15:08:17.238773 32161
> hierarchical.cpp:1139] Performed allocation for 1 agents in 93771ns
> [15:08:21]W: [Step 10/10] I0425 15:08:18.103023 32166 slave.cpp:4633]
> Current disk usage 3.07%. Max allowed age: 6.085051962227002days
> [15:08:21]W: [Step 10/10] I0425 15:08:18.109217 32168 slave.cpp:4996]
> Querying resource estimator for oversubscribable resources
> [15:08:21]W: [Step 10/10] I0425 15:08:18.109316 32167 slave.cpp:5010]
> Received oversubscribable resources from the resource estimator
> [15:08:21]W: [Step 10/10] I0425 15:08:18.111702 32168 master.cpp:1375]
> Framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 (default) at
> [email protected]:42326 disconnected
> [15:08:21]W: [Step 10/10] I0425 15:08:18.111734 32168 master.cpp:2766]
> Disconnecting framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 (default)
> at [email protected]:42326
> [15:08:21]W: [Step 10/10] I0425 15:08:18.111748 32168 master.cpp:2790]
> Deactivating framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 (default) at
> [email protected]:42326
> [15:08:21]W: [Step 10/10] I0425 15:08:18.111824 32164 hierarchical.cpp:375]
> Deactivated framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:08:21]W: [Step 10/10] W0425 15:08:18.111907 32168 master.hpp:1828]
> Master attempted to send message to disconnected framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 (default) at
> [email protected]:42326
> [15:08:21]W: [Step 10/10] I0425 15:08:18.111946 32168 master.cpp:1399]
> Giving framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 (default) at
> [email protected]:42326 0ns to
> failover
> [15:08:21]W: [Step 10/10] I0425 15:08:18.111939 32161 hierarchical.cpp:891]
> Recovered cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] (total:
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated:
> cpus(*):1; mem(*):128) on agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 from
> framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:08:23]W: [Step 10/10] I0425 15:08:18.112205 32162
> containerizer.cpp:1481] Destroying container
> 'dca2f70c-0fdf-42f6-afba-3cca70f28b01'
> [15:08:23]W: [Step 10/10] I0425 15:08:18.112217 32162
> containerizer.cpp:1484] Waiting for the provisioner to complete for container
> 'dca2f70c-0fdf-42f6-afba-3cca70f28b01'
> [15:08:23]W: [Step 10/10] I0425 15:08:18.113154 32162 master.cpp:5484]
> Framework failover timeout, removing framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 (default) at
> [email protected]:42326
> [15:08:23]W: [Step 10/10] I0425 15:08:18.113168 32162 master.cpp:6212]
> Removing framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 (default) at
> [email protected]:42326
> [15:08:23]W: [Step 10/10] I0425 15:08:18.113201 32168 slave.cpp:3699]
> Received ping from slave-observer(420)@172.30.2.13:42326
> [15:08:23]W: [Step 10/10] I0425 15:08:18.113204 32162 master.cpp:6727]
> Updating the state of task 41d96480-fae8-44fe-bd96-7c625ddc6a09 of framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 (latest state: TASK_KILLED, status
> update state: TASK_KILLED)
> [15:08:23]W: [Step 10/10] I0425 15:08:18.113246 32168 slave.cpp:2250] Asked
> to shut down framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 by
> [email protected]:42326
> [15:08:23]W: [Step 10/10] I0425 15:08:18.113261 32168 slave.cpp:2275]
> Shutting down framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:08:23]W: [Step 10/10] I0425 15:08:18.113271 32168 slave.cpp:4449]
> Shutting down executor '41d96480-fae8-44fe-bd96-7c625ddc6a09' of framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:08:23]W: [Step 10/10] W0425 15:08:18.113277 32168 slave.hpp:680] Unable
> to send event to executor '41d96480-fae8-44fe-bd96-7c625ddc6a09' of framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000: unknown connection type
> [15:08:23]W: [Step 10/10] I0425 15:08:18.113292 32162 master.cpp:6793]
> Removing task 41d96480-fae8-44fe-bd96-7c625ddc6a09 with resources cpus(*):1;
> mem(*):128 of framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 on agent
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 at slave(456)@172.30.2.13:42326
> (ip-172-30-2-13.mesosphere.io)
> [15:08:23]W: [Step 10/10] I0425 15:08:18.113322 32161 hierarchical.cpp:891]
> Recovered cpus(*):1; mem(*):128 (total: cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000], allocated: ) on agent
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 from framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:08:23]W: [Step 10/10] I0425 15:08:18.113464 32165 hierarchical.cpp:326]
> Removed framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:08:23]W: [Step 10/10] I0425 15:08:18.116307 32162 slave.cpp:4552]
> Ignoring registration timeout for executor
> '41d96480-fae8-44fe-bd96-7c625ddc6a09' because the framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 is terminating
> [15:08:23]W: [Step 10/10] I0425 15:08:18.238991 32162
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:23]W: [Step 10/10] I0425 15:08:18.239017 32162
> hierarchical.cpp:1139] Performed allocation for 1 agents in 64918ns
> [15:08:23]W: [Step 10/10] I0425 15:08:19.239764 32164
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:23]W: [Step 10/10] I0425 15:08:19.239802 32164
> hierarchical.cpp:1139] Performed allocation for 1 agents in 73308ns
> [15:08:23]W: [Step 10/10] I0425 15:08:20.241013 32168
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:23]W: [Step 10/10] I0425 15:08:20.241056 32168
> hierarchical.cpp:1139] Performed allocation for 1 agents in 85649ns
> [15:08:23]W: [Step 10/10] I0425 15:08:21.241225 32161
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:23]W: [Step 10/10] I0425 15:08:21.241264 32161
> hierarchical.cpp:1139] Performed allocation for 1 agents in 73603ns
> [15:08:23]W: [Step 10/10] I0425 15:08:22.242439 32166
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:23]W: [Step 10/10] I0425 15:08:22.242478 32166
> hierarchical.cpp:1139] Performed allocation for 1 agents in 86831ns
> [15:08:23]W: [Step 10/10] I0425 15:08:23.113929 32165 slave.cpp:4522]
> Killing executor '41d96480-fae8-44fe-bd96-7c625ddc6a09' of framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:08:23]W: [Step 10/10] I0425 15:08:23.243474 32165
> hierarchical.cpp:1488] No resources available to allocate!
> [15:08:23]W: [Step 10/10] I0425 15:08:23.243494 32165
> hierarchical.cpp:1139] Performed allocation for 1 agents in 49013ns
> [15:08:23]W: [Step 10/10] I0425 15:08:23.661591 32168 provisioner.cpp:338]
> Destroying container rootfs at
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/provisioner/containers/dca2f70c-0fdf-42f6-afba-3cca70f28b01/backends/copy/rootfses/f7583759-ea67-4cf2-aa56-edcf3fdcb207'
> for container dca2f70c-0fdf-42f6-afba-3cca70f28b01
> [15:08:23]W: [Step 10/10] E0425 15:08:23.664181 32164 slave.cpp:4018]
> Container 'dca2f70c-0fdf-42f6-afba-3cca70f28b01' for executor
> '41d96480-fae8-44fe-bd96-7c625ddc6a09' of framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 failed to start: Container is
> currently being destroyed
> [15:08:24]W: [Step 10/10] I0425 15:08:24.163928 32161 slave.cpp:4124]
> Executor '41d96480-fae8-44fe-bd96-7c625ddc6a09' of framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000 has terminated with unknown status
> [15:08:24]W: [Step 10/10] I0425 15:08:24.163964 32161 slave.cpp:4235]
> Cleaning up executor '41d96480-fae8-44fe-bd96-7c625ddc6a09' of framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:08:24]W: [Step 10/10] I0425 15:08:24.164093 32161 slave.cpp:4323]
> Cleaning up framework f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:08:24]W: [Step 10/10] I0425 15:08:24.164082 32166 gc.cpp:55] Scheduling
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/slaves/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0/frameworks/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000/executors/41d96480-fae8-44fe-bd96-7c625ddc6a09/runs/dca2f70c-0fdf-42f6-afba-3cca70f28b01'
> for gc 6.99999810154074days in the future
> [15:08:24]W: [Step 10/10] I0425 15:08:24.164145 32168
> status_update_manager.cpp:282] Closing status update streams for framework
> f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000
> [15:08:24]W: [Step 10/10] I0425 15:08:24.164146 32166 gc.cpp:55] Scheduling
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/slaves/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0/frameworks/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000/executors/41d96480-fae8-44fe-bd96-7c625ddc6a09'
> for gc 6.99999810096days in the future
> [15:08:24]W: [Step 10/10] I0425 15:08:24.164185 32161 slave.cpp:823] Agent
> terminating
> [15:08:24]W: [Step 10/10] I0425 15:08:24.164221 32166 gc.cpp:55] Scheduling
> '/mnt/teamcity/temp/buildTmp/DockerRuntimeIsolatorTest_ROOT_DockerDefaultEntryptLocalPuller_IzCc1S/slaves/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0/frameworks/f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-0000'
> for gc 6.99999810013926days in the future
> [15:08:24]W: [Step 10/10] I0425 15:08:24.164257 32165 master.cpp:1336]
> Agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 at slave(456)@172.30.2.13:42326
> (ip-172-30-2-13.mesosphere.io) disconnected
> [15:08:24]W: [Step 10/10] I0425 15:08:24.164278 32165 master.cpp:2825]
> Disconnecting agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 at
> slave(456)@172.30.2.13:42326 (ip-172-30-2-13.mesosphere.io)
> [15:08:24]W: [Step 10/10] I0425 15:08:24.164324 32165 master.cpp:2844]
> Deactivating agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 at
> slave(456)@172.30.2.13:42326 (ip-172-30-2-13.mesosphere.io)
> [15:08:24]W: [Step 10/10] I0425 15:08:24.164429 32165 hierarchical.cpp:560]
> Agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0 deactivated
> [15:08:24]W: [Step 10/10] I0425 15:08:24.166201 32147 master.cpp:1189]
> Master terminating
> [15:08:24]W: [Step 10/10] I0425 15:08:24.166317 32162 hierarchical.cpp:505]
> Removed agent f480c5f5-0eb6-43fe-a0c9-6bd9cd62f517-S0
> [15:08:26] : [Step 10/10] [ FAILED ]
> DockerRuntimeIsolatorTest.ROOT_DockerDefaultEntryptLocalPuller (84810 ms)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
