-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/70528/#review216492
-----------------------------------------------------------



Bad patch!

Reviews applied: [70526, 70527, 70528]

Failed command: ['bash', '-c', "set -o pipefail; export OS='ubuntu:14.04' 
BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose 
--disable-libtool-wrappers --disable-parallel-test-execution' 
ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/docker-build.sh 2>&1 | tee 
build_70528"]

Error:
...<truncated>...
UID 52b069fa-1131-41fd-861c-1230ef843ede on agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0
I0710 18:19:26.869289 18267 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:37975/slave(1199)/api/v1/resource_provider
I0710 18:19:26.870834 18273 process.cpp:3671] Handling HTTP event for process 
'slave(1199)' with path: '/slave(1199)/api/v1/resource_provider'
I0710 18:19:26.874341 18281 process.cpp:3671] Handling HTTP event for process 
'master' with path: '/master/api/v1'
I0710 18:19:26.876186 18268 http.cpp:1115] HTTP POST for /master/api/v1 from 
172.17.0.2:59214
I0710 18:19:26.876731 18268 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0710 18:19:26.877645 18268 master.cpp:3785] Authorizing principal 
'test-principal' to unreserve resources 
'[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_Ra4Xby/2GB-3ba32cea-b665-4e39-8fa2-044850ba5fe5","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"9a5db9fa-3490-4d6d-9200-f8fdc8d5b603"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0710 18:19:26.880581 18287 sched.cpp:960] Rescinded offer 
de29b93d-7ba1-4009-9d77-451584f13437-O5
I0710 18:19:26.880709 18287 sched.cpp:971] Scheduler::offerRescinded took 
34521ns
I0710 18:19:26.880852 18284 master.cpp:12470] Removing offer 
de29b93d-7ba1-4009-9d77-451584f13437-O5
I0710 18:19:26.880779 18269 hierarchical.cpp:1218] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_Ra4Xby/2GB-3ba32cea-b665-4e39-8fa2-044850ba5fe5,test)]:2048;
 cpus(allocated: storage/default-role):2; mem(allocated: 
storage/default-role):1024; disk(allocated: storage/default-role):1024; 
ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; 
disk:1024; ports:[31000-32000]; disk(reservations: 
[(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_Ra4Xby/2GB-3ba32cea-b665-4e39-8fa2-044850ba5fe5,test)]:2048,
 allocated: {}) on agent de29b93d-7ba1-4009-9d77-451584f13437-S0 from framework 
de29b93d-7ba1-40
 09-9d77-451584f13437-0000
I0710 18:19:26.881059 18269 hierarchical.cpp:1264] Framework 
de29b93d-7ba1-4009-9d77-451584f13437-0000 filtered agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0 for 5secs
I0710 18:19:26.883929 18285 master.cpp:12361] Sending operation '' (uuid: 
29dd5c44-70eb-4479-82db-5b8c91a86cb1) to agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0 at slave(1199)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:26.884701 18285 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:26.887869 18277 provider.cpp:481] Received APPLY_OPERATION event
I0710 18:19:26.887921 18277 provider.cpp:1295] Received UNRESERVE operation '' 
(uuid: 29dd5c44-70eb-4479-82db-5b8c91a86cb1)
I0710 18:19:26.895143 18268 hierarchical.cpp:1508] Performed allocation for 1 
agents in 1.590289ms
I0710 18:19:26.895936 18279 master.cpp:10195] Sending offers [ 
de29b93d-7ba1-4009-9d77-451584f13437-O6 ] to framework 
de29b93d-7ba1-4009-9d77-451584f13437-0000 (default) at 
scheduler-78871aab-8d14-43b9-94fd-2dc92e6fb5b4@172.17.0.2:37975
I0710 18:19:26.896667 18276 sched.cpp:934] Scheduler::resourceOffers took 
75360ns
I0710 18:19:26.909900 18274 http.cpp:1115] HTTP POST for 
/slave(1199)/api/v1/resource_provider from 172.17.0.2:59196
I0710 18:19:26.911051 18267 slave.cpp:8217] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 52b069fa-1131-41fd-861c-1230ef843ede) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0710 18:19:26.911311 18267 slave.cpp:8670] Updating the state of operation 
with no ID (uuid: 52b069fa-1131-41fd-861c-1230ef843ede) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0710 18:19:26.911448 18267 slave.cpp:8424] Forwarding status update of 
operation with no ID (operation_uuid: 52b069fa-1131-41fd-861c-1230ef843ede) for 
an operator API call
I0710 18:19:26.911824 18273 master.cpp:12017] Updating the state of operation 
'' (uuid: 52b069fa-1131-41fd-861c-1230ef843ede) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0710 18:19:26.912524 18267 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:26.986228 18268 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
df76107d-0764-45e8-960f-dc0414ee1b9e) for operation UUID 
29dd5c44-70eb-4479-82db-5b8c91a86cb1 on agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0
I0710 18:19:26.986383 18268 status_update_manager_process.hpp:414] Creating 
operation status update stream 29dd5c44-70eb-4479-82db-5b8c91a86cb1 
checkpoint=true
I0710 18:19:26.986377 18277 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0710 18:19:26.987130 18268 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: df76107d-0764-45e8-960f-dc0414ee1b9e) for operation UUID 
29dd5c44-70eb-4479-82db-5b8c91a86cb1 on agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0
I0710 18:19:27.052891 18268 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
df76107d-0764-45e8-960f-dc0414ee1b9e) for operation UUID 
29dd5c44-70eb-4479-82db-5b8c91a86cb1 on agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0
I0710 18:19:27.054214 18268 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
e23f337b-152b-484b-a4ea-a1e1526d5bee) for stream 
52b069fa-1131-41fd-861c-1230ef843ede
I0710 18:19:27.054692 18268 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
e23f337b-152b-484b-a4ea-a1e1526d5bee) for operation UUID 
52b069fa-1131-41fd-861c-1230ef843ede on agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0
I0710 18:19:27.055070 18279 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:37975/slave(1199)/api/v1/resource_provider
I0710 18:19:27.057257 18287 process.cpp:3671] Handling HTTP event for process 
'slave(1199)' with path: '/slave(1199)/api/v1/resource_provider'
I0710 18:19:27.097807 18273 http.cpp:1115] HTTP POST for 
/slave(1199)/api/v1/resource_provider from 172.17.0.2:59196
I0710 18:19:27.099110 18285 slave.cpp:8217] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 29dd5c44-70eb-4479-82db-5b8c91a86cb1) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0710 18:19:27.099820 18285 slave.cpp:8670] Updating the state of operation 
with no ID (uuid: 29dd5c44-70eb-4479-82db-5b8c91a86cb1) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0710 18:19:27.100134 18285 slave.cpp:8424] Forwarding status update of 
operation with no ID (operation_uuid: 29dd5c44-70eb-4479-82db-5b8c91a86cb1) for 
an operator API call
I0710 18:19:27.100687 18275 master.cpp:12017] Updating the state of operation 
'' (uuid: 29dd5c44-70eb-4479-82db-5b8c91a86cb1) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0710 18:19:27.101477 18266 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:27.103384 18284 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0710 18:19:27.119695 18268 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 52b069fa-1131-41fd-861c-1230ef843ede
I0710 18:19:27.120221 18268 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
df76107d-0764-45e8-960f-dc0414ee1b9e) for stream 
29dd5c44-70eb-4479-82db-5b8c91a86cb1
I0710 18:19:27.120594 18268 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
df76107d-0764-45e8-960f-dc0414ee1b9e) for operation UUID 
29dd5c44-70eb-4479-82db-5b8c91a86cb1 on agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0
I0710 18:19:27.203598 18268 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 29dd5c44-70eb-4479-82db-5b8c91a86cb1
I0710 18:19:27.272167 18280 master.cpp:1410] Framework 
de29b93d-7ba1-4009-9d77-451584f13437-0000 (default) at 
scheduler-78871aab-8d14-43b9-94fd-2dc92e6fb5b4@172.17.0.2:37975 disconnected
I0710 18:19:27.272240 18280 master.cpp:3342] Deactivating framework 
de29b93d-7ba1-4009-9d77-451584f13437-0000 (default) at 
scheduler-78871aab-8d14-43b9-94fd-2dc92e6fb5b4@172.17.0.2:37975
I0710 18:19:27.272677 18273 hierarchical.cpp:475] Deactivated framework 
de29b93d-7ba1-4009-9d77-451584f13437-0000
I0710 18:19:27.273097 18280 master.cpp:12470] Removing offer 
de29b93d-7ba1-4009-9d77-451584f13437-O6
I0710 18:19:27.273169 18280 master.cpp:3319] Disconnecting framework 
de29b93d-7ba1-4009-9d77-451584f13437-0000 (default) at 
scheduler-78871aab-8d14-43b9-94fd-2dc92e6fb5b4@172.17.0.2:37975
I0710 18:19:27.273227 18280 master.cpp:1425] Giving framework 
de29b93d-7ba1-4009-9d77-451584f13437-0000 (default) at 
scheduler-78871aab-8d14-43b9-94fd-2dc92e6fb5b4@172.17.0.2:37975 0ns to failover
I0710 18:19:27.273789 18272 slave.cpp:912] Agent terminating
I0710 18:19:27.274554 18272 manager.cpp:163] Terminating resource provider 
9a5db9fa-3490-4d6d-9200-f8fdc8d5b603
I0710 18:19:27.274716 18273 hierarchical.cpp:1218] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_Ra4Xby/2GB-3ba32cea-b665-4e39-8fa2-044850ba5fe5,test)]:2048;
 cpus(allocated: storage/default-role):2; mem(allocated: 
storage/default-role):1024; disk(allocated: storage/default-role):1024; 
ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; 
disk:1024; ports:[31000-32000]; disk(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_Ra4Xby/2GB-3ba32cea-b665-4e39-8fa2-044850ba5fe5,test)]:2048,
 allocated: {}) on agent de29b93d-7ba1-4009-9d77-451584f13437-S0 from framework 
