[MESOS-7425] ImageAlpine/ProvisionerDockerTest.ROOT_INTERNET_CURL_SimpleCommand/3 is flaky in some OS.

• Type: Bug
• Status: Accepted
• Priority: Major
• Resolution: Unresolved
• Fix Version/s: 1.5.0
• Component/s: flaky
• Labels: flaky-test mesosphere

Environment

Ubuntu 16.04 with SSL enabled;
Ubuntu 16.10 with SSL enabled;
Ubuntu 14.04;
Debian 8;
other Linux distros

• Sprint: Mesosphere Sprint 69
• Story Points: 3
• Assignee: Unassigned
• Reporter: Gilbert Song
• Created: 25/Apr/17 17:03
• Updated: 30/Jan/20 15:44

Description

The unit test (ProvisionerDockerTest.ROOT_INTERNET_CURL_SimpleCommand) is fine, only flaky with one parameter (where GetParam() = "registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine"). Might related this GnuTLS bug (https://bugs.launchpad.net/ubuntu/+source/gnutls26/+bug/1111882). The bug might be exposed by the slowness (due to intercontinental communication with AliCloud).

In Ubuntu 16.04 with SSL enable:

[ RUN      ] ImageAlpine/ProvisionerDockerTest.ROOT_INTERNET_CURL_SimpleCommand/3
I0425 00:29:19.848593 11273 cluster.cpp:162] Creating default 'local' authorizer
I0425 00:29:19.849653  9377 master.cpp:438] Master 9e93bad0-595c-4165-813a-7d70d96df372 (ip-10-11-189-151.ec2.internal) started on 10.11.189.151:35690
I0425 00:29:19.849674  9377 master.cpp:440] 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" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/pO6niJ/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_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/pO6niJ/master" --zk_session_timeout="10secs"
I0425 00:29:19.849766  9377 master.cpp:490] Master only allowing authenticated frameworks to register
I0425 00:29:19.849773  9377 master.cpp:504] Master only allowing authenticated agents to register
I0425 00:29:19.849777  9377 master.cpp:517] Master only allowing authenticated HTTP frameworks to register
I0425 00:29:19.849781  9377 credentials.hpp:37] Loading credentials for authentication from '/tmp/pO6niJ/credentials'
I0425 00:29:19.849856  9377 master.cpp:562] Using default 'crammd5' authenticator
I0425 00:29:19.849901  9377 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0425 00:29:19.849959  9377 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0425 00:29:19.850005  9377 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0425 00:29:19.850128  9377 master.cpp:642] Authorization enabled
I0425 00:29:19.850250  9380 whitelist_watcher.cpp:77] No whitelist given
I0425 00:29:19.850265  9375 hierarchical.cpp:159] Initialized hierarchical allocator process
I0425 00:29:19.850888  9381 master.cpp:2163] Elected as the leading master!
I0425 00:29:19.850906  9381 master.cpp:1702] Recovering from registrar
I0425 00:29:19.850966  9378 registrar.cpp:345] Recovering registrar
I0425 00:29:19.851186  9382 registrar.cpp:389] Successfully fetched the registry (0B) in 184064ns
I0425 00:29:19.851223  9382 registrar.cpp:493] Applied 1 operations in 4692ns; attempting to update the registry
I0425 00:29:19.851419  9378 registrar.cpp:550] Successfully updated the registry in 172800ns
I0425 00:29:19.851459  9378 registrar.cpp:422] Successfully recovered registrar
I0425 00:29:19.851677  9378 master.cpp:1801] Recovered 0 agents from the registry (172B); allowing 10mins for agents to re-register
I0425 00:29:19.851686  9381 hierarchical.cpp:186] Skipping recovery of hierarchical allocator: nothing to recover
I0425 00:29:19.853339 11273 containerizer.cpp:221] Using isolation: docker/runtime,filesystem/linux,network/cni,volume/image
I0425 00:29:19.856330 11273 linux_launcher.cpp:150] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
E0425 00:29:19.862097 11273 shell.hpp:107] Command 'hadoop version 2>&1' failed; this is the output:
sh: 1: hadoop: not found
I0425 00:29:19.862139 11273 fetcher.cpp:69] 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
I0425 00:29:19.862186 11273 registry_puller.cpp:115] Creating registry puller with docker registry 'https://registry-1.docker.io'
I0425 00:29:19.862634 11273 provisioner.cpp:249] Using default backend 'overlay'
I0425 00:29:19.863445 11273 cluster.cpp:448] Creating default 'local' authorizer
I0425 00:29:19.863874  9379 slave.cpp:225] Mesos agent started on (886)@10.11.189.151:35690
I0425 00:29:19.863894  9379 slave.cpp:226] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_executors="true" --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/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_HeIqIm/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/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="10mins" --executor_secret_key="/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_HeIqIm/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_HeIqIm/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/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_HeIqIm/http_credentials" --http_heartbeat_interval="30secs" --image_providers="docker" --initialize_driver_logging="true" --isolation="docker/runtime,filesystem/linux" --launcher="linux" --launcher_dir="/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-ubuntu-16.04/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --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/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_HeIqIm" --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/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_o3cp02"
I0425 00:29:19.864078  9379 credentials.hpp:86] Loading credential for authentication from '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_HeIqIm/credential'
I0425 00:29:19.864161  9379 slave.cpp:258] Agent using credential for: test-principal
I0425 00:29:19.864184  9379 credentials.hpp:37] Loading credentials for authentication from '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_HeIqIm/http_credentials'
I0425 00:29:19.864295  9379 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
I0425 00:29:19.864354  9379 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
I0425 00:29:19.864439  9379 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0425 00:29:19.864480  9379 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
I0425 00:29:19.864540  9379 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0425 00:29:19.864610  9379 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
I0425 00:29:19.864907 11273 sched.cpp:232] Version: 1.3.0
I0425 00:29:19.865114  9378 sched.cpp:336] New master detected at master@10.11.189.151:35690
I0425 00:29:19.865154  9378 sched.cpp:407] Authenticating with master master@10.11.189.151:35690
I0425 00:29:19.865164  9378 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0425 00:29:19.865160  9379 slave.cpp:525] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0425 00:29:19.865193  9379 slave.cpp:533] Agent attributes: [  ]
I0425 00:29:19.865200  9379 slave.cpp:538] Agent hostname: ip-10-11-189-151.ec2.internal
I0425 00:29:19.865267  9376 status_update_manager.cpp:177] Pausing sending status updates
I0425 00:29:19.865331  9377 authenticatee.cpp:121] Creating new client SASL connection
I0425 00:29:19.865515  9379 state.cpp:62] Recovering state from '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_o3cp02/meta'
I0425 00:29:19.865608  9379 status_update_manager.cpp:203] Recovering status update manager
I0425 00:29:19.865690  9378 master.cpp:7257] Authenticating scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690
I0425 00:29:19.865744  9377 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1609)@10.11.189.151:35690
I0425 00:29:19.865803  9378 containerizer.cpp:608] Recovering containerizer
I0425 00:29:19.865859  9381 authenticator.cpp:98] Creating new server SASL connection
I0425 00:29:19.866163  9378 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0425 00:29:19.866190  9378 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0425 00:29:19.866258  9377 authenticator.cpp:204] Received SASL authentication start
I0425 00:29:19.866312  9377 authenticator.cpp:326] Authentication requires more steps
I0425 00:29:19.866385  9381 authenticatee.cpp:259] Received SASL authentication step
I0425 00:29:19.866525  9381 authenticator.cpp:232] Received SASL authentication step
I0425 00:29:19.866551  9381 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-10-11-189-151.ec2.internal' server FQDN: 'ip-10-11-189-151.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0425 00:29:19.866559  9381 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0425 00:29:19.866569  9381 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0425 00:29:19.866580  9381 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-10-11-189-151.ec2.internal' server FQDN: 'ip-10-11-189-151.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0425 00:29:19.866590  9381 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0425 00:29:19.866601  9381 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0425 00:29:19.866616  9381 authenticator.cpp:318] Authentication success
I0425 00:29:19.866709  9377 authenticatee.cpp:299] Authentication success
I0425 00:29:19.866753  9381 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1609)@10.11.189.151:35690
I0425 00:29:19.866761  9382 master.cpp:7287] Successfully authenticated principal 'test-principal' at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690
I0425 00:29:19.866884  9380 sched.cpp:513] Successfully authenticated with master master@10.11.189.151:35690
I0425 00:29:19.866906  9380 sched.cpp:836] Sending SUBSCRIBE call to master@10.11.189.151:35690
I0425 00:29:19.866948  9380 sched.cpp:869] Will retry registration in 1.304264764secs if necessary
I0425 00:29:19.867007  9376 master.cpp:2815] Received SUBSCRIBE call for framework 'default' at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690
I0425 00:29:19.867048  9376 master.cpp:2199] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
I0425 00:29:19.867158  9379 metadata_manager.cpp:233] Successfully loaded image 'zhq527725/whiteout'
I0425 00:29:19.867180  9379 metadata_manager.cpp:233] Successfully loaded image 'quay.io/coreos/alpine-sh'
I0425 00:29:19.867188  9379 metadata_manager.cpp:233] Successfully loaded image 'library/alpine@sha256:9f08005dff552038f0ad2f46b8e65ff3d25641747d3912e3ea8da6785046561a'
I0425 00:29:19.867197  9379 metadata_manager.cpp:233] Successfully loaded image 'haosdent/https-server'
I0425 00:29:19.867203  9379 metadata_manager.cpp:233] Successfully loaded image 'chhsiao/overwrite'
I0425 00:29:19.867202  9380 master.cpp:2892] Subscribing framework default with checkpointing disabled and capabilities [  ]
I0425 00:29:19.867211  9379 metadata_manager.cpp:233] Successfully loaded image 'library/alpine'
I0425 00:29:19.867224  9379 metadata_manager.cpp:233] Successfully loaded image 'alpine'
I0425 00:29:19.867245  9379 metadata_manager.cpp:233] Successfully loaded image 'hello-world'
I0425 00:29:19.867251  9379 metadata_manager.cpp:236] Successfully loaded 8 Docker images
I0425 00:29:19.867337  9375 provisioner.cpp:410] Provisioner recovery complete
I0425 00:29:19.867476  9376 hierarchical.cpp:271] Added framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:19.867537  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:29:19.867555  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:19.867571  9376 hierarchical.cpp:1446] Performed allocation for 0 agents in 43493ns
I0425 00:29:19.867585  9379 sched.cpp:759] Framework registered with 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:19.867610  9381 slave.cpp:5963] Finished recovery
I0425 00:29:19.867619  9379 sched.cpp:773] Scheduler::registered took 22506ns
I0425 00:29:19.867837  9381 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:29:19.867959  9381 slave.cpp:918] New master detected at master@10.11.189.151:35690
I0425 00:29:19.867966  9380 status_update_manager.cpp:177] Pausing sending status updates
I0425 00:29:19.868017  9381 slave.cpp:953] Detecting new master
I0425 00:29:19.868064  9381 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:29:19.874207  9375 slave.cpp:980] Authenticating with master master@10.11.189.151:35690
I0425 00:29:19.874238  9375 slave.cpp:991] Using default CRAM-MD5 authenticatee
I0425 00:29:19.874322  9376 authenticatee.cpp:121] Creating new client SASL connection
I0425 00:29:19.874626  9376 master.cpp:7257] Authenticating slave(886)@10.11.189.151:35690
I0425 00:29:19.874694  9377 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1610)@10.11.189.151:35690
I0425 00:29:19.874764  9377 authenticator.cpp:98] Creating new server SASL connection
I0425 00:29:19.875027  9377 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0425 00:29:19.875052  9377 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0425 00:29:19.875092  9377 authenticator.cpp:204] Received SASL authentication start
I0425 00:29:19.875128  9377 authenticator.cpp:326] Authentication requires more steps
I0425 00:29:19.875159  9377 authenticatee.cpp:259] Received SASL authentication step
I0425 00:29:19.875211  9377 authenticator.cpp:232] Received SASL authentication step
I0425 00:29:19.875236  9377 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-10-11-189-151.ec2.internal' server FQDN: 'ip-10-11-189-151.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0425 00:29:19.875247  9377 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0425 00:29:19.875253  9377 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0425 00:29:19.875260  9377 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-10-11-189-151.ec2.internal' server FQDN: 'ip-10-11-189-151.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0425 00:29:19.875265  9377 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0425 00:29:19.875269  9377 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0425 00:29:19.875277  9377 authenticator.cpp:318] Authentication success
I0425 00:29:19.875319  9376 authenticatee.cpp:299] Authentication success
I0425 00:29:19.875354  9380 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1610)@10.11.189.151:35690
I0425 00:29:19.875365  9377 master.cpp:7287] Successfully authenticated principal 'test-principal' at slave(886)@10.11.189.151:35690
I0425 00:29:19.875485  9378 slave.cpp:1075] Successfully authenticated with master master@10.11.189.151:35690
I0425 00:29:19.875546  9378 slave.cpp:1503] Will retry registration in 9.174264ms if necessary
I0425 00:29:19.875613  9379 master.cpp:5447] Registering agent at slave(886)@10.11.189.151:35690 (ip-10-11-189-151.ec2.internal) with id 9e93bad0-595c-4165-813a-7d70d96df372-S0
I0425 00:29:19.875737  9376 registrar.cpp:493] Applied 1 operations in 20145ns; attempting to update the registry
I0425 00:29:19.875962  9375 registrar.cpp:550] Successfully updated the registry in 198912ns
I0425 00:29:19.876155  9378 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:29:19.876188  9382 master.cpp:5521] Registered agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 at slave(886)@10.11.189.151:35690 (ip-10-11-189-151.ec2.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0425 00:29:19.876226  9378 slave.cpp:1121] Registered with master master@10.11.189.151:35690; given agent ID 9e93bad0-595c-4165-813a-7d70d96df372-S0
I0425 00:29:19.876240  9378 fetcher.cpp:94] Clearing fetcher cache
I0425 00:29:19.876271  9379 hierarchical.cpp:527] Added agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 (ip-10-11-189-151.ec2.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I0425 00:29:19.876302  9381 status_update_manager.cpp:184] Resuming sending status updates
I0425 00:29:19.876386  9378 slave.cpp:1149] Checkpointing SlaveInfo to '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_o3cp02/meta/slaves/9e93bad0-595c-4165-813a-7d70d96df372-S0/slave.info'
I0425 00:29:19.876505  9378 slave.cpp:1187] Forwarding total oversubscribed resources {}
I0425 00:29:19.876528  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:19.876549  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 210333ns
I0425 00:29:19.876642  9375 master.cpp:7087] Sending 1 offers to framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690
I0425 00:29:19.876720  9375 master.cpp:6106] Received update of agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 at slave(886)@10.11.189.151:35690 (ip-10-11-189-151.ec2.internal) with total oversubscribed resources {}
I0425 00:29:19.876838  9378 sched.cpp:933] Scheduler::resourceOffers took 69836ns
I0425 00:29:19.877310  9380 master.cpp:3853] Processing ACCEPT call for offers: [ 9e93bad0-595c-4165-813a-7d70d96df372-O0 ] on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 at slave(886)@10.11.189.151:35690 (ip-10-11-189-151.ec2.internal) for framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690
I0425 00:29:19.877351  9380 master.cpp:3429] Authorizing framework principal 'test-principal' to launch task ed590512-47bf-4152-8d7d-08fe715af093
I0425 00:29:19.877840  9380 master.cpp:9102] Adding task ed590512-47bf-4152-8d7d-08fe715af093 with resources cpus(*)(allocated: *):1; mem(*)(allocated: *):128 on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 at slave(886)@10.11.189.151:35690 (ip-10-11-189-151.ec2.internal)
I0425 00:29:19.877890  9380 master.cpp:4503] Launching task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690 with resources cpus(*)(allocated: *):1; mem(*)(allocated: *):128 on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 at slave(886)@10.11.189.151:35690 (ip-10-11-189-151.ec2.internal)
I0425 00:29:19.878155  9375 slave.cpp:1613] Got assigned task 'ed590512-47bf-4152-8d7d-08fe715af093' for framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:19.878453  9375 slave.cpp:1894] Authorizing task 'ed590512-47bf-4152-8d7d-08fe715af093' for framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:19.878490  9375 slave.cpp:6582] Authorizing framework principal 'test-principal' to launch task ed590512-47bf-4152-8d7d-08fe715af093
I0425 00:29:19.878533  9379 hierarchical.cpp:852] Updated allocation of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 on agent 9e93bad0-595c-4165-813a-7d70d96df372-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]
I0425 00:29:19.878756  9379 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):1; mem(*)(allocated: *):896; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*)(allocated: *):1; mem(*)(allocated: *):128) on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 from framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:19.878787  9379 hierarchical.cpp:1153] Framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 filtered agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 for 5secs
I0425 00:29:19.878828  9382 slave.cpp:2081] Launching task 'ed590512-47bf-4152-8d7d-08fe715af093' for framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:19.879096  9382 paths.cpp:556] Trying to chown '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_o3cp02/slaves/9e93bad0-595c-4165-813a-7d70d96df372-S0/frameworks/9e93bad0-595c-4165-813a-7d70d96df372-0000/executors/ed590512-47bf-4152-8d7d-08fe715af093/runs/a8e309c2-92f7-40b9-80f8-2967b86ae75c' to user 'root'
I0425 00:29:19.879240  9382 slave.cpp:6926] Launching executor 'ed590512-47bf-4152-8d7d-08fe715af093' of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 with resources cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32 in work directory '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_o3cp02/slaves/9e93bad0-595c-4165-813a-7d70d96df372-S0/frameworks/9e93bad0-595c-4165-813a-7d70d96df372-0000/executors/ed590512-47bf-4152-8d7d-08fe715af093/runs/a8e309c2-92f7-40b9-80f8-2967b86ae75c'
I0425 00:29:19.879470  9382 slave.cpp:2310] Queued task 'ed590512-47bf-4152-8d7d-08fe715af093' for executor 'ed590512-47bf-4152-8d7d-08fe715af093' of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:19.879510  9382 slave.cpp:871] Successfully attached file '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_o3cp02/slaves/9e93bad0-595c-4165-813a-7d70d96df372-S0/frameworks/9e93bad0-595c-4165-813a-7d70d96df372-0000/executors/ed590512-47bf-4152-8d7d-08fe715af093/runs/a8e309c2-92f7-40b9-80f8-2967b86ae75c'
I0425 00:29:19.879716  9377 containerizer.cpp:1001] Starting container a8e309c2-92f7-40b9-80f8-2967b86ae75c for executor 'ed590512-47bf-4152-8d7d-08fe715af093' of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:19.880002  9378 metadata_manager.cpp:168] Looking for image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine'
I0425 00:29:19.880187  9381 registry_puller.cpp:247] Pulling image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine' from 'docker-manifest://registry.cn-hangzhou.aliyuncs.comacs-sample/alpine?latest#https' to '/tmp/mesos/store/docker/staging/WxSj3j'
I0425 00:29:20.851302  9381 hierarchical.cpp:2106] Filtered offer with cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 for role * of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:20.851371  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:29:20.851382  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:20.851394  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 228014ns
I0425 00:29:21.852063  9378 hierarchical.cpp:2106] Filtered offer with cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 for role * of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:21.852145  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:29:21.852169  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:21.852186  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 255749ns
I0425 00:29:22.853153  9375 hierarchical.cpp:2106] Filtered offer with cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 for role * of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:22.853229  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:29:22.853246  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:22.853265  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 241062ns
I0425 00:29:23.853662  9377 hierarchical.cpp:2106] Filtered offer with cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 for role * of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:23.853724  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:29:23.853736  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:23.853746  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 219486ns
I0425 00:29:24.854605  9381 hierarchical.cpp:2106] Filtered offer with cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 for role * of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:29:24.854671  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:29:24.854682  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:24.854693  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 230099ns
I0425 00:29:25.855563  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:25.855618  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 276010ns
I0425 00:29:25.855722  9378 master.cpp:7087] Sending 1 offers to framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690
I0425 00:29:25.855871  9378 sched.cpp:933] Scheduler::resourceOffers took 11958ns
I0425 00:29:26.856763  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:29:26.856812  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:26.856823  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 150700ns
I0425 00:29:27.857220  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:29:27.857275  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:27.857290  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 118790ns
I0425 00:29:28.858621  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:29:28.858671  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:28.858685  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 160531ns
I0425 00:29:29.859889  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:29:29.859938  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:29.859951  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 108334ns
I0425 00:29:30.165771  9379 registry_puller.cpp:271] The manifest for image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine' is '{
   "schemaVersion": 1,
   "name": "acs-sample/alpine",
   "tag": "latest",
   "architecture": "amd64",
   "fsLayers": [
      {
         "blobSum": "sha256:e8f44459dd6d0c16d75074033a92ee25fb59322fe92bdc4eb0fd8216da524450"
      },
      {
         "blobSum": "sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4"
      },
      {
         "blobSum": "sha256:5a026b6c49645017324e8db8865843fcea2c8a65a5f7cdf79779b8fe77ae10e5"
      }
   ],
   "history": [
      {
         "v1Compatibility": "{\"architecture\":\"amd64\",\"author\":\"Li Yi \\[e-mail]\\u003e\",\"config\":{\"Hostname\":\"2d83388e0efb\",\"Domainname\":\"\",\"User\":\"\",\"AttachStdin\":false,\"AttachStdout\":false,\"AttachStderr\":false,\"Tty\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Env\":[\"PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin\"],\"Cmd\":null,\"ArgsEscaped\":true,\"Image\":\"sha256:008a7f94b39384eb9e3251f6ffb9ebdd46fad5c3bfd381e3c3900d532b5f5862\",\"Volumes\":null,\"WorkingDir\":\"\",\"Entrypoint\":null,\"OnBuild\":[],\"Labels\":{}},\"container\":\"179f9079b3cd3b763a47fb759c998e588b63400a0b94403522f08e0ef72f887f\",\"container_config\":{\"Hostname\":\"2d83388e0efb\",\"Domainname\":\"\",\"User\":\"\",\"AttachStdin\":false,\"AttachStdout\":false,\"AttachStderr\":false,\"Tty\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Env\":[\"PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin\"],\"Cmd\":[\"/bin/sh\",\"-c\",\"sed -i 's/dl-cdn.alpinelinux.org/mirrors.aliyun.com/' /etc/apk/repositories\"],\"ArgsEscaped\":true,\"Image\":\"sha256:008a7f94b39384eb9e3251f6ffb9ebdd46fad5c3bfd381e3c3900d532b5f5862\",\"Volumes\":null,\"WorkingDir\":\"\",\"Entrypoint\":null,\"OnBuild\":[],\"Labels\":{}},\"created\":\"2017-01-07T02:28:20.848942814Z\",\"docker_version\":\"1.11.2\",\"id\":\"f5701b0b03085b8526f4a748be6af6701ec3500810dc63a07aa7d2fd77c4731a\",\"os\":\"linux\",\"parent\":\"86ba7e1049e64dd33a6f52718a63d5110e359484b219da65eb6fcd31c65ab433\"}"
      },
      {
         "v1Compatibility": "{\"id\":\"86ba7e1049e64dd33a6f52718a63d5110e359484b219da65eb6fcd31c65ab433\",\"parent\":\"514619160f9c4a9c09230460e6c4fe9cdedbc45f6453374e62566f58f27cd4a2\",\"created\":\"2017-01-07T02:28:20.344127831Z\",\"container_config\":{\"Cmd\":[\"/bin/sh -c #(nop) MAINTAINER Li Yi \\[e-mail]\\u003e\"]},\"author\":\"Li Yi \\[e-mail]\\u003e\",\"throwaway\":true}"
      },
      {
         "v1Compatibility": "{\"id\":\"514619160f9c4a9c09230460e6c4fe9cdedbc45f6453374e62566f58f27cd4a2\",\"created\":\"2016-12-27T18:17:01.738510187Z\",\"container_config\":{\"Cmd\":[\"/bin/sh -c #(nop) ADD file:62421fd56c1160b96b28fc8320ae4332f8578329ea675d45e7c54a4d161d6d89 in / \"]}}"
      }
   ],
   "signatures": [
      {
         "header": {
            "jwk": {
               "crv": "P-256",
               "kid": "ES74:GPSW:LK42:VK7T:CAL2:A5BO:6B6G:U6ZB:GXIF:7IGG:6ESC:PNVR",
               "kty": "EC",
               "x": "3a6uEZqhuY3VgksCh-HuYfWsLZeDpTHNmp9543qryag",
               "y": "In5dg9SFmCL-tNce-1oyzZmhaF6EhEKlVAit6tIdlU4"
            },
            "alg": "ES256"
         },
         "signature": "FTEIQp-Ullusai5kB1fOj6HTc9iRyMmLghSWMalWFl05wdQV_6iiXVfKVZafj-6kq3Gy5k5RmJGB37vKcwWCtA",
         "protected": "eyJmb3JtYXRMZW5ndGgiOjI3NjEsImZvcm1hdFRhaWwiOiJDbjAiLCJ0aW1lIjoiMjAxNy0wNC0yNVQwMDoyOToyOVoifQ"
      }
   ]
}'
I0425 00:29:30.165880  9379 registry_puller.cpp:416] Fetching blob 'sha256:e8f44459dd6d0c16d75074033a92ee25fb59322fe92bdc4eb0fd8216da524450' for layer 'f5701b0b03085b8526f4a748be6af6701ec3500810dc63a07aa7d2fd77c4731a' of image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine'
I0425 00:29:30.165911  9379 registry_puller.cpp:416] Fetching blob 'sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4' for layer '86ba7e1049e64dd33a6f52718a63d5110e359484b219da65eb6fcd31c65ab433' of image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine'
I0425 00:29:30.165951  9379 registry_puller.cpp:416] Fetching blob 'sha256:5a026b6c49645017324e8db8865843fcea2c8a65a5f7cdf79779b8fe77ae10e5' for layer '514619160f9c4a9c09230460e6c4fe9cdedbc45f6453374e62566f58f27cd4a2' of image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine'
I0425 00:29:30.860903  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:29:30.860956  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:30.860972  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 111571ns
I0425 00:29:31.861965  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:29:31.862016  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:31.862030  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 155523ns
I0425 00:29:32.863139  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:29:32.863195  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:32.863211  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 133917ns
I0425 00:29:33.863438  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:29:33.863492  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:33.863507  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 162545ns
I0425 00:29:34.864226  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:29:34.864282  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:34.864295  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 125116ns
I0425 00:29:34.868407  9375 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:29:34.868526  9379 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:29:34.876653  9381 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:29:35.865447  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:29:35.865499  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:35.865516  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 153535ns
I0425 00:29:36.866488  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:29:36.866562  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:36.866577  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 156998ns
I0425 00:29:37.867594  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:29:37.867647  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:37.867668  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 151017ns
I0425 00:29:38.868161  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:29:38.868214  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:38.868229  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 112085ns
I0425 00:29:39.869470  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:29:39.869518  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:39.869529  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 107544ns
I0425 00:29:40.870422  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:29:40.870473  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:40.870486  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 126440ns
I0425 00:29:41.871700  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:29:41.871747  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:41.871759  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 105967ns
I0425 00:29:42.872972  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:29:42.873020  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:42.873034  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 111326ns
I0425 00:29:43.874119  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:29:43.874171  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:43.874192  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 125256ns
I0425 00:29:44.875252  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:29:44.875299  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:44.875313  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 99260ns
I0425 00:29:45.876380  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:29:45.876431  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:45.876446  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 133201ns
I0425 00:29:46.877552  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:29:46.877602  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:46.877616  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 103910ns
I0425 00:29:47.878831  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:29:47.878882  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:47.878896  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 126093ns
I0425 00:29:48.880101  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:29:48.880148  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:48.880162  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 99398ns
I0425 00:29:49.869315  9375 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:29:49.869421  9375 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:29:49.877488  9382 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:29:49.880615  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:29:49.880643  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:49.880657  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 76162ns
I0425 00:29:50.881835  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:29:50.881883  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:50.881896  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 98524ns
I0425 00:29:51.883060  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:29:51.883107  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:51.883121  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 97892ns
I0425 00:29:52.884239  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:29:52.884286  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:52.884300  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 101402ns
I0425 00:29:53.885465  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:29:53.885524  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:53.885538  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 111746ns
I0425 00:29:54.886557  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:29:54.886631  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:54.886644  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 132717ns
I0425 00:29:55.887665  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:29:55.887712  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:55.887725  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 99026ns
I0425 00:29:56.888814  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:29:56.888864  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:56.888876  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 100777ns
I0425 00:29:57.890074  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:29:57.890122  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:57.890136  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 101201ns
I0425 00:29:58.891192  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:29:58.891237  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:58.891250  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 108125ns
I0425 00:29:59.892218  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:29:59.892266  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:29:59.892278  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 97842ns
I0425 00:30:00.892582  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:30:00.892627  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:00.892640  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 102858ns
I0425 00:30:01.893185  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:30:01.893235  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:01.893249  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 101848ns
I0425 00:30:02.893534  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:30:02.893581  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:02.893594  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 103799ns
I0425 00:30:03.894634  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:30:03.894681  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:03.894695  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 103029ns
I0425 00:30:04.870568  9375 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:30:04.870713  9378 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:30:04.877728  9380 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:30:04.895040  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:30:04.895063  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:04.895076  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 71414ns
I0425 00:30:05.896342  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:30:05.896390  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:05.896404  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 135043ns
I0425 00:30:06.897462  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:30:06.897513  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:06.897527  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 104866ns
I0425 00:30:07.898780  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:30:07.898834  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:07.898849  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 106841ns
I0425 00:30:08.900164  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:30:08.900223  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:08.900235  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 117635ns
I0425 00:30:09.900743  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:30:09.900795  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:09.900810  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 106414ns
I0425 00:30:10.902205  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:30:10.902257  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:10.902269  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 103665ns
I0425 00:30:11.902784  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:30:11.902843  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:11.902858  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 115211ns
I0425 00:30:12.903375  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:30:12.903427  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:12.903441  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 112367ns
I0425 00:30:13.903867  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:30:13.903919  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:13.903934  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 117993ns
I0425 00:30:14.904387  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:30:14.904435  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:14.904449  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 103773ns
I0425 00:30:15.905026  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:30:15.905083  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:15.905100  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 115278ns
I0425 00:30:16.905932  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:30:16.905985  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:16.905999  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 112497ns
I0425 00:30:17.906715  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:30:17.906770  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:17.906786  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 114852ns
I0425 00:30:18.907601  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:30:18.907660  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:18.907675  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 113542ns
I0425 00:30:19.866029  9378 slave.cpp:5659] Current disk usage 47.72%. Max allowed age: 2.959364828549711days
I0425 00:30:19.871136  9376 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:30:19.871235  9382 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:30:19.878329  9379 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:30:19.908540  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:30:19.908583  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:19.908596  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 94685ns
I0425 00:30:20.909811  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:30:20.909867  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:20.909881  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 114377ns
I0425 00:30:21.911046  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:30:21.911098  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:21.911120  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 114071ns
I0425 00:30:22.912282  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:30:22.912327  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:22.912339  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 99126ns
I0425 00:30:23.913568  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:30:23.913619  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:23.913633  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 117035ns
I0425 00:30:24.914640  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:30:24.914690  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:24.914703  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 100455ns
I0425 00:30:25.915765  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:30:25.915814  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:25.915827  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 101052ns
I0425 00:30:26.916949  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:30:26.916996  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:26.917008  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 100893ns
I0425 00:30:27.918160  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:30:27.918207  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:27.918220  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 96845ns
I0425 00:30:28.918553  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:30:28.918632  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:28.918647  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 142386ns
I0425 00:30:29.919832  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:30:29.919883  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:29.919898  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 109858ns
I0425 00:30:30.920233  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:30:30.920284  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:30.920300  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 114788ns
I0425 00:30:31.920657  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:30:31.920707  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:31.920722  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 109170ns
I0425 00:30:32.921242  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:30:32.921293  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:32.921306  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 111171ns
I0425 00:30:33.921847  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:30:33.921900  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:33.921913  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 116730ns
I0425 00:30:34.871983  9377 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:30:34.872095  9377 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:30:34.879156  9379 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:30:34.922456  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:30:34.922492  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:34.922546  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 130236ns
I0425 00:30:35.922828  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:30:35.922878  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:35.922891  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 106100ns
I0425 00:30:36.923202  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:30:36.923249  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:36.923264  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 106056ns
I0425 00:30:37.924355  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:30:37.924403  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:37.924417  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 110059ns
I0425 00:30:38.925451  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:30:38.925498  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:38.925511  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 99577ns
I0425 00:30:39.926656  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:30:39.926707  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:39.926722  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 107348ns
I0425 00:30:40.927899  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:30:40.927949  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:40.927963  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 103303ns
I0425 00:30:41.929183  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:30:41.929231  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:41.929245  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 105999ns
I0425 00:30:42.929529  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:30:42.929580  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:42.929594  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 111581ns
I0425 00:30:43.929829  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:30:43.929877  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:43.929893  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 100822ns
I0425 00:30:44.931041  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:30:44.931089  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:44.931103  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 108892ns
I0425 00:30:45.931998  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:30:45.932049  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:45.932070  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 106625ns
I0425 00:30:46.933214  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:30:46.933262  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:46.933275  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 98884ns
I0425 00:30:47.933738  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:30:47.933789  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:47.933804  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 115785ns
I0425 00:30:48.934365  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:30:48.934413  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:48.934427  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 102520ns
I0425 00:30:49.872807  9375 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:30:49.872967  9381 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:30:49.879951  9382 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:30:49.935196  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:30:49.935248  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:49.935263  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 110654ns
I0425 00:30:50.936429  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:30:50.936476  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:50.936491  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 107119ns
I0425 00:30:51.937667  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:30:51.937716  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:51.937731  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 107560ns
I0425 00:30:52.938840  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:30:52.938894  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:52.938907  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 111104ns
I0425 00:30:53.940076  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:30:53.940126  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:53.940140  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 109006ns
I0425 00:30:54.941241  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:30:54.941292  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:54.941305  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 105435ns
I0425 00:30:55.942452  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:30:55.942500  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:55.942538  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 128467ns
I0425 00:30:56.943527  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:30:56.943577  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:56.943589  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 100423ns
I0425 00:30:57.944792  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:30:57.944840  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:57.944854  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 99636ns
I0425 00:30:58.945964  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:30:58.946020  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:58.946043  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 125869ns
I0425 00:30:59.947178  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:30:59.947229  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:30:59.947244  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 106091ns
I0425 00:31:00.948454  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:31:00.948503  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:00.948515  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 98713ns
I0425 00:31:01.949739  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:31:01.949790  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:01.949805  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 114668ns
I0425 00:31:02.950875  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:31:02.950923  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:02.950937  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 99895ns
I0425 00:31:03.952090  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:31:03.952139  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:03.952154  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 103363ns
I0425 00:31:04.874127  9377 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:31:04.874282  9376 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:31:04.880285  9382 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:31:04.952661  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:31:04.952703  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:04.952716  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 89640ns
I0425 00:31:05.953958  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:31:05.954011  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:05.954031  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 110996ns
I0425 00:31:06.955232  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:31:06.955279  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:06.955292  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 98069ns
I0425 00:31:07.956569  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:31:07.956619  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:07.956634  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 112711ns
I0425 00:31:08.957026  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:31:08.957090  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:08.957105  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 126434ns
I0425 00:31:09.957756  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:31:09.957805  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:09.957820  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 112087ns
I0425 00:31:10.958524  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:31:10.958609  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:10.958631  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 154431ns
I0425 00:31:11.959281  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:31:11.959337  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:11.959352  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 124356ns
I0425 00:31:12.959959  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:31:12.960013  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:12.960033  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 118501ns
I0425 00:31:13.960597  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:31:13.960650  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:13.960664  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 105191ns
I0425 00:31:14.961431  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:31:14.961483  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:14.961498  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 115809ns
I0425 00:31:15.962080  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:31:15.962136  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:15.962152  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 108927ns
I0425 00:31:16.962756  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:31:16.962811  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:16.962832  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 118802ns
I0425 00:31:17.963315  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:31:17.963367  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:17.963382  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 108754ns
I0425 00:31:18.963768  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:31:18.963817  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:18.963830  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 101322ns
I0425 00:31:19.866844  9375 slave.cpp:5659] Current disk usage 47.72%. Max allowed age: 2.959323317634039days
I0425 00:31:19.874943  9378 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:31:19.875077  9381 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:31:19.881114  9378 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:31:19.964510  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:31:19.964556  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:19.964570  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 103805ns
I0425 00:31:20.964875  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:31:20.964923  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:20.964936  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 103909ns
I0425 00:31:21.966076  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:31:21.966125  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:21.966140  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 109329ns
I0425 00:31:22.967332  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:31:22.967377  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:22.967391  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 96722ns
I0425 00:31:23.968509  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:31:23.968559  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:23.968572  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 101421ns
I0425 00:31:24.968823  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:31:24.968873  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:24.968886  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 102647ns
I0425 00:31:25.969987  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:31:25.970036  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:25.970048  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 99812ns
I0425 00:31:26.971031  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:31:26.971081  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:26.971094  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 105881ns
I0425 00:31:27.972234  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:31:27.972280  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:27.972295  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 100071ns
I0425 00:31:28.973474  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:31:28.973522  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:28.973536  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 102884ns
I0425 00:31:29.974722  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:31:29.974771  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:29.974784  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 99735ns
I0425 00:31:30.975910  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:31:30.975960  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:30.975972  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 99235ns
I0425 00:31:31.977013  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:31:31.977064  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:31.977078  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 106606ns
I0425 00:31:32.978341  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:31:32.978390  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:32.978404  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 103076ns
I0425 00:31:33.979463  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:31:33.979508  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:33.979523  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 100815ns
I0425 00:31:34.876237  9376 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:31:34.876366  9377 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:31:34.881404  9382 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:31:34.980805  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:31:34.980850  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:34.980872  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 104263ns
I0425 00:31:35.981856  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:31:35.981905  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:35.981920  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 106311ns
I0425 00:31:36.982926  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:31:36.982981  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:36.982997  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 113267ns
I0425 00:31:37.983958  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:31:37.984009  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:37.984024  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 110423ns
I0425 00:31:38.985074  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:31:38.985124  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:38.985138  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 104049ns
I0425 00:31:39.986104  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:31:39.986162  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:39.986178  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 117769ns
I0425 00:31:40.987274  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:31:40.987327  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:40.987341  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 113011ns
I0425 00:31:41.988507  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:31:41.988559  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:41.988574  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 110645ns
I0425 00:31:42.989712  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:31:42.989764  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:42.989778  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 111440ns
I0425 00:31:43.990967  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:31:43.991016  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:43.991030  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 108517ns
I0425 00:31:44.992110  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:31:44.992167  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:44.992189  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 118207ns
I0425 00:31:45.993221  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:31:45.993268  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:45.993283  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 101802ns
I0425 00:31:46.994503  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:31:46.994575  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:46.994590  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 126239ns
I0425 00:31:47.995561  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:31:47.995610  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:47.995625  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 109325ns
I0425 00:31:48.996747  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:31:48.996800  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:48.996814  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 111151ns
I0425 00:31:49.877391  9377 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:31:49.877511  9377 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:31:49.882575  9382 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:31:49.997963  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:31:49.998013  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:49.998026  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 106695ns
I0425 00:31:50.999068  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:31:50.999126  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:50.999147  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 118300ns
I0425 00:31:52.000046  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:31:52.000099  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:52.000114  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 105107ns
I0425 00:31:53.001206  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:31:53.001255  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:53.001268  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 101167ns
I0425 00:31:54.002301  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:31:54.002351  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:54.002367  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 108670ns
I0425 00:31:55.003530  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:31:55.003581  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:55.003594  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 102506ns
I0425 00:31:56.004695  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:31:56.004742  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:56.004756  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 103417ns
I0425 00:31:57.005800  9377 hierarchical.cpp:1862] No allocations performed
I0425 00:31:57.005847  9377 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:57.005861  9377 hierarchical.cpp:1446] Performed allocation for 1 agents in 105517ns
I0425 00:31:58.006860  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:31:58.006909  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:58.006923  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 101966ns
I0425 00:31:59.008119  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:31:59.008169  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:31:59.008183  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 102831ns
I0425 00:32:00.009254  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:32:00.009304  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:00.009317  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 102437ns
I0425 00:32:01.010449  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:32:01.010499  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:01.010535  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 129630ns
I0425 00:32:02.011827  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:32:02.011880  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:02.011895  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 108068ns
I0425 00:32:03.012966  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:32:03.013015  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:03.013029  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 113316ns
I0425 00:32:04.014117  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:32:04.014168  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:04.014183  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 109372ns
I0425 00:32:04.877794  9375 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:32:04.877928  9378 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:32:04.882961  9381 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:32:05.014591  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:32:05.014644  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:05.014659  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 107007ns
I0425 00:32:06.015796  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:32:06.015846  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:06.015859  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 109714ns
I0425 00:32:07.016155  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:32:07.016206  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:07.016218  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 102334ns
I0425 00:32:08.016667  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:32:08.016721  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:08.016736  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 109749ns
E0425 00:32:08.204195  9375 slave.cpp:5041] Container 'a8e309c2-92f7-40b9-80f8-2967b86ae75c' for executor 'ed590512-47bf-4152-8d7d-08fe715af093' of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 failed to start: Collect failed: Failed to perform 'curl': curl: (56) GnuTLS recv error (-9): A TLS packet with unexpected length was received.
I0425 00:32:08.204308  9381 containerizer.cpp:2077] Destroying container a8e309c2-92f7-40b9-80f8-2967b86ae75c in PROVISIONING state
I0425 00:32:08.204387  9381 containerizer.cpp:2132] Waiting for the provisioner to complete provisioning before destroying container a8e309c2-92f7-40b9-80f8-2967b86ae75c
I0425 00:32:08.204453  9381 provisioner.cpp:484] Ignoring destroy request for unknown container a8e309c2-92f7-40b9-80f8-2967b86ae75c
I0425 00:32:08.204689  9375 slave.cpp:5154] Executor 'ed590512-47bf-4152-8d7d-08fe715af093' of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 has terminated with unknown status
I0425 00:32:08.204737  9375 slave.cpp:4215] Handling status update TASK_FAILED (UUID: 3d5965f8-b716-48c0-a3f9-268197ccf93f) for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 from @0.0.0.0:0
W0425 00:32:08.205035  9380 containerizer.cpp:1892] Ignoring update for unknown container a8e309c2-92f7-40b9-80f8-2967b86ae75c
I0425 00:32:08.205186  9381 status_update_manager.cpp:323] Received status update TASK_FAILED (UUID: 3d5965f8-b716-48c0-a3f9-268197ccf93f) for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:08.205211  9381 status_update_manager.cpp:500] Creating StatusUpdate stream for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:08.205351  9381 status_update_manager.cpp:377] Forwarding update TASK_FAILED (UUID: 3d5965f8-b716-48c0-a3f9-268197ccf93f) for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 to the agent
I0425 00:32:08.205431  9376 slave.cpp:4655] Forwarding the update TASK_FAILED (UUID: 3d5965f8-b716-48c0-a3f9-268197ccf93f) for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 to master@10.11.189.151:35690
I0425 00:32:08.205529  9376 slave.cpp:4549] Status update manager successfully handled status update TASK_FAILED (UUID: 3d5965f8-b716-48c0-a3f9-268197ccf93f) for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:08.205592  9381 master.cpp:6251] Status update TASK_FAILED (UUID: 3d5965f8-b716-48c0-a3f9-268197ccf93f) for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 from agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 at slave(886)@10.11.189.151:35690 (ip-10-11-189-151.ec2.internal)
I0425 00:32:08.205620  9381 master.cpp:6319] Forwarding status update TASK_FAILED (UUID: 3d5965f8-b716-48c0-a3f9-268197ccf93f) for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:08.205669  9381 master.cpp:8350] Updating the state of task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
I0425 00:32:08.205742  9380 sched.cpp:1041] Scheduler::statusUpdate took 27931ns
I0425 00:32:08.205878  9378 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):1; mem(*)(allocated: *):128 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*)(allocated: *):1; mem(*)(allocated: *):896; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000]) on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 from framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
../../src/tests/containerizer/provisioner_docker_tests.cpp:537: Failure
Value of: statusRunning->state()
  Actual: TASK_FAILED
