Benno Evers created MESOS-9261:
----------------------------------

             Summary: PersistentVolumeTest.ShrinkVolume is flaky
                 Key: MESOS-9261
                 URL: https://issues.apache.org/jira/browse/MESOS-9261
             Project: Mesos
          Issue Type: Bug
            Reporter: Benno Evers


Observed in an internal CI run:
{noformat}
../../src/tests/persistent_volume_tests.cpp:832
      Expected: TASK_FINISHED
To be equal to: taskFinished->state()
      Which is: TASK_FAILED
{noformat}

Full log:
{noformat}
[ RUN      ] DiskResource/PersistentVolumeTest.ShrinkVolume/0
I0925 23:58:13.544659 21740 cluster.cpp:173] Creating default 'local' authorizer
I0925 23:58:13.545785  9453 master.cpp:413] Master 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432 (ip-172-16-10-34.ec2.internal) started on 
172.16.10.34:35358
I0925 23:58:13.545801  9453 master.cpp:416] Flags at startup: --acls="" 
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" 
--allocation_interval="1secs" --allocator="hierarchical" 
--authenticate_agents="true" --authenticate_frameworks="true" 
--authenticate_http_frameworks="true" --authenticate_http_readonly="true" 
--authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" 
--authenticators="crammd5" --authorizers="local" 
--credentials="/tmp/tf2SmN/credentials" --filter_gpu_resources="true" 
--framework_sorter="drf" --help="false" --hostname_lookup="true" 
--http_authenticators="basic" --http_framework_authenticators="basic" 
--initialize_driver_logging="true" --log_auto_initialize="true" 
--logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" 
--max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" 
--max_unreachable_tasks_per_framework="1000" --memory_profiling="false" 
--min_allocatable_resources="cpus:0.01|mem:32" --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" 
--require_agent_domain="false" --role_sorter="drf" --root_submissions="true" 
--version="false" --webui_dir="/usr/local/share/mesos/webui" 
--work_dir="/tmp/tf2SmN/master" --zk_session_timeout="10secs"
I0925 23:58:13.545931  9453 master.cpp:465] Master only allowing authenticated 
frameworks to register
I0925 23:58:13.545939  9453 master.cpp:471] Master only allowing authenticated 
agents to register
I0925 23:58:13.545945  9453 master.cpp:477] Master only allowing authenticated 
HTTP frameworks to register
I0925 23:58:13.545951  9453 credentials.hpp:37] Loading credentials for 
authentication from '/tmp/tf2SmN/credentials'
I0925 23:58:13.546041  9453 master.cpp:521] Using default 'crammd5' 
authenticator
I0925 23:58:13.546085  9453 http.cpp:1037] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-readonly'
I0925 23:58:13.546119  9453 http.cpp:1037] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-readwrite'
I0925 23:58:13.546149  9453 http.cpp:1037] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-scheduler'
I0925 23:58:13.546174  9453 master.cpp:602] Authorization enabled
I0925 23:58:13.546268  9457 hierarchical.cpp:182] Initialized hierarchical 
allocator process
I0925 23:58:13.546294  9457 whitelist_watcher.cpp:77] No whitelist given
I0925 23:58:13.546878  9458 master.cpp:2083] Elected as the leading master!
I0925 23:58:13.546891  9458 master.cpp:1638] Recovering from registrar
I0925 23:58:13.546941  9453 registrar.cpp:339] Recovering registrar
I0925 23:58:13.547065  9453 registrar.cpp:383] Successfully fetched the 
registry (0B) in 0ns
I0925 23:58:13.547092  9453 registrar.cpp:487] Applied 1 operations in 7135ns; 
attempting to update the registry
I0925 23:58:13.547225  9453 registrar.cpp:544] Successfully updated the 
registry in 0ns
I0925 23:58:13.547250  9453 registrar.cpp:416] Successfully recovered registrar
I0925 23:58:13.547319  9453 master.cpp:1752] Recovered 0 agents from the 
registry (172B); allowing 10mins for agents to reregister
I0925 23:58:13.547336  9457 hierarchical.cpp:220] Skipping recovery of 
hierarchical allocator: nothing to recover
W0925 23:58:13.549054 21740 process.cpp:2810] Attempted to spawn already 
running process files@172.16.10.34:35358
I0925 23:58:13.549363 21740 containerizer.cpp:305] Using isolation { 
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I0925 23:58:13.551201 21740 linux_launcher.cpp:144] Using /cgroup/freezer as 
the freezer hierarchy for the Linux launcher
I0925 23:58:13.551496 21740 provisioner.cpp:298] Using default backend 'copy'
I0925 23:58:13.551942 21740 cluster.cpp:485] Creating default 'local' authorizer
I0925 23:58:13.552358  9456 slave.cpp:267] Mesos agent started on 
(1192)@172.16.10.34:35358
W0925 23:58:13.552541 21740 process.cpp:2810] Attempted to spawn already 
running process version@172.16.10.34:35358
I0925 23:58:13.552376  9456 slave.cpp:268] Flags at startup: --acls="" 
--appc_simple_discovery_uri_prefix="http://"; 
--appc_store_dir="/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_3MZxfo/store/appc"
 --authenticate_http_executors="true" --authenticate_http_readonly="true" 
--authenticate_http_readwrite="true" --authenticatee="crammd5" 
--authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" 
--authentication_timeout_min="5secs" --authorizer="local" 
--cgroups_cpu_enable_pids_and_tids_count="false" 
--cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false" 
--cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" 
--cgroups_root="mesos" --container_disk_watch_interval="15secs" 
--containerizers="mesos" 
--credential="/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_3MZxfo/credential"
 --default_role="*" --disallow_sharing_agent_pid_namespace="false" 
--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/DiskResource_PersistentVolumeTest_ShrinkVolume_0_3MZxfo/store/docker"
 --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" 
--enforce_container_disk_quota="false" --executor_registration_timeout="1mins" 
--executor_reregistration_timeout="2secs" 
--executor_shutdown_grace_period="5secs" 
--fetcher_cache_dir="/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_3MZxfo/fetch"
 --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" 
--frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" 
--gc_non_executor_container_sandboxes="false" --help="false" 
--hostname_lookup="true" --http_command_executor="false" 
--http_credentials="/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_3MZxfo/http_credentials"
 --http_heartbeat_interval="30secs" --initialize_driver_logging="true" 
--isolation="posix/cpu,posix/mem" 
--jwt_secret_key="/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_3MZxfo/jwt_secret_key"
 --launcher="linux" 
--launcher_dir="/home/centos/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-centos-6/mesos/build/src"
 --logbufsecs="0" --logging_level="INFO" 
--max_completed_executors_per_framework="150" --memory_profiling="false" 
--network_cni_metrics="true" --oversubscribed_resources_interval="15secs" 
--perf_duration="10secs" --perf_interval="1mins" --port="5051" 
--qos_correction_interval_min="0ns" --quiet="false" 
--reconfiguration_policy="equal" --recover="reconnect" 
--recovery_timeout="15mins" --registration_backoff_factor="10ms" 
--resources="[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":4096.0},"type":"SCALAR"}]"
 --revocable_cpu_low_priority="true" 
--runtime_dir="/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_3MZxfo" 
--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/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw" 
--zk_session_timeout="10secs"
I0925 23:58:13.552578  9456 credentials.hpp:86] Loading credential for 
authentication from 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_3MZxfo/credential'
I0925 23:58:13.552805  9456 slave.cpp:300] Agent using credential for: 
test-principal
I0925 23:58:13.552815  9456 credentials.hpp:37] Loading credentials for 
authentication from 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_3MZxfo/http_credentials'
I0925 23:58:13.552872  9456 http.cpp:1037] Creating default 'basic' HTTP 
authenticator for realm 'mesos-agent-executor'
I0925 23:58:13.552935  9456 http.cpp:1058] Creating default 'jwt' HTTP 
authenticator for realm 'mesos-agent-executor'
I0925 23:58:13.552996  9456 http.cpp:1037] Creating default 'basic' HTTP 
authenticator for realm 'mesos-agent-readonly'
I0925 23:58:13.553050  9456 http.cpp:1058] Creating default 'jwt' HTTP 
authenticator for realm 'mesos-agent-readonly'
I0925 23:58:13.553091  9456 http.cpp:1037] Creating default 'basic' HTTP 
authenticator for realm 'mesos-agent-readwrite'
I0925 23:58:13.553114  9456 http.cpp:1058] Creating default 'jwt' HTTP 
authenticator for realm 'mesos-agent-readwrite'
I0925 23:58:13.553264  9456 disk_profile_adaptor.cpp:80] Creating default disk 
profile adaptor module
I0925 23:58:13.553721 21740 sched.cpp:232] Version: 1.8.0
I0925 23:58:13.553863  9453 hierarchical.cpp:1564] Performed allocation for 0 
agents in 6298ns
I0925 23:58:13.553874  9457 sched.cpp:336] New master detected at 
master@172.16.10.34:35358
I0925 23:58:13.553900  9457 sched.cpp:401] Authenticating with master 
master@172.16.10.34:35358
I0925 23:58:13.553910  9457 sched.cpp:408] Using default CRAM-MD5 authenticatee
I0925 23:58:13.554004  9457 authenticatee.cpp:121] Creating new client SASL 
connection
I0925 23:58:13.554080  9453 master.cpp:9653] Authenticating 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.554126  9453 authenticator.cpp:414] Starting authentication 
session for crammd5-authenticatee(2043)@172.16.10.34:35358
I0925 23:58:13.554116  9456 slave.cpp:615] Agent resources: 
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"name":"disk","reservations":[{"role":"default-role","type":"STATIC"}],"scalar":{"value":4096.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0925 23:58:13.554173  9456 slave.cpp:623] Agent attributes: [  ]
I0925 23:58:13.554181  9456 slave.cpp:632] Agent hostname: 
ip-172-16-10-34.ec2.internal
I0925 23:58:13.554188  9453 authenticator.cpp:98] Creating new server SASL 
connection
I0925 23:58:13.554240  9453 task_status_update_manager.cpp:181] Pausing sending 
task status updates
I0925 23:58:13.554265  9453 authenticatee.cpp:213] Received SASL authentication 
mechanisms: CRAM-MD5
I0925 23:58:13.554277  9453 authenticatee.cpp:239] Attempting to authenticate 
with mechanism 'CRAM-MD5'
I0925 23:58:13.554330  9457 authenticator.cpp:204] Received SASL authentication 
start
I0925 23:58:13.554373  9457 authenticator.cpp:326] Authentication requires more 
steps
I0925 23:58:13.554401  9457 authenticatee.cpp:259] Received SASL authentication 
step
I0925 23:58:13.554425  9456 state.cpp:66] Recovering state from 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/meta'
I0925 23:58:13.554438  9457 authenticator.cpp:232] Received SASL authentication 
step
I0925 23:58:13.554452  9457 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'ip-172-16-10-34' server FQDN: 'ip-172-16-10-34' 
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0925 23:58:13.554461  9457 auxprop.cpp:181] Looking up auxiliary property 
'*userPassword'
I0925 23:58:13.554471  9457 auxprop.cpp:181] Looking up auxiliary property 
'*cmusaslsecretCRAM-MD5'
I0925 23:58:13.554473  9456 slave.cpp:6909] Finished recovering checkpointed 
state from '/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/meta', 
beginning agent recovery
I0925 23:58:13.554481  9457 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'ip-172-16-10-34' server FQDN: 'ip-172-16-10-34' 
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0925 23:58:13.554486  9457 auxprop.cpp:131] Skipping auxiliary property 
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0925 23:58:13.554493  9457 auxprop.cpp:131] Skipping auxiliary property 
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0925 23:58:13.554519  9456 task_status_update_manager.cpp:207] Recovering task 
status update manager
I0925 23:58:13.554615  9454 containerizer.cpp:727] Recovering Mesos containers
I0925 23:58:13.554617  9457 authenticator.cpp:318] Authentication success
I0925 23:58:13.554666  9454 linux_launcher.cpp:286] Recovering Linux launcher
I0925 23:58:13.554697  9457 authenticatee.cpp:299] Authentication success
I0925 23:58:13.554733  9457 master.cpp:9685] Successfully authenticated 
principal 'test-principal' at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.554760  9457 authenticator.cpp:432] Authentication session 
cleanup for crammd5-authenticatee(2043)@172.16.10.34:35358
I0925 23:58:13.554774  9459 containerizer.cpp:1053] Recovering isolators
I0925 23:58:13.554941  9452 containerizer.cpp:1092] Recovering provisioner
I0925 23:58:13.555047  9452 provisioner.cpp:494] Provisioner recovery complete
I0925 23:58:13.555167  9457 composing.cpp:339] Finished recovering all 
containerizers
I0925 23:58:13.555178  9454 sched.cpp:513] Successfully authenticated with 
master master@172.16.10.34:35358
I0925 23:58:13.555189  9454 sched.cpp:817] Sending SUBSCRIBE call to 
master@172.16.10.34:35358
I0925 23:58:13.555228  9454 sched.cpp:850] Will retry registration in 
799.699413ms if necessary
I0925 23:58:13.555292  9453 master.cpp:2854] Received SUBSCRIBE call for 
framework 'default' at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.555315  9453 master.cpp:2155] Authorizing framework principal 
'test-principal' to receive offers for roles '{ default-role/foo }'
I0925 23:58:13.555320  9456 slave.cpp:7138] Recovering executors
I0925 23:58:13.555338  9456 slave.cpp:7291] Finished recovery
I0925 23:58:13.555407  9453 master.cpp:2935] Subscribing framework default with 
checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0925 23:58:13.555876  9453 master.cpp:9883] Adding framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358 with roles {  
} suppressed
I0925 23:58:13.556040  9453 sched.cpp:744] Framework registered with 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.556064  9453 sched.cpp:758] Scheduler::registered took 9722ns
I0925 23:58:13.556107  9457 task_status_update_manager.cpp:181] Pausing sending 
task status updates
I0925 23:58:13.556136  9455 slave.cpp:1254] New master detected at 
master@172.16.10.34:35358
I0925 23:58:13.556172  9455 slave.cpp:1319] Detecting new master
I0925 23:58:13.556066  9458 hierarchical.cpp:306] Added framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.556231  9458 hierarchical.cpp:1564] Performed allocation for 0 
agents in 5896ns
I0925 23:58:13.556267  9455 slave.cpp:1346] Authenticating with master 
master@172.16.10.34:35358
I0925 23:58:13.556283  9455 slave.cpp:1355] Using default CRAM-MD5 authenticatee
I0925 23:58:13.556344  9455 authenticatee.cpp:121] Creating new client SASL 
connection
I0925 23:58:13.556397  9455 master.cpp:9653] Authenticating 
slave(1192)@172.16.10.34:35358
I0925 23:58:13.556428  9455 authenticator.cpp:414] Starting authentication 
session for crammd5-authenticatee(2044)@172.16.10.34:35358
I0925 23:58:13.556490  9456 authenticator.cpp:98] Creating new server SASL 
connection
I0925 23:58:13.556572  9456 authenticatee.cpp:213] Received SASL authentication 
mechanisms: CRAM-MD5
I0925 23:58:13.556582  9456 authenticatee.cpp:239] Attempting to authenticate 
with mechanism 'CRAM-MD5'
I0925 23:58:13.556612  9456 authenticator.cpp:204] Received SASL authentication 
start
I0925 23:58:13.556640  9456 authenticator.cpp:326] Authentication requires more 
steps
I0925 23:58:13.556671  9456 authenticatee.cpp:259] Received SASL authentication 
step
I0925 23:58:13.556707  9456 authenticator.cpp:232] Received SASL authentication 
step
I0925 23:58:13.556723  9456 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'ip-172-16-10-34' server FQDN: 'ip-172-16-10-34' 
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0925 23:58:13.556728  9456 auxprop.cpp:181] Looking up auxiliary property 
'*userPassword'
I0925 23:58:13.556735  9456 auxprop.cpp:181] Looking up auxiliary property 
'*cmusaslsecretCRAM-MD5'
I0925 23:58:13.556741  9456 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'ip-172-16-10-34' server FQDN: 'ip-172-16-10-34' 
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0925 23:58:13.556746  9456 auxprop.cpp:131] Skipping auxiliary property 
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0925 23:58:13.556751  9456 auxprop.cpp:131] Skipping auxiliary property 
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0925 23:58:13.556759  9456 authenticator.cpp:318] Authentication success
I0925 23:58:13.556802  9452 authenticatee.cpp:299] Authentication success
I0925 23:58:13.556819  9454 master.cpp:9685] Successfully authenticated 
principal 'test-principal' at slave(1192)@172.16.10.34:35358
I0925 23:58:13.556860  9452 slave.cpp:1446] Successfully authenticated with 
master master@172.16.10.34:35358
I0925 23:58:13.556947  9452 slave.cpp:1877] Will retry registration in 
8.393489ms if necessary
I0925 23:58:13.556999  9459 master.cpp:6605] Received register agent message 
from slave(1192)@172.16.10.34:35358 (ip-172-16-10-34.ec2.internal)
I0925 23:58:13.557078  9459 master.cpp:3964] Authorizing agent providing 
resources 'cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):4096; 
ports:[31000-32000]' with principal 'test-principal'
I0925 23:58:13.557139  9459 master.cpp:3609] Authorizing principal 
'test-principal' to reserve resources 'cpus:2; mem:2048; disk(reservations: 
[(STATIC,default-role)]):4096; ports:[31000-32000]'
I0925 23:58:13.557004  9456 authenticator.cpp:432] Authentication session 
cleanup for crammd5-authenticatee(2044)@172.16.10.34:35358
I0925 23:58:13.557359  9459 master.cpp:6672] Authorized registration of agent 
at slave(1192)@172.16.10.34:35358 (ip-172-16-10-34.ec2.internal)
I0925 23:58:13.557392  9459 master.cpp:6787] Registering agent at 
slave(1192)@172.16.10.34:35358 (ip-172-16-10-34.ec2.internal) with id 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0
I0925 23:58:13.557540  9459 registrar.cpp:487] Applied 1 operations in 69099ns; 
attempting to update the registry
I0925 23:58:13.561594  9459 registrar.cpp:544] Successfully updated the 
registry in 0ns
I0925 23:58:13.561647  9459 master.cpp:6835] Admitted agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.561763  9459 master.cpp:6880] Registered agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal) with cpus:2; mem:2048; disk(reservations: 
[(STATIC,default-role)]):4096; ports:[31000-32000]
I0925 23:58:13.561806  9455 hierarchical.cpp:601] Added agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 (ip-172-16-10-34.ec2.internal) with 
cpus:2; mem:2048; disk(reservations: [(STATIC,default-role)]):4096; 
ports:[31000-32000] (allocated: {})
I0925 23:58:13.561846  9459 slave.cpp:1479] Registered with master 
master@172.16.10.34:35358; given agent ID 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0
I0925 23:58:13.561977  9455 hierarchical.cpp:1564] Performed allocation for 1 
agents in 124089ns
I0925 23:58:13.562011  9455 task_status_update_manager.cpp:188] Resuming 
sending task status updates
I0925 23:58:13.562036  9459 slave.cpp:1499] Checkpointing SlaveInfo to 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/meta/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/slave.info'
I0925 23:58:13.562115  9455 master.cpp:9468] Sending offers [ 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-O0 ] to framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.562264  9455 sched.cpp:914] Scheduler::resourceOffers took 
28849ns
I0925 23:58:13.562346  9459 slave.cpp:1548] Forwarding agent update 
{"operations":{},"resource_version_uuid":{"value":"LqvSyOw5S8mFKAacYcg5TA=="},"slave_id":{"value":"9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0"},"update_oversubscribed_resources":false}
I0925 23:58:13.562557  9459 master.cpp:7939] Ignoring update on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal) as it reports no changes
I0925 23:58:13.572201  9452 master.cpp:11462] Removing offer 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-O0
I0925 23:58:13.572299  9452 master.cpp:4467] Processing ACCEPT call for offers: 
[ 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-O0 ] on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal) for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.572345  9452 master.cpp:3609] Authorizing principal 
'test-principal' to reserve resources 'disk(allocated: 
default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)]):4096'
I0925 23:58:13.572407  9452 master.cpp:3744] Authorizing principal 
'test-principal' to create volumes 
'[{"allocation_info":{"role":"default-role/foo"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"},{"principal":"test-principal","role":"default-role/foo","type":"DYNAMIC"}],"scalar":{"value":4096.0},"type":"SCALAR"}]'
I0925 23:58:13.572654  9454 master.cpp:4835] Applying RESERVE operation for 
resources 
[{"allocation_info":{"role":"default-role/foo"},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"},{"principal":"test-principal","role":"default-role/foo","type":"DYNAMIC"}],"scalar":{"value":4096.0},"type":"SCALAR"}]
 from framework 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358 to agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.572773  9454 master.cpp:11353] Sending operation '' (uuid: 
09843770-47e2-4acd-ac83-b5e586d8ba24) to agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.572871  9454 master.cpp:4978] Applying CREATE operation for 
volumes 
[{"allocation_info":{"role":"default-role/foo"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"},{"principal":"test-principal","role":"default-role/foo","type":"DYNAMIC"}],"scalar":{"value":4096.0},"type":"SCALAR"}]
 from framework 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358 to agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.572979  9454 master.cpp:11353] Sending operation '' (uuid: 
eb309008-2ff8-4d34-9336-533d7eeee7dd) to agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.573339  9454 slave.cpp:4202] Updated checkpointed resources from 
{} to disk(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)]):4096
I0925 23:58:13.573374  9454 slave.cpp:7990] Updating the state of operation 
with no ID (uuid: 09843770-47e2-4acd-ac83-b5e586d8ba24) for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (latest state: OPERATION_FINISHED, 
status update state: OPERATION_FINISHED)
I0925 23:58:13.573884  9454 slave.cpp:4202] Updated checkpointed resources from 
disk(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)]):4096 to 
disk(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:4096
I0925 23:58:13.573922  9454 slave.cpp:7990] Updating the state of operation 
with no ID (uuid: eb309008-2ff8-4d34-9336-533d7eeee7dd) for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (latest state: OPERATION_FINISHED, 
status update state: OPERATION_FINISHED)
I0925 23:58:13.574184  9454 hierarchical.cpp:967] Updated allocation of 
framework 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 from cpus(allocated: 
default-role/foo):2; mem(allocated: default-role/foo):2048; disk(allocated: 
default-role/foo)(reservations: [(STATIC,default-role)]):4096; ports(allocated: 
default-role/foo):[31000-32000] to cpus(allocated: default-role/foo):2; 
mem(allocated: default-role/foo):2048; ports(allocated: 
default-role/foo):[31000-32000]; disk(allocated: 
default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:4096
I0925 23:58:13.574329  9454 hierarchical.cpp:1236] Recovered cpus(allocated: 
default-role/foo):2; mem(allocated: default-role/foo):2048; ports(allocated: 
default-role/foo):[31000-32000]; disk(allocated: 
default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:4096
 (total: cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:4096,
 allocated: {}) on agent 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 from framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.574383  9454 master.cpp:11103] Updating the state of operation 