de29b93d-7ba1-4009-9d77-451584f13437-0000
I0710 18:19:27.275143 18278 master.cpp:1295] Agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0 at slave(1199)@172.17.0.2:37975 
(e12b3ef9ecdc) disconnected
I0710 18:19:27.275213 18278 master.cpp:3379] Disconnecting agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0 at slave(1199)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:27.275310 18278 master.cpp:3398] Deactivating agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0 at slave(1199)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:27.275586 18278 hierarchical.cpp:799] Agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0 deactivated
I0710 18:19:27.276111 18268 master.cpp:9987] Framework failover timeout, 
removing framework de29b93d-7ba1-4009-9d77-451584f13437-0000 (default) at 
scheduler-78871aab-8d14-43b9-94fd-2dc92e6fb5b4@172.17.0.2:37975
I0710 18:19:27.276366 18268 master.cpp:10979] Removing framework 
de29b93d-7ba1-4009-9d77-451584f13437-0000 (default) at 
scheduler-78871aab-8d14-43b9-94fd-2dc92e6fb5b4@172.17.0.2:37975
E0710 18:19:27.277257 18275 http_connection.hpp:452] End-Of-File received
I0710 18:19:27.277369 18282 hierarchical.cpp:1432] Allocation paused
I0710 18:19:27.278020 18282 hierarchical.cpp:417] Removed framework 
de29b93d-7ba1-4009-9d77-451584f13437-0000
I0710 18:19:27.278158 18275 http_connection.hpp:217] Re-detecting endpoint
I0710 18:19:27.278561 18282 hierarchical.cpp:1442] Allocation resumed
I0710 18:19:27.279628 18275 http_connection.hpp:338] Ignoring disconnection 
attempt from stale connection
I0710 18:19:27.279786 18275 http_connection.hpp:338] Ignoring disconnection 
attempt from stale connection
I0710 18:19:27.279934 18275 http_connection.hpp:227] New endpoint detected at 
http://172.17.0.2:37975/slave(1199)/api/v1/resource_provider
I0710 18:19:27.281606 18273 provider.cpp:471] Disconnected from resource 
provider manager
I0710 18:19:27.281839 18265 status_update_manager_process.hpp:379] Pausing 
operation status update manager
I0710 18:19:27.282487 18283 containerizer.cpp:2575] Destroying container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 in RUNNING state
I0710 18:19:27.282542 18283 containerizer.cpp:3277] Transitioning the state of 
container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 from RUNNING to DESTROYING
I0710 18:19:27.283211 18283 launcher.cpp:161] Asked to destroy container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0710 18:19:27.283812 18286 http_connection.hpp:283] Connected with the remote 
endpoint at http://172.17.0.2:37975/slave(1199)/api/v1/resource_provider
I0710 18:19:27.284471 18272 provider.cpp:459] Connected to resource provider 
manager
I0710 18:19:27.284497 18266 hierarchical.cpp:1508] Performed allocation for 1 
agents in 187208ns
I0710 18:19:27.285238 18288 http_connection.hpp:131] Sending 1 call to 
http://172.17.0.2:37975/slave(1199)/api/v1/resource_provider
I0710 18:19:27.286166 18289 process.cpp:2781] Returning '404 Not Found' for 
'/slave(1199)/api/v1/resource_provider'
E0710 18:19:27.287606 18273 provider.cpp:702] Failed to subscribe resource 
provider with type 'org.apache.mesos.rp.local.storage' and name 'test': 
Received '404 Not Found' ()
I0710 18:19:27.337044 18267 hierarchical.cpp:1508] Performed allocation for 1 
agents in 253684ns
I0710 18:19:27.386363 18271 containerizer.cpp:3116] Container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 has exited
I0710 18:19:27.388221 18270 provisioner.cpp:609] Ignoring destroy request for 
unknown container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0710 18:19:27.388928 18279 hierarchical.cpp:1508] Performed allocation for 1 
agents in 256474ns
I0710 18:19:27.391644 18265 container_daemon.cpp:189] Invoking post-stop hook 
for container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0710 18:19:27.391880 18267 service_manager.cpp:723] Disconnected from endpoint 
'unix:///tmp/mesos-csi-bVfwzr/endpoint.sock' of CSI plugin container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0710 18:19:27.392349 18268 container_daemon.cpp:121] Launching container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0710 18:19:27.395656 18289 process.cpp:2781] Returning '404 Not Found' for 
'/slave(1199)/api/v1'
I0710 18:19:27.407985 18281 master.cpp:1135] Master terminating
I0710 18:19:27.408905 18268 hierarchical.cpp:775] Removed all filters for agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0
I0710 18:19:27.409237 18268 hierarchical.cpp:650] Removed agent 
de29b93d-7ba1-4009-9d77-451584f13437-S0
[       OK ] 
CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v0
 (2652 ms)
[ RUN      ] 
CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1
I0710 18:19:27.425076 18264 cluster.cpp:176] Creating default 'local' authorizer
I0710 18:19:27.431495 18278 master.cpp:440] Master 
e79cd135-44ed-4f64-85ab-8c65ec7d1714 (e12b3ef9ecdc) started on 172.17.0.2:37975
I0710 18:19:27.431561 18278 master.cpp:443] Flags at startup: --acls="" 
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" 
--allocation_interval="50ms" --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/rkqm6j/credentials" --filter_gpu_resources="true" 
--framework_sorter="drf" --help="false" --hostname_lookup="true" 
--http_authenticators="basic" --http_framework_authenticators="basic" 
--initialize_driver_logging="true" --log_auto_initialize="true" 
--logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" 
--max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" 
--max_operator_event_stream_subscribers="1000" 
--max_unreachable_tasks_per_framework="1000" --memory_profiling="false" 
--min_alloca
 table_resources="cpus:0.01|mem:32" --port="5050" 
--publish_per_framework_metrics="true" --quiet="false" 
--recovery_agent_removal_limit="100%" --registry="in_memory" 
--registry_fetch_timeout="1mins" --registry_gc_interval="15mins" 
--registry_max_agent_age="2weeks" --registry_max_agent_count="102400" 
--registry_store_timeout="100secs" --registry_strict="false" 
--require_agent_domain="false" --role_sorter="drf" --root_submissions="true" 
--version="false" --webui_dir="/mesos/mesos-1.9.0/_inst/share/mesos/webui" 
--work_dir="/tmp/rkqm6j/master" --zk_session_timeout="10secs"
I0710 18:19:27.432322 18278 master.cpp:492] Master only allowing authenticated 
frameworks to register
I0710 18:19:27.432405 18278 master.cpp:498] Master only allowing authenticated 
agents to register
I0710 18:19:27.432487 18278 master.cpp:504] Master only allowing authenticated 
HTTP frameworks to register
I0710 18:19:27.432731 18278 credentials.hpp:37] Loading credentials for 
authentication from '/tmp/rkqm6j/credentials'
I0710 18:19:27.433341 18278 master.cpp:548] Using default 'crammd5' 
authenticator
I0710 18:19:27.433825 18278 http.cpp:975] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-readonly'
I0710 18:19:27.434288 18278 http.cpp:975] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-readwrite'
I0710 18:19:27.434605 18278 http.cpp:975] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-scheduler'
I0710 18:19:27.434916 18278 master.cpp:629] Authorization enabled
I0710 18:19:27.435497 18273 hierarchical.cpp:241] Initialized hierarchical 
allocator process
I0710 18:19:27.435511 18285 whitelist_watcher.cpp:77] No whitelist given
I0710 18:19:27.439503 18278 master.cpp:2150] Elected as the leading master!
I0710 18:19:27.439563 18278 master.cpp:1664] Recovering from registrar
I0710 18:19:27.439759 18270 registrar.cpp:339] Recovering registrar
I0710 18:19:27.440868 18270 registrar.cpp:383] Successfully fetched the 
registry (0B) in 0ns
I0710 18:19:27.441032 18270 registrar.cpp:487] Applied 1 operations in 52193ns; 
attempting to update the registry
I0710 18:19:27.441936 18270 registrar.cpp:544] Successfully updated the 
registry in 0ns
I0710 18:19:27.442096 18270 registrar.cpp:416] Successfully recovered registrar
I0710 18:19:27.442831 18283 hierarchical.cpp:280] Skipping recovery of 
hierarchical allocator: nothing to recover
I0710 18:19:27.442831 18284 master.cpp:1799] Recovered 0 agents from the 
registry (143B); allowing 10mins for agents to reregister
W0710 18:19:27.449008 18264 process.cpp:2877] Attempted to spawn already 
running process files@172.17.0.2:37975
I0710 18:19:27.450378 18264 containerizer.cpp:314] Using isolation { 
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0710 18:19:27.450964 18264 backend.cpp:76] Failed to create 'aufs' backend: 
AufsBackend requires root privileges
W0710 18:19:27.451112 18264 backend.cpp:76] Failed to create 'bind' backend: 
BindBackend requires root privileges
I0710 18:19:27.451158 18264 provisioner.cpp:298] Using default backend 'copy'
I0710 18:19:27.453532 18264 cluster.cpp:510] Creating default 'local' authorizer
I0710 18:19:27.455806 18284 slave.cpp:265] Mesos agent started on 
(1200)@172.17.0.2:37975
I0710 18:19:27.455869 18284 slave.cpp:266] Flags at startup: --acls="" 
--appc_simple_discovery_uri_prefix="http://"; 
--appc_store_dir="/tmp/rkqm6j/n6MFVV/store/appc" 
--authenticate_http_readonly="true" --authenticate_http_readwrite="false" 
--authenticatee="crammd5" --authentication_backoff_factor="1secs" 
--authentication_timeout_max="1mins" --authentication_timeout_min="5secs" 
--authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" 
--cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false" 
--cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" 
--cgroups_root="mesos" --container_disk_watch_interval="15secs" 
--containerizers="mesos" --credential="/tmp/rkqm6j/n6MFVV/credential" 
--default_role="*" --disallow_sharing_agent_ipc_namespace="false" 
--disallow_sharing_agent_pid_namespace="false" 
--disk_profile_adaptor="org_apache_mesos_UriDiskProfileAdaptor" 
--disk_watch_interval="1mins" --docker="docker" --docker_ignore_runtime="false" 
--docker_kill_orphans="true" 
 --docker_registry="https://registry-1.docker.io"; --docker_remove_delay="6hrs" 
--docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" 
--docker_store_dir="/tmp/rkqm6j/n6MFVV/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/rkqm6j/n6MFVV/fetch" --fetcher_cache_size="2GB" 
--fetcher_stall_timeout="1mins" 
--frameworks_home="/tmp/rkqm6j/n6MFVV/frameworks" --gc_delay="1weeks" 
--gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" 
--help="false" --hostname_lookup="true" --http_command_executor="false" 
--http_credentials="/tmp/rkqm6j/n6MFVV/http_credentials" 
--http_heartbeat_interval="30secs" --initialize_driver_logging="true" 
--isolation="posix/cpu,posix/mem" --launcher="posix" 
--launcher_dir="/mesos/mesos-1.9.0/_build/src" --logbufsecs="0" --
 logging_level="INFO" --max_completed_executors_per_framework="150" 