Expected: TASK_RUNNING
I0425 00:32:08.205893  9380 master.cpp:5165] Processing ACKNOWLEDGE call 3d5965f8-b716-48c0-a3f9-268197ccf93f for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690 on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0
I0425 00:32:08.205941  9380 master.cpp:8444] Removing task ed590512-47bf-4152-8d7d-08fe715af093 with resources cpus(*)(allocated: *):1; mem(*)(allocated: *):128 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 at slave(886)@10.11.189.151:35690 (ip-10-11-189-151.ec2.internal)
I0425 00:32:08.206102  9379 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 3d5965f8-b716-48c0-a3f9-268197ccf93f) for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:08.206157  9379 status_update_manager.cpp:531] Cleaning up status update stream for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:08.206238  9379 slave.cpp:3504] Status update manager successfully handled status update acknowledgement (UUID: 3d5965f8-b716-48c0-a3f9-268197ccf93f) for task ed590512-47bf-4152-8d7d-08fe715af093 of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:08.206264  9379 slave.cpp:7270] Completing task ed590512-47bf-4152-8d7d-08fe715af093
I0425 00:32:08.206276  9379 slave.cpp:5261] Cleaning up executor 'ed590512-47bf-4152-8d7d-08fe715af093' of framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:08.206372  9380 gc.cpp:55] Scheduling '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_o3cp02/slaves/9e93bad0-595c-4165-813a-7d70d96df372-S0/frameworks/9e93bad0-595c-4165-813a-7d70d96df372-0000/executors/ed590512-47bf-4152-8d7d-08fe715af093/runs/a8e309c2-92f7-40b9-80f8-2967b86ae75c' for gc 6.9999976119437days in the future
I0425 00:32:08.206395  9379 slave.cpp:5349] Cleaning up framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:08.206420  9380 gc.cpp:55] Scheduling '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_o3cp02/slaves/9e93bad0-595c-4165-813a-7d70d96df372-S0/frameworks/9e93bad0-595c-4165-813a-7d70d96df372-0000/executors/ed590512-47bf-4152-8d7d-08fe715af093' for gc 6.99999761130667days in the future
I0425 00:32:08.206457  9377 status_update_manager.cpp:285] Closing status update streams for framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:08.206463  9380 gc.cpp:55] Scheduling '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_o3cp02/slaves/9e93bad0-595c-4165-813a-7d70d96df372-S0/frameworks/9e93bad0-595c-4165-813a-7d70d96df372-0000' for gc 6.99999761055407days in the future
I0425 00:32:09.017879  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:09.017935  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 232033ns
I0425 00:32:09.018018  9381 master.cpp:7087] Sending 1 offers to framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690
I0425 00:32:09.018160  9381 sched.cpp:933] Scheduler::resourceOffers took 9757ns
I0425 00:32:10.018276  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:32:10.018328  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:10.018342  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 111823ns
I0425 00:32:11.018934  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:32:11.018985  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:11.018998  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 108930ns
I0425 00:32:12.019572  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:32:12.019623  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:12.019639  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 118998ns
I0425 00:32:13.020869  9381 hierarchical.cpp:1862] No allocations performed
I0425 00:32:13.020920  9381 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:13.020934  9381 hierarchical.cpp:1446] Performed allocation for 1 agents in 130944ns
I0425 00:32:14.022327  9380 hierarchical.cpp:1862] No allocations performed
I0425 00:32:14.022388  9380 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:14.022403  9380 hierarchical.cpp:1446] Performed allocation for 1 agents in 124394ns
I0425 00:32:15.022846  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:32:15.022904  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:15.022920  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 112650ns
I0425 00:32:16.023427  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:32:16.023488  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:16.023502  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 130423ns
I0425 00:32:17.023960  9382 hierarchical.cpp:1862] No allocations performed
I0425 00:32:17.024011  9382 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:17.024025  9382 hierarchical.cpp:1446] Performed allocation for 1 agents in 103174ns
I0425 00:32:18.024456  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:32:18.024507  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:18.024523  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 114040ns
I0425 00:32:19.025089  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:32:19.025138  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:19.025151  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 102790ns
I0425 00:32:19.867946  9375 slave.cpp:5659] Current disk usage 47.72%. Max allowed age: 2.959381160713253days
I0425 00:32:19.879035  9382 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:32:19.879148  9380 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:32:19.883221  9375 slave.cpp:4745] Received ping from slave-observer(797)@10.11.189.151:35690
I0425 00:32:20.025717  9376 hierarchical.cpp:1862] No allocations performed
I0425 00:32:20.025768  9376 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:20.025791  9376 hierarchical.cpp:1446] Performed allocation for 1 agents in 113901ns
I0425 00:32:21.026859  9379 hierarchical.cpp:1862] No allocations performed
I0425 00:32:21.026906  9379 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:21.026921  9379 hierarchical.cpp:1446] Performed allocation for 1 agents in 97543ns
I0425 00:32:22.028084  9375 hierarchical.cpp:1862] No allocations performed
I0425 00:32:22.028136  9375 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:22.028149  9375 hierarchical.cpp:1446] Performed allocation for 1 agents in 104289ns
I0425 00:32:23.029299  9378 hierarchical.cpp:1862] No allocations performed
I0425 00:32:23.029347  9378 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:32:23.029361  9378 hierarchical.cpp:1446] Performed allocation for 1 agents in 108606ns
../../src/tests/containerizer/provisioner_docker_tests.cpp:539: Failure
Failed to wait 15secs for statusFinished
I0425 00:32:23.207125  9380 master.cpp:1432] Framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690 disconnected
I0425 00:32:23.207170  9380 master.cpp:3162] Deactivating framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690
I0425 00:32:23.207239  9377 hierarchical.cpp:376] Deactivated framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
../../src/tests/containerizer/provisioner_docker_tests.cpp:529: Failure
Actual function call count doesn't match EXPECT_CALL(sched, statusUpdate(&driver, _))...
         Expected: to be called twice
           Actual: called once - unsatisfied and active