'' (uuid: 09843770-47e2-4acd-ac83-b5e586d8ba24) for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (latest state: OPERATION_PENDING, 
status update state: OPERATION_FINISHED)
I0925 23:58:13.574422  9454 master.cpp:11103] Updating the state of operation 
'' (uuid: eb309008-2ff8-4d34-9336-533d7eeee7dd) for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (latest state: OPERATION_PENDING, 
status update state: OPERATION_FINISHED)
I0925 23:58:13.574723  9452 hierarchical.cpp:1564] Performed allocation for 1 
agents in 94573ns
I0925 23:58:13.574832  9459 master.cpp:9468] Sending offers [ 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-O1 ] to framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.574985  9459 sched.cpp:914] Scheduler::resourceOffers took 
31220ns
I0925 23:58:13.575347  9455 master.cpp:11462] Removing offer 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-O1
I0925 23:58:13.575428  9455 master.cpp:4467] Processing ACCEPT call for offers: 
[ 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-O1 ] on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal) for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.575454  9455 master.cpp:3847] Authorizing principal 
'test-principal' to resize volume 'disk(allocated: 
default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:4096'
I0925 23:58:13.575678  9452 master.cpp:5232] Processing SHRINK_VOLUME operation 
for volume disk(allocated: default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:4096
 subtracting scalar value 512 from framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358 on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.575778  9452 master.cpp:11353] Sending operation '' (uuid: 
b9434fd8-d9d5-4742-92a8-92ad1089f51b) to agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.576210  9452 slave.cpp:4202] Updated checkpointed resources from 
disk(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:4096
 to disk(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:3584;
 disk(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)]):512