--memory_profiling="false" --network_cni_metrics="true" 
--network_cni_root_dir_persist="false" 
--oversubscribed_resources_interval="15secs" --perf_duration="10secs" 
--perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" 
--quiet="false" --reconfiguration_policy="equal" --recover="reconnect" 
--recovery_timeout="15mins" --registration_backoff_factor="10ms" 
--resource_provider_config_dir="/tmp/rkqm6j/resource_provider_configs" 
--resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" 
--revocable_cpu_low_priority="true" 
--runtime_dir="/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_Q0Gssh"
 --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/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsW
 ithResourceProviderResources_v1_3KtgZC" --zk_session_timeout="10secs"
I0710 18:19:27.456924 18284 credentials.hpp:86] Loading credential for 
authentication from '/tmp/rkqm6j/n6MFVV/credential'
I0710 18:19:27.457357 18284 slave.cpp:298] Agent using credential for: 
test-principal
I0710 18:19:27.457391 18284 credentials.hpp:37] Loading credentials for 
authentication from '/tmp/rkqm6j/n6MFVV/http_credentials'
I0710 18:19:27.457938 18284 http.cpp:975] Creating default 'basic' HTTP 
authenticator for realm 'mesos-agent-readonly'
I0710 18:19:27.458730 18284 disk_profile_adaptor.cpp:82] Creating disk profile 
adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0710 18:19:27.461709 18284 slave.cpp:613] Agent resources: 
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0710 18:19:27.462091 18284 slave.cpp:621] Agent attributes: [  ]
I0710 18:19:27.462123 18284 slave.cpp:630] Agent hostname: e12b3ef9ecdc
I0710 18:19:27.462451 18272 task_status_update_manager.cpp:181] Pausing sending 
task status updates
I0710 18:19:27.462471 18273 status_update_manager_process.hpp:379] Pausing 
operation status update manager
I0710 18:19:27.463452 18278 process.cpp:3671] Handling HTTP event for process 
'test-disk-profile-server' with path: '/test-disk-profile-server/profiles'
I0710 18:19:27.465423 18275 state.cpp:67] Recovering state from 
'/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_3KtgZC/meta'
I0710 18:19:27.465967 18270 slave.cpp:7246] Finished recovering checkpointed 
state from 
'/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_3KtgZC/meta',
 beginning agent recovery
I0710 18:19:27.466696 18267 task_status_update_manager.cpp:207] Recovering task 
status update manager
I0710 18:19:27.468144 18273 containerizer.cpp:796] Recovering Mesos containers
I0710 18:19:27.468689 18273 containerizer.cpp:1122] Recovering isolators
I0710 18:19:27.469405 18286 uri_disk_profile_adaptor.cpp:305] Updated disk 
profile mapping to 1 active profiles
I0710 18:19:27.469792 18287 containerizer.cpp:1161] Recovering provisioner
I0710 18:19:27.470798 18288 provisioner.cpp:498] Provisioner recovery complete
I0710 18:19:27.471989 18281 composing.cpp:339] Finished recovering all 
containerizers
I0710 18:19:27.472759 18272 slave.cpp:7708] Recovering executors
I0710 18:19:27.472900 18272 slave.cpp:7861] Finished recovery
I0710 18:19:27.474261 18266 task_status_update_manager.cpp:181] Pausing sending 
task status updates
I0710 18:19:27.474293 18273 status_update_manager_process.hpp:379] Pausing 
operation status update manager
I0710 18:19:27.474324 18285 slave.cpp:1258] New master detected at 
master@172.17.0.2:37975
I0710 18:19:27.474728 18285 slave.cpp:1323] Detecting new master
I0710 18:19:27.476152 18284 slave.cpp:1350] Authenticating with master 
master@172.17.0.2:37975
I0710 18:19:27.476332 18284 slave.cpp:1359] Using default CRAM-MD5 authenticatee
I0710 18:19:27.476819 18287 authenticatee.cpp:121] Creating new client SASL 
connection
I0710 18:19:27.477382 18277 master.cpp:10380] Authenticating 
slave(1200)@172.17.0.2:37975
I0710 18:19:27.477699 18282 authenticator.cpp:414] Starting authentication 
session for crammd5-authenticatee(2048)@172.17.0.2:37975
I0710 18:19:27.478307 18280 authenticator.cpp:98] Creating new server SASL 
connection
I0710 18:19:27.478716 18276 authenticatee.cpp:213] Received SASL authentication 
mechanisms: CRAM-MD5
I0710 18:19:27.478752 18276 authenticatee.cpp:239] Attempting to authenticate 
with mechanism 'CRAM-MD5'
I0710 18:19:27.479152 18288 authenticator.cpp:204] Received SASL authentication 
start
I0710 18:19:27.479254 18288 authenticator.cpp:326] Authentication requires more 
steps
I0710 18:19:27.479468 18288 authenticatee.cpp:259] Received SASL authentication 
step
I0710 18:19:27.479744 18274 authenticator.cpp:232] Received SASL authentication 
step
I0710 18:19:27.479789 18274 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'e12b3ef9ecdc' server FQDN: 'e12b3ef9ecdc' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: false 
I0710 18:19:27.479887 18274 auxprop.cpp:181] Looking up auxiliary property 
'*userPassword'
I0710 18:19:27.480221 18274 auxprop.cpp:181] Looking up auxiliary property 
'*cmusaslsecretCRAM-MD5'
I0710 18:19:27.480265 18274 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'e12b3ef9ecdc' server FQDN: 'e12b3ef9ecdc' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: true 
I0710 18:19:27.480357 18274 auxprop.cpp:131] Skipping auxiliary property 
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0710 18:19:27.480659 18274 auxprop.cpp:131] Skipping auxiliary property 
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0710 18:19:27.480700 18274 authenticator.cpp:318] Authentication success
I0710 18:19:27.480890 18283 authenticatee.cpp:299] Authentication success
I0710 18:19:27.481566 18267 slave.cpp:1450] Successfully authenticated with 
master master@172.17.0.2:37975
I0710 18:19:27.481691 18271 master.cpp:10412] Successfully authenticated 
principal 'test-principal' at slave(1200)@172.17.0.2:37975
I0710 18:19:27.481832 18274 authenticator.cpp:432] Authentication session 
cleanup for crammd5-authenticatee(2048)@172.17.0.2:37975
I0710 18:19:27.482309 18267 slave.cpp:1900] Will retry registration in 
12.283598ms if necessary
I0710 18:19:27.482561 18269 master.cpp:6900] Received register agent message 
from slave(1200)@172.17.0.2:37975 (e12b3ef9ecdc)
I0710 18:19:27.483060 18269 master.cpp:4099] Authorizing agent providing 
resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 
'test-principal'
I0710 18:19:27.483866 18285 master.cpp:6967] Authorized registration of agent 
at slave(1200)@172.17.0.2:37975 (e12b3ef9ecdc)
I0710 18:19:27.484012 18285 master.cpp:7082] Registering agent at 
slave(1200)@172.17.0.2:37975 (e12b3ef9ecdc) with id 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:27.485005 18265 registrar.cpp:487] Applied 1 operations in 
232867ns; attempting to update the registry
I0710 18:19:27.485872 18265 registrar.cpp:544] Successfully updated the 
registry in 0ns
I0710 18:19:27.486143 18282 master.cpp:7130] Admitted agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:27.487751 18275 hierarchical.cpp:617] Added agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 (e12b3ef9ecdc) with cpus:2; mem:1024; 
disk:1024; ports:[31000-32000] (allocated: {})
I0710 18:19:27.488358 18275 hierarchical.cpp:1508] Performed allocation for 1 
agents in 216466ns
I0710 18:19:27.488687 18282 master.cpp:7175] Registered agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0710 18:19:27.488823 18281 slave.cpp:1483] Registered with master 
master@172.17.0.2:37975; given agent ID e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:27.489109 18283 task_status_update_manager.cpp:188] Resuming 
sending task status updates
I0710 18:19:27.489775 18281 slave.cpp:1518] Checkpointing SlaveInfo to 
'/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_3KtgZC/meta/slaves/e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0/slave.info'
I0710 18:19:27.489873 18271 status_update_manager_process.hpp:385] Resuming 
operation status update manager
I0710 18:19:27.491647 18281 slave.cpp:1570] Forwarding agent update 
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"S2xFV0+oTgOheMMpigqN0g=="},"slave_id":{"value":"e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0"},"update_oversubscribed_resources":false}
I0710 18:19:27.493427 18273 master.cpp:8261] Ignoring update on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc) as it reports no changes
I0710 18:19:27.498891 18276 process.cpp:3671] Handling HTTP event for process 
'slave(1200)' with path: '/slave(1200)/api/v1'
I0710 18:19:27.500715 18270 http.cpp:1115] HTTP POST for /slave(1200)/api/v1 
from 172.17.0.2:59224
I0710 18:19:27.501394 18270 http.cpp:2120] Processing GET_CONTAINERS call
I0710 18:19:27.508384 18280 container_daemon.cpp:121] Launching container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0710 18:19:27.513440 18275 process.cpp:3671] Handling HTTP event for process 
'slave(1200)' with path: '/slave(1200)/api/v1'
I0710 18:19:27.515040 18270 http.cpp:1115] HTTP POST for /slave(1200)/api/v1 
from 172.17.0.2:59226
I0710 18:19:27.516172 18270 http.cpp:2486] Processing LAUNCH_CONTAINER call for 
container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0710 18:19:27.517283 18274 http.cpp:2590] Creating sandbox 
'/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_3KtgZC/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0710 18:19:27.518061 18285 containerizer.cpp:1357] Starting container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0710 18:19:27.519356 18285 containerizer.cpp:1529] Checkpointed 
ContainerConfig at 
'/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_Q0Gssh/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0710 18:19:27.519404 18285 containerizer.cpp:3277] Transitioning the state of 
container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 from PROVISIONING to PREPARING
I0710 18:19:27.523145 18286 containerizer.cpp:2055] Launching 
'mesos-containerizer' with flags '--help="false" 
--launch_info="{"command":{"arguments":["/mesos/mesos-1.9.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY","--available_capacity=2GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.9.0/_build/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_3KtgZC/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"},{"name":"CSI_ENDPOINT","type":"VALUE","value":"unix:///tmp/mesos-csi-YWF1fy/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperat
 