I0425 00:32:23.207339  9380 master.cpp:3139] Disconnecting framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690
I0425 00:32:23.207357  9380 master.cpp:1447] Giving framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690 0ns to failover
I0425 00:32:23.207370  9377 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):1; mem(*)(allocated: *):128 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*)(allocated: *):1; mem(*)(allocated: *):896; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000]) on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 from framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:23.207526  9376 master.cpp:6928] Framework failover timeout, removing framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690
I0425 00:32:23.207551  9376 master.cpp:7782] Removing framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 (default) at scheduler-e4c5eab0-7480-4ccc-af43-841a7374e30d@10.11.189.151:35690
I0425 00:32:23.207608  9377 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):1; mem(*)(allocated: *):896; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 from framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:23.207659  9382 slave.cpp:3057] Asked to shut down framework 9e93bad0-595c-4165-813a-7d70d96df372-0000 by master@10.11.189.151:35690
I0425 00:32:23.207690  9382 slave.cpp:3072] Cannot shut down unknown framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:23.207871  9376 hierarchical.cpp:323] Removed framework 9e93bad0-595c-4165-813a-7d70d96df372-0000
I0425 00:32:23.208017  9377 slave.cpp:790] Agent terminating
I0425 00:32:23.208117  9375 master.cpp:1315] Agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 at slave(886)@10.11.189.151:35690 (ip-10-11-189-151.ec2.internal) disconnected
I0425 00:32:23.208139  9375 master.cpp:3199] Disconnecting agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 at slave(886)@10.11.189.151:35690 (ip-10-11-189-151.ec2.internal)
I0425 00:32:23.208180  9375 master.cpp:3218] Deactivating agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 at slave(886)@10.11.189.151:35690 (ip-10-11-189-151.ec2.internal)
I0425 00:32:23.208264  9375 hierarchical.cpp:655] Agent 9e93bad0-595c-4165-813a-7d70d96df372-S0 deactivated
I0425 00:32:23.210009 11273 master.cpp:1157] Master terminating
I0425 00:32:23.210252  9380 hierarchical.cpp:560] Removed agent 9e93bad0-595c-4165-813a-7d70d96df372-S0
[  FAILED  ] ImageAlpine/ProvisionerDockerTest.ROOT_INTERNET_CURL_SimpleCommand/3, where GetParam() = "registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine" (183363 ms)
[----------] 4 tests from ImageAlpine/ProvisionerDockerTest (184791 ms total)