I0925 23:58:13.576253  9452 slave.cpp:7990] Updating the state of operation 
with no ID (uuid: b9434fd8-d9d5-4742-92a8-92ad1089f51b) for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (latest state: OPERATION_FINISHED, 
status update state: OPERATION_FINISHED)
I0925 23:58:13.576571  9453 master.cpp:11103] Updating the state of operation 
'' (uuid: b9434fd8-d9d5-4742-92a8-92ad1089f51b) for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (latest state: OPERATION_PENDING, 
status update state: OPERATION_FINISHED)
I0925 23:58:13.576660  9452 hierarchical.cpp:967] Updated allocation of 
framework 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 from cpus(allocated: 
default-role/foo):2; mem(allocated: default-role/foo):2048; ports(allocated: 
default-role/foo):[31000-32000]; disk(allocated: 
default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:4096
 to cpus(allocated: default-role/foo):2; mem(allocated: default-role/foo):2048; 
ports(allocated: default-role/foo):[31000-32000]; disk(allocated: 
default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:3584;
 disk(allocated: default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)]):512
I0925 23:58:13.576820  9452 hierarchical.cpp:1236] Recovered cpus(allocated: 
default-role/foo):2; mem(allocated: default-role/foo):2048; ports(allocated: 
default-role/foo):[31000-32000]; disk(allocated: 
default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:3584;
 disk(allocated: default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)]):512 (total: 
cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:3584;
 disk(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)]):512, 