ionsWithResourceProviderResources_v1_3KtgZC/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}"
 --pipe_read="89" --pipe_write="90" 
--runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_Q0Gssh/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"
 --unshare_namespace_mnt="false"'
I0710 18:19:27.537741 18286 launcher.cpp:145] Forked child with pid '32086' for 
container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0710 18:19:27.538817 18286 containerizer.cpp:3277] Transitioning the state of 
container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 from PREPARING to ISOLATING
I0710 18:19:27.540877 18286 containerizer.cpp:3277] Transitioning the state of 
container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 from ISOLATING to FETCHING
I0710 18:19:27.541438 18275 fetcher.cpp:369] Starting to fetch URIs for 
container: 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE,
 directory: 
/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_3KtgZC/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0710 18:19:27.542670 18286 containerizer.cpp:3277] Transitioning the state of 
container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 from FETCHING to RUNNING
I0710 18:19:27.545914 18278 container_daemon.cpp:140] Invoking post-start hook 
for container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0710 18:19:27.546280 18278 service_manager.cpp:703] Connecting to endpoint 
'unix:///tmp/mesos-csi-YWF1fy/endpoint.sock' of CSI plugin container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0710 18:19:27.687363 18288 hierarchical.cpp:1508] Performed allocation for 1 
agents in 183073ns
I0710 18:19:27.738562 18271 hierarchical.cpp:1508] Performed allocation for 1 
agents in 223545ns
I0710 18:19:27.790472 18273 hierarchical.cpp:1508] Performed allocation for 1 
agents in 181305ns
I0710 18:19:27.842316 18277 hierarchical.cpp:1508] Performed allocation for 1 
agents in 240981ns
I0710 18:19:27.894361 18279 hierarchical.cpp:1508] Performed allocation for 1 
agents in 284586ns
I0710 18:19:27.914559 18275 service_manager.cpp:545] Probing endpoint 
'unix:///tmp/mesos-csi-YWF1fy/endpoint.sock' with CSI v1
I0710 18:19:27.929983 32090 test_csi_plugin.cpp:909] ProbeRequest '{}'
I0710 18:19:27.932400 18274 container_daemon.cpp:171] Waiting for container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0710 18:19:27.935068 32091 test_csi_plugin.cpp:895] 
GetPluginCapabilitiesRequest '{}'
I0710 18:19:27.935396 18277 process.cpp:3671] Handling HTTP event for process 
'slave(1200)' with path: '/slave(1200)/api/v1'
I0710 18:19:27.936741 18279 http.cpp:1115] HTTP POST for /slave(1200)/api/v1 
from 172.17.0.2:59228
I0710 18:19:27.937602 18279 http.cpp:2704] Processing WAIT_CONTAINER call for 
container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0710 18:19:27.939591 32091 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0710 18:19:27.939795 32090 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0710 18:19:27.941382 18283 v1_volume_manager.cpp:648] NODE_SERVICE loaded: 
{"name":".","vendorVersion":"1.9.0"}
I0710 18:19:27.941982 18283 v1_volume_manager.cpp:648] CONTROLLER_SERVICE 
loaded: {"name":".","vendorVersion":"1.9.0"}
I0710 18:19:27.944254 32092 test_csi_plugin.cpp:1105] 
ControllerGetCapabilitiesRequest '{}'
I0710 18:19:27.945598 18280 hierarchical.cpp:1508] Performed allocation for 1 
agents in 236360ns
I0710 18:19:27.947943 32091 test_csi_plugin.cpp:1241] 
NodeGetCapabilitiesRequest '{}'
I0710 18:19:27.951732 32092 test_csi_plugin.cpp:1255] NodeGetInfoRequest '{}'
I0710 18:19:27.953920 18265 provider.cpp:659] Finished recovery for resource 
provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0710 18:19:27.954095 18266 status_update_manager_process.hpp:379] Pausing 
operation status update manager
I0710 18:19:27.954566 18281 http_connection.hpp:227] New endpoint detected at 
http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:27.957571 18285 http_connection.hpp:283] Connected with the remote 
endpoint at http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:27.958168 18280 provider.cpp:459] Connected to resource provider 
manager
I0710 18:19:27.959003 18276 http_connection.hpp:131] Sending 1 call to 
http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:27.960371 18279 process.cpp:3671] Handling HTTP event for process 
'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider'
I0710 18:19:27.962412 18265 http.cpp:1115] HTTP POST for 
/slave(1200)/api/v1/resource_provider from 172.17.0.2:59232
I0710 18:19:27.963191 18269 manager.cpp:807] Subscribing resource provider 
{"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.9.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY","--available_capacity=2GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.9.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"}},"type":"org.apache.mesos.rp.local.storage"}
I0710 18:19:27.997427 18287 hierarchical.cpp:1508] Performed allocation for 1 
agents in 171221ns
I0710 18:19:28.000103 18288 slave.cpp:8217] Handling resource provider message 
'SUBSCRIBE: 
{"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"1877f885-a47f-408a-a55e-a7194c423045"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.9.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY","--available_capacity=2GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.9.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"}},"type":"org.apache.mesos.rp.local.storage"}'
I0710 18:19:28.002220 18275 provider.cpp:481] Received SUBSCRIBED event
I0710 18:19:28.002266 18275 provider.cpp:1255] Subscribed with ID 
1877f885-a47f-408a-a55e-a7194c423045
I0710 18:19:28.003197 18265 status_update_manager_process.hpp:314] Recovering 
operation status update manager
I0710 18:19:28.048661 18281 hierarchical.cpp:1508] Performed allocation for 1 
agents in 235693ns
I0710 18:19:28.052311 32092 test_csi_plugin.cpp:1050] ListVolumesRequest '{}'
I0710 18:19:28.054347 18284 provider.cpp:2145] Sending UPDATE_STATE call with 
resources '{}' and 0 operations to agent e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.054670 18284 provider.cpp:745] Resource provider 
1877f885-a47f-408a-a55e-a7194c423045 is in READY state
I0710 18:19:28.054760 18280 http_connection.hpp:131] Sending 3 call to 
http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:28.054738 18286 status_update_manager_process.hpp:385] Resuming 
operation status update manager
I0710 18:19:28.055660 18279 provider.cpp:1181] Updating profiles { test } for 
resource provider 1877f885-a47f-408a-a55e-a7194c423045
I0710 18:19:28.056341 18275 process.cpp:3671] Handling HTTP event for process 
'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider'
I0710 18:19:28.058176 18285 http.cpp:1115] HTTP POST for 
/slave(1200)/api/v1/resource_provider from 172.17.0.2:59230
I0710 18:19:28.058704 18286 manager.cpp:1039] Received UPDATE_STATE call with 
resources '[]' and 0 operations from resource provider 
1877f885-a47f-408a-a55e-a7194c423045
I0710 18:19:28.058977 18280 slave.cpp:8217] Handling resource provider message 
'UPDATE_STATE: 1877f885-a47f-408a-a55e-a7194c423045 {}'
I0710 18:19:28.059082 18280 slave.cpp:8337] Forwarding new total resources 
cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0710 18:19:28.059232 32091 test_csi_plugin.cpp:1078] GetCapacityRequest 
'{"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0710 18:19:28.061549 18272 hierarchical.cpp:753] Grew agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 by {} (total), {  } (used)
I0710 18:19:28.061899 18272 hierarchical.cpp:710] Agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 (e12b3ef9ecdc) updated with total 
resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0710 18:19:28.063412 18277 provider.cpp:933] Removing '{}' and adding 
'disk(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' to the 
total resources
I0710 18:19:28.117127 18277 provider.cpp:2145] Sending UPDATE_STATE call with 
resources 'disk(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' and 0 
operations to agent e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.118026 18287 http_connection.hpp:131] Sending 3 call to 
http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:28.119382 18288 process.cpp:3671] Handling HTTP event for process 
'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider'
W0710 18:19:28.120575 18264 process.cpp:2877] Attempted to spawn already 
running process version@172.17.0.2:37975
I0710 18:19:28.121714 18264 sched.cpp:239] Version: 1.9.0
I0710 18:19:28.122684 18284 sched.cpp:343] New master detected at 
master@172.17.0.2:37975
I0710 18:19:28.122905 18284 sched.cpp:408] Authenticating with master 
master@172.17.0.2:37975
I0710 18:19:28.122929 18284 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0710 18:19:28.123412 18266 authenticatee.cpp:121] Creating new client SASL 
connection
I0710 18:19:28.123734 18265 hierarchical.cpp:1508] Performed allocation for 1 
agents in 241976ns
I0710 18:19:28.123921 18266 master.cpp:10380] Authenticating 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:28.124253 18271 authenticator.cpp:414] Starting authentication 
session for crammd5-authenticatee(2049)@172.17.0.2:37975
I0710 18:19:28.124621 18272 authenticator.cpp:98] Creating new server SASL 
connection
I0710 18:19:28.124974 18279 authenticatee.cpp:213] Received SASL authentication 
mechanisms: CRAM-MD5
I0710 18:19:28.125002 18279 authenticatee.cpp:239] Attempting to authenticate 
with mechanism 'CRAM-MD5'
I0710 18:19:28.125154 18275 authenticator.cpp:204] Received SASL authentication 
start
I0710 18:19:28.125233 18275 authenticator.cpp:326] Authentication requires more 
steps
I0710 18:19:28.125375 18269 authenticatee.cpp:259] Received SASL authentication 
step
I0710 18:19:28.125545 18278 authenticator.cpp:232] Received SASL authentication 
step
I0710 18:19:28.125689 18278 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'e12b3ef9ecdc' server FQDN: 'e12b3ef9ecdc' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: false 
I0710 18:19:28.125788 18278 auxprop.cpp:181] Looking up auxiliary property 
'*userPassword'
I0710 18:19:28.125913 18278 auxprop.cpp:181] Looking up auxiliary property 
'*cmusaslsecretCRAM-MD5'
I0710 18:19:28.126098 18278 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'e12b3ef9ecdc' server FQDN: 'e12b3ef9ecdc' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: true 
I0710 18:19:28.126176 18278 auxprop.cpp:131] Skipping auxiliary property 
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0710 18:19:28.126255 18278 auxprop.cpp:131] Skipping auxiliary property 
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0710 18:19:28.126286 18278 authenticator.cpp:318] Authentication success
I0710 18:19:28.126437 18287 authenticatee.cpp:299] Authentication success
I0710 18:19:28.127120 18288 master.cpp:10412] Successfully authenticated 
principal 'test-principal' at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:28.127159 18277 sched.cpp:520] Successfully authenticated with 
master master@172.17.0.2:37975
I0710 18:19:28.127178 18268 authenticator.cpp:432] Authentication session 
cleanup for crammd5-authenticatee(2049)@172.17.0.2:37975
I0710 18:19:28.127281 18277 sched.cpp:835] Sending SUBSCRIBE call to 
master@172.17.0.2:37975
I0710 18:19:28.127586 18277 sched.cpp:870] Will retry registration in 
1.325098376secs if necessary
I0710 18:19:28.127864 18286 master.cpp:2890] Received SUBSCRIBE call for 
framework 'default' at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:28.127902 18286 master.cpp:2222] Authorizing framework principal 
'test-principal' to receive offers for roles '{ storage/default-role }'
I0710 18:19:28.128624 18274 master.cpp:2977] Subscribing framework default with 
checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0710 18:19:28.135233 18274 master.cpp:10610] Adding framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975 with roles {  } 
suppressed
I0710 18:19:28.136035 18282 sched.cpp:751] Framework registered with 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.136104 18282 sched.cpp:770] Scheduler::registered took 34757ns
I0710 18:19:28.136515 18284 hierarchical.cpp:368] Added framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.137840 18284 hierarchical.cpp:1508] Performed allocation for 1 
agents in 1.115278ms
I0710 18:19:28.138711 18271 master.cpp:10195] Sending offers [ 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O0 ] to framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:28.139392 18272 sched.cpp:934] Scheduler::resourceOffers took 
126186ns
I0710 18:19:28.139786 18279 master.cpp:6119] Processing DECLINE call for 
offers: [ e79cd135-44ed-4f64-85ab-8c65ec7d1714-O0 ] for framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975 with 5 seconds 
filter
I0710 18:19:28.140334 18279 master.cpp:12470] Removing offer 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O0
I0710 18:19:28.140976 18275 hierarchical.cpp:1218] Recovered cpus(allocated: 
storage/default-role):2; mem(allocated: storage/default-role):1024; 
disk(allocated: storage/default-role):1024; ports(allocated: 
storage/default-role):[31000-32000] (total: cpus:2; mem:1024; disk:1024; 
ports:[31000-32000], allocated: {}) on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 from framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.141052 18275 hierarchical.cpp:1264] Framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 filtered agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 for 5secs
I0710 18:19:28.156960 18270 http.cpp:1115] HTTP POST for 
/slave(1200)/api/v1/resource_provider from 172.17.0.2:59230
I0710 18:19:28.157719 18288 manager.cpp:1039] Received UPDATE_STATE call with 
resources 
'[{"disk":{"source":{"profile":"test","type":"RAW","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"1877f885-a47f-408a-a55e-a7194c423045"},"reservations":[{"role":"storage","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
 and 0 operations from resource provider 1877f885-a47f-408a-a55e-a7194c423045