In Debian 8:

[ RUN      ] ImageAlpine/ProvisionerDockerTest.ROOT_INTERNET_CURL_SimpleCommand/3
I0425 00:45:33.503415 15614 cluster.cpp:162] Creating default 'local' authorizer
I0425 00:45:33.504519 15620 master.cpp:438] Master 66aaf7ed-8452-49aa-bb1b-467835ab99a5 (ip-10-102-186-248.ec2.internal) started on 10.102.186.248:48431
I0425 00:45:33.504537 15620 master.cpp:440] 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" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/u7tvnp/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_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/u7tvnp/master" --zk_session_timeout="10secs"
I0425 00:45:33.504636 15620 master.cpp:490] Master only allowing authenticated frameworks to register
I0425 00:45:33.504640 15620 master.cpp:504] Master only allowing authenticated agents to register
I0425 00:45:33.504643 15620 master.cpp:517] Master only allowing authenticated HTTP frameworks to register
I0425 00:45:33.504647 15620 credentials.hpp:37] Loading credentials for authentication from '/tmp/u7tvnp/credentials'
I0425 00:45:33.504719 15620 master.cpp:562] Using default 'crammd5' authenticator
I0425 00:45:33.504765 15620 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0425 00:45:33.504832 15620 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0425 00:45:33.504868 15620 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0425 00:45:33.504883 15620 master.cpp:642] Authorization enabled
I0425 00:45:33.504936 15621 whitelist_watcher.cpp:77] No whitelist given
I0425 00:45:33.504963 15615 hierarchical.cpp:159] Initialized hierarchical allocator process
I0425 00:45:33.505539 15616 master.cpp:2163] Elected as the leading master!
I0425 00:45:33.505555 15616 master.cpp:1702] Recovering from registrar
I0425 00:45:33.505610 15618 registrar.cpp:345] Recovering registrar
I0425 00:45:33.505803 15617 registrar.cpp:389] Successfully fetched the registry (0B) in 172800ns
I0425 00:45:33.505833 15617 registrar.cpp:493] Applied 1 operations in 3220ns; attempting to update the registry
I0425 00:45:33.506048 15622 registrar.cpp:550] Successfully updated the registry in 178944ns
I0425 00:45:33.506084 15622 registrar.cpp:422] Successfully recovered registrar
I0425 00:45:33.506253 15618 master.cpp:1801] Recovered 0 agents from the registry (176B); allowing 10mins for agents to re-register
I0425 00:45:33.506268 15621 hierarchical.cpp:186] Skipping recovery of hierarchical allocator: nothing to recover
I0425 00:45:33.507951 15614 containerizer.cpp:221] Using isolation: docker/runtime,filesystem/linux,network/cni,volume/image
I0425 00:45:33.510823 15614 linux_launcher.cpp:150] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
E0425 00:45:33.513103 15614 shell.hpp:107] Command 'hadoop version 2>&1' failed; this is the output:
sh: 1: hadoop: not found
I0425 00:45:33.513139 15614 fetcher.cpp:69] 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
I0425 00:45:33.513237 15614 registry_puller.cpp:115] Creating registry puller with docker registry 'https://registry-1.docker.io'
I0425 00:45:33.513686 15614 provisioner.cpp:249] Using default backend 'copy'
I0425 00:45:33.514117 15614 linux.cpp:144] Bind mounting '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_d0foT7' and making it a shared mount
I0425 00:45:33.518879 15614 cluster.cpp:448] Creating default 'local' authorizer
I0425 00:45:33.519299 15622 slave.cpp:225] Mesos agent started on (879)@10.102.186.248:48431
I0425 00:45:33.519316 15622 slave.cpp:226] 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/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_SWphpQ/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/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="10mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_SWphpQ/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/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_SWphpQ/http_credentials" --http_heartbeat_interval="30secs" --image_providers="docker" --initialize_driver_logging="true" --isolation="docker/runtime,filesystem/linux" --launcher="linux" --launcher_dir="/home/admin/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-debian-8/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/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_SWphpQ" --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/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_d0foT7"
I0425 00:45:33.519520 15622 credentials.hpp:86] Loading credential for authentication from '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_SWphpQ/credential'
I0425 00:45:33.519626 15622 slave.cpp:258] Agent using credential for: test-principal
I0425 00:45:33.519639 15622 credentials.hpp:37] Loading credentials for authentication from '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_SWphpQ/http_credentials'
I0425 00:45:33.519719 15622 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0425 00:45:33.519758 15622 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0425 00:45:33.520299 15622 slave.cpp:525] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0425 00:45:33.520325 15614 sched.cpp:232] Version: 1.3.0
I0425 00:45:33.520332 15622 slave.cpp:533] Agent attributes: [  ]
I0425 00:45:33.520339 15622 slave.cpp:538] Agent hostname: ip-10-102-186-248.ec2.internal
I0425 00:45:33.520392 15620 status_update_manager.cpp:177] Pausing sending status updates
I0425 00:45:33.520493 15618 sched.cpp:336] New master detected at master@10.102.186.248:48431
I0425 00:45:33.520521 15618 sched.cpp:407] Authenticating with master master@10.102.186.248:48431
I0425 00:45:33.520526 15618 sched.cpp:414] Using default CRAM-MD5 authenticatee
I0425 00:45:33.520614 15615 authenticatee.cpp:121] Creating new client SASL connection
I0425 00:45:33.520725 15616 state.cpp:62] Recovering state from '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_d0foT7/meta'
I0425 00:45:33.520844 15622 status_update_manager.cpp:203] Recovering status update manager
I0425 00:45:33.520943 15622 containerizer.cpp:608] Recovering containerizer
I0425 00:45:33.520995 15619 master.cpp:7257] Authenticating scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431
I0425 00:45:33.521060 15622 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1594)@10.102.186.248:48431
I0425 00:45:33.521165 15621 authenticator.cpp:98] Creating new server SASL connection
I0425 00:45:33.521476 15621 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0425 00:45:33.521497 15621 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0425 00:45:33.521528 15621 authenticator.cpp:204] Received SASL authentication start
I0425 00:45:33.521603 15621 authenticator.cpp:326] Authentication requires more steps
I0425 00:45:33.521733 15616 authenticatee.cpp:259] Received SASL authentication step
I0425 00:45:33.521822 15619 authenticator.cpp:232] Received SASL authentication step
I0425 00:45:33.521844 15619 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-10-102-186-248.ec2.internal' server FQDN: 'ip-10-102-186-248.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0425 00:45:33.521850 15619 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0425 00:45:33.521862 15619 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0425 00:45:33.521870 15619 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-10-102-186-248.ec2.internal' server FQDN: 'ip-10-102-186-248.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0425 00:45:33.521878 15619 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0425 00:45:33.521883 15619 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0425 00:45:33.521895 15619 authenticator.cpp:318] Authentication success
I0425 00:45:33.521961 15619 authenticatee.cpp:299] Authentication success
I0425 00:45:33.521994 15616 master.cpp:7287] Successfully authenticated principal 'test-principal' at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431
I0425 00:45:33.522106 15621 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1594)@10.102.186.248:48431
I0425 00:45:33.522164 15618 sched.cpp:513] Successfully authenticated with master master@10.102.186.248:48431
I0425 00:45:33.522177 15618 sched.cpp:836] Sending SUBSCRIBE call to master@10.102.186.248:48431
I0425 00:45:33.522214 15618 sched.cpp:869] Will retry registration in 689.94832ms if necessary
I0425 00:45:33.522291 15619 master.cpp:2815] Received SUBSCRIBE call for framework 'default' at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431
I0425 00:45:33.522320 15619 master.cpp:2199] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
I0425 00:45:33.522318 15616 metadata_manager.cpp:233] Successfully loaded image 'chhsiao/overwrite'
I0425 00:45:33.522343 15616 metadata_manager.cpp:233] Successfully loaded image 'quay.io/coreos/alpine-sh'
I0425 00:45:33.522349 15616 metadata_manager.cpp:233] Successfully loaded image 'library/alpine@sha256:9f08005dff552038f0ad2f46b8e65ff3d25641747d3912e3ea8da6785046561a'
I0425 00:45:33.522354 15616 metadata_manager.cpp:233] Successfully loaded image 'haosdent/https-server'
I0425 00:45:33.522359 15616 metadata_manager.cpp:233] Successfully loaded image 'alpine'
I0425 00:45:33.522364 15616 metadata_manager.cpp:233] Successfully loaded image 'hello-world'
I0425 00:45:33.522369 15616 metadata_manager.cpp:233] Successfully loaded image 'library/alpine'
I0425 00:45:33.522378 15616 metadata_manager.cpp:233] Successfully loaded image 'zhq527725/whiteout'
I0425 00:45:33.522384 15616 metadata_manager.cpp:236] Successfully loaded 8 Docker images
I0425 00:45:33.522452 15622 master.cpp:2892] Subscribing framework default with checkpointing disabled and capabilities [  ]
I0425 00:45:33.522547 15620 provisioner.cpp:410] Provisioner recovery complete
I0425 00:45:33.522686 15622 sched.cpp:759] Framework registered with 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:33.522770 15622 sched.cpp:773] Scheduler::registered took 66617ns
I0425 00:45:33.522809 15615 slave.cpp:5963] Finished recovery
I0425 00:45:33.522858 15621 hierarchical.cpp:271] Added framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:33.522910 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:45:33.522927 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:33.522940 15621 hierarchical.cpp:1446] Performed allocation for 0 agents in 38940ns
I0425 00:45:33.523018 15615 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:45:33.523095 15619 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:45:33.523144 15619 slave.cpp:918] New master detected at master@10.102.186.248:48431
I0425 00:45:33.523156 15620 status_update_manager.cpp:177] Pausing sending status updates
I0425 00:45:33.523180 15619 slave.cpp:953] Detecting new master
I0425 00:45:33.526471 15620 slave.cpp:980] Authenticating with master master@10.102.186.248:48431
I0425 00:45:33.526496 15620 slave.cpp:991] Using default CRAM-MD5 authenticatee
I0425 00:45:33.526561 15620 authenticatee.cpp:121] Creating new client SASL connection
I0425 00:45:33.526933 15620 master.cpp:7257] Authenticating slave(879)@10.102.186.248:48431
I0425 00:45:33.526980 15616 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1595)@10.102.186.248:48431
I0425 00:45:33.527056 15620 authenticator.cpp:98] Creating new server SASL connection
I0425 00:45:33.527338 15620 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0425 00:45:33.527354 15620 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0425 00:45:33.527379 15620 authenticator.cpp:204] Received SASL authentication start
I0425 00:45:33.527400 15620 authenticator.cpp:326] Authentication requires more steps
I0425 00:45:33.527456 15620 authenticatee.cpp:259] Received SASL authentication step
I0425 00:45:33.527505 15620 authenticator.cpp:232] Received SASL authentication step
I0425 00:45:33.527523 15620 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-10-102-186-248.ec2.internal' server FQDN: 'ip-10-102-186-248.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0425 00:45:33.527529 15620 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0425 00:45:33.527539 15620 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0425 00:45:33.527549 15620 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-10-102-186-248.ec2.internal' server FQDN: 'ip-10-102-186-248.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0425 00:45:33.527554 15620 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0425 00:45:33.527557 15620 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0425 00:45:33.527577 15620 authenticator.cpp:318] Authentication success
I0425 00:45:33.527637 15620 authenticatee.cpp:299] Authentication success
I0425 00:45:33.527665 15615 master.cpp:7287] Successfully authenticated principal 'test-principal' at slave(879)@10.102.186.248:48431
I0425 00:45:33.527704 15618 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1595)@10.102.186.248:48431
I0425 00:45:33.527751 15620 slave.cpp:1075] Successfully authenticated with master master@10.102.186.248:48431
I0425 00:45:33.527864 15620 slave.cpp:1503] Will retry registration in 17.405506ms if necessary
I0425 00:45:33.527922 15616 master.cpp:5447] Registering agent at slave(879)@10.102.186.248:48431 (ip-10-102-186-248.ec2.internal) with id 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0
I0425 00:45:33.528024 15616 registrar.cpp:493] Applied 1 operations in 9023ns; attempting to update the registry
I0425 00:45:33.528195 15616 registrar.cpp:550] Successfully updated the registry in 145920ns
I0425 00:45:33.528376 15617 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:45:33.528376 15621 master.cpp:5521] Registered agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 at slave(879)@10.102.186.248:48431 (ip-10-102-186-248.ec2.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0425 00:45:33.528434 15619 hierarchical.cpp:527] Added agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 (ip-10-102-186-248.ec2.internal) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I0425 00:45:33.528460 15617 slave.cpp:1121] Registered with master master@10.102.186.248:48431; given agent ID 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0
I0425 00:45:33.528475 15617 fetcher.cpp:94] Clearing fetcher cache
I0425 00:45:33.528540 15618 status_update_manager.cpp:184] Resuming sending status updates
I0425 00:45:33.528612 15617 slave.cpp:1149] Checkpointing SlaveInfo to '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_d0foT7/meta/slaves/66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0/slave.info'
I0425 00:45:33.528709 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:33.528728 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 224580ns
I0425 00:45:33.528736 15617 slave.cpp:1187] Forwarding total oversubscribed resources {}
I0425 00:45:33.528831 15616 master.cpp:7087] Sending 1 offers to framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431
I0425 00:45:33.528893 15616 master.cpp:6106] Received update of agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 at slave(879)@10.102.186.248:48431 (ip-10-102-186-248.ec2.internal) with total oversubscribed resources {}
I0425 00:45:33.529003 15615 sched.cpp:933] Scheduler::resourceOffers took 49805ns
I0425 00:45:33.529434 15619 master.cpp:3853] Processing ACCEPT call for offers: [ 66aaf7ed-8452-49aa-bb1b-467835ab99a5-O0 ] on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 at slave(879)@10.102.186.248:48431 (ip-10-102-186-248.ec2.internal) for framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431
I0425 00:45:33.529465 15619 master.cpp:3429] Authorizing framework principal 'test-principal' to launch task cb4814db-edd4-45ce-892f-81ba1a630d7e
I0425 00:45:33.529870 15616 master.cpp:9102] Adding task cb4814db-edd4-45ce-892f-81ba1a630d7e with resources cpus(*)(allocated: *):1; mem(*)(allocated: *):128 on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 at slave(879)@10.102.186.248:48431 (ip-10-102-186-248.ec2.internal)
I0425 00:45:33.529914 15616 master.cpp:4503] Launching task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431 with resources cpus(*)(allocated: *):1; mem(*)(allocated: *):128 on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 at slave(879)@10.102.186.248:48431 (ip-10-102-186-248.ec2.internal)
I0425 00:45:33.530120 15621 slave.cpp:1613] Got assigned task 'cb4814db-edd4-45ce-892f-81ba1a630d7e' for framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:33.530295 15621 slave.cpp:1894] Authorizing task 'cb4814db-edd4-45ce-892f-81ba1a630d7e' for framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:33.530315 15621 slave.cpp:6582] Authorizing framework principal 'test-principal' to launch task cb4814db-edd4-45ce-892f-81ba1a630d7e
I0425 00:45:33.530311 15622 hierarchical.cpp:852] Updated allocation of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-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]
I0425 00:45:33.530496 15622 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):1; mem(*)(allocated: *):896; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*)(allocated: *):1; mem(*)(allocated: *):128) on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 from framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:33.530537 15622 hierarchical.cpp:1153] Framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 filtered agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 for 5secs
I0425 00:45:33.530603 15619 slave.cpp:2081] Launching task 'cb4814db-edd4-45ce-892f-81ba1a630d7e' for framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:33.530830 15619 paths.cpp:556] Trying to chown '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_d0foT7/slaves/66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0/frameworks/66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000/executors/cb4814db-edd4-45ce-892f-81ba1a630d7e/runs/2e7b13d8-71be-4eca-a8d4-6a75c3c3bbdd' to user 'root'
I0425 00:45:33.530938 15619 slave.cpp:6926] Launching executor 'cb4814db-edd4-45ce-892f-81ba1a630d7e' of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 with resources cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32 in work directory '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_d0foT7/slaves/66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0/frameworks/66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000/executors/cb4814db-edd4-45ce-892f-81ba1a630d7e/runs/2e7b13d8-71be-4eca-a8d4-6a75c3c3bbdd'
I0425 00:45:33.531111 15622 containerizer.cpp:1001] Starting container 2e7b13d8-71be-4eca-a8d4-6a75c3c3bbdd for executor 'cb4814db-edd4-45ce-892f-81ba1a630d7e' of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:33.531126 15619 slave.cpp:2310] Queued task 'cb4814db-edd4-45ce-892f-81ba1a630d7e' for executor 'cb4814db-edd4-45ce-892f-81ba1a630d7e' of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:33.531154 15619 slave.cpp:871] Successfully attached file '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_d0foT7/slaves/66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0/frameworks/66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000/executors/cb4814db-edd4-45ce-892f-81ba1a630d7e/runs/2e7b13d8-71be-4eca-a8d4-6a75c3c3bbdd'
I0425 00:45:33.531419 15619 metadata_manager.cpp:168] Looking for image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine'
I0425 00:45:33.537080 15619 registry_puller.cpp:247] Pulling image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine' from 'docker-manifest://registry.cn-hangzhou.aliyuncs.comacs-sample/alpine?latest#https' to '/tmp/mesos/store/docker/staging/atbL8Z'
I0425 00:45:34.505594 15618 hierarchical.cpp:2106] Filtered offer with cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 for role * of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:34.505648 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:45:34.505657 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:34.505669 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 216032ns
I0425 00:45:35.506376 15618 hierarchical.cpp:2106] Filtered offer with cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 for role * of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:35.506433 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:45:35.506443 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:35.506458 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 202241ns
I0425 00:45:36.506703 15621 hierarchical.cpp:2106] Filtered offer with cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 for role * of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:36.506757 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:45:36.506764 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:36.506774 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 203864ns
I0425 00:45:37.507366 15619 hierarchical.cpp:2106] Filtered offer with cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 for role * of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:37.507422 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:45:37.507431 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:37.507441 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 180545ns
I0425 00:45:38.508496 15620 hierarchical.cpp:2106] Filtered offer with cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000] on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 for role * of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:45:38.508545 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:45:38.508554 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:38.508564 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 167774ns
I0425 00:45:39.509889 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:39.509938 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 298657ns
I0425 00:45:39.510082 15618 master.cpp:7087] Sending 1 offers to framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431
I0425 00:45:39.510247 15618 sched.cpp:933] Scheduler::resourceOffers took 21048ns
I0425 00:45:40.510540 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:45:40.510571 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:40.510582 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 110528ns
I0425 00:45:40.910145 15615 registry_puller.cpp:271] The manifest for image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine' is '{
   "schemaVersion": 1,
   "name": "acs-sample/alpine",
   "tag": "latest",
   "architecture": "amd64",
   "fsLayers": [
      {
         "blobSum": "sha256:e8f44459dd6d0c16d75074033a92ee25fb59322fe92bdc4eb0fd8216da524450"
      },
      {
         "blobSum": "sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4"
      },
      {
         "blobSum": "sha256:5a026b6c49645017324e8db8865843fcea2c8a65a5f7cdf79779b8fe77ae10e5"
      }
   ],
   "history": [
      {
         "v1Compatibility": "{\"architecture\":\"amd64\",\"author\":\"Li Yi \\[e-mail]\\u003e\",\"config\":{\"Hostname\":\"2d83388e0efb\",\"Domainname\":\"\",\"User\":\"\",\"AttachStdin\":false,\"AttachStdout\":false,\"AttachStderr\":false,\"Tty\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Env\":[\"PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin\"],\"Cmd\":null,\"ArgsEscaped\":true,\"Image\":\"sha256:008a7f94b39384eb9e3251f6ffb9ebdd46fad5c3bfd381e3c3900d532b5f5862\",\"Volumes\":null,\"WorkingDir\":\"\",\"Entrypoint\":null,\"OnBuild\":[],\"Labels\":{}},\"container\":\"179f9079b3cd3b763a47fb759c998e588b63400a0b94403522f08e0ef72f887f\",\"container_config\":{\"Hostname\":\"2d83388e0efb\",\"Domainname\":\"\",\"User\":\"\",\"AttachStdin\":false,\"AttachStdout\":false,\"AttachStderr\":false,\"Tty\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Env\":[\"PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin\"],\"Cmd\":[\"/bin/sh\",\"-c\",\"sed -i 's/dl-cdn.alpinelinux.org/mirrors.aliyun.com/' /etc/apk/repositories\"],\"ArgsEscaped\":true,\"Image\":\"sha256:008a7f94b39384eb9e3251f6ffb9ebdd46fad5c3bfd381e3c3900d532b5f5862\",\"Volumes\":null,\"WorkingDir\":\"\",\"Entrypoint\":null,\"OnBuild\":[],\"Labels\":{}},\"created\":\"2017-01-07T02:28:20.848942814Z\",\"docker_version\":\"1.11.2\",\"id\":\"f5701b0b03085b8526f4a748be6af6701ec3500810dc63a07aa7d2fd77c4731a\",\"os\":\"linux\",\"parent\":\"86ba7e1049e64dd33a6f52718a63d5110e359484b219da65eb6fcd31c65ab433\"}"
      },
      {
         "v1Compatibility": "{\"id\":\"86ba7e1049e64dd33a6f52718a63d5110e359484b219da65eb6fcd31c65ab433\",\"parent\":\"514619160f9c4a9c09230460e6c4fe9cdedbc45f6453374e62566f58f27cd4a2\",\"created\":\"2017-01-07T02:28:20.344127831Z\",\"container_config\":{\"Cmd\":[\"/bin/sh -c #(nop) MAINTAINER Li Yi \\[e-mail]\\u003e\"]},\"author\":\"Li Yi \\[e-mail]\\u003e\",\"throwaway\":true}"
      },
      {
         "v1Compatibility": "{\"id\":\"514619160f9c4a9c09230460e6c4fe9cdedbc45f6453374e62566f58f27cd4a2\",\"created\":\"2016-12-27T18:17:01.738510187Z\",\"container_config\":{\"Cmd\":[\"/bin/sh -c #(nop) ADD file:62421fd56c1160b96b28fc8320ae4332f8578329ea675d45e7c54a4d161d6d89 in / \"]}}"
      }
   ],
   "signatures": [
      {
         "header": {
            "jwk": {
               "crv": "P-256",
               "kid": "6J4T:C3QE:LUDM:GXWX:LKI3:JIR6:UB6E:S2FT:BQ6R:H45A:7QFK:C5HQ",
               "kty": "EC",
               "x": "9l-rfHjKiCm-k5V5C060xni5Yzfqug0li_DgT9Dv3K0",
               "y": "OgxB2ma8e9eCtY7A0Mouwgh1Q6yX70gLDoWKgjyE35Q"
            },
            "alg": "ES256"
         },
         "signature": "ZW9J1SCz1wQpqxKe-nbiGJSSAblo-M_3UBaAgMizHCVCpiuGHZlub5HHDIpKinQxgwB1N-4AL805kRPj91JK8w",
         "protected": "eyJmb3JtYXRMZW5ndGgiOjI3NjEsImZvcm1hdFRhaWwiOiJDbjAiLCJ0aW1lIjoiMjAxNy0wNC0yNVQwMDo0NTo0MVoifQ"
      }
   ]
}'
I0425 00:45:40.910217 15615 registry_puller.cpp:416] Fetching blob 'sha256:e8f44459dd6d0c16d75074033a92ee25fb59322fe92bdc4eb0fd8216da524450' for layer 'f5701b0b03085b8526f4a748be6af6701ec3500810dc63a07aa7d2fd77c4731a' of image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine'
I0425 00:45:40.910231 15615 registry_puller.cpp:416] Fetching blob 'sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4' for layer '86ba7e1049e64dd33a6f52718a63d5110e359484b219da65eb6fcd31c65ab433' of image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine'
I0425 00:45:40.910243 15615 registry_puller.cpp:416] Fetching blob 'sha256:5a026b6c49645017324e8db8865843fcea2c8a65a5f7cdf79779b8fe77ae10e5' for layer '514619160f9c4a9c09230460e6c4fe9cdedbc45f6453374e62566f58f27cd4a2' of image 'registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine'
I0425 00:45:41.511876 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:45:41.511919 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:41.511945 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 129533ns
I0425 00:45:42.512536 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:45:42.512567 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:42.512578 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 103484ns
I0425 00:45:43.513188 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:45:43.513219 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:43.513237 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 90046ns
I0425 00:45:44.513717 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:45:44.513752 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:44.513767 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 107430ns
I0425 00:45:45.514942 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:45:45.514968 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:45.514979 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 101778ns
I0425 00:45:46.516119 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:45:46.516155 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:46.516170 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 103658ns
I0425 00:45:47.517051 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:45:47.517083 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:47.517101 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 108734ns
I0425 00:45:48.518436 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:45:48.518474 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:48.518491 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 131985ns
I0425 00:45:48.523699 15618 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:45:48.523831 15621 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:45:48.529012 15622 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:45:49.519569 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:45:49.519605 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:49.519621 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 103206ns
I0425 00:45:50.520088 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:45:50.520118 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:50.520129 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 97803ns
I0425 00:45:51.521353 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:45:51.521380 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:51.521391 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 97390ns
I0425 00:45:52.522693 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:45:52.522724 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:52.522734 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 94194ns
I0425 00:45:53.524027 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:45:53.524060 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:53.524072 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 115248ns
I0425 00:45:54.525203 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:45:54.525236 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:54.525249 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 94880ns
I0425 00:45:55.525785 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:45:55.525818 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:55.525830 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 96658ns
I0425 00:45:56.527041 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:45:56.527072 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:56.527086 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 101037ns
I0425 00:45:57.527777 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:45:57.527808 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:57.527822 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 96673ns
I0425 00:45:58.528244 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:45:58.528278 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:58.528295 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 124734ns
I0425 00:45:59.529062 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:45:59.529100 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:45:59.529114 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 93012ns
I0425 00:46:00.529815 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:46:00.529847 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:00.529860 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 85437ns
I0425 00:46:01.530594 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:46:01.530625 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:01.530637 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 89330ns
I0425 00:46:02.531550 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:46:02.531582 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:02.531595 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 91830ns
I0425 00:46:03.524193 15617 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:46:03.524327 15622 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:46:03.529508 15621 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:46:03.532737 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:46:03.532755 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:03.532766 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 70955ns
I0425 00:46:04.533241 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:46:04.533273 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:04.533285 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 87853ns
I0425 00:46:05.533819 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:46:05.533850 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:05.533861 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 92262ns
I0425 00:46:06.534193 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:46:06.534224 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:06.534235 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 80757ns
I0425 00:46:07.534459 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:46:07.534489 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:07.534502 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 92500ns
I0425 00:46:08.535063 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:46:08.535099 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:08.535116 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 92913ns
I0425 00:46:09.535588 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:46:09.535617 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:09.535629 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 81399ns
I0425 00:46:10.536689 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:46:10.536720 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:10.536732 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 87343ns
I0425 00:46:11.537286 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:46:11.537318 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:11.537333 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 100578ns
I0425 00:46:12.537974 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:46:12.538005 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:12.538017 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 90527ns
I0425 00:46:13.538718 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:46:13.538754 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:13.538770 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 97770ns
I0425 00:46:14.539891 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:46:14.539927 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:14.539939 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 92925ns
I0425 00:46:15.540166 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:46:15.540196 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:15.540208 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 87354ns
I0425 00:46:16.540390 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:46:16.540421 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:16.540433 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 85609ns
I0425 00:46:17.540633 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:46:17.540670 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:17.540686 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 94698ns
I0425 00:46:18.525243 15622 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:46:18.525372 15617 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:46:18.530525 15615 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:46:18.541776 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:46:18.541796 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:18.541808 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 68438ns
I0425 00:46:19.543087 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:46:19.543119 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:19.543131 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 91552ns
I0425 00:46:20.543581 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:46:20.543618 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:20.543632 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 90681ns
I0425 00:46:21.544172 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:46:21.544205 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:21.544219 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 99514ns
I0425 00:46:22.544685 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:46:22.544718 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:22.544737 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 96726ns
I0425 00:46:23.545258 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:46:23.545289 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:23.545302 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 98006ns
I0425 00:46:24.545748 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:46:24.545778 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:24.545789 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 78603ns
I0425 00:46:25.546388 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:46:25.546424 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:25.546440 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 91556ns
I0425 00:46:26.547646 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:46:26.547675 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:26.547688 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 84072ns
I0425 00:46:27.548171 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:46:27.548199 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:27.548212 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 80240ns
I0425 00:46:28.548591 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:46:28.548626 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:28.548640 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 92958ns
I0425 00:46:29.549507 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:46:29.549538 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:29.549551 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 90868ns
I0425 00:46:30.550674 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:46:30.550709 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:30.550725 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 104196ns
I0425 00:46:31.551915 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:46:31.551944 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:31.551957 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 86873ns
I0425 00:46:32.552175 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:46:32.552207 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:32.552219 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 93161ns
I0425 00:46:33.521525 15622 slave.cpp:5659] Current disk usage 31.15%. Max allowed age: 4.119208818237095days
I0425 00:46:33.525698 15622 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:46:33.525809 15616 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:46:33.530988 15622 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:46:33.553261 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:46:33.553282 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:33.553293 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 70510ns
I0425 00:46:34.553782 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:46:34.553818 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:34.553831 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 103274ns
I0425 00:46:35.555004 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:46:35.555037 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:35.555048 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 85957ns
I0425 00:46:36.555646 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:46:36.555680 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:36.555697 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 90391ns
I0425 00:46:37.555997 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:46:37.556032 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:37.556046 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 92216ns
I0425 00:46:38.556341 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:46:38.556373 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:38.556385 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 86845ns
I0425 00:46:39.556829 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:46:39.556862 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:39.556875 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 86643ns
I0425 00:46:40.557451 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:46:40.557482 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:40.557495 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 88779ns
I0425 00:46:41.557888 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:46:41.557914 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:41.557927 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 82923ns
I0425 00:46:42.558518 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:46:42.558557 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:42.558570 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 93185ns
I0425 00:46:43.559815 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:46:43.559850 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:43.559865 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 91984ns
I0425 00:46:44.560151 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:46:44.560181 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:44.560194 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 81152ns
I0425 00:46:45.560745 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:46:45.560775 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:45.560787 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 80429ns
I0425 00:46:46.561501 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:46:46.561529 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:46.561542 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 81042ns
I0425 00:46:47.562113 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:46:47.562142 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:47.562160 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 86950ns
I0425 00:46:48.526957 15620 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:46:48.527081 15621 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:46:48.531098 15617 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:46:48.563354 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:46:48.563377 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:48.563390 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 71139ns
I0425 00:46:49.563758 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:46:49.563789 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:49.563802 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 87362ns
I0425 00:46:50.564988 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:46:50.565019 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:50.565032 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 83114ns
I0425 00:46:51.565395 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:46:51.565425 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:51.565438 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 86952ns
I0425 00:46:52.565680 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:46:52.565713 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:52.565726 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 87883ns
I0425 00:46:53.566310 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:46:53.566342 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:53.566356 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 94051ns
I0425 00:46:54.567569 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:46:54.567598 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:54.567611 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 81867ns
I0425 00:46:55.567988 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:46:55.568019 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:55.568032 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 88451ns
I0425 00:46:56.568395 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:46:56.568425 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:56.568439 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 86206ns
I0425 00:46:57.568833 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:46:57.568863 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:57.568876 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 82254ns
I0425 00:46:58.569802 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:46:58.569839 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:58.569859 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 100014ns
I0425 00:46:59.571130 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:46:59.571162 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:46:59.571174 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 87592ns
I0425 00:47:00.571758 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:47:00.571794 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:00.571810 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 95453ns
I0425 00:47:01.572432 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:47:01.572461 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:01.572474 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 82819ns
I0425 00:47:02.573107 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:47:02.573145 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:02.573161 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 94950ns
I0425 00:47:03.527701 15617 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:47:03.527819 15615 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:47:03.532047 15617 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:47:03.574319 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:47:03.574352 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:03.574367 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 94415ns
I0425 00:47:04.575137 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:47:04.575170 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:04.575182 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 86973ns
I0425 00:47:05.575932 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:47:05.575964 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:05.575978 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 93178ns
I0425 00:47:06.576580 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:47:06.576614 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:06.576632 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 92159ns
I0425 00:47:07.577303 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:47:07.577339 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:07.577358 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 92595ns
I0425 00:47:08.577924 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:47:08.577956 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:08.577970 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 89861ns
I0425 00:47:09.578143 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:47:09.578179 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:09.578194 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 95713ns
I0425 00:47:10.578397 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:47:10.578428 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:10.578440 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 85129ns
I0425 00:47:11.579663 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:47:11.579694 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:11.579706 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 82761ns
I0425 00:47:12.580169 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:47:12.580200 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:12.580212 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 82155ns
I0425 00:47:13.580476 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:47:13.580513 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:13.580529 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 93118ns
I0425 00:47:14.580658 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:47:14.580687 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:14.580699 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 79778ns
I0425 00:47:15.580891 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:47:15.580925 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:15.580938 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 91129ns
I0425 00:47:16.582113 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:47:16.582144 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:16.582156 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 88590ns
I0425 00:47:17.582554 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:47:17.582584 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:17.582597 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 83012ns
I0425 00:47:18.528460 15621 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:47:18.528566 15617 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:47:18.532757 15619 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:47:18.583433 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:47:18.583469 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:18.583484 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 99036ns
I0425 00:47:19.584705 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:47:19.584738 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:19.584750 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 86995ns
I0425 00:47:20.585147 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:47:20.585178 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:20.585191 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 87061ns
I0425 00:47:21.585364 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:47:21.585394 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:21.585407 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 86717ns
I0425 00:47:22.585764 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:47:22.585795 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:22.585808 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 87701ns
I0425 00:47:23.585993 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:47:23.586024 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:23.586035 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 82483ns
I0425 00:47:24.587151 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:47:24.587182 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:24.587193 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 81527ns
I0425 00:47:25.588277 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:47:25.588309 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:25.588320 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 83233ns
I0425 00:47:26.589573 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:47:26.589607 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:26.589618 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 91825ns
I0425 00:47:27.589846 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:47:27.589879 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:27.589890 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 84865ns
I0425 00:47:28.590461 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:47:28.590495 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:28.590513 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 101533ns
I0425 00:47:29.590685 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:47:29.590719 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:29.590734 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 90404ns
I0425 00:47:30.591927 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:47:30.591958 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:30.591970 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 86070ns
I0425 00:47:31.592475 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:47:31.592506 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:31.592519 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 83514ns
I0425 00:47:32.593726 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:47:32.593762 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:32.593775 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 93860ns
I0425 00:47:33.522635 15616 slave.cpp:5659] Current disk usage 31.15%. Max allowed age: 4.119172076230520days
I0425 00:47:33.529049 15616 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:47:33.529146 15621 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:47:33.533337 15622 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:47:33.594724 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:47:33.594758 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:33.594772 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 94493ns
I0425 00:47:34.596019 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:47:34.596050 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:34.596061 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 83570ns
I0425 00:47:35.596328 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:47:35.596361 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:35.596374 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 89292ns
I0425 00:47:36.596727 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:47:36.596757 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:36.596771 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 84490ns
I0425 00:47:37.597591 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:47:37.597621 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:37.597635 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 82565ns
I0425 00:47:38.598881 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:47:38.598912 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:38.598924 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 82755ns
I0425 00:47:39.599231 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:47:39.599267 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:39.599282 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 93751ns
I0425 00:47:40.600376 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:47:40.600409 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:40.600420 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 84053ns
I0425 00:47:41.600574 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:47:41.600610 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:41.600623 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 92940ns
I0425 00:47:42.601127 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:47:42.601160 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:42.601172 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 87614ns
I0425 00:47:43.602382 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:47:43.602412 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:43.602424 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 82698ns
I0425 00:47:44.602607 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:47:44.602638 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:44.602650 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 91765ns
I0425 00:47:45.602843 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:47:45.602874 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:45.602886 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 88915ns
I0425 00:47:46.604094 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:47:46.604130 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:46.604147 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 101335ns
I0425 00:47:47.605204 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:47:47.605237 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:47.605249 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 91454ns
I0425 00:47:48.530197 15622 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:47:48.530293 15622 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:47:48.534481 15620 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:47:48.605998 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:47:48.606019 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:48.606030 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 70161ns
I0425 00:47:49.606384 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:47:49.606413 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:49.606427 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 87067ns
I0425 00:47:50.607192 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:47:50.607228 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:50.607241 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 101858ns
I0425 00:47:51.608464 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:47:51.608496 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:51.608510 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 84193ns
I0425 00:47:52.609776 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:47:52.609807 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:52.609819 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 109936ns
I0425 00:47:53.610999 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:47:53.611032 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:53.611047 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 93226ns
I0425 00:47:54.611305 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:47:54.611341 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:54.611356 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 93560ns
I0425 00:47:55.611599 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:47:55.611634 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:55.611654 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 93040ns
I0425 00:47:56.611996 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:47:56.612028 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:56.612041 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 86227ns
I0425 00:47:57.612522 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:47:57.612555 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:57.612570 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 86794ns
I0425 00:47:58.613041 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:47:58.613075 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:58.613090 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 95568ns
I0425 00:47:59.613389 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:47:59.613425 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:47:59.613438 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 93901ns
I0425 00:48:00.614094 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:48:00.614152 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:00.614168 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 113276ns
I0425 00:48:01.614780 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:48:01.614812 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:01.614825 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 85776ns
I0425 00:48:02.615471 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:48:02.615504 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:02.615516 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 84478ns
I0425 00:48:03.531450 15620 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:48:03.531577 15621 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:48:03.534606 15617 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:48:03.616161 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:48:03.616186 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:03.616199 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 74357ns
I0425 00:48:04.616714 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:48:04.616745 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:04.616758 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 82748ns
I0425 00:48:05.616981 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:48:05.617013 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:05.617027 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 91107ns
I0425 00:48:06.618259 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:48:06.618290 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:06.618309 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 96538ns
I0425 00:48:07.619467 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:48:07.619498 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:07.619510 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 85200ns
I0425 00:48:08.619700 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:48:08.619735 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:08.619751 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 91163ns
I0425 00:48:09.620290 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:48:09.620319 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:09.620332 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 80861ns
I0425 00:48:10.620858 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:48:10.620889 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:10.620901 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 86552ns
I0425 00:48:11.621506 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:48:11.621541 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:11.621559 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 97807ns
I0425 00:48:12.622087 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:48:12.622117 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:12.622128 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 83409ns
I0425 00:48:13.622786 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:48:13.622819 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:13.622833 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 89393ns
I0425 00:48:14.623219 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:48:14.623250 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:14.623261 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 81768ns
I0425 00:48:15.623731 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:48:15.623762 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:15.623775 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 86752ns
I0425 00:48:16.624320 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:48:16.624349 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:16.624362 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 87519ns
I0425 00:48:17.624514 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:48:17.624547 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:17.624565 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 90529ns
I0425 00:48:18.532430 15622 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:48:18.532555 15616 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:48:18.535820 15619 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:48:18.625144 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:48:18.625180 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:18.625193 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 89511ns
I0425 00:48:19.626181 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:48:19.626220 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:19.626236 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 95203ns
I0425 00:48:20.626452 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:48:20.626487 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:20.626507 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 92619ns
I0425 00:48:21.626677 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:48:21.626714 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:21.626729 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 94469ns
I0425 00:48:22.627975 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:48:22.628010 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:22.628022 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 91592ns
I0425 00:48:23.629233 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:48:23.629271 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:23.629286 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 96887ns
E0425 00:48:24.451211 15618 slave.cpp:5041] Container '2e7b13d8-71be-4eca-a8d4-6a75c3c3bbdd' for executor 'cb4814db-edd4-45ce-892f-81ba1a630d7e' of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 failed to start: Collect failed: Failed to perform 'curl': curl: (18) transfer closed with 1853804 bytes remaining to read
I0425 00:48:24.451439 15615 containerizer.cpp:2077] Destroying container 2e7b13d8-71be-4eca-a8d4-6a75c3c3bbdd in PROVISIONING state
I0425 00:48:24.451512 15615 containerizer.cpp:2132] Waiting for the provisioner to complete provisioning before destroying container 2e7b13d8-71be-4eca-a8d4-6a75c3c3bbdd
I0425 00:48:24.451606 15615 provisioner.cpp:484] Ignoring destroy request for unknown container 2e7b13d8-71be-4eca-a8d4-6a75c3c3bbdd
I0425 00:48:24.451774 15615 slave.cpp:5154] Executor 'cb4814db-edd4-45ce-892f-81ba1a630d7e' of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 has terminated with unknown status
I0425 00:48:24.451830 15615 slave.cpp:4215] Handling status update TASK_FAILED (UUID: c5f7ff14-0d39-4e82-8857-54295fc01580) for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 from @0.0.0.0:0
W0425 00:48:24.452092 15615 containerizer.cpp:1892] Ignoring update for unknown container 2e7b13d8-71be-4eca-a8d4-6a75c3c3bbdd
I0425 00:48:24.452226 15620 status_update_manager.cpp:323] Received status update TASK_FAILED (UUID: c5f7ff14-0d39-4e82-8857-54295fc01580) for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:24.452250 15620 status_update_manager.cpp:500] Creating StatusUpdate stream for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:24.452442 15620 status_update_manager.cpp:377] Forwarding update TASK_FAILED (UUID: c5f7ff14-0d39-4e82-8857-54295fc01580) for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 to the agent
I0425 00:48:24.452519 15618 slave.cpp:4655] Forwarding the update TASK_FAILED (UUID: c5f7ff14-0d39-4e82-8857-54295fc01580) for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 to master@10.102.186.248:48431
I0425 00:48:24.452621 15618 slave.cpp:4549] Status update manager successfully handled status update TASK_FAILED (UUID: c5f7ff14-0d39-4e82-8857-54295fc01580) for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:24.452694 15621 master.cpp:6251] Status update TASK_FAILED (UUID: c5f7ff14-0d39-4e82-8857-54295fc01580) for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 from agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 at slave(879)@10.102.186.248:48431 (ip-10-102-186-248.ec2.internal)
I0425 00:48:24.452720 15621 master.cpp:6319] Forwarding status update TASK_FAILED (UUID: c5f7ff14-0d39-4e82-8857-54295fc01580) for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:24.452766 15621 master.cpp:8350] Updating the state of task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
I0425 00:48:24.452854 15619 sched.cpp:1041] Scheduler::statusUpdate took 31632ns
I0425 00:48:24.452978 15620 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):1; mem(*)(allocated: *):128 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*)(allocated: *):1; mem(*)(allocated: *):896; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000]) on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 from framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:24.453003 15621 master.cpp:5165] Processing ACKNOWLEDGE call c5f7ff14-0d39-4e82-8857-54295fc01580 for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431 on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0
I0425 00:48:24.453057 15621 master.cpp:8444] Removing task cb4814db-edd4-45ce-892f-81ba1a630d7e with resources cpus(*)(allocated: *):1; mem(*)(allocated: *):128 of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 at slave(879)@10.102.186.248:48431 (ip-10-102-186-248.ec2.internal)
/home/admin/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-debian-8/mesos/src/tests/containerizer/provisioner_docker_tests.cpp:537: Failure
Value of: statusRunning->state()
  Actual: TASK_FAILED