allocated: {}) on agent 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 from framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.577255  9457 master.cpp:9468] Sending offers [ 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-O2 ] to framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.577411  9457 sched.cpp:914] Scheduler::resourceOffers took 
35004ns
I0925 23:58:13.577450  9458 hierarchical.cpp:1564] Performed allocation for 1 
agents in 440508ns
I0925 23:58:13.577900  9452 master.cpp:11462] Removing offer 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-O2
I0925 23:58:13.578003  9452 master.cpp:4467] Processing ACCEPT call for offers: 
[ 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-O2 ] on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal) for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.578042  9452 master.cpp:3541] Authorizing framework principal 
'test-principal' to launch task 38b0a542-e749-4cc3-810b-252b5dc4be34
I0925 23:58:13.578745  9457 master.cpp:12209] Adding task 
38b0a542-e749-4cc3-810b-252b5dc4be34 with resources cpus(allocated: 
default-role/foo):2; mem(allocated: default-role/foo):2048; ports(allocated: 
default-role/foo):[31000-32000]; disk(allocated: 
default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:3584;
 disk(allocated: default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)]):512 on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.578861  9457 master.cpp:5439] Launching task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358 with 
resources 
[{"allocation_info":{"role":"default-role/foo"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role/foo"},"name":"mem","scalar":{"value":2048.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role/foo"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"},{"allocation_info":{"role":"default-role/foo"},"disk":{"persistence":{"id":"id1","principal":"test-principal"},"volume":{"container_path":"path1","mode":"RW"}},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"},{"principal":"test-principal","role":"default-role/foo","type":"DYNAMIC"}],"scalar":{"value":3584.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role/foo"},"name":"disk","reservations":[{"role":"default-role","type":"STATIC"},{"principal":"test-principal","role":"default-role/foo","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]
 on agent 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at 
slave(1192)@172.16.10.34:35358 (ip-172-16-10-34.ec2.internal) on  new executor
I0925 23:58:13.579246  9457 slave.cpp:2014] Got assigned task 
'38b0a542-e749-4cc3-810b-252b5dc4be34' for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.579565  9457 slave.cpp:2388] Authorizing task 
'38b0a542-e749-4cc3-810b-252b5dc4be34' for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.579591  9457 slave.cpp:8466] Authorizing framework principal 
'test-principal' to launch task 38b0a542-e749-4cc3-810b-252b5dc4be34
I0925 23:58:13.580206  9457 slave.cpp:2831] Launching task 
'38b0a542-e749-4cc3-810b-252b5dc4be34' for framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.580255  9457 paths.cpp:752] Creating sandbox 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2'
 for user 'root'
I0925 23:58:13.580718  9457 slave.cpp:8994] Launching executor 
'38b0a542-e749-4cc3-810b-252b5dc4be34' of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 with resources 
[{"allocation_info":{"role":"default-role/foo"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"default-role/foo"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}]
 in work directory 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2'
I0925 23:58:13.580981  9457 slave.cpp:3028] Queued task 
'38b0a542-e749-4cc3-810b-252b5dc4be34' for executor 
'38b0a542-e749-4cc3-810b-252b5dc4be34' of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.581019  9457 slave.cpp:988] Successfully attached 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2'
 to virtual path 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/latest'
I0925 23:58:13.581032  9457 slave.cpp:988] Successfully attached 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2'
 to virtual path 
'/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/latest'
I0925 23:58:13.581161  9457 slave.cpp:3509] Launching container 
e3b3402e-f906-4990-a033-f1a5fde7c5f2 for executor 
'38b0a542-e749-4cc3-810b-252b5dc4be34' of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.581321  9457 slave.cpp:988] Successfully attached 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2'
 to virtual path 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2'
I0925 23:58:13.581492  9454 containerizer.cpp:1280] Starting container 
e3b3402e-f906-4990-a033-f1a5fde7c5f2
I0925 23:58:13.581987  9454 containerizer.cpp:1446] Checkpointed 
ContainerConfig at 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_3MZxfo/containers/e3b3402e-f906-4990-a033-f1a5fde7c5f2/config'
I0925 23:58:13.582001  9454 containerizer.cpp:3118] Transitioning the state of 
container e3b3402e-f906-4990-a033-f1a5fde7c5f2 from PROVISIONING to PREPARING
I0925 23:58:13.582180  9459 posix.cpp:213] Changing the ownership of the 
persistent volume at 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/volumes/roles/default-role
 foo/id1' with uid 0 and gid 0