I0710 18:19:28.158241 18283 slave.cpp:8217] Handling resource provider message 
'UPDATE_STATE: 1877f885-a47f-408a-a55e-a7194c423045 disk(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048'
I0710 18:19:28.158418 18283 slave.cpp:8337] Forwarding new total resources 
cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048
I0710 18:19:28.160778 18268 hierarchical.cpp:710] Agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 (e12b3ef9ecdc) updated with total 
resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048
I0710 18:19:28.162269 18268 hierarchical.cpp:1508] Performed allocation for 1 
agents in 1.222373ms
I0710 18:19:28.163028 18276 master.cpp:10195] Sending offers [ 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O1 ] to framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:28.163813 18274 sched.cpp:934] Scheduler::resourceOffers took 
89522ns
I0710 18:19:28.174217 18266 master.cpp:12470] Removing offer 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O1
I0710 18:19:28.174365 18284 hierarchical.cpp:1508] Performed allocation for 1 
agents in 361460ns
I0710 18:19:28.174882 18266 master.cpp:4636] Processing ACCEPT call for offers: 
[ e79cd135-44ed-4f64-85ab-8c65ec7d1714-O1 ] on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc) for framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 
(default) at scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:28.175025 18266 master.cpp:4009] Authorizing principal 
'test-principal' to create a MOUNT disk from 'disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048'
I0710 18:19:28.176112 18275 master.cpp:5911] Processing CREATE_DISK operation 
with source disk(allocated: storage/default-role)(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048 from 
framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975 to agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:28.176791 18275 master.cpp:12361] Sending operation '' (uuid: 
8125e4eb-f729-408d-b4f0-6c129aa5ae9f) to agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:28.177151 18269 hierarchical.cpp:1432] Allocation paused
I0710 18:19:28.177395 18267 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:28.178274 18269 hierarchical.cpp:1218] Recovered ports(allocated: 
storage/default-role):[31000-32000]; cpus(allocated: storage/default-role):2; 
mem(allocated: storage/default-role):1024; disk(allocated: 
storage/default-role):1024 (total: cpus:2; mem:1024; disk:1024; 
ports:[31000-32000]; disk(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048, 
allocated: disk(allocated: storage/default-role)(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048) on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 from framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.178372 18269 hierarchical.cpp:1264] Framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 filtered agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 for 5secs
I0710 18:19:28.178634 18269 hierarchical.cpp:1442] Allocation resumed
I0710 18:19:28.180131 18280 provider.cpp:481] Received APPLY_OPERATION event
I0710 18:19:28.180172 18280 provider.cpp:1295] Received CREATE_DISK operation 
'' (uuid: 8125e4eb-f729-408d-b4f0-6c129aa5ae9f)
I0710 18:19:28.227145 18276 hierarchical.cpp:2358] Filtered offer with cpus:2; 
mem:1024; disk:1024; ports:[31000-32000] on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 for role storage/default-role of 
framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.227329 18276 hierarchical.cpp:1508] Performed allocation for 1 
agents in 986715ns
I0710 18:19:28.235137 18274 v1_volume_manager.cpp:292] Creating volume with 
name '8125e4eb-f729-408d-b4f0-6c129aa5ae9f'
I0710 18:19:28.238116 32092 test_csi_plugin.cpp:922] CreateVolumeRequest 
'{"name":"8125e4eb-f729-408d-b4f0-6c129aa5ae9f","capacityRange":{"requiredBytes":"2147483648","limitBytes":"2147483648"},"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0710 18:19:28.278712 18279 hierarchical.cpp:2358] Filtered offer with cpus:2; 
mem:1024; disk:1024; ports:[31000-32000] on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 for role storage/default-role of 
framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.278975 18279 hierarchical.cpp:1508] Performed allocation for 1 
agents in 801951ns
I0710 18:19:28.328424 18273 provider.cpp:1597] Applying conversion from 
'disk(allocated: storage/default-role)(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' to 
'disk(allocated: storage/default-role)(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048'
 for operation (uuid: 8125e4eb-f729-408d-b4f0-6c129aa5ae9f)
I0710 18:19:28.330430 18275 hierarchical.cpp:2358] Filtered offer with cpus:2; 
mem:1024; disk:1024; ports:[31000-32000] on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 for role storage/default-role of 
framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.330579 18275 hierarchical.cpp:1508] Performed allocation for 1 
agents in 649237ns
I0710 18:19:28.378381 18287 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
e937d8ac-c505-4665-b290-f7111515104f) for operation UUID 
8125e4eb-f729-408d-b4f0-6c129aa5ae9f of framework 
'e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000' on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.378556 18287 status_update_manager_process.hpp:414] Creating 
operation status update stream 8125e4eb-f729-408d-b4f0-6c129aa5ae9f 
checkpoint=true
I0710 18:19:28.379253 18287 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: e937d8ac-c505-4665-b290-f7111515104f) for operation UUID 
8125e4eb-f729-408d-b4f0-6c129aa5ae9f of framework 
'e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000' on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.382218 18269 hierarchical.cpp:2358] Filtered offer with cpus:2; 
mem:1024; disk:1024; ports:[31000-32000] on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 for role storage/default-role of 
framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.382351 18269 hierarchical.cpp:1508] Performed allocation for 1 
agents in 621997ns
I0710 18:19:28.428452 18287 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
e937d8ac-c505-4665-b290-f7111515104f) for operation UUID 
8125e4eb-f729-408d-b4f0-6c129aa5ae9f of framework 
'e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000' on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.429533 18270 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:28.430689 18277 process.cpp:3671] Handling HTTP event for process 
'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider'
I0710 18:19:28.434026 18283 hierarchical.cpp:2358] Filtered offer with cpus:2; 
mem:1024; disk:1024; ports:[31000-32000] on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 for role storage/default-role of 
framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.434181 18283 hierarchical.cpp:1508] Performed allocation for 1 
agents in 770338ns
I0710 18:19:28.469142 18282 http.cpp:1115] HTTP POST for 
/slave(1200)/api/v1/resource_provider from 172.17.0.2:59230
I0710 18:19:28.470427 18281 slave.cpp:8217] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 8125e4eb-f729-408d-b4f0-6c129aa5ae9f) for 
framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (latest state: 
OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0710 18:19:28.470669 18281 slave.cpp:8670] Updating the state of operation 
with no ID (uuid: 8125e4eb-f729-408d-b4f0-6c129aa5ae9f) for framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (latest state: OPERATION_FINISHED, 
status update state: OPERATION_FINISHED)
I0710 18:19:28.471148 18281 slave.cpp:8424] Forwarding status update of 
operation with no ID (operation_uuid: 8125e4eb-f729-408d-b4f0-6c129aa5ae9f) for 
framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.471573 18272 master.cpp:12017] Updating the state of operation 
'' (uuid: 8125e4eb-f729-408d-b4f0-6c129aa5ae9f) for framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (latest state: OPERATION_PENDING, 
status update state: OPERATION_FINISHED)
I0710 18:19:28.472980 18284 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:28.473732 18266 hierarchical.cpp:956] Updated allocation of 
framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 from disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048 to 
disk(allocated: storage/default-role)(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048
I0710 18:19:28.474491 18277 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0710 18:19:28.474534 18266 hierarchical.cpp:1218] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048
 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048,
 allocated: {}) on agent e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 from framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.474686 18266 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