Expected: TASK_RUNNING
I0425 00:48:24.453230 15618 status_update_manager.cpp:395] Received status update acknowledgement (UUID: c5f7ff14-0d39-4e82-8857-54295fc01580) for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:24.453271 15618 status_update_manager.cpp:531] Cleaning up status update stream for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:24.453359 15618 slave.cpp:3504] Status update manager successfully handled status update acknowledgement (UUID: c5f7ff14-0d39-4e82-8857-54295fc01580) for task cb4814db-edd4-45ce-892f-81ba1a630d7e of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:24.453375 15618 slave.cpp:7270] Completing task cb4814db-edd4-45ce-892f-81ba1a630d7e
I0425 00:48:24.453382 15618 slave.cpp:5261] Cleaning up executor 'cb4814db-edd4-45ce-892f-81ba1a630d7e' of framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:24.453487 15621 gc.cpp:55] Scheduling '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_d0foT7/slaves/66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0/frameworks/66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000/executors/cb4814db-edd4-45ce-892f-81ba1a630d7e/runs/2e7b13d8-71be-4eca-a8d4-6a75c3c3bbdd' for gc 6.9999947517363days in the future
I0425 00:48:24.453500 15618 slave.cpp:5349] Cleaning up framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:24.453541 15621 gc.cpp:55] Scheduling '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_d0foT7/slaves/66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0/frameworks/66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000/executors/cb4814db-edd4-45ce-892f-81ba1a630d7e' for gc 6.99999475125037days in the future
I0425 00:48:24.453572 15622 status_update_manager.cpp:285] Closing status update streams for framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:24.453580 15621 gc.cpp:55] Scheduling '/tmp/ImageAlpine_ProvisionerDockerTest_ROOT_INTERNET_CURL_SimpleCommand_3_d0foT7/slaves/66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0/frameworks/66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000' for gc 6.99999475074074days in the future
I0425 00:48:24.629964 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:24.630002 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 213185ns
I0425 00:48:24.630094 15619 master.cpp:7087] Sending 1 offers to framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431
I0425 00:48:24.630249 15619 sched.cpp:933] Scheduler::resourceOffers took 14384ns
I0425 00:48:25.631129 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:48:25.631162 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:25.631175 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 92755ns
I0425 00:48:26.631368 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:48:26.631402 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:26.631414 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 83746ns
I0425 00:48:27.631629 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:48:27.631666 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:27.631681 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 96263ns
I0425 00:48:28.632977 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:48:28.633008 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:28.633021 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 93606ns
I0425 00:48:29.634191 15618 hierarchical.cpp:1862] No allocations performed
I0425 00:48:29.634225 15618 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:29.634238 15618 hierarchical.cpp:1446] Performed allocation for 1 agents in 91467ns
I0425 00:48:30.635473 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:48:30.635505 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:30.635517 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 86622ns
I0425 00:48:31.636826 15620 hierarchical.cpp:1862] No allocations performed
I0425 00:48:31.636859 15620 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:31.636874 15620 hierarchical.cpp:1446] Performed allocation for 1 agents in 112862ns
I0425 00:48:32.637212 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:48:32.637246 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:32.637259 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 116135ns
I0425 00:48:33.523192 15621 slave.cpp:5659] Current disk usage 31.15%. Max allowed age: 4.119248281873785days
I0425 00:48:33.533390 15621 slave.cpp:6145] Querying resource estimator for oversubscribable resources
I0425 00:48:33.533496 15620 slave.cpp:6159] Received oversubscribable resources {} from the resource estimator
I0425 00:48:33.536694 15618 slave.cpp:4745] Received ping from slave-observer(790)@10.102.186.248:48431
I0425 00:48:33.638227 15615 hierarchical.cpp:1862] No allocations performed
I0425 00:48:33.638258 15615 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:33.638273 15615 hierarchical.cpp:1446] Performed allocation for 1 agents in 85970ns
I0425 00:48:34.638473 15621 hierarchical.cpp:1862] No allocations performed
I0425 00:48:34.638505 15621 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:34.638525 15621 hierarchical.cpp:1446] Performed allocation for 1 agents in 89681ns
I0425 00:48:35.638979 15617 hierarchical.cpp:1862] No allocations performed
I0425 00:48:35.639010 15617 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:35.639022 15617 hierarchical.cpp:1446] Performed allocation for 1 agents in 85833ns
I0425 00:48:36.639559 15616 hierarchical.cpp:1862] No allocations performed
I0425 00:48:36.639597 15616 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:36.639612 15616 hierarchical.cpp:1446] Performed allocation for 1 agents in 96415ns
I0425 00:48:37.639792 15622 hierarchical.cpp:1862] No allocations performed
I0425 00:48:37.639824 15622 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:37.639837 15622 hierarchical.cpp:1446] Performed allocation for 1 agents in 90176ns
I0425 00:48:38.640101 15619 hierarchical.cpp:1862] No allocations performed
I0425 00:48:38.640138 15619 hierarchical.cpp:1952] No inverse offers to send out!
I0425 00:48:38.640153 15619 hierarchical.cpp:1446] Performed allocation for 1 agents in 93250ns
/home/admin/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-debian-8/mesos/src/tests/containerizer/provisioner_docker_tests.cpp:539: Failure
Failed to wait 15secs for statusFinished
I0425 00:48:39.453934 15620 master.cpp:1432] Framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431 disconnected
I0425 00:48:39.453970 15620 master.cpp:3162] Deactivating framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431
I0425 00:48:39.454038 15616 hierarchical.cpp:376] Deactivated framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
/home/admin/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-debian-8/mesos/src/tests/containerizer/provisioner_docker_tests.cpp:529: Failure
Actual function call count doesn't match EXPECT_CALL(sched, statusUpdate(&driver, _))...
         Expected: to be called twice
           Actual: called once - unsatisfied and active