I0925 23:58:13.582222  9459 posix.cpp:259] Adding symlink from 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/volumes/roles/default-role
 foo/id1' to 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2/path1'
 for persistent volume disk(allocated: default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:3584
 of container e3b3402e-f906-4990-a033-f1a5fde7c5f2
I0925 23:58:13.583061  9453 containerizer.cpp:1939] Launching 
'mesos-containerizer' with flags '--help="false" 
--launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/home/centos/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-centos-6/mesos/build/src"],"shell":false,"value":"/home/centos/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-centos-6/mesos/build/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.34:35358"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiJlM2IzNDAyZS1mOTA2LTQ5OTAtYTAzMy1mMWE1ZmRlN2M1ZjIiLCJlaWQiOiIzOGIwYTU0Mi1lNzQ5LTRjYzMtODEwYi0yNTJiNWRjNGJlMzQiLCJmaWQiOiI5ZjhkNGI1Ni1kZTRjLTRkZjYtODZkOS05MmE2YzNjOWU0MzItMDAwMCJ9.w1HqBsiTVW-GCmdG93cpy2F-sB3RtAn8Cbb8Zvr5OAc"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"38b0a542-e749-4cc3-810b-252b5dc4be34"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(1192)@172.16.10.34:35358"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2"}]},"task_environment":{},"user":"root","working_directory":"/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2"}"
 --pipe_read="23" --pipe_write="60" 
--runtime_directory="/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_3MZxfo/containers/e3b3402e-f906-4990-a033-f1a5fde7c5f2"
 --unshare_namespace_mnt="false"'
I0925 23:58:13.583266  9459 linux_launcher.cpp:492] Launching container 
e3b3402e-f906-4990-a033-f1a5fde7c5f2 and cloning with namespaces 
I0925 23:58:13.595609  9453 containerizer.cpp:3118] Transitioning the state of 
container e3b3402e-f906-4990-a033-f1a5fde7c5f2 from PREPARING to ISOLATING
I0925 23:58:13.596472  9456 containerizer.cpp:3118] Transitioning the state of 
container e3b3402e-f906-4990-a033-f1a5fde7c5f2 from ISOLATING to FETCHING
I0925 23:58:13.596541  9456 fetcher.cpp:369] Starting to fetch URIs for 
container: e3b3402e-f906-4990-a033-f1a5fde7c5f2, directory: 
/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2
I0925 23:58:13.597002  9456 containerizer.cpp:3118] Transitioning the state of 
container e3b3402e-f906-4990-a033-f1a5fde7c5f2 from FETCHING to RUNNING
I0925 23:58:13.696091  1144 exec.cpp:162] Version: 1.8.0
I0925 23:58:13.697645  9452 slave.cpp:4803] Got registration for executor 
'38b0a542-e749-4cc3-810b-252b5dc4be34' of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 from executor(1)@172.16.10.34:37056
I0925 23:58:13.698565  1166 exec.cpp:236] Executor registered on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0
I0925 23:58:13.698691  9458 slave.cpp:3241] Sending queued task 
'38b0a542-e749-4cc3-810b-252b5dc4be34' to executor 
'38b0a542-e749-4cc3-810b-252b5dc4be34' of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 at executor(1)@172.16.10.34:37056
I0925 23:58:13.699892  1161 executor.cpp:182] Received SUBSCRIBED event
I0925 23:58:13.700116  1161 executor.cpp:186] Subscribed executor on 
ip-172-16-10-34.ec2.internal
I0925 23:58:13.700424  1165 executor.cpp:182] Received LAUNCH event
I0925 23:58:13.701351  1165 executor.cpp:679] Starting task 
38b0a542-e749-4cc3-810b-252b5dc4be34
I0925 23:58:13.702916  9454 slave.cpp:5269] Handling status update 
TASK_STARTING (Status UUID: f4552cff-4566-42dc-94fc-a99e16e03503) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 from executor(1)@172.16.10.34:37056
I0925 23:58:13.703491  9457 task_status_update_manager.cpp:328] Received task 
status update TASK_STARTING (Status UUID: f4552cff-4566-42dc-94fc-a99e16e03503) 
for task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.703536  9457 task_status_update_manager.cpp:507] Creating 
StatusUpdate stream for task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.703662  9457 task_status_update_manager.cpp:383] Forwarding task 
status update TASK_STARTING (Status UUID: f4552cff-4566-42dc-94fc-a99e16e03503) 
for task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 to the agent
I0925 23:58:13.703737  9455 slave.cpp:5761] Forwarding the update TASK_STARTING 
(Status UUID: f4552cff-4566-42dc-94fc-a99e16e03503) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 to master@172.16.10.34:35358
I0925 23:58:13.703820  9455 slave.cpp:5654] Task status update manager 
successfully handled status update TASK_STARTING (Status UUID: 
f4552cff-4566-42dc-94fc-a99e16e03503) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.703841  9455 slave.cpp:5670] Sending acknowledgement for status 
update TASK_STARTING (Status UUID: f4552cff-4566-42dc-94fc-a99e16e03503) for 
task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 to executor(1)@172.16.10.34:37056
I0925 23:58:13.703917  9453 master.cpp:8375] Status update TASK_STARTING 
(Status UUID: f4552cff-4566-42dc-94fc-a99e16e03503) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 from agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.703943  9453 master.cpp:8432] Forwarding status update 
TASK_STARTING (Status UUID: f4552cff-4566-42dc-94fc-a99e16e03503) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.704008  9453 master.cpp:10932] Updating the state of task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (latest state: TASK_STARTING, status 
update state: TASK_STARTING)
I0925 23:58:13.704104  9453 sched.cpp:1022] Scheduler::statusUpdate took 24546ns
I0925 23:58:13.704185  9453 master.cpp:6241] Processing ACKNOWLEDGE call for 
status f4552cff-4566-42dc-94fc-a99e16e03503 for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358 on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0
I0925 23:58:13.704264  9453 task_status_update_manager.cpp:401] Received task 
status update acknowledgement (UUID: f4552cff-4566-42dc-94fc-a99e16e03503) for 
task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
II0925 23:58:13.706604  1165 executor.cpp:499] Running 
'/home/centos/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-centos-6/mesos/build/src/mesos-containerizer
 launch <POSSIBLY-SENSITIVE-DATA>'