e937d8ac-c505-4665-b290-f7111515104f) for stream 
8125e4eb-f729-408d-b4f0-6c129aa5ae9f
I0710 18:19:28.474808 18266 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
e937d8ac-c505-4665-b290-f7111515104f) for operation UUID 
8125e4eb-f729-408d-b4f0-6c129aa5ae9f of framework 
'e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000' on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.487457 18276 hierarchical.cpp:1508] Performed allocation for 1 
agents in 1.581875ms
I0710 18:19:28.488250 18280 master.cpp:10195] Sending offers [ 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O2 ] to framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:28.489082 18265 sched.cpp:934] Scheduler::resourceOffers took 
125712ns
I0710 18:19:28.493477 18273 process.cpp:3671] Handling HTTP event for process 
'master' with path: '/master/api/v1'
I0710 18:19:28.495692 18278 http.cpp:1115] HTTP POST for /master/api/v1 from 
172.17.0.2:59234
I0710 18:19:28.496055 18278 http.cpp:263] Processing call RESERVE_RESOURCES
I0710 18:19:28.496798 18278 master.cpp:3721] Authorizing principal 
'test-principal' to reserve resources 'disk(reservations: 
[(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048'
I0710 18:19:28.498522 18268 master.cpp:12470] Removing offer 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O2
I0710 18:19:28.498795 18280 sched.cpp:960] Rescinded offer 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O2
I0710 18:19:28.498908 18280 sched.cpp:971] Scheduler::offerRescinded took 
29020ns
I0710 18:19:28.499430 18276 hierarchical.cpp:1218] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048;
 cpus(allocated: storage/default-role):2; mem(allocated: 
storage/default-role):1024; disk(allocated: storage/default-role):1024; 
ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; 
disk:1024; ports:[31000-32000]; disk(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048,
 allocated: {}) on agent e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 from framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.499557 18276 hierarchical.cpp:1264] Framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 filtered agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 for 5secs
I0710 18:19:28.501969 18281 master.cpp:12361] Sending operation '' (uuid: 
0a26c752-60d7-499a-804d-46859411f9b5) to agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:28.502660 18282 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:28.505834 18270 provider.cpp:481] Received APPLY_OPERATION event
I0710 18:19:28.505908 18270 provider.cpp:1295] Received RESERVE operation '' 
(uuid: 0a26c752-60d7-499a-804d-46859411f9b5)
I0710 18:19:28.536121 18266 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 8125e4eb-f729-408d-b4f0-6c129aa5ae9f
I0710 18:19:28.621700 18283 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
34889926-eb09-414b-9e39-d21d489c6470) for operation UUID 
0a26c752-60d7-499a-804d-46859411f9b5 on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.621855 18283 status_update_manager_process.hpp:414] Creating 
operation status update stream 0a26c752-60d7-499a-804d-46859411f9b5 
checkpoint=true
I0710 18:19:28.622504 18283 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: 34889926-eb09-414b-9e39-d21d489c6470) for operation UUID 
0a26c752-60d7-499a-804d-46859411f9b5 on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.697230 18283 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
34889926-eb09-414b-9e39-d21d489c6470) for operation UUID 
0a26c752-60d7-499a-804d-46859411f9b5 on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.698331 18278 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:28.699465 18277 process.cpp:3671] Handling HTTP event for process 
'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider'
I0710 18:19:28.703126 18280 hierarchical.cpp:1508] Performed allocation for 1 
agents in 1.554499ms
I0710 18:19:28.703919 18268 master.cpp:10195] Sending offers [ 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O3 ] to framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:28.704718 18276 sched.cpp:934] Scheduler::resourceOffers took 
82107ns
I0710 18:19:28.708495 18271 process.cpp:3671] Handling HTTP event for process 
'master' with path: '/master/api/v1'
I0710 18:19:28.710709 18279 http.cpp:1115] HTTP POST for /master/api/v1 from 
172.17.0.2:59236
I0710 18:19:28.711140 18279 http.cpp:263] Processing call CREATE_VOLUMES
I0710 18:19:28.712123 18279 master.cpp:3848] Authorizing principal 
'test-principal' to create volumes 
'[{"disk":{"persistence":{"id":"f9f2be01-6998-4d1a-a31a-7cc0634f5e05","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"},"volume":{"container_path":"volume","mode":"RW"}},"name":"disk","provider_id":{"value":"1877f885-a47f-408a-a55e-a7194c423045"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0710 18:19:28.714236 18286 master.cpp:12470] Removing offer 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O3
I0710 18:19:28.714409 18283 sched.cpp:960] Rescinded offer 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O3
I0710 18:19:28.714488 18283 sched.cpp:971] Scheduler::offerRescinded took 
23197ns
I0710 18:19:28.714941 18266 hierarchical.cpp:1218] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048;
 cpus(allocated: storage/default-role):2; mem(allocated: 
storage/default-role):1024; disk(allocated: storage/default-role):1024; 
ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; 
disk:1024; ports:[31000-32000]; disk(reservations: 
[(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048,
 allocated: {}) on agent e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 from framework 
e79cd135-44ed-4f
 64-85ab-8c65ec7d1714-0000
I0710 18:19:28.715063 18266 hierarchical.cpp:1264] Framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 filtered agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 for 5secs
I0710 18:19:28.717453 18270 master.cpp:12361] Sending operation '' (uuid: 
8f3bff95-6a8a-4093-b92d-79c2ddad1268) to agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:28.718219 18277 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:28.721416 18284 provider.cpp:481] Received APPLY_OPERATION event
I0710 18:19:28.721493 18284 provider.cpp:1295] Received CREATE operation '' 
(uuid: 8f3bff95-6a8a-4093-b92d-79c2ddad1268)
I0710 18:19:28.726598 18267 master.cpp:6233] Processing REVIVE call for 
framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:28.727195 18267 hierarchical.cpp:1365] Unsuppressed offers for 
roles { storage/default-role } of framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.727223 18267 hierarchical.cpp:1387] Revived roles { 
storage/default-role } of framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:28.728871 18267 hierarchical.cpp:1508] Performed allocation for 1 
agents in 1.404198ms
I0710 18:19:28.729324 18267 hierarchical.cpp:1508] Performed allocation for 1 
agents in 208814ns
I0710 18:19:28.729815 18273 master.cpp:10195] Sending offers [ 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O4 ] to framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:28.730573 18283 sched.cpp:934] Scheduler::resourceOffers took 
79416ns
I0710 18:19:28.740780 18285 http.cpp:1115] HTTP POST for 
/slave(1200)/api/v1/resource_provider from 172.17.0.2:59230
I0710 18:19:28.742146 18277 slave.cpp:8217] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 0a26c752-60d7-499a-804d-46859411f9b5) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0710 18:19:28.742452 18277 slave.cpp:8670] Updating the state of operation 
with no ID (uuid: 0a26c752-60d7-499a-804d-46859411f9b5) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0710 18:19:28.742516 18277 slave.cpp:8424] Forwarding status update of 
operation with no ID (operation_uuid: 0a26c752-60d7-499a-804d-46859411f9b5) for 
an operator API call
I0710 18:19:28.742980 18282 master.cpp:12017] Updating the state of operation 
'' (uuid: 0a26c752-60d7-499a-804d-46859411f9b5) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0710 18:19:28.743654 18281 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:28.823695 18283 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
d29768a0-b8bc-4059-8019-428b46ecbf88) for operation UUID 
8f3bff95-6a8a-4093-b92d-79c2ddad1268 on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.823828 18283 status_update_manager_process.hpp:414] Creating 
operation status update stream 8f3bff95-6a8a-4093-b92d-79c2ddad1268 
checkpoint=true
I0710 18:19:28.823915 18284 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0710 18:19:28.824409 18283 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: d29768a0-b8bc-4059-8019-428b46ecbf88) for operation UUID 
8f3bff95-6a8a-4093-b92d-79c2ddad1268 on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.890337 18283 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
d29768a0-b8bc-4059-8019-428b46ecbf88) for operation UUID 
8f3bff95-6a8a-4093-b92d-79c2ddad1268 on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.890831 18283 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
34889926-eb09-414b-9e39-d21d489c6470) for stream 
0a26c752-60d7-499a-804d-46859411f9b5
I0710 18:19:28.890911 18283 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
34889926-eb09-414b-9e39-d21d489c6470) for operation UUID 
0a26c752-60d7-499a-804d-46859411f9b5 on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:28.891522 18266 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:28.892653 18278 process.cpp:3671] Handling HTTP event for process 
'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider'
I0710 18:19:28.932821 18271 http.cpp:1115] HTTP POST for 
/slave(1200)/api/v1/resource_provider from 172.17.0.2:59230
I0710 18:19:28.934157 18274 slave.cpp:8217] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 8f3bff95-6a8a-4093-b92d-79c2ddad1268) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0710 18:19:28.934478 18274 slave.cpp:8670] Updating the state of operation 
with no ID (uuid: 8f3bff95-6a8a-4093-b92d-79c2ddad1268) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0710 18:19:28.934540 18274 slave.cpp:8424] Forwarding status update of 
operation with no ID (operation_uuid: 8f3bff95-6a8a-4093-b92d-79c2ddad1268) for 
an operator API call
I0710 18:19:28.935040 18272 master.cpp:12017] Updating the state of operation 
'' (uuid: 8f3bff95-6a8a-4093-b92d-79c2ddad1268) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0710 18:19:28.935698 18276 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:28.937294 18270 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0710 18:19:28.957085 18283 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 0a26c752-60d7-499a-804d-46859411f9b5
I0710 18:19:28.957355 18283 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
d29768a0-b8bc-4059-8019-428b46ecbf88) for stream 
8f3bff95-6a8a-4093-b92d-79c2ddad1268
I0710 18:19:28.957458 18283 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
d29768a0-b8bc-4059-8019-428b46ecbf88) for operation UUID 
8f3bff95-6a8a-4093-b92d-79c2ddad1268 on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:29.049270 18283 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 8f3bff95-6a8a-4093-b92d-79c2ddad1268
I0710 18:19:29.255816 18282 process.cpp:3671] Handling HTTP event for process 
'master' with path: '/master/api/v1'
I0710 18:19:29.257936 18279 http.cpp:1115] HTTP POST for /master/api/v1 from 
172.17.0.2:59238
I0710 18:19:29.258469 18279 http.cpp:263] Processing call DESTROY_VOLUMES
I0710 18:19:29.260020 18279 master.cpp:3893] Authorizing principal 
'test-principal' to destroy volumes 
'[{"disk":{"persistence":{"id":"f9f2be01-6998-4d1a-a31a-7cc0634f5e05","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"},"volume":{"container_path":"volume","mode":"RW"}},"name":"disk","provider_id":{"value":"1877f885-a47f-408a-a55e-a7194c423045"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0710 18:19:29.262686 18276 master.cpp:12470] Removing offer 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O4
I0710 18:19:29.262871 18267 sched.cpp:960] Rescinded offer 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O4
I0710 18:19:29.262960 18267 sched.cpp:971] Scheduler::offerRescinded took 
27313ns
I0710 18:19:29.263631 18273 hierarchical.cpp:1218] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test),f9f2be01-6998-4d1a-a31a-7cc0634f5e05:volume]:2048;
 cpus(allocated: storage/default-role):2; mem(allocated: 
storage/default-role):1024; disk(allocated: storage/default-role):1024; 
ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; 
disk:1024; ports:[31000-32000]; disk(reservations: 
[(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test),f9f2be01-6998-4d1a-a31a-7cc0634f5e05:volume]:2048,
 allocat
 ed: {}) on agent e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 from framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:29.263756 18273 hierarchical.cpp:1264] Framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 filtered agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 for 5secs