I0425 00:48:39.454298 15620 master.cpp:3139] Disconnecting framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431
I0425 00:48:39.454329 15620 master.cpp:1447] Giving framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431 0ns to failover
I0425 00:48:39.454376 15622 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):1; mem(*)(allocated: *):128 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*)(allocated: *):1; mem(*)(allocated: *):896; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000]) on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 from framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:39.454555 15622 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):1; mem(*)(allocated: *):896; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 from framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:39.454638 15616 slave.cpp:790] Agent terminating
I0425 00:48:39.454738 15620 master.cpp:1315] Agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 at slave(879)@10.102.186.248:48431 (ip-10-102-186-248.ec2.internal) disconnected
I0425 00:48:39.454759 15620 master.cpp:3199] Disconnecting agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 at slave(879)@10.102.186.248:48431 (ip-10-102-186-248.ec2.internal)
I0425 00:48:39.454782 15620 master.cpp:3218] Deactivating agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 at slave(879)@10.102.186.248:48431 (ip-10-102-186-248.ec2.internal)
I0425 00:48:39.454896 15618 hierarchical.cpp:655] Agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0 deactivated
I0425 00:48:39.455556 15619 master.cpp:6928] Framework failover timeout, removing framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431
I0425 00:48:39.455574 15619 master.cpp:7782] Removing framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000 (default) at scheduler-2cc7e212-87b9-4ab9-926d-36693b788567@10.102.186.248:48431
I0425 00:48:39.455736 15616 hierarchical.cpp:323] Removed framework 66aaf7ed-8452-49aa-bb1b-467835ab99a5-0000
I0425 00:48:39.456972 15614 master.cpp:1157] Master terminating
I0425 00:48:39.457185 15622 hierarchical.cpp:560] Removed agent 66aaf7ed-8452-49aa-bb1b-467835ab99a5-S0
[  FAILED  ] ImageAlpine/ProvisionerDockerTest.ROOT_INTERNET_CURL_SimpleCommand/3, where GetParam() = "registry.cn-hangzhou.aliyuncs.com/acs-sample/alpine" (185956 ms)
[----------] 4 tests from ImageAlpine/ProvisionerDockerTest (188436 ms total)

Issue Links

• relates to: MESOS-9262 ProvisionerDockerBackendTest.ROOT_INTERNET_CURL_DTYPE_Whiteout is flaky