0925 23:58:13.704324  9453 slave.cpp:4505] Task status update manager 
successfully handled status update acknowledgement (UUID: 
f4552cff-4566-42dc-94fc-a99e16e03503) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.708935  1165 executor.cpp:693] Forked command at 1168
I0925 23:58:13.812824  1165 executor.cpp:994] Failed to get exit status for 
Command (pid: 1168)
I0925 23:58:13.814445  9455 slave.cpp:5269] Handling status update TASK_RUNNING 
(Status UUID: fc5f6dd5-0b64-40d0-ba88-efffe4017dc8) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 from executor(1)@172.16.10.34:37056
I0925 23:58:13.814780  9452 slave.cpp:5269] Handling status update TASK_FAILED 
(Status UUID: fcfc2372-6254-4491-817c-b4e455a0905b) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 from executor(1)@172.16.10.34:37056
I0925 23:58:13.815140  9456 task_status_update_manager.cpp:328] Received task 
status update TASK_RUNNING (Status UUID: fc5f6dd5-0b64-40d0-ba88-efffe4017dc8) 
for task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.815191  9456 task_status_update_manager.cpp:383] Forwarding task 
status update TASK_RUNNING (Status UUID: fc5f6dd5-0b64-40d0-ba88-efffe4017dc8) 
for task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 to the agent
I0925 23:58:13.815248  9456 slave.cpp:5761] Forwarding the update TASK_RUNNING 
(Status UUID: fc5f6dd5-0b64-40d0-ba88-efffe4017dc8) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 to master@172.16.10.34:35358
I0925 23:58:13.815362  9455 master.cpp:8375] Status update TASK_RUNNING (Status 
UUID: fc5f6dd5-0b64-40d0-ba88-efffe4017dc8) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 from agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.815387  9455 master.cpp:8432] Forwarding status update 
TASK_RUNNING (Status UUID: fc5f6dd5-0b64-40d0-ba88-efffe4017dc8) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.815408  9456 slave.cpp:5654] Task status update manager 
successfully handled status update TASK_RUNNING (Status UUID: 
fc5f6dd5-0b64-40d0-ba88-efffe4017dc8) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.815428  9456 slave.cpp:5670] Sending acknowledgement for status 
update TASK_RUNNING (Status UUID: fc5f6dd5-0b64-40d0-ba88-efffe4017dc8) for 
task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 to executor(1)@172.16.10.34:37056
I0925 23:58:13.815451  9455 master.cpp:10932] Updating the state of task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (latest state: TASK_RUNNING, status 
update state: TASK_RUNNING)
I0925 23:58:13.815629  9456 sched.cpp:1022] Scheduler::statusUpdate took 21722ns
I0925 23:58:13.815831  9456 master.cpp:6241] Processing ACKNOWLEDGE call for 
status fc5f6dd5-0b64-40d0-ba88-efffe4017dc8 for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358 on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0
I0925 23:58:13.815910  9458 posix.cpp:144] Removing symlink 
'/tmp/DiskResource_PersistentVolumeTest_ShrinkVolume_0_yozsCw/slaves/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0/frameworks/9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000/executors/38b0a542-e749-4cc3-810b-252b5dc4be34/runs/e3b3402e-f906-4990-a033-f1a5fde7c5f2/path1'
 for persistent volume disk(allocated: default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:3584
 of container e3b3402e-f906-4990-a033-f1a5fde7c5f2
I0925 23:58:13.815986  9456 task_status_update_manager.cpp:401] Received task 
status update acknowledgement (UUID: fc5f6dd5-0b64-40d0-ba88-efffe4017dc8) for 
task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.816063  9458 slave.cpp:4505] Task status update manager 
successfully handled status update acknowledgement (UUID: 
fc5f6dd5-0b64-40d0-ba88-efffe4017dc8) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.816354  9455 task_status_update_manager.cpp:328] Received task 
status update TASK_FAILED (Status UUID: fcfc2372-6254-4491-817c-b4e455a0905b) 
for task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.816426  9455 task_status_update_manager.cpp:383] Forwarding task 
status update TASK_FAILED (Status UUID: fcfc2372-6254-4491-817c-b4e455a0905b) 
for task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 to the agent
I0925 23:58:13.816493  9455 slave.cpp:5761] Forwarding the update TASK_FAILED 
(Status UUID: fcfc2372-6254-4491-817c-b4e455a0905b) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 to master@172.16.10.34:35358
I0925 23:58:13.816709  9455 slave.cpp:5654] Task status update manager 
successfully handled status update TASK_FAILED (Status UUID: 
fcfc2372-6254-4491-817c-b4e455a0905b) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.816728  9455 slave.cpp:5670] Sending acknowledgement for status 
update TASK_FAILED (Status UUID: fcfc2372-6254-4491-817c-b4e455a0905b) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 to executor(1)@172.16.10.34:37056
I0925 23:58:13.817131  9454 master.cpp:8375] Status update TASK_FAILED (Status 
UUID: fcfc2372-6254-4491-817c-b4e455a0905b) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 from agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.817173  9454 master.cpp:8432] Forwarding status update 
TASK_FAILED (Status UUID: fcfc2372-6254-4491-817c-b4e455a0905b) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.817250  9454 master.cpp:10932] Updating the state of task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (latest state: TASK_FAILED, status 
update state: TASK_FAILED)
I0925 23:58:13.817535  9454 sched.cpp:1022] Scheduler::statusUpdate took 36557ns
I0925 23:58:13.817781  9454 hierarchical.cpp:1236] Recovered cpus(allocated: 
default-role/foo):2; mem(allocated: default-role/foo):2048; ports(allocated: 
default-role/foo):[31000-32000]; disk(allocated: 
default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:3584;
 disk(allocated: default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)]):512 (total: 
cpus:2; mem:2048; ports:[31000-32000]; disk(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:3584;
 disk(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)]):512, 