I0710 18:19:29.266412 18286 master.cpp:12361] Sending operation '' (uuid: 
2908e76e-1742-4508-a58c-2fba0d11bcdd) to agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:29.266957 18284 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:29.270370 18282 provider.cpp:481] Received APPLY_OPERATION event
I0710 18:19:29.270437 18282 provider.cpp:1295] Received DESTROY operation '' 
(uuid: 2908e76e-1742-4508-a58c-2fba0d11bcdd)
I0710 18:19:29.275267 18272 hierarchical.cpp:1508] Performed allocation for 1 
agents in 1.46004ms
I0710 18:19:29.275995 18287 master.cpp:10195] Sending offers [ 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O5 ] to framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:29.277012 18279 sched.cpp:934] Scheduler::resourceOffers took 
116325ns
I0710 18:19:29.369099 18269 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
3bf463bd-215e-454d-81af-430730b3c919) for operation UUID 
2908e76e-1742-4508-a58c-2fba0d11bcdd on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:29.369266 18269 status_update_manager_process.hpp:414] Creating 
operation status update stream 2908e76e-1742-4508-a58c-2fba0d11bcdd 
checkpoint=true
I0710 18:19:29.369904 18269 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: 3bf463bd-215e-454d-81af-430730b3c919) for operation UUID 
2908e76e-1742-4508-a58c-2fba0d11bcdd on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:29.435403 18269 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
3bf463bd-215e-454d-81af-430730b3c919) for operation UUID 
2908e76e-1742-4508-a58c-2fba0d11bcdd on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:29.436755 18267 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:29.438258 18266 process.cpp:3671] Handling HTTP event for process 
'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider'
I0710 18:19:29.441679 18270 process.cpp:3671] Handling HTTP event for process 
'master' with path: '/master/api/v1'
I0710 18:19:29.443490 18277 http.cpp:1115] HTTP POST for /master/api/v1 from 
172.17.0.2:59240
I0710 18:19:29.443786 18277 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0710 18:19:29.444465 18277 master.cpp:3785] Authorizing principal 
'test-principal' to unreserve resources 
'[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"1877f885-a47f-408a-a55e-a7194c423045"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0710 18:19:29.446391 18268 master.cpp:12470] Removing offer 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O5
I0710 18:19:29.446593 18272 sched.cpp:960] Rescinded offer 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O5
I0710 18:19:29.446676 18272 sched.cpp:971] Scheduler::offerRescinded took 
27434ns
I0710 18:19:29.447307 18281 hierarchical.cpp:1218] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048;
 cpus(allocated: storage/default-role):2; mem(allocated: 
storage/default-role):1024; disk(allocated: storage/default-role):1024; 
ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; 
disk:1024; ports:[31000-32000]; disk(reservations: 
[(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048,
 allocated: {}) on agent e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 from framework 
e79cd135-44ed-4f
 64-85ab-8c65ec7d1714-0000
I0710 18:19:29.447432 18281 hierarchical.cpp:1264] Framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 filtered agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 for 5secs
I0710 18:19:29.449656 18287 master.cpp:12361] Sending operation '' (uuid: 
80e011bf-f19c-469c-9ecf-ca1a748bdebf) to agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:29.450224 18269 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:29.452736 18283 provider.cpp:481] Received APPLY_OPERATION event
I0710 18:19:29.452786 18283 provider.cpp:1295] Received UNRESERVE operation '' 
(uuid: 80e011bf-f19c-469c-9ecf-ca1a748bdebf)
I0710 18:19:29.462713 18265 hierarchical.cpp:1508] Performed allocation for 1 
agents in 1.280671ms
I0710 18:19:29.463522 18277 master.cpp:10195] Sending offers [ 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O6 ] to framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:29.464221 18274 sched.cpp:934] Scheduler::resourceOffers took 
76583ns
I0710 18:19:29.476868 18279 http.cpp:1115] HTTP POST for 
/slave(1200)/api/v1/resource_provider from 172.17.0.2:59230
I0710 18:19:29.477941 18282 slave.cpp:8217] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 2908e76e-1742-4508-a58c-2fba0d11bcdd) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0710 18:19:29.478144 18282 slave.cpp:8670] Updating the state of operation 
with no ID (uuid: 2908e76e-1742-4508-a58c-2fba0d11bcdd) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0710 18:19:29.478191 18282 slave.cpp:8424] Forwarding status update of 
operation with no ID (operation_uuid: 2908e76e-1742-4508-a58c-2fba0d11bcdd) for 
an operator API call
I0710 18:19:29.478530 18269 master.cpp:12017] Updating the state of operation 
'' (uuid: 2908e76e-1742-4508-a58c-2fba0d11bcdd) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0710 18:19:29.479130 18273 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:29.603513 18274 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
e0133de8-a184-4b8f-a830-df18faff2d79) for operation UUID 
80e011bf-f19c-469c-9ecf-ca1a748bdebf on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:29.603617 18274 status_update_manager_process.hpp:414] Creating 
operation status update stream 80e011bf-f19c-469c-9ecf-ca1a748bdebf 
checkpoint=true
I0710 18:19:29.603677 18283 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0710 18:19:29.604203 18274 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: e0133de8-a184-4b8f-a830-df18faff2d79) for operation UUID 
80e011bf-f19c-469c-9ecf-ca1a748bdebf on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:29.670435 18274 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
e0133de8-a184-4b8f-a830-df18faff2d79) for operation UUID 
80e011bf-f19c-469c-9ecf-ca1a748bdebf on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:29.670955 18274 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
3bf463bd-215e-454d-81af-430730b3c919) for stream 
2908e76e-1742-4508-a58c-2fba0d11bcdd
I0710 18:19:29.671049 18274 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
3bf463bd-215e-454d-81af-430730b3c919) for operation UUID 
2908e76e-1742-4508-a58c-2fba0d11bcdd on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:29.671445 18272 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:29.672569 18287 process.cpp:3671] Handling HTTP event for process 
'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider'
I0710 18:19:29.712952 18266 http.cpp:1115] HTTP POST for 
/slave(1200)/api/v1/resource_provider from 172.17.0.2:59230
I0710 18:19:29.714032 18286 slave.cpp:8217] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 80e011bf-f19c-469c-9ecf-ca1a748bdebf) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0710 18:19:29.714252 18286 slave.cpp:8670] Updating the state of operation 
with no ID (uuid: 80e011bf-f19c-469c-9ecf-ca1a748bdebf) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0710 18:19:29.714303 18286 slave.cpp:8424] Forwarding status update of 
operation with no ID (operation_uuid: 80e011bf-f19c-469c-9ecf-ca1a748bdebf) for 
an operator API call
I0710 18:19:29.714730 18270 master.cpp:12017] Updating the state of operation 
'' (uuid: 80e011bf-f19c-469c-9ecf-ca1a748bdebf) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0710 18:19:29.715322 18288 slave.cpp:4198] Ignoring new checkpointed resources 
and operations identical to the current version
I0710 18:19:29.716696 18268 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0710 18:19:29.737282 18274 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 2908e76e-1742-4508-a58c-2fba0d11bcdd
I0710 18:19:29.737641 18274 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
e0133de8-a184-4b8f-a830-df18faff2d79) for stream 
80e011bf-f19c-469c-9ecf-ca1a748bdebf
I0710 18:19:29.737759 18274 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
e0133de8-a184-4b8f-a830-df18faff2d79) for operation UUID 
80e011bf-f19c-469c-9ecf-ca1a748bdebf on agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:29.829489 18274 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 80e011bf-f19c-469c-9ecf-ca1a748bdebf
I0710 18:19:29.898327 18267 master.cpp:1410] Framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975 disconnected
I0710 18:19:29.898414 18267 master.cpp:3342] Deactivating framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:29.898816 18266 hierarchical.cpp:475] Deactivated framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:29.899682 18267 master.cpp:12470] Removing offer 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-O6
I0710 18:19:29.899796 18267 master.cpp:3319] Disconnecting framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:29.899902 18264 slave.cpp:912] Agent terminating
I0710 18:19:29.899966 18267 master.cpp:1425] Giving framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975 0ns to failover
I0710 18:19:29.900481 18266 hierarchical.cpp:1218] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048;
 cpus(allocated: storage/default-role):2; mem(allocated: 
storage/default-role):1024; disk(allocated: storage/default-role):1024; 
ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; 
disk:1024; ports:[31000-32000]; disk(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_MVT5vY/2GB-8125e4eb-f729-408d-b4f0-6c129aa5ae9f,test)]:2048,
 allocated: {}) on agent e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 from framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:29.900789 18264 manager.cpp:163] Terminating resource provider 
1877f885-a47f-408a-a55e-a7194c423045
I0710 18:19:29.901252 18282 master.cpp:1295] Agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc) disconnected
I0710 18:19:29.901280 18282 master.cpp:3379] Disconnecting agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:29.901366 18282 master.cpp:3398] Deactivating agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 at slave(1200)@172.17.0.2:37975 
(e12b3ef9ecdc)
I0710 18:19:29.901526 18273 hierarchical.cpp:799] Agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0 deactivated
I0710 18:19:29.901558 18282 master.cpp:9987] Framework failover timeout, 
removing framework e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
I0710 18:19:29.901589 18282 master.cpp:10979] Removing framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000 (default) at 
scheduler-2a54bab4-e021-4680-8e5a-f7adbfef0953@172.17.0.2:37975
E0710 18:19:29.901926 18276 http_connection.hpp:452] End-Of-File received
I0710 18:19:29.902154 18280 hierarchical.cpp:1432] Allocation paused
I0710 18:19:29.902593 18280 hierarchical.cpp:417] Removed framework 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-0000
I0710 18:19:29.902715 18280 hierarchical.cpp:1442] Allocation resumed
I0710 18:19:29.902854 18276 http_connection.hpp:217] Re-detecting endpoint
I0710 18:19:29.903324 18276 http_connection.hpp:338] Ignoring disconnection 
attempt from stale connection
I0710 18:19:29.903394 18268 provider.cpp:471] Disconnected from resource 
provider manager
I0710 18:19:29.903426 18276 http_connection.hpp:338] Ignoring disconnection 
attempt from stale connection
I0710 18:19:29.903497 18268 status_update_manager_process.hpp:379] Pausing 
operation status update manager
I0710 18:19:29.903587 18276 http_connection.hpp:227] New endpoint detected at 
http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:29.905181 18282 containerizer.cpp:2575] Destroying container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 in RUNNING state
I0710 18:19:29.905215 18282 containerizer.cpp:3277] Transitioning the state of 
container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 from RUNNING to DESTROYING
I0710 18:19:29.905596 18282 launcher.cpp:161] Asked to destroy container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0710 18:19:29.906571 18285 http_connection.hpp:283] Connected with the remote 
endpoint at http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:29.906934 18271 hierarchical.cpp:1508] Performed allocation for 1 
agents in 256448ns
I0710 18:19:29.907325 18283 provider.cpp:459] Connected to resource provider 
manager
I0710 18:19:29.907963 18266 http_connection.hpp:131] Sending 1 call to 
http://172.17.0.2:37975/slave(1200)/api/v1/resource_provider
I0710 18:19:29.908725 18289 process.cpp:2781] Returning '404 Not Found' for 
'/slave(1200)/api/v1/resource_provider'
E0710 18:19:29.909910 18279 provider.cpp:702] Failed to subscribe resource 
provider with type 'org.apache.mesos.rp.local.storage' and name 'test': 
Received '404 Not Found' ()
I0710 18:19:29.957996 18273 hierarchical.cpp:1508] Performed allocation for 1 
agents in 194259ns
I0710 18:19:30.009065 18278 containerizer.cpp:3116] Container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 has exited
I0710 18:19:30.009605 18265 hierarchical.cpp:1508] Performed allocation for 1 
agents in 199085ns
I0710 18:19:30.010592 18267 provisioner.cpp:609] Ignoring destroy request for 
unknown container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0710 18:19:30.013105 18270 container_daemon.cpp:189] Invoking post-stop hook 
for container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0710 18:19:30.013298 18273 service_manager.cpp:723] Disconnected from endpoint 
'unix:///tmp/mesos-csi-YWF1fy/endpoint.sock' of CSI plugin container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0710 18:19:30.013533 18288 container_daemon.cpp:121] Launching container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0710 18:19:30.016075 18289 process.cpp:2781] Returning '404 Not Found' for 
'/slave(1200)/api/v1'
I0710 18:19:30.025835 18264 master.cpp:1135] Master terminating
I0710 18:19:30.026612 18269 hierarchical.cpp:775] Removed all filters for agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
I0710 18:19:30.026638 18269 hierarchical.cpp:650] Removed agent 
e79cd135-44ed-4f64-85ab-8c65ec7d1714-S0
[       OK ] 
CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1
 (2614 ms)
[----------] 50 tests from CSIVersion/StorageLocalResourceProviderTest (137047 
ms total)

[----------] Global test environment tear-down
[==========] 2265 tests from 216 test cases ran. (1218913 ms total)
[  PASSED  ] 2263 tests.
[  FAILED  ] 2 tests, listed below:
[  FAILED  ] SlaveTest.AgentFailoverHTTPExecutorUsingResourceProviderResources
[  FAILED  ] CSIVersion/StorageLocalResourceProviderTest.OperationUpdate/v0, 
where GetParam() = "v0"

 2 FAILED TESTS
  YOU HAVE 31 DISABLED TESTS

I0710 18:19:30.124083 18289 process.cpp:935] Stopped the socket accept loop
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-1.9.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.9.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.9.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.9.0/_build'
make: *** [distcheck] Error 1
+ docker rmi --force mesos-1562776977-27186
Untagged: mesos-1562776977-27186:latest
Deleted: sha256:bf1b1c9919faf14c51d7b8233ae41c74ce670303654a9d4c1e69654f22e1b169
Deleted: sha256:3ce15ca8220c1f9edfe0f63314684209590d8d8aab655a5a533d4fe94bb679c5
Deleted: sha256:5462f9a3d6388bc8cb8e7b36e44d26d8f32ad4bfbbdbf3e7175c4ba79530ff3c
Deleted: sha256:931f037b34e9117d6249a7e4e8df117b68ad245949423c92cd07126051730962
Deleted: sha256:228279e282fbf56385c8516543adc7b949e7f630e6f1bceea88f8d81b11c2a0d
Deleted: sha256:b0333072005406213454bf254c21b20a77e483087497490d4f26d8fc7992adf6
Deleted: sha256:f0b2d3c2ccd34c6029fd63346557886911b1292eecf79e144d7eb8c6e6b3bf85
Deleted: sha256:0ef7adf1c77559a935930c3642dad842a8a6a50efebc8dbf3fe3dd4034ebd9b4
Deleted: sha256:5a9a00a1fb67834cb214acca2591ecd00ae0beeab58f7ae91fe6e42e0c89e96a
Deleted: sha256:3e32fe0b26dffb358ab687cb1b6286dba50142d1888e4e82d14245ad47e4e6f5
Deleted: sha256:714ce1f5321bb7581057a61ae245615b436bed2a5582abf0ac342230e43e38da
Deleted: sha256:0343a5dbde7419b5c2b9dcd9a0ae1a3adde41b2c6c4ee2b30ef9b127092fee37
Deleted: sha256:2226b4c531126c2fe339db573d0bfcdefb0ca85de110209d31397bb82873ae30
Deleted: sha256:0a99fb45d40509717c29d529215996ba6042ca0ef587869fe924249d56f819d3
Deleted: sha256:6d9d9a481e5b43c5cd8ce9be2ca191ac1ee5b74911c1913cc10119ca43fcde17
Deleted: sha256:1541ae4d62d2f7ad95f72a20fd630a6adf8963be69af77e96f756eb03c5ee846
Deleted: sha256:2c917c93b888bcca9fa05383a618024818589c8cbf89cf9aad1173121d2290de
Deleted: sha256:45a3c73bd61573eb3ad237da70b184db93fdab991a7c53e679d827bba01ab933
Deleted: sha256:ea10ca23cba1558c0c3e05b5e8682160c418ba8dd81048f494c8b482e76388b2
Deleted: sha256:3561bf314cac6ac05dd6b3a472176df565bb426776e288bb9fac3ab4243ed7da
Deleted: sha256:0f3728f8b98b28099e1add395459a0d5a025bb0461a8d213f24fe8c65b348bdd
Deleted: sha256:b977c5a9cbb92b8c0bf84ed3a570093547748f008b379551f60ddbee9219235a
Deleted: sha256:033f05cf8e508a7e173059ef298d16258a63fca000e0ab10d10f3eeadee7751f
Deleted: sha256:4393591473846279e0dd7169eb626c89b4b483829dc1eaee2ebd5f5135b195d8
Deleted: sha256:1260b09efbb2b07dccb3c9a5c8ab1c7110271c8fb28f92a632400cb626f986b9
Deleted: sha256:5fee73965c0fb230c45cebd77b2e76cc6ddbd7e1d76123d06fcf9e2794c07f38
Deleted: sha256:c53b1abc476c507a9ad6e02a480282afa6e392a72c8c46140c316b67dfc2f3d0
Deleted: sha256:428452c5e76460cdc65a122e2bc9404f4d495b1fc1c3d41b5ddfcb7535044833
Deleted: sha256:1fedd49b5e838335f104cc8ed41fef6378e63898b5b836276786fa9256e6b9af
Deleted: sha256:f09fd816579faa2cee7125d5d163904fd95a30c229cb2b4b47ba8b10b5c69122
Deleted: sha256:2c5e00d77a67934d5e39493477f262b878f127b9c01b491f06d8f06f78819578
Deleted: sha256:664a2bb343be8b1a691e0ce9c563ee654c30a1c694dc1b25ebb5467fa3d074fd
Deleted: sha256:4ac0c5a114c714b429ff471f5415974618e0b6fc743070d445cd0e2ac586cc7b
Deleted: sha256:5f200444c0009c41eb39bc1cf37a5b3c2e953478f2f373c5a1873dee820e0ced
Deleted: sha256:b057ab380990c219581e3b074919413ebe31079cbd0d615f63872c471b4dc633

Full log: https://builds.apache.org/job/Mesos-Reviewbot-Linux/2478/console

- Mesos Reviewbot


On July 10, 2019, 2:58 p.m., Benno Evers wrote:
> 
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/70528/
> -----------------------------------------------------------
> 
> (Updated July 10, 2019, 2:58 p.m.)
> 
> 
> Review request for mesos, Greg Mann, Joseph Wu, and Till Toenshoff.
> 
> 
> Repository: mesos
> 
> 
> Description
> -------
> 
> Updated the release guide in `docs/release-guide.md` to match
> the de-facto process we're using to release new versions.
> 
> Also mentioned some additional third-party tooling to the post-release
> desription.
> 
> 
> Diffs
> -----
> 
>   docs/release-guide.md a3ad2668a1953a7f20dd7209e122481ad8b30f17 
> 
> 
> Diff: https://reviews.apache.org/r/70528/diff/3/
> 
> 
> Testing
> -------
> 
> Released Mesos 1.8.0 according to this procedure.
> 
> 
> Thanks,
> 
> Benno Evers
> 
>

Reply via email to