allocated: {}) on agent 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 from framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.817857  9454 master.cpp:6241] Processing ACKNOWLEDGE call for 
status fcfc2372-6254-4491-817c-b4e455a0905b for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358 on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0
I0925 23:58:13.817899  9454 master.cpp:11030] Removing task 
38b0a542-e749-4cc3-810b-252b5dc4be34 with resources cpus(allocated: 
default-role/foo):2; mem(allocated: default-role/foo):2048; ports(allocated: 
default-role/foo):[31000-32000]; disk(allocated: 
default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)])[id1:path1]:3584;
 disk(allocated: default-role/foo)(reservations: 
[(STATIC,default-role),(DYNAMIC,default-role/foo,test-principal)]):512 of 
framework 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 on agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.818210  9455 task_status_update_manager.cpp:401] Received task 
status update acknowledgement (UUID: fcfc2372-6254-4491-817c-b4e455a0905b) for 
task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.818249  9455 task_status_update_manager.cpp:538] Cleaning up 
status update stream for task 38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.818389  9455 slave.cpp:4505] Task status update manager 
successfully handled status update acknowledgement (UUID: 
fcfc2372-6254-4491-817c-b4e455a0905b) for task 
38b0a542-e749-4cc3-810b-252b5dc4be34 of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.818426  9455 slave.cpp:9651] Completing task 
38b0a542-e749-4cc3-810b-252b5dc4be34
../../src/tests/persistent_volume_tests.cpp:832: Failure
      Expected: TASK_FINISHED
To be equal to: taskFinished->state()
      Which is: TASK_FAILED
I0925 23:58:13.822894 21740 sched.cpp:2008] Asked to stop the driver
I0925 23:58:13.822934  9456 sched.cpp:1184] Stopping framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.823029  9456 master.cpp:10185] Processing TEARDOWN call for 
framework 9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.823045  9456 master.cpp:10197] Removing framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.823053  9456 master.cpp:3230] Deactivating framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 (default) at 
scheduler-698fe310-c09d-4019-88d9-d2cb427c1dfb@172.16.10.34:35358
I0925 23:58:13.823144  9459 hierarchical.cpp:420] Deactivated framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.823220  9459 hierarchical.cpp:359] Removed framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.823144  9456 slave.cpp:3896] Asked to shut down framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 by master@172.16.10.34:35358
I0925 23:58:13.823434  9456 slave.cpp:3921] Shutting down framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000
I0925 23:58:13.823449  9456 slave.cpp:6640] Shutting down executor 
'38b0a542-e749-4cc3-810b-252b5dc4be34' of framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 at executor(1)@172.16.10.34:37056
I0925 23:58:13.823680  1159 exec.cpp:445] Executor asked to shutdown
I0925 23:58:13.823760  1159 executor.cpp:182] Received SHUTDOWN event
I0925 23:58:13.823770  1159 executor.cpp:796] Shutting down
I0925 23:58:13.823825  9457 slave.cpp:909] Agent terminating
I0925 23:58:13.823843  9457 slave.cpp:3896] Asked to shut down framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 by @0.0.0.0:0
W0925 23:58:13.823854  9457 slave.cpp:3917] Ignoring shutdown framework 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-0000 because it is terminating
I0925 23:58:13.824080  9457 master.cpp:1251] Agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal) disconnected
I0925 23:58:13.824096  9457 master.cpp:3267] Disconnecting agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.824113  9457 master.cpp:3286] Deactivating agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 at slave(1192)@172.16.10.34:35358 
(ip-172-16-10-34.ec2.internal)
I0925 23:58:13.824148  9457 hierarchical.cpp:795] Agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0 deactivated
I0925 23:58:13.824193  9457 containerizer.cpp:2455] Destroying container 
e3b3402e-f906-4990-a033-f1a5fde7c5f2 in RUNNING state
I0925 23:58:13.824204  9457 containerizer.cpp:3118] Transitioning the state of 
container e3b3402e-f906-4990-a033-f1a5fde7c5f2 from RUNNING to DESTROYING
I0925 23:58:13.824400  9457 linux_launcher.cpp:580] Asked to destroy container 
e3b3402e-f906-4990-a033-f1a5fde7c5f2
I0925 23:58:13.824440  9457 linux_launcher.cpp:622] Destroying cgroup 
'/cgroup/freezer/mesos/e3b3402e-f906-4990-a033-f1a5fde7c5f2'
I0925 23:58:13.824827  9457 cgroups.cpp:2838] Freezing cgroup 
/cgroup/freezer/mesos/e3b3402e-f906-4990-a033-f1a5fde7c5f2
I0925 23:58:13.825012  9453 cgroups.cpp:1229] Successfully froze cgroup 
/cgroup/freezer/mesos/e3b3402e-f906-4990-a033-f1a5fde7c5f2 after 152064ns
I0925 23:58:13.825305  9457 cgroups.cpp:2856] Thawing cgroup 
/cgroup/freezer/mesos/e3b3402e-f906-4990-a033-f1a5fde7c5f2
I0925 23:58:13.825521  9457 cgroups.cpp:1258] Successfully thawed cgroup 
/cgroup/freezer/mesos/e3b3402e-f906-4990-a033-f1a5fde7c5f2 after 167168ns
I0925 23:58:13.924283  9459 containerizer.cpp:2957] Container 
e3b3402e-f906-4990-a033-f1a5fde7c5f2 has exited
I0925 23:58:13.924923  9459 provisioner.cpp:597] Ignoring destroy request for 
unknown container e3b3402e-f906-4990-a033-f1a5fde7c5f2
I0925 23:58:13.940817 21740 master.cpp:1093] Master terminating
I0925 23:58:13.940992  9453 hierarchical.cpp:637] Removed agent 
9f8d4b56-de4c-4df6-86d9-92a6c3c9e432-S0
[  FAILED  ] DiskResource/PersistentVolumeTest.ShrinkVolume/0, where GetParam() 
= 0 (399 ms)
{noformat}



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Reply via email to