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



Bad patch!

Reviews applied: [71314, 71315, 71316, 71317, 71318]

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_71318"]

Error:
...<truncated>...
ing HTTP event for process 'slave(1240)' with path: 
'/slave(1240)/api/v1/resource_provider'
I0820 07:50:11.134178 18977 process.cpp:3671] Handling HTTP event for process 
'master' with path: '/master/api/v1'
I0820 07:50:11.136255 18983 http.cpp:1115] HTTP POST for /master/api/v1 from 
172.17.0.2:46860
I0820 07:50:11.136601 18983 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0820 07:50:11.137399 18983 master.cpp:3890] Authorizing principal 
'test-principal' to unreserve resources 
'[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_4LEQKF/2GB-4bfda151-3c6d-428e-9b92-057a0bcd0189","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":"ef3efb14-ec6b-4a26-8592-a333164a26c0"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0820 07:50:11.139417 18990 master.cpp:12724] Removing offer 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-O5
I0820 07:50:11.139562 18978 sched.cpp:960] Rescinded offer 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-O5
I0820 07:50:11.139645 18978 sched.cpp:971] Scheduler::offerRescinded took 
24196ns
I0820 07:50:11.140141 18984 hierarchical.cpp:1454] 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_4LEQKF/2GB-4bfda151-3c6d-428e-9b92-057a0bcd0189,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_4LEQKF/2GB-4bfda151-3c6d-428e-9b92-057a0bcd0189,test)]:2048,
 allocated: {}) on agent ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0 from framework 
ff5d03c7-8ace-4a
 c1-9805-a49e0efcef9a-0000
I0820 07:50:11.140281 18984 hierarchical.cpp:1500] Framework 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-0000 filtered agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0 for 5secs
I0820 07:50:11.143219 18971 master.cpp:12615] Sending operation '' (uuid: 
92442653-a3ee-4107-af40-5265520d0471) to agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0 at slave(1240)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:11.143769 18974 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:11.146616 18973 provider.cpp:481] Received APPLY_OPERATION event
I0820 07:50:11.146670 18973 provider.cpp:1295] Received UNRESERVE operation '' 
(uuid: 92442653-a3ee-4107-af40-5265520d0471)
I0820 07:50:11.154505 18992 hierarchical.cpp:1740] Performed allocation for 1 
agents in 1.230229ms
I0820 07:50:11.155087 18969 master.cpp:10432] Sending offers [ 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-O6 ] to framework 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-0000 (default) at 
scheduler-b0e65a5f-97b3-4e6c-ac42-c42e2b7b34a8@172.17.0.2:39167
I0820 07:50:11.155699 18983 sched.cpp:934] Scheduler::resourceOffers took 
75678ns
I0820 07:50:11.173789 18971 http.cpp:1115] HTTP POST for 
/slave(1240)/api/v1/resource_provider from 172.17.0.2:46850
I0820 07:50:11.174675 18972 slave.cpp:8423] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 2a859ec5-d153-4dbf-b341-51e0fd80bd0d) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0820 07:50:11.174861 18972 slave.cpp:8876] Updating the state of operation 
with no ID (uuid: 2a859ec5-d153-4dbf-b341-51e0fd80bd0d) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0820 07:50:11.174917 18972 slave.cpp:8630] Forwarding status update of 
operation with no ID (operation_uuid: 2a859ec5-d153-4dbf-b341-51e0fd80bd0d) for 
an operator API call
I0820 07:50:11.175410 18974 master.cpp:12271] Updating the state of operation 
'' (uuid: 2a859ec5-d153-4dbf-b341-51e0fd80bd0d) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0820 07:50:11.175925 18987 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:11.237556 18983 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
6ea1402f-1fef-45b6-9b94-c770aa21980b) for operation UUID 
92442653-a3ee-4107-af40-5265520d0471 on agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0
I0820 07:50:11.237639 18983 status_update_manager_process.hpp:414] Creating 
operation status update stream 92442653-a3ee-4107-af40-5265520d0471 
checkpoint=true
I0820 07:50:11.237643 18973 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0820 07:50:11.238073 18983 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: 6ea1402f-1fef-45b6-9b94-c770aa21980b) for operation UUID 
92442653-a3ee-4107-af40-5265520d0471 on agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0
I0820 07:50:11.304503 18983 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
6ea1402f-1fef-45b6-9b94-c770aa21980b) for operation UUID 
92442653-a3ee-4107-af40-5265520d0471 on agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0
I0820 07:50:11.304883 18983 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
394eda8c-3f59-4206-96a5-9915ea004465) for stream 
2a859ec5-d153-4dbf-b341-51e0fd80bd0d
I0820 07:50:11.304961 18983 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
394eda8c-3f59-4206-96a5-9915ea004465) for operation UUID 
2a859ec5-d153-4dbf-b341-51e0fd80bd0d on agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0
I0820 07:50:11.305425 18988 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:39167/slave(1240)/api/v1/resource_provider
I0820 07:50:11.306582 18984 process.cpp:3671] Handling HTTP event for process 
'slave(1240)' with path: '/slave(1240)/api/v1/resource_provider'
I0820 07:50:11.346109 18986 http.cpp:1115] HTTP POST for 
/slave(1240)/api/v1/resource_provider from 172.17.0.2:46850
I0820 07:50:11.347250 18989 slave.cpp:8423] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 92442653-a3ee-4107-af40-5265520d0471) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0820 07:50:11.347431 18989 slave.cpp:8876] Updating the state of operation 
with no ID (uuid: 92442653-a3ee-4107-af40-5265520d0471) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0820 07:50:11.347482 18989 slave.cpp:8630] Forwarding status update of 
operation with no ID (operation_uuid: 92442653-a3ee-4107-af40-5265520d0471) for 
an operator API call
I0820 07:50:11.347893 18976 master.cpp:12271] Updating the state of operation 
'' (uuid: 92442653-a3ee-4107-af40-5265520d0471) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0820 07:50:11.348466 18977 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:11.350119 18978 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0820 07:50:11.371372 18983 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 2a859ec5-d153-4dbf-b341-51e0fd80bd0d
I0820 07:50:11.371716 18983 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
6ea1402f-1fef-45b6-9b94-c770aa21980b) for stream 
92442653-a3ee-4107-af40-5265520d0471
I0820 07:50:11.371809 18983 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
6ea1402f-1fef-45b6-9b94-c770aa21980b) for operation UUID 
92442653-a3ee-4107-af40-5265520d0471 on agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0
I0820 07:50:11.463675 18983 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 92442653-a3ee-4107-af40-5265520d0471
I0820 07:50:11.531983 18980 master.cpp:1412] Framework 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-0000 (default) at 
scheduler-b0e65a5f-97b3-4e6c-ac42-c42e2b7b34a8@172.17.0.2:39167 disconnected
I0820 07:50:11.532042 18980 master.cpp:3362] Deactivating framework 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-0000 (default) at 
scheduler-b0e65a5f-97b3-4e6c-ac42-c42e2b7b34a8@172.17.0.2:39167
I0820 07:50:11.532521 18986 hierarchical.cpp:707] Deactivated framework 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-0000
I0820 07:50:11.533011 18968 slave.cpp:924] Agent terminating
I0820 07:50:11.533154 18980 master.cpp:12724] Removing offer 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-O6
I0820 07:50:11.533228 18980 master.cpp:3339] Disconnecting framework 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-0000 (default) at 
scheduler-b0e65a5f-97b3-4e6c-ac42-c42e2b7b34a8@172.17.0.2:39167
I0820 07:50:11.533288 18980 master.cpp:1427] Giving framework 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-0000 (default) at 
scheduler-b0e65a5f-97b3-4e6c-ac42-c42e2b7b34a8@172.17.0.2:39167 0ns to failover
I0820 07:50:11.534062 18968 manager.cpp:163] Terminating resource provider 
ef3efb14-ec6b-4a26-8592-a333164a26c0
I0820 07:50:11.534027 18986 hierarchical.cpp:1454] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_4LEQKF/2GB-4bfda151-3c6d-428e-9b92-057a0bcd0189,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_4LEQKF/2GB-4bfda151-3c6d-428e-9b92-057a0bcd0189,test)]:2048,
 allocated: {}) on agent ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0 from framework 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-0000
I0820 07:50:11.534631 18983 master.cpp:10224] Framework failover timeout, 
removing framework ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-0000 (default) at 
scheduler-b0e65a5f-97b3-4e6c-ac42-c42e2b7b34a8@172.17.0.2:39167
I0820 07:50:11.534662 18983 master.cpp:11223] Removing framework 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-0000 (default) at 
scheduler-b0e65a5f-97b3-4e6c-ac42-c42e2b7b34a8@172.17.0.2:39167
I0820 07:50:11.535022 18972 hierarchical.cpp:1664] Allocation paused
E0820 07:50:11.535404 18970 http_connection.hpp:452] End-Of-File received
I0820 07:50:11.535509 18972 hierarchical.cpp:649] Removed framework 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-0000
I0820 07:50:11.535614 18983 master.cpp:1297] Agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0 at slave(1240)@172.17.0.2:39167 
(a6f681cf2c75) disconnected
I0820 07:50:11.535647 18983 master.cpp:3399] Disconnecting agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0 at slave(1240)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:11.535651 18972 hierarchical.cpp:1674] Allocation resumed
I0820 07:50:11.535737 18983 master.cpp:3418] Deactivating agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0 at slave(1240)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:11.535837 18970 http_connection.hpp:217] Re-detecting endpoint
I0820 07:50:11.535872 18981 hierarchical.cpp:1035] Agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0 deactivated
I0820 07:50:11.536242 18970 http_connection.hpp:227] New endpoint detected at 
http://172.17.0.2:39167/slave(1240)/api/v1/resource_provider
I0820 07:50:11.536378 18969 provider.cpp:471] Disconnected from resource 
provider manager
I0820 07:50:11.536424 18970 http_connection.hpp:338] Ignoring disconnection 
attempt from stale connection
I0820 07:50:11.536481 18970 http_connection.hpp:338] Ignoring disconnection 
attempt from stale connection
I0820 07:50:11.536607 18990 status_update_manager_process.hpp:379] Pausing 
operation status update manager
I0820 07:50:11.537741 18989 containerizer.cpp:2616] Destroying container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 in RUNNING state
I0820 07:50:11.537788 18989 containerizer.cpp:3319] 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 after 2.522831744secs
I0820 07:50:11.538154 18989 launcher.cpp:161] Asked to destroy container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0820 07:50:11.540104 18985 hierarchical.cpp:1740] Performed allocation for 1 
agents in 236979ns
I0820 07:50:11.541126 18988 http_connection.hpp:283] Connected with the remote 
endpoint at http://172.17.0.2:39167/slave(1240)/api/v1/resource_provider
I0820 07:50:11.541605 18990 provider.cpp:459] Connected to resource provider 
manager
I0820 07:50:11.542309 18978 http_connection.hpp:131] Sending 1 call to 
http://172.17.0.2:39167/slave(1240)/api/v1/resource_provider
I0820 07:50:11.543268 18993 process.cpp:2781] Returning '404 Not Found' for 
'/slave(1240)/api/v1/resource_provider'
E0820 07:50:11.544579 18972 provider.cpp:702] Failed to subscribe resource 
provider with type 'org.apache.mesos.rp.local.storage' and name 'test': 
Received '404 Not Found' ()
I0820 07:50:11.592396 18983 hierarchical.cpp:1740] Performed allocation for 1 
agents in 196778ns
I0820 07:50:11.642464 18985 containerizer.cpp:3157] Container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 has exited
I0820 07:50:11.643797 18973 hierarchical.cpp:1740] Performed allocation for 1 
agents in 111193ns
I0820 07:50:11.643945 18988 provisioner.cpp:612] Ignoring destroy request for 
unknown container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0820 07:50:11.646574 18983 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'
I0820 07:50:11.646760 18983 service_manager.cpp:723] Disconnected from endpoint 
'unix:///tmp/mesos-csi-K2oAQF/endpoint.sock' of CSI plugin container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0820 07:50:11.647030 18981 container_daemon.cpp:121] Launching container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0820 07:50:11.649976 18993 process.cpp:2781] Returning '404 Not Found' for 
'/slave(1240)/api/v1'
I0820 07:50:11.658731 18979 master.cpp:1137] Master terminating
I0820 07:50:11.659461 18971 hierarchical.cpp:1011] Removed all filters for 
agent ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0
I0820 07:50:11.659494 18971 hierarchical.cpp:886] Removed agent 
ff5d03c7-8ace-4ac1-9805-a49e0efcef9a-S0
[       OK ] 
CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v0
 (2402 ms)
[ RUN      ] 
CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1
I0820 07:50:11.672829 18968 cluster.cpp:177] Creating default 'local' authorizer
I0820 07:50:11.677028 18975 master.cpp:440] Master 
43219129-6529-4c4a-aa0c-06bf579390d3 (a6f681cf2c75) started on 172.17.0.2:39167
I0820 07:50:11.677052 18975 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/hyLcno/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/hyLcno/master" --zk_session_timeout="10secs"
I0820 07:50:11.677453 18975 master.cpp:492] Master only allowing authenticated 
frameworks to register
I0820 07:50:11.677474 18975 master.cpp:498] Master only allowing authenticated 
agents to register
I0820 07:50:11.677489 18975 master.cpp:504] Master only allowing authenticated 
HTTP frameworks to register
I0820 07:50:11.677505 18975 credentials.hpp:37] Loading credentials for 
authentication from '/tmp/hyLcno/credentials'
I0820 07:50:11.677774 18975 master.cpp:548] Using default 'crammd5' 
authenticator
I0820 07:50:11.677956 18975 http.cpp:975] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-readonly'
I0820 07:50:11.678174 18975 http.cpp:975] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-readwrite'
I0820 07:50:11.678335 18975 http.cpp:975] Creating default 'basic' HTTP 
authenticator for realm 'mesos-master-scheduler'
I0820 07:50:11.678515 18975 master.cpp:629] Authorization enabled
I0820 07:50:11.678874 18981 hierarchical.cpp:473] Initialized hierarchical 
allocator process
I0820 07:50:11.684738 18984 whitelist_watcher.cpp:77] No whitelist given
I0820 07:50:11.687585 18973 master.cpp:2170] Elected as the leading master!
I0820 07:50:11.687620 18973 master.cpp:1666] Recovering from registrar
I0820 07:50:11.687813 18986 registrar.cpp:339] Recovering registrar
I0820 07:50:11.688557 18986 registrar.cpp:383] Successfully fetched the 
registry (0B) in 0ns
I0820 07:50:11.688676 18986 registrar.cpp:487] Applied 1 operations in 35539ns; 
attempting to update the registry
I0820 07:50:11.689324 18986 registrar.cpp:544] Successfully updated the 
registry in 0ns
I0820 07:50:11.689442 18986 registrar.cpp:416] Successfully recovered registrar
I0820 07:50:11.689944 18980 hierarchical.cpp:512] Skipping recovery of 
hierarchical allocator: nothing to recover
I0820 07:50:11.689936 18969 master.cpp:1819] Recovered 0 agents from the 
registry (143B); allowing 10mins for agents to reregister
W0820 07:50:11.695791 18968 process.cpp:2877] Attempted to spawn already 
running process files@172.17.0.2:39167
I0820 07:50:11.697038 18968 containerizer.cpp:318] Using isolation { 
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0820 07:50:11.697631 18968 backend.cpp:76] Failed to create 'overlay' backend: 
OverlayBackend requires root privileges
W0820 07:50:11.697659 18968 backend.cpp:76] Failed to create 'aufs' backend: 
AufsBackend requires root privileges
W0820 07:50:11.697774 18968 backend.cpp:76] Failed to create 'bind' backend: 
BindBackend requires root privileges
I0820 07:50:11.697809 18968 provisioner.cpp:300] Using default backend 'copy'
I0820 07:50:11.700109 18968 cluster.cpp:518] Creating default 'local' authorizer
I0820 07:50:11.702195 18981 slave.cpp:267] Mesos agent started on 
(1241)@172.17.0.2:39167
I0820 07:50:11.702219 18981 slave.cpp:268] Flags at startup: --acls="" 
--appc_simple_discovery_uri_prefix="http://"; 
--appc_store_dir="/tmp/hyLcno/Yic2Rb/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/hyLcno/Yic2Rb/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/hyLcno/Yic2Rb/store/docker" 
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" 
--docker_volume_chown="false" --enforce_container_disk_quota="false" 
--executor_registration_timeout="1mins" 
--executor_reregistration_timeout="2secs" 
--executor_shutdown_grace_period="5secs" 
--fetcher_cache_dir="/tmp/hyLcno/Yic2Rb/fetch" --fetcher_cache_size="2GB" 
--fetcher_stall_timeout="1mins" 
--frameworks_home="/tmp/hyLcno/Yic2Rb/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/hyLcno/Yic2Rb/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/hyLcno/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_0p7WYe"
 --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_StorageLocalResourcePr
 oviderTest_OperatorOperationsWithResourceProviderResources_v1_p7xS5h" 
--zk_session_timeout="10secs"
I0820 07:50:11.702673 18981 credentials.hpp:86] Loading credential for 
authentication from '/tmp/hyLcno/Yic2Rb/credential'
I0820 07:50:11.702826 18981 slave.cpp:300] Agent using credential for: 
test-principal
I0820 07:50:11.702849 18981 credentials.hpp:37] Loading credentials for 
authentication from '/tmp/hyLcno/Yic2Rb/http_credentials'
I0820 07:50:11.703101 18981 http.cpp:975] Creating default 'basic' HTTP 
authenticator for realm 'mesos-agent-readonly'
I0820 07:50:11.703500 18981 disk_profile_adaptor.cpp:82] Creating disk profile 
adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0820 07:50:11.705160 18981 slave.cpp:615] 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"}]
I0820 07:50:11.705363 18981 slave.cpp:623] Agent attributes: [  ]
I0820 07:50:11.705384 18981 slave.cpp:632] Agent hostname: a6f681cf2c75
I0820 07:50:11.705548 18975 task_status_update_manager.cpp:181] Pausing sending 
task status updates
I0820 07:50:11.705595 18974 status_update_manager_process.hpp:379] Pausing 
operation status update manager
I0820 07:50:11.706802 18972 process.cpp:3671] Handling HTTP event for process 
'test-disk-profile-server' with path: '/test-disk-profile-server/profiles'
I0820 07:50:11.707331 18991 state.cpp:67] Recovering state from 
'/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_p7xS5h/meta'
I0820 07:50:11.707609 18977 slave.cpp:7450] Finished recovering checkpointed 
state from 
'/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_p7xS5h/meta',
 beginning agent recovery
I0820 07:50:11.708300 18980 task_status_update_manager.cpp:207] Recovering task 
status update manager
I0820 07:50:11.708765 18980 containerizer.cpp:821] Recovering Mesos containers
I0820 07:50:11.709195 18980 containerizer.cpp:1157] Recovering isolators
I0820 07:50:11.710247 18977 containerizer.cpp:1196] Recovering provisioner
I0820 07:50:11.710892 18987 uri_disk_profile_adaptor.cpp:305] Updated disk 
profile mapping to 1 active profiles
I0820 07:50:11.710960 18985 provisioner.cpp:500] Provisioner recovery complete
I0820 07:50:11.711869 18979 composing.cpp:339] Finished recovering all 
containerizers
I0820 07:50:11.712204 18969 slave.cpp:7914] Recovering executors
I0820 07:50:11.712325 18969 slave.cpp:8067] Finished recovery
I0820 07:50:11.713232 18970 task_status_update_manager.cpp:181] Pausing sending 
task status updates
I0820 07:50:11.713255 18980 status_update_manager_process.hpp:379] Pausing 
operation status update manager
I0820 07:50:11.713268 18969 slave.cpp:1351] New master detected at 
master@172.17.0.2:39167
I0820 07:50:11.713449 18969 slave.cpp:1416] Detecting new master
I0820 07:50:11.714759 18974 slave.cpp:1443] Authenticating with master 
master@172.17.0.2:39167
I0820 07:50:11.714871 18974 slave.cpp:1452] Using default CRAM-MD5 authenticatee
I0820 07:50:11.715235 18972 authenticatee.cpp:121] Creating new client SASL 
connection
I0820 07:50:11.715623 18986 master.cpp:10617] Authenticating 
slave(1241)@172.17.0.2:39167
I0820 07:50:11.715773 18977 authenticator.cpp:414] Starting authentication 
session for crammd5-authenticatee(2096)@172.17.0.2:39167
I0820 07:50:11.716167 18982 authenticator.cpp:98] Creating new server SASL 
connection
I0820 07:50:11.716495 18987 authenticatee.cpp:213] Received SASL authentication 
mechanisms: CRAM-MD5
I0820 07:50:11.716536 18987 authenticatee.cpp:239] Attempting to authenticate 
with mechanism 'CRAM-MD5'
I0820 07:50:11.716691 18990 authenticator.cpp:204] Received SASL authentication 
start
I0820 07:50:11.716773 18990 authenticator.cpp:326] Authentication requires more 
steps
I0820 07:50:11.716913 18985 authenticatee.cpp:259] Received SASL authentication 
step
I0820 07:50:11.717079 18992 authenticator.cpp:232] Received SASL authentication 
step
I0820 07:50:11.717118 18992 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'a6f681cf2c75' server FQDN: 'a6f681cf2c75' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: false 
I0820 07:50:11.717134 18992 auxprop.cpp:181] Looking up auxiliary property 
'*userPassword'
I0820 07:50:11.717175 18992 auxprop.cpp:181] Looking up auxiliary property 
'*cmusaslsecretCRAM-MD5'
I0820 07:50:11.717202 18992 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'a6f681cf2c75' server FQDN: 'a6f681cf2c75' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: true 
I0820 07:50:11.717216 18992 auxprop.cpp:131] Skipping auxiliary property 
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0820 07:50:11.717226 18992 auxprop.cpp:131] Skipping auxiliary property 
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0820 07:50:11.717249 18992 authenticator.cpp:318] Authentication success
I0820 07:50:11.717389 18984 authenticatee.cpp:299] Authentication success
I0820 07:50:11.717494 18988 master.cpp:10649] Successfully authenticated 
principal 'test-principal' at slave(1241)@172.17.0.2:39167
I0820 07:50:11.717545 18973 authenticator.cpp:432] Authentication session 
cleanup for crammd5-authenticatee(2096)@172.17.0.2:39167
I0820 07:50:11.717789 18975 slave.cpp:1543] Successfully authenticated with 
master master@172.17.0.2:39167
I0820 07:50:11.718183 18975 slave.cpp:1993] Will retry registration in 
8.461124ms if necessary
I0820 07:50:11.718343 18976 master.cpp:7088] Received register agent message 
from slave(1241)@172.17.0.2:39167 (a6f681cf2c75)
I0820 07:50:11.718645 18976 master.cpp:4204] Authorizing agent providing 
resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 
'test-principal'
I0820 07:50:11.719280 18969 master.cpp:7155] Authorized registration of agent 
at slave(1241)@172.17.0.2:39167 (a6f681cf2c75)
I0820 07:50:11.719382 18969 master.cpp:7267] Registering agent at 
slave(1241)@172.17.0.2:39167 (a6f681cf2c75) with id 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:11.720106 18983 registrar.cpp:487] Applied 1 operations in 
248217ns; attempting to update the registry
I0820 07:50:11.720896 18983 registrar.cpp:544] Successfully updated the 
registry in 0ns
I0820 07:50:11.721124 18982 master.cpp:7315] Admitted agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:11.721966 18982 master.cpp:7360] Registered agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0820 07:50:11.722079 18990 slave.cpp:1576] Registered with master 
master@172.17.0.2:39167; given agent ID 43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:11.722118 18985 hierarchical.cpp:853] Added agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 (a6f681cf2c75) with cpus:2; mem:1024; 
disk:1024; ports:[31000-32000] (allocated: {})
I0820 07:50:11.722249 18971 task_status_update_manager.cpp:188] Resuming 
sending task status updates
I0820 07:50:11.722512 18985 hierarchical.cpp:1740] Performed allocation for 1 
agents in 185752ns
I0820 07:50:11.722549 18990 slave.cpp:1611] Checkpointing SlaveInfo to 
'/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_p7xS5h/meta/slaves/43219129-6529-4c4a-aa0c-06bf579390d3-S0/slave.info'
I0820 07:50:11.722595 18992 status_update_manager_process.hpp:385] Resuming 
operation status update manager
I0820 07:50:11.723695 18990 slave.cpp:1663] Forwarding agent update 
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"f5a02A0ZQQO1KJyksexl4Q=="},"slave_id":{"value":"43219129-6529-4c4a-aa0c-06bf579390d3-S0"},"update_oversubscribed_resources":false}
I0820 07:50:11.724504 18975 master.cpp:8487] Ignoring update on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75) as it reports no changes
I0820 07:50:11.728602 18977 process.cpp:3671] Handling HTTP event for process 
'slave(1241)' with path: '/slave(1241)/api/v1'
I0820 07:50:11.729712 18985 http.cpp:1115] HTTP POST for /slave(1241)/api/v1 
from 172.17.0.2:46870
I0820 07:50:11.730168 18985 http.cpp:2146] Processing GET_CONTAINERS call
I0820 07:50:11.735424 18972 container_daemon.cpp:121] Launching container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0820 07:50:11.737633 18987 process.cpp:3671] Handling HTTP event for process 
'slave(1241)' with path: '/slave(1241)/api/v1'
I0820 07:50:11.738523 18985 http.cpp:1115] HTTP POST for /slave(1241)/api/v1 
from 172.17.0.2:46872
I0820 07:50:11.739320 18985 http.cpp:2606] Processing LAUNCH_CONTAINER call for 
container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0820 07:50:11.740063 18985 http.cpp:2710] Creating sandbox 
'/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_p7xS5h/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0820 07:50:11.740672 18973 containerizer.cpp:1392] Starting container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0820 07:50:11.741250 18973 containerizer.cpp:3319] Transitioning the state of 
container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 from STARTING to PROVISIONING after 0ns
I0820 07:50:11.741941 18973 containerizer.cpp:1570] Checkpointed 
ContainerConfig at 
'/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_0p7WYe/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0820 07:50:11.741987 18973 containerizer.cpp:3319] 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 after 0ns
I0820 07:50:11.744508 18989 containerizer.cpp:2096] 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_BpfPcl","--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_p7xS5h/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-a3U2JZ/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperat
 
ionsWithResourceProviderResources_v1_p7xS5h/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}"
 --pipe_read="87" --pipe_write="88" 
--runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_0p7WYe/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"
 --unshare_namespace_mnt="false"'
I0820 07:50:11.751555 18989 launcher.cpp:145] Forked child with pid '704' for 
container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0820 07:50:11.752418 18989 containerizer.cpp:3319] 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 after 0ns
I0820 07:50:11.753923 18989 containerizer.cpp:3319] 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 after 0ns
I0820 07:50:11.754249 18992 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_p7xS5h/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0820 07:50:11.755357 18990 containerizer.cpp:3319] 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 after 0ns
I0820 07:50:11.758136 18991 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'
I0820 07:50:11.758584 18976 service_manager.cpp:703] Connecting to endpoint 
'unix:///tmp/mesos-csi-a3U2JZ/endpoint.sock' of CSI plugin container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0820 07:50:12.312392 18983 service_manager.cpp:545] Probing endpoint 
'unix:///tmp/mesos-csi-a3U2JZ/endpoint.sock' with CSI v1
I0820 07:50:12.312896 18987 hierarchical.cpp:1740] Performed allocation for 1 
agents in 248872ns
I0820 07:50:12.327654   708 test_csi_plugin.cpp:909] ProbeRequest '{}'
I0820 07:50:12.329582 18984 container_daemon.cpp:171] Waiting for container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0820 07:50:12.331956   709 test_csi_plugin.cpp:895] 
GetPluginCapabilitiesRequest '{}'
I0820 07:50:12.332409 18976 process.cpp:3671] Handling HTTP event for process 
'slave(1241)' with path: '/slave(1241)/api/v1'
I0820 07:50:12.333658 18988 http.cpp:1115] HTTP POST for /slave(1241)/api/v1 
from 172.17.0.2:46874
I0820 07:50:12.334081 18988 http.cpp:2824] Processing WAIT_CONTAINER call for 
container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0820 07:50:12.335060   709 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0820 07:50:12.335220   708 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0820 07:50:12.336640 18970 v1_volume_manager.cpp:649] NODE_SERVICE loaded: 
{"name":".","vendorVersion":"1.9.0"}
I0820 07:50:12.337185 18970 v1_volume_manager.cpp:649] CONTROLLER_SERVICE 
loaded: {"name":".","vendorVersion":"1.9.0"}
I0820 07:50:12.339763   710 test_csi_plugin.cpp:1105] 
ControllerGetCapabilitiesRequest '{}'
I0820 07:50:12.342932   710 test_csi_plugin.cpp:1241] 
NodeGetCapabilitiesRequest '{}'
I0820 07:50:12.345142   708 test_csi_plugin.cpp:1255] NodeGetInfoRequest '{}'
I0820 07:50:12.346557 18990 provider.cpp:659] Finished recovery for resource 
provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0820 07:50:12.346664 18992 status_update_manager_process.hpp:379] Pausing 
operation status update manager
I0820 07:50:12.347004 18984 http_connection.hpp:227] New endpoint detected at 
http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:12.349844 18975 http_connection.hpp:283] Connected with the remote 
endpoint at http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:12.350451 18986 provider.cpp:459] Connected to resource provider 
manager
I0820 07:50:12.350977 18977 http_connection.hpp:131] Sending 1 call to 
http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:12.351891 18988 process.cpp:3671] Handling HTTP event for process 
'slave(1241)' with path: '/slave(1241)/api/v1/resource_provider'
I0820 07:50:12.353381 18971 http.cpp:1115] HTTP POST for 
/slave(1241)/api/v1/resource_provider from 172.17.0.2:46878
I0820 07:50:12.353933 18990 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_BpfPcl","--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"}
I0820 07:50:12.364094 18974 hierarchical.cpp:1740] Performed allocation for 1 
agents in 176192ns
I0820 07:50:12.384876 18976 slave.cpp:8423] Handling resource provider message 
'SUBSCRIBE: 
{"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"24606324-6f53-40c5-b6df-116a9f6b522b"},"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_BpfPcl","--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"}'
I0820 07:50:12.386536 18973 provider.cpp:481] Received SUBSCRIBED event
I0820 07:50:12.386586 18973 provider.cpp:1255] Subscribed with ID 
24606324-6f53-40c5-b6df-116a9f6b522b
I0820 07:50:12.387298 18992 status_update_manager_process.hpp:314] Recovering 
operation status update manager
I0820 07:50:12.415078 18981 hierarchical.cpp:1740] Performed allocation for 1 
agents in 231636ns
I0820 07:50:12.428436   710 test_csi_plugin.cpp:1050] ListVolumesRequest '{}'
I0820 07:50:12.430595 18976 provider.cpp:2145] Sending UPDATE_STATE call with 
resources '{}' and 0 operations to agent 43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:12.430832 18976 provider.cpp:745] Resource provider 
24606324-6f53-40c5-b6df-116a9f6b522b is in READY state
I0820 07:50:12.430932 18986 status_update_manager_process.hpp:385] Resuming 
operation status update manager
I0820 07:50:12.430922 18977 http_connection.hpp:131] Sending 3 call to 
http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:12.431517 18983 provider.cpp:1181] Updating profiles { test } for 
resource provider 24606324-6f53-40c5-b6df-116a9f6b522b
I0820 07:50:12.432180 18990 process.cpp:3671] Handling HTTP event for process 
'slave(1241)' with path: '/slave(1241)/api/v1/resource_provider'
I0820 07:50:12.433732 18986 http.cpp:1115] HTTP POST for 
/slave(1241)/api/v1/resource_provider from 172.17.0.2:46876
I0820 07:50:12.434180 18976 manager.cpp:1039] Received UPDATE_STATE call with 
resources '[]' and 0 operations from resource provider 
24606324-6f53-40c5-b6df-116a9f6b522b
I0820 07:50:12.434386 18977 slave.cpp:8423] Handling resource provider message 
'UPDATE_STATE: 24606324-6f53-40c5-b6df-116a9f6b522b {}'
I0820 07:50:12.434481 18977 slave.cpp:8543] Forwarding new total resources 
cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0820 07:50:12.434492   710 test_csi_plugin.cpp:1078] GetCapacityRequest 
'{"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0820 07:50:12.436398 18989 hierarchical.cpp:989] Grew agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 by {} (total), {  } (used)
I0820 07:50:12.436744 18989 hierarchical.cpp:946] Agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 (a6f681cf2c75) updated with total 
resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0820 07:50:12.438154 18984 provider.cpp:933] Removing '{}' and adding 
'disk(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' to the 
total resources
I0820 07:50:12.476464 18984 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 43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:12.476914 18969 http_connection.hpp:131] Sending 3 call to 
http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:12.478009 18971 process.cpp:3671] Handling HTTP event for process 
'slave(1241)' with path: '/slave(1241)/api/v1/resource_provider'
W0820 07:50:12.479461 18968 process.cpp:2877] Attempted to spawn already 
running process version@172.17.0.2:39167
I0820 07:50:12.480589 18968 sched.cpp:239] Version: 1.9.0
I0820 07:50:12.481559 18977 sched.cpp:343] New master detected at 
master@172.17.0.2:39167
I0820 07:50:12.481709 18977 sched.cpp:408] Authenticating with master 
master@172.17.0.2:39167
I0820 07:50:12.481729 18977 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0820 07:50:12.482204 18987 authenticatee.cpp:121] Creating new client SASL 
connection
I0820 07:50:12.482481 18981 hierarchical.cpp:1740] Performed allocation for 1 
agents in 195861ns
I0820 07:50:12.482610 18992 master.cpp:10617] Authenticating 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:12.482792 18980 authenticator.cpp:414] Starting authentication 
session for crammd5-authenticatee(2097)@172.17.0.2:39167
I0820 07:50:12.483160 18988 authenticator.cpp:98] Creating new server SASL 
connection
I0820 07:50:12.483449 18989 authenticatee.cpp:213] Received SASL authentication 
mechanisms: CRAM-MD5
I0820 07:50:12.483491 18989 authenticatee.cpp:239] Attempting to authenticate 
with mechanism 'CRAM-MD5'
I0820 07:50:12.483647 18985 authenticator.cpp:204] Received SASL authentication 
start
I0820 07:50:12.483739 18985 authenticator.cpp:326] Authentication requires more 
steps
I0820 07:50:12.483912 18974 authenticatee.cpp:259] Received SASL authentication 
step
I0820 07:50:12.484081 18991 authenticator.cpp:232] Received SASL authentication 
step
I0820 07:50:12.484117 18991 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'a6f681cf2c75' server FQDN: 'a6f681cf2c75' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: false 
I0820 07:50:12.484153 18991 auxprop.cpp:181] Looking up auxiliary property 
'*userPassword'
I0820 07:50:12.484212 18991 auxprop.cpp:181] Looking up auxiliary property 
'*cmusaslsecretCRAM-MD5'
I0820 07:50:12.484261 18991 auxprop.cpp:109] Request to lookup properties for 
user: 'test-principal' realm: 'a6f681cf2c75' server FQDN: 'a6f681cf2c75' 
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
SASL_AUXPROP_AUTHZID: true 
I0820 07:50:12.484284 18991 auxprop.cpp:131] Skipping auxiliary property 
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0820 07:50:12.484299 18991 auxprop.cpp:131] Skipping auxiliary property 
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0820 07:50:12.484334 18991 authenticator.cpp:318] Authentication success
I0820 07:50:12.484477 18990 authenticatee.cpp:299] Authentication success
I0820 07:50:12.484580 18969 master.cpp:10649] Successfully authenticated 
principal 'test-principal' at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:12.484616 18984 authenticator.cpp:432] Authentication session 
cleanup for crammd5-authenticatee(2097)@172.17.0.2:39167
I0820 07:50:12.484915 18978 sched.cpp:520] Successfully authenticated with 
master master@172.17.0.2:39167
I0820 07:50:12.484941 18978 sched.cpp:835] Sending SUBSCRIBE call to 
master@172.17.0.2:39167
I0820 07:50:12.485090 18978 sched.cpp:870] Will retry registration in 
942.89023ms if necessary
I0820 07:50:12.485302 18972 master.cpp:2910] Received SUBSCRIBE call for 
framework 'default' at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:12.485347 18972 master.cpp:2242] Authorizing framework principal 
'test-principal' to receive offers for roles '{ storage/default-role }'
I0820 07:50:12.486029 18976 master.cpp:2997] Subscribing framework default with 
checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0820 07:50:12.488775 18976 master.cpp:10847] Adding framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167 with roles {  } 
suppressed
I0820 07:50:12.489339 18983 sched.cpp:751] Framework registered with 
43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.489392 18983 sched.cpp:770] Scheduler::registered took 22944ns
I0820 07:50:12.489929 18977 hierarchical.cpp:600] Added framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.491183 18977 hierarchical.cpp:1740] Performed allocation for 1 
agents in 1.076419ms
I0820 07:50:12.491719 18988 master.cpp:10432] Sending offers [ 
43219129-6529-4c4a-aa0c-06bf579390d3-O0 ] to framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:12.492336 18989 sched.cpp:934] Scheduler::resourceOffers took 
119468ns
I0820 07:50:12.492740 18985 master.cpp:6224] Processing DECLINE call for 
offers: [ 43219129-6529-4c4a-aa0c-06bf579390d3-O0 ] for framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167 with 5 seconds 
filter
I0820 07:50:12.493533 18985 master.cpp:12724] Removing offer 
43219129-6529-4c4a-aa0c-06bf579390d3-O0
I0820 07:50:12.494298 18974 hierarchical.cpp:1454] 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 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 from framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.494391 18974 hierarchical.cpp:1500] Framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 filtered agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for 5secs
I0820 07:50:12.522038 18971 http.cpp:1115] HTTP POST for 
/slave(1241)/api/v1/resource_provider from 172.17.0.2:46876
I0820 07:50:12.522701 18990 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":"24606324-6f53-40c5-b6df-116a9f6b522b"},"reservations":[{"role":"storage","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
 and 0 operations from resource provider 24606324-6f53-40c5-b6df-116a9f6b522b
I0820 07:50:12.523172 18984 slave.cpp:8423] Handling resource provider message 
'UPDATE_STATE: 24606324-6f53-40c5-b6df-116a9f6b522b disk(reservations: 
[(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048'
I0820 07:50:12.523308 18984 slave.cpp:8543] 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
I0820 07:50:12.525368 18973 hierarchical.cpp:946] Agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 (a6f681cf2c75) 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
I0820 07:50:12.526633 18973 hierarchical.cpp:1740] Performed allocation for 1 
agents in 1.063047ms
I0820 07:50:12.527241 18976 master.cpp:10432] Sending offers [ 
43219129-6529-4c4a-aa0c-06bf579390d3-O1 ] to framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:12.527842 18987 sched.cpp:934] Scheduler::resourceOffers took 
72302ns
I0820 07:50:12.536797 18980 master.cpp:12724] Removing offer 
43219129-6529-4c4a-aa0c-06bf579390d3-O1
I0820 07:50:12.537247 18980 master.cpp:4741] Processing ACCEPT call for offers: 
[ 43219129-6529-4c4a-aa0c-06bf579390d3-O1 ] on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75) for framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000 
(default) at scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:12.537369 18988 hierarchical.cpp:1740] Performed allocation for 1 
agents in 272547ns
I0820 07:50:12.537353 18980 master.cpp:4114] 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'
I0820 07:50:12.538287 18991 master.cpp:6016] 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 43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167 to agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:12.538822 18991 master.cpp:12615] Sending operation '' (uuid: 
26f8cfe7-9464-4fb6-a358-15ee06c09734) to agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:12.539098 18979 hierarchical.cpp:1664] Allocation paused
I0820 07:50:12.539235 18970 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:12.540019 18979 hierarchical.cpp:1454] 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 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 from framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.540105 18979 hierarchical.cpp:1500] Framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 filtered agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for 5secs
I0820 07:50:12.540331 18979 hierarchical.cpp:1674] Allocation resumed
I0820 07:50:12.541250 18973 provider.cpp:481] Received APPLY_OPERATION event
I0820 07:50:12.541285 18973 provider.cpp:1295] Received CREATE_DISK operation 
'' (uuid: 26f8cfe7-9464-4fb6-a358-15ee06c09734)
I0820 07:50:12.588739 18987 hierarchical.cpp:2591] Filtered offer with cpus:2; 
mem:1024; disk:1024; ports:[31000-32000] on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for role storage/default-role of 
framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.588903 18987 hierarchical.cpp:1740] Performed allocation for 1 
agents in 815411ns
I0820 07:50:12.594058 18981 v1_volume_manager.cpp:293] Creating volume with 
name '26f8cfe7-9464-4fb6-a358-15ee06c09734'
I0820 07:50:12.596871   710 test_csi_plugin.cpp:922] CreateVolumeRequest 
'{"name":"26f8cfe7-9464-4fb6-a358-15ee06c09734","capacityRange":{"requiredBytes":"2147483648","limitBytes":"2147483648"},"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0820 07:50:12.640332 18974 hierarchical.cpp:2591] Filtered offer with cpus:2; 
mem:1024; disk:1024; ports:[31000-32000] on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for role storage/default-role of 
framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.640494 18974 hierarchical.cpp:1740] Performed allocation for 1 
agents in 685766ns
I0820 07:50:12.687072 18969 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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,test)]:2048'
 for operation (uuid: 26f8cfe7-9464-4fb6-a358-15ee06c09734)
I0820 07:50:12.691795 18991 hierarchical.cpp:2591] Filtered offer with cpus:2; 
mem:1024; disk:1024; ports:[31000-32000] on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for role storage/default-role of 
framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.691913 18991 hierarchical.cpp:1740] Performed allocation for 1 
agents in 483321ns
I0820 07:50:12.737262 18975 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
dac4de20-f457-4bc8-b59b-71f9eaf76a90) for operation UUID 
26f8cfe7-9464-4fb6-a358-15ee06c09734 of framework 
'43219129-6529-4c4a-aa0c-06bf579390d3-0000' on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:12.737329 18975 status_update_manager_process.hpp:414] Creating 
operation status update stream 26f8cfe7-9464-4fb6-a358-15ee06c09734 
checkpoint=true
I0820 07:50:12.737754 18975 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: dac4de20-f457-4bc8-b59b-71f9eaf76a90) for operation UUID 
26f8cfe7-9464-4fb6-a358-15ee06c09734 of framework 
'43219129-6529-4c4a-aa0c-06bf579390d3-0000' on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:12.743408 18971 hierarchical.cpp:2591] Filtered offer with cpus:2; 
mem:1024; disk:1024; ports:[31000-32000] on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for role storage/default-role of 
framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.743520 18971 hierarchical.cpp:1740] Performed allocation for 1 
agents in 433697ns
I0820 07:50:12.795058 18979 hierarchical.cpp:2591] Filtered offer with cpus:2; 
mem:1024; disk:1024; ports:[31000-32000] on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for role storage/default-role of 
framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.795228 18979 hierarchical.cpp:1740] Performed allocation for 1 
agents in 757062ns
I0820 07:50:12.804188 18975 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
dac4de20-f457-4bc8-b59b-71f9eaf76a90) for operation UUID 
26f8cfe7-9464-4fb6-a358-15ee06c09734 of framework 
'43219129-6529-4c4a-aa0c-06bf579390d3-0000' on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:12.805332 18984 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:12.806602 18982 process.cpp:3671] Handling HTTP event for process 
'slave(1241)' with path: '/slave(1241)/api/v1/resource_provider'
I0820 07:50:12.845769 18981 http.cpp:1115] HTTP POST for 
/slave(1241)/api/v1/resource_provider from 172.17.0.2:46876
I0820 07:50:12.846781 18985 slave.cpp:8423] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 26f8cfe7-9464-4fb6-a358-15ee06c09734) for 
framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000 (latest state: 
OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0820 07:50:12.846982 18985 slave.cpp:8876] Updating the state of operation 
with no ID (uuid: 26f8cfe7-9464-4fb6-a358-15ee06c09734) for framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (latest state: OPERATION_FINISHED, 
status update state: OPERATION_FINISHED)
I0820 07:50:12.847106 18988 hierarchical.cpp:2591] Filtered offer with cpus:2; 
mem:1024; disk:1024; ports:[31000-32000] on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for role storage/default-role of 
framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.847247 18988 hierarchical.cpp:1740] Performed allocation for 1 
agents in 677035ns
I0820 07:50:12.847373 18985 slave.cpp:8630] Forwarding status update of 
operation with no ID (operation_uuid: 26f8cfe7-9464-4fb6-a358-15ee06c09734) for 
framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.847766 18980 master.cpp:12271] Updating the state of operation 
'' (uuid: 26f8cfe7-9464-4fb6-a358-15ee06c09734) for framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (latest state: OPERATION_PENDING, 
status update state: OPERATION_FINISHED)
I0820 07:50:12.848973 18970 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:12.849433 18991 hierarchical.cpp:1192] Updated allocation of 
framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000 on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,test)]:2048
I0820 07:50:12.850010 18991 hierarchical.cpp:1454] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,test)]:2048,
 allocated: {}) on agent 43219129-6529-4c4a-aa0c-06bf579390d3-S0 from framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.850687 18978 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0820 07:50:12.850893 18976 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
dac4de20-f457-4bc8-b59b-71f9eaf76a90) for stream 
26f8cfe7-9464-4fb6-a358-15ee06c09734
I0820 07:50:12.851016 18976 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
dac4de20-f457-4bc8-b59b-71f9eaf76a90) for operation UUID 
26f8cfe7-9464-4fb6-a358-15ee06c09734 of framework 
'43219129-6529-4c4a-aa0c-06bf579390d3-0000' on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:12.899969 18973 hierarchical.cpp:1740] Performed allocation for 1 
agents in 1.469631ms
I0820 07:50:12.900929 18992 master.cpp:10432] Sending offers [ 
43219129-6529-4c4a-aa0c-06bf579390d3-O2 ] to framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:12.901860 18983 sched.cpp:934] Scheduler::resourceOffers took 
129237ns
I0820 07:50:12.905416 18974 process.cpp:3671] Handling HTTP event for process 
'master' with path: '/master/api/v1'
I0820 07:50:12.907366 18991 http.cpp:1115] HTTP POST for /master/api/v1 from 
172.17.0.2:46880
I0820 07:50:12.907608 18991 http.cpp:263] Processing call RESERVE_RESOURCES
I0820 07:50:12.908416 18991 master.cpp:3826] 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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,test)]:2048'
I0820 07:50:12.910650 18982 master.cpp:12724] Removing offer 
43219129-6529-4c4a-aa0c-06bf579390d3-O2
I0820 07:50:12.910826 18973 sched.cpp:960] Rescinded offer 
43219129-6529-4c4a-aa0c-06bf579390d3-O2
I0820 07:50:12.910912 18973 sched.cpp:971] Scheduler::offerRescinded took 
23521ns
I0820 07:50:12.911561 18978 hierarchical.cpp:1454] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,test)]:2048,
 allocated: {}) on agent 43219129-6529-4c4a-aa0c-06bf579390d3-S0 from framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:12.911684 18978 hierarchical.cpp:1500] Framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 filtered agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for 5secs
I0820 07:50:12.912621 18976 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 26f8cfe7-9464-4fb6-a358-15ee06c09734
I0820 07:50:12.914355 18983 master.cpp:12615] Sending operation '' (uuid: 
c6230470-aeb1-4cdf-83a2-580128b1c9ce) to agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:12.914850 18988 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:12.963459 18992 provider.cpp:481] Received APPLY_OPERATION event
I0820 07:50:12.963512 18992 provider.cpp:1295] Received RESERVE operation '' 
(uuid: c6230470-aeb1-4cdf-83a2-580128b1c9ce)
I0820 07:50:13.047586 18991 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
43f25195-1b67-4d73-b968-ae84da2a44a3) for operation UUID 
c6230470-aeb1-4cdf-83a2-580128b1c9ce on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.047643 18991 status_update_manager_process.hpp:414] Creating 
operation status update stream c6230470-aeb1-4cdf-83a2-580128b1c9ce 
checkpoint=true
I0820 07:50:13.047922 18991 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: 43f25195-1b67-4d73-b968-ae84da2a44a3) for operation UUID 
c6230470-aeb1-4cdf-83a2-580128b1c9ce on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.114406 18991 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
43f25195-1b67-4d73-b968-ae84da2a44a3) for operation UUID 
c6230470-aeb1-4cdf-83a2-580128b1c9ce on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.115123 18984 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:13.116003 18982 process.cpp:3671] Handling HTTP event for process 
'slave(1241)' with path: '/slave(1241)/api/v1/resource_provider'
I0820 07:50:13.119549 18978 hierarchical.cpp:1740] Performed allocation for 1 
agents in 1.649384ms
I0820 07:50:13.120142 18983 master.cpp:10432] Sending offers [ 
43219129-6529-4c4a-aa0c-06bf579390d3-O3 ] to framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:13.120750 18989 sched.cpp:934] Scheduler::resourceOffers took 
68795ns
I0820 07:50:13.123826 18969 process.cpp:3671] Handling HTTP event for process 
'master' with path: '/master/api/v1'
I0820 07:50:13.126408 18975 http.cpp:1115] HTTP POST for /master/api/v1 from 
172.17.0.2:46882
I0820 07:50:13.126791 18975 http.cpp:263] Processing call CREATE_VOLUMES
I0820 07:50:13.127951 18975 master.cpp:3953] Authorizing principal 
'test-principal' to create volumes 
'[{"disk":{"persistence":{"id":"5925422e-68b7-4c4b-a0c3-99af30d83f36","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734","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":"24606324-6f53-40c5-b6df-116a9f6b522b"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0820 07:50:13.130291 18972 master.cpp:12724] Removing offer 
43219129-6529-4c4a-aa0c-06bf579390d3-O3
I0820 07:50:13.130442 18986 sched.cpp:960] Rescinded offer 
43219129-6529-4c4a-aa0c-06bf579390d3-O3
I0820 07:50:13.130520 18986 sched.cpp:971] Scheduler::offerRescinded took 
21527ns
I0820 07:50:13.131072 18991 hierarchical.cpp:1454] 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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,test)]:2048,
 allocated: {}) on agent 43219129-6529-4c4a-aa0c-06bf579390d3-S0 from framework 
43219129-6529-4c
 4a-aa0c-06bf579390d3-0000
I0820 07:50:13.131186 18991 hierarchical.cpp:1500] Framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 filtered agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for 5secs
I0820 07:50:13.133409 18984 master.cpp:12615] Sending operation '' (uuid: 
89156202-cf9e-4600-a265-7eabdc6eff5e) to agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:13.134001 18973 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:13.136447 18970 provider.cpp:481] Received APPLY_OPERATION event
I0820 07:50:13.136487 18970 provider.cpp:1295] Received CREATE operation '' 
(uuid: 89156202-cf9e-4600-a265-7eabdc6eff5e)
I0820 07:50:13.142103 18971 master.cpp:6417] Processing REVIVE call for 
framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:13.142500 18975 hierarchical.cpp:1607] Unsuppressed offers and 
cleared filters for roles { storage/default-role } of framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:13.143745 18975 hierarchical.cpp:1740] Performed allocation for 1 
agents in 1.081906ms
I0820 07:50:13.144109 18975 hierarchical.cpp:1740] Performed allocation for 1 
agents in 180264ns
I0820 07:50:13.144438 18992 master.cpp:10432] Sending offers [ 
43219129-6529-4c4a-aa0c-06bf579390d3-O4 ] to framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:13.145054 18992 sched.cpp:934] Scheduler::resourceOffers took 
76205ns
I0820 07:50:13.157625 18982 http.cpp:1115] HTTP POST for 
/slave(1241)/api/v1/resource_provider from 172.17.0.2:46876
I0820 07:50:13.158627 18978 slave.cpp:8423] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: c6230470-aeb1-4cdf-83a2-580128b1c9ce) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0820 07:50:13.158849 18978 slave.cpp:8876] Updating the state of operation 
with no ID (uuid: c6230470-aeb1-4cdf-83a2-580128b1c9ce) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0820 07:50:13.158900 18978 slave.cpp:8630] Forwarding status update of 
operation with no ID (operation_uuid: c6230470-aeb1-4cdf-83a2-580128b1c9ce) for 
an operator API call
I0820 07:50:13.159324 18983 master.cpp:12271] Updating the state of operation 
'' (uuid: c6230470-aeb1-4cdf-83a2-580128b1c9ce) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0820 07:50:13.159847 18988 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:13.240561 18992 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
f6dc3693-02c6-4a31-9400-8bc3a0518aee) for operation UUID 
89156202-cf9e-4600-a265-7eabdc6eff5e on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.240619 18992 status_update_manager_process.hpp:414] Creating 
operation status update stream 89156202-cf9e-4600-a265-7eabdc6eff5e 
checkpoint=true
I0820 07:50:13.240661 18970 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0820 07:50:13.240947 18992 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: f6dc3693-02c6-4a31-9400-8bc3a0518aee) for operation UUID 
89156202-cf9e-4600-a265-7eabdc6eff5e on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.307463 18992 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
f6dc3693-02c6-4a31-9400-8bc3a0518aee) for operation UUID 
89156202-cf9e-4600-a265-7eabdc6eff5e on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.307792 18992 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
43f25195-1b67-4d73-b968-ae84da2a44a3) for stream 
c6230470-aeb1-4cdf-83a2-580128b1c9ce
I0820 07:50:13.307854 18992 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
43f25195-1b67-4d73-b968-ae84da2a44a3) for operation UUID 
c6230470-aeb1-4cdf-83a2-580128b1c9ce on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.308291 18972 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:13.309589 18991 process.cpp:3671] Handling HTTP event for process 
'slave(1241)' with path: '/slave(1241)/api/v1/resource_provider'
I0820 07:50:13.350080 18973 http.cpp:1115] HTTP POST for 
/slave(1241)/api/v1/resource_provider from 172.17.0.2:46876
I0820 07:50:13.350874 18988 slave.cpp:8423] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 89156202-cf9e-4600-a265-7eabdc6eff5e) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0820 07:50:13.351048 18988 slave.cpp:8876] Updating the state of operation 
with no ID (uuid: 89156202-cf9e-4600-a265-7eabdc6eff5e) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0820 07:50:13.351094 18988 slave.cpp:8630] Forwarding status update of 
operation with no ID (operation_uuid: 89156202-cf9e-4600-a265-7eabdc6eff5e) for 
an operator API call
I0820 07:50:13.351420 18985 master.cpp:12271] Updating the state of operation 
'' (uuid: 89156202-cf9e-4600-a265-7eabdc6eff5e) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0820 07:50:13.351882 18980 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:13.353945 18976 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0820 07:50:13.374306 18992 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream c6230470-aeb1-4cdf-83a2-580128b1c9ce
I0820 07:50:13.374514 18992 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
f6dc3693-02c6-4a31-9400-8bc3a0518aee) for stream 
89156202-cf9e-4600-a265-7eabdc6eff5e
I0820 07:50:13.374577 18992 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
f6dc3693-02c6-4a31-9400-8bc3a0518aee) for operation UUID 
89156202-cf9e-4600-a265-7eabdc6eff5e on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.458125 18992 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 89156202-cf9e-4600-a265-7eabdc6eff5e
I0820 07:50:13.520530 18983 process.cpp:3671] Handling HTTP event for process 
'master' with path: '/master/api/v1'
I0820 07:50:13.522100 18974 http.cpp:1115] HTTP POST for /master/api/v1 from 
172.17.0.2:46884
I0820 07:50:13.522357 18974 http.cpp:263] Processing call DESTROY_VOLUMES
I0820 07:50:13.523149 18974 master.cpp:3998] Authorizing principal 
'test-principal' to destroy volumes 
'[{"disk":{"persistence":{"id":"5925422e-68b7-4c4b-a0c3-99af30d83f36","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734","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":"24606324-6f53-40c5-b6df-116a9f6b522b"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0820 07:50:13.525097 18980 master.cpp:12724] Removing offer 
43219129-6529-4c4a-aa0c-06bf579390d3-O4
I0820 07:50:13.525228 18990 sched.cpp:960] Rescinded offer 
43219129-6529-4c4a-aa0c-06bf579390d3-O4
I0820 07:50:13.525310 18990 sched.cpp:971] Scheduler::offerRescinded took 
31236ns
I0820 07:50:13.526046 18975 hierarchical.cpp:1454] 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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,test),5925422e-68b7-4c4b-a0c3-99af30d83f36: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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,test),5925422e-68b7-4c4b-a0c3-99af30d83f36:volume]:2048,
 allocat
 ed: {}) on agent 43219129-6529-4c4a-aa0c-06bf579390d3-S0 from framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:13.526162 18975 hierarchical.cpp:1500] Framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 filtered agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for 5secs
I0820 07:50:13.529242 18986 master.cpp:12615] Sending operation '' (uuid: 
55254d64-0040-4352-a890-4993fe7a6f51) to agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:13.529891 18986 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:13.532908 18983 provider.cpp:481] Received APPLY_OPERATION event
I0820 07:50:13.532944 18983 provider.cpp:1295] Received DESTROY operation '' 
(uuid: 55254d64-0040-4352-a890-4993fe7a6f51)
I0820 07:50:13.540879 18971 hierarchical.cpp:1740] Performed allocation for 1 
agents in 1.072701ms
I0820 07:50:13.541394 18974 master.cpp:10432] Sending offers [ 
43219129-6529-4c4a-aa0c-06bf579390d3-O5 ] to framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:13.541942 18979 sched.cpp:934] Scheduler::resourceOffers took 
68839ns
I0820 07:50:13.626821 18977 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
c86b7cfb-aa83-4ec1-8634-520415a3120b) for operation UUID 
55254d64-0040-4352-a890-4993fe7a6f51 on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.626895 18977 status_update_manager_process.hpp:414] Creating 
operation status update stream 55254d64-0040-4352-a890-4993fe7a6f51 
checkpoint=true
I0820 07:50:13.627255 18977 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: c86b7cfb-aa83-4ec1-8634-520415a3120b) for operation UUID 
55254d64-0040-4352-a890-4993fe7a6f51 on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.677235 18977 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
c86b7cfb-aa83-4ec1-8634-520415a3120b) for operation UUID 
55254d64-0040-4352-a890-4993fe7a6f51 on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.677970 18980 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:13.678824 18984 process.cpp:3671] Handling HTTP event for process 
'slave(1241)' with path: '/slave(1241)/api/v1/resource_provider'
I0820 07:50:13.682473 18991 process.cpp:3671] Handling HTTP event for process 
'master' with path: '/master/api/v1'
I0820 07:50:13.684052 18973 http.cpp:1115] HTTP POST for /master/api/v1 from 
172.17.0.2:46886
I0820 07:50:13.684293 18973 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0820 07:50:13.684891 18973 master.cpp:3890] Authorizing principal 
'test-principal' to unreserve resources 
'[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734","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":"24606324-6f53-40c5-b6df-116a9f6b522b"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0820 07:50:13.686826 18969 master.cpp:12724] Removing offer 
43219129-6529-4c4a-aa0c-06bf579390d3-O5
I0820 07:50:13.686962 18974 sched.cpp:960] Rescinded offer 
43219129-6529-4c4a-aa0c-06bf579390d3-O5
I0820 07:50:13.687054 18974 sched.cpp:971] Scheduler::offerRescinded took 
32199ns
I0820 07:50:13.687474 18971 hierarchical.cpp:1454] 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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,test)]:2048,
 allocated: {}) on agent 43219129-6529-4c4a-aa0c-06bf579390d3-S0 from framework 
43219129-6529-4c
 4a-aa0c-06bf579390d3-0000
I0820 07:50:13.687580 18971 hierarchical.cpp:1500] Framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 filtered agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 for 5secs
I0820 07:50:13.689693 18979 master.cpp:12615] Sending operation '' (uuid: 
578da613-d66f-4eb9-a91a-c4e532d2e5e7) to agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:13.690168 18990 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:13.693253 18978 provider.cpp:481] Received APPLY_OPERATION event
I0820 07:50:13.693328 18978 provider.cpp:1295] Received UNRESERVE operation '' 
(uuid: 578da613-d66f-4eb9-a91a-c4e532d2e5e7)
I0820 07:50:13.703112 18988 hierarchical.cpp:1740] Performed allocation for 1 
agents in 1.414602ms
I0820 07:50:13.703788 18987 master.cpp:10432] Sending offers [ 
43219129-6529-4c4a-aa0c-06bf579390d3-O6 ] to framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:13.704495 18973 sched.cpp:934] Scheduler::resourceOffers took 
77084ns
I0820 07:50:13.718076 18979 http.cpp:1115] HTTP POST for 
/slave(1241)/api/v1/resource_provider from 172.17.0.2:46876
I0820 07:50:13.718963 18983 slave.cpp:8423] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 55254d64-0040-4352-a890-4993fe7a6f51) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0820 07:50:13.719125 18983 slave.cpp:8876] Updating the state of operation 
with no ID (uuid: 55254d64-0040-4352-a890-4993fe7a6f51) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0820 07:50:13.719173 18983 slave.cpp:8630] Forwarding status update of 
operation with no ID (operation_uuid: 55254d64-0040-4352-a890-4993fe7a6f51) for 
an operator API call
I0820 07:50:13.719501 18977 master.cpp:12271] Updating the state of operation 
'' (uuid: 55254d64-0040-4352-a890-4993fe7a6f51) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0820 07:50:13.719985 18972 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:13.795092 18987 status_update_manager_process.hpp:152] Received 
operation status update OPERATION_FINISHED (Status UUID: 
63c92821-9569-454b-afe3-76df78f19332) for operation UUID 
578da613-d66f-4eb9-a91a-c4e532d2e5e7 on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.795150 18987 status_update_manager_process.hpp:414] Creating 
operation status update stream 578da613-d66f-4eb9-a91a-c4e532d2e5e7 
checkpoint=true
I0820 07:50:13.795217 18978 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0820 07:50:13.795445 18987 status_update_manager_process.hpp:929] 
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status 
UUID: 63c92821-9569-454b-afe3-76df78f19332) for operation UUID 
578da613-d66f-4eb9-a91a-c4e532d2e5e7 on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.845294 18987 status_update_manager_process.hpp:528] Forwarding 
operation status update OPERATION_FINISHED (Status UUID: 
63c92821-9569-454b-afe3-76df78f19332) for operation UUID 
578da613-d66f-4eb9-a91a-c4e532d2e5e7 on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.845615 18987 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
c86b7cfb-aa83-4ec1-8634-520415a3120b) for stream 
55254d64-0040-4352-a890-4993fe7a6f51
I0820 07:50:13.845672 18987 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
c86b7cfb-aa83-4ec1-8634-520415a3120b) for operation UUID 
55254d64-0040-4352-a890-4993fe7a6f51 on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:13.846236 18989 http_connection.hpp:131] Sending 2 call to 
http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:13.847402 18969 process.cpp:3671] Handling HTTP event for process 
'slave(1241)' with path: '/slave(1241)/api/v1/resource_provider'
I0820 07:50:13.885995 18977 http.cpp:1115] HTTP POST for 
/slave(1241)/api/v1/resource_provider from 172.17.0.2:46876
I0820 07:50:13.886770 18972 slave.cpp:8423] Handling resource provider message 
'UPDATE_OPERATION_STATUS: (uuid: 578da613-d66f-4eb9-a91a-c4e532d2e5e7) for 
framework  (latest state: OPERATION_FINISHED, status update state: 
OPERATION_FINISHED)'
I0820 07:50:13.886940 18972 slave.cpp:8876] Updating the state of operation 
with no ID (uuid: 578da613-d66f-4eb9-a91a-c4e532d2e5e7) for an operation API 
call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0820 07:50:13.886986 18972 slave.cpp:8630] Forwarding status update of 
operation with no ID (operation_uuid: 578da613-d66f-4eb9-a91a-c4e532d2e5e7) for 
an operator API call
I0820 07:50:13.887298 18990 master.cpp:12271] Updating the state of operation 
'' (uuid: 578da613-d66f-4eb9-a91a-c4e532d2e5e7) for an operator API call 
(latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0820 07:50:13.887763 18986 slave.cpp:4352] Ignoring new checkpointed resources 
and operations identical to the current version
I0820 07:50:13.889394 18974 provider.cpp:481] Received 
ACKNOWLEDGE_OPERATION_STATUS event
I0820 07:50:13.912231 18987 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 55254d64-0040-4352-a890-4993fe7a6f51
I0820 07:50:13.912472 18987 status_update_manager_process.hpp:252] Received 
operation status update acknowledgement (UUID: 
63c92821-9569-454b-afe3-76df78f19332) for stream 
578da613-d66f-4eb9-a91a-c4e532d2e5e7
I0820 07:50:13.912524 18987 status_update_manager_process.hpp:929] 
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 
63c92821-9569-454b-afe3-76df78f19332) for operation UUID 
578da613-d66f-4eb9-a91a-c4e532d2e5e7 on agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:14.004343 18987 status_update_manager_process.hpp:490] Cleaning up 
operation status update stream 578da613-d66f-4eb9-a91a-c4e532d2e5e7
I0820 07:50:14.072506 18983 master.cpp:1412] Framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167 disconnected
I0820 07:50:14.072580 18983 master.cpp:3362] Deactivating framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:14.072952 18972 hierarchical.cpp:707] Deactivated framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:14.073279 18968 slave.cpp:924] Agent terminating
I0820 07:50:14.073990 18968 manager.cpp:163] Terminating resource provider 
24606324-6f53-40c5-b6df-116a9f6b522b
I0820 07:50:14.074009 18983 master.cpp:12724] Removing offer 
43219129-6529-4c4a-aa0c-06bf579390d3-O6
I0820 07:50:14.074092 18983 master.cpp:3339] Disconnecting framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:14.074149 18983 master.cpp:1427] Giving framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167 0ns to failover
I0820 07:50:14.074549 18971 master.cpp:1297] Agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75) disconnected
I0820 07:50:14.074584 18971 master.cpp:3399] Disconnecting agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:14.074581 18986 hierarchical.cpp:1454] Recovered disk(allocated: 
storage/default-role)(reservations: 
[(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,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_BpfPcl/2GB-26f8cfe7-9464-4fb6-a358-15ee06c09734,test)]:2048,
 allocated: {}) on agent 43219129-6529-4c4a-aa0c-06bf579390d3-S0 from framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:14.074666 18971 master.cpp:3418] Deactivating agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 at slave(1241)@172.17.0.2:39167 
(a6f681cf2c75)
I0820 07:50:14.074803 18977 hierarchical.cpp:1035] Agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0 deactivated
E0820 07:50:14.075062 18970 http_connection.hpp:452] End-Of-File received
I0820 07:50:14.075462 18970 http_connection.hpp:217] Re-detecting endpoint
I0820 07:50:14.075518 18991 master.cpp:10224] Framework failover timeout, 
removing framework 43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:14.075564 18991 master.cpp:11223] Removing framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000 (default) at 
scheduler-e79d571a-04c3-47bc-9c23-68e2da8695ad@172.17.0.2:39167
I0820 07:50:14.075875 18970 http_connection.hpp:338] Ignoring disconnection 
attempt from stale connection
I0820 07:50:14.075944 18973 provider.cpp:471] Disconnected from resource 
provider manager
I0820 07:50:14.075985 18985 hierarchical.cpp:1664] Allocation paused
I0820 07:50:14.076030 18970 http_connection.hpp:338] Ignoring disconnection 
attempt from stale connection
I0820 07:50:14.076082 18987 status_update_manager_process.hpp:379] Pausing 
operation status update manager
I0820 07:50:14.076100 18970 http_connection.hpp:227] New endpoint detected at 
http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:14.076404 18985 hierarchical.cpp:649] Removed framework 
43219129-6529-4c4a-aa0c-06bf579390d3-0000
I0820 07:50:14.076450 18985 hierarchical.cpp:1674] Allocation resumed
I0820 07:50:14.077409 18984 containerizer.cpp:2616] Destroying container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 in RUNNING state
I0820 07:50:14.077489 18984 containerizer.cpp:3319] 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 after 2.6576352secs
I0820 07:50:14.078027 18984 launcher.cpp:161] Asked to destroy container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0820 07:50:14.079059 18982 http_connection.hpp:283] Connected with the remote 
endpoint at http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:14.079614 18987 provider.cpp:459] Connected to resource provider 
manager
I0820 07:50:14.080235 18979 http_connection.hpp:131] Sending 1 call to 
http://172.17.0.2:39167/slave(1241)/api/v1/resource_provider
I0820 07:50:14.080422 18986 hierarchical.cpp:1740] Performed allocation for 1 
agents in 175363ns
E0820 07:50:14.080718 18979 provider.cpp:702] Failed to subscribe resource 
provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Cannot 
process 'SUBSCRIBE' call as the driver is in state SUBSCRIBING
I0820 07:50:14.081138 18993 process.cpp:2781] Returning '404 Not Found' for 
'/slave(1241)/api/v1/resource_provider'
E0820 07:50:14.082398 18970 provider.cpp:702] Failed to subscribe resource 
provider with type 'org.apache.mesos.rp.local.storage' and name 'test': 
Received '404 Not Found' ()
I0820 07:50:14.131481 18977 hierarchical.cpp:1740] Performed allocation for 1 
agents in 244284ns
I0820 07:50:14.181380 18981 containerizer.cpp:3157] Container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
 has exited
I0820 07:50:14.182896 18983 provisioner.cpp:612] Ignoring destroy request for 
unknown container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0820 07:50:14.182974 18987 hierarchical.cpp:1740] Performed allocation for 1 
agents in 191390ns
I0820 07:50:14.185235 18972 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'
I0820 07:50:14.185444 18976 service_manager.cpp:723] Disconnected from endpoint 
'unix:///tmp/mesos-csi-a3U2JZ/endpoint.sock' of CSI plugin container 
org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0820 07:50:14.185699 18982 container_daemon.cpp:121] Launching container 
'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0820 07:50:14.188993 18993 process.cpp:2781] Returning '404 Not Found' for 
'/slave(1241)/api/v1'
I0820 07:50:14.198318 18968 master.cpp:1137] Master terminating
I0820 07:50:14.199061 18989 hierarchical.cpp:1011] Removed all filters for 
agent 43219129-6529-4c4a-aa0c-06bf579390d3-S0
I0820 07:50:14.199091 18989 hierarchical.cpp:886] Removed agent 
43219129-6529-4c4a-aa0c-06bf579390d3-S0
[       OK ] 
CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1
 (2537 ms)
[----------] 50 tests from CSIVersion/StorageLocalResourceProviderTest (109694 
ms total)

[----------] Global test environment tear-down
[==========] 2312 tests from 221 test cases ran. (1335189 ms total)
[  PASSED  ] 2308 tests.
[  FAILED  ] 4 tests, listed below:
[  FAILED  ] ContentType/MasterDrainingTest.DrainAgentDisconnected/0, where 
GetParam() = application/x-protobuf
[  FAILED  ] ContentType/MasterDrainingTest.DrainAgentDisconnected/1, where 
GetParam() = application/json
[  FAILED  ] ContentType/MasterDrainingTest.DrainAgentUnreachable/0, where 
GetParam() = application/x-protobuf
[  FAILED  ] ContentType/MasterDrainingTest.DrainAgentUnreachable/1, where 
GetParam() = application/json

 4 FAILED TESTS
  YOU HAVE 32 DISABLED TESTS

I0820 07:50:14.316937 18993 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-1566280947-27307
Untagged: mesos-1566280947-27307:latest
Deleted: sha256:7313414f22899395646e0973fa06178460d53d09873f00537e858635e2311909
Deleted: sha256:9982cbf726d2ef13ffac941b67cbf56510c661285e4be831daddebf665b890d0
Deleted: sha256:a1f6bca1ab9065bb36e8e1f011da515d82dc25b08db158d339f90ea82814a0f7
Deleted: sha256:a57938da8d4fd1586f7f7d177b254e345a742fe5346450e2f347b91773f29748
Deleted: sha256:6e7945f3da0030fdb5ed96aed6bbfbfe67089d56b0b8606a6c35d66185c15c40
Deleted: sha256:5dcec58ad41506bd8fe532d1ed66f2e0bd1111373257c2db0382d576393d70b2
Deleted: sha256:ce832b3bf3785e419e97b1505831c36700e17f89d74e3b2afbe906d7e7f128ce
Deleted: sha256:2bf1a78985379c7800a087d87d527495c235db2a048b6dd99161eae76211fce7
Deleted: sha256:315cafb573e43ec79d7a263450bc517ad65e81f4936fda15f3c5da5839831844
Deleted: sha256:fd7855fa2f3d246e03312bb1360e7d4ba7aa1bbb29b7573307ece27e71dc34cf
Deleted: sha256:b72f431dd3374a8397091b1e3ba5ab595721e419e480e86053be66b9093abb74
Deleted: sha256:e67de5f679a9285a95d230ecfd453d4f833c91aced5ccc7f5a45085827c0a458
Deleted: sha256:7dabba80aebd001a3eea5bf9e21e63d8b7f3fe7e5e33d001bb57b46e949df39f
Deleted: sha256:8359b1c17aa037563d7cc332ad47765df658ffbbfc7d67d0d5b0cbc5fcf6af79
Deleted: sha256:ec7618c410ab46e36b5b46ab4efe8d6f4cefd7bb85b4378ff9edbb5864f3ac0a
Deleted: sha256:9de00cbfc747e79c6744f00a02c9538c8952a30cfda263e7cebb933c93f33f63
Deleted: sha256:26406244a95083e945c34c46fde7a9380b7fa11d8c4a22c90a49020e328d7f4b
Deleted: sha256:cd706e9228db8f6d84436dcd6378240bb736071b43ba472b44d28ec258224746
Deleted: sha256:e62efd2f56416c39e197fbba73792c0671413b77f21b81330d8ae2519e172256
Deleted: sha256:259b4d563ccda51223eef7e90be66573aca589024fee849ad97ce4b0de47c63b
Deleted: sha256:ddddf302beab5027e7ae2117003449533d31523fff2a42d6c18e4d96e0042da1
Deleted: sha256:bfd5b78bc6c3d825618fd31da89f2129389f6a424568611d56a879e330673996
Deleted: sha256:b03e68e4a1f7ed90117a11cc091c72562719467b25f66c26f38706cd20b06900
Deleted: sha256:fed7b96ed1937c2e4c23d4514a5561521509bbc20b61d854429923b4411e4f97
Deleted: sha256:119dbeae0290737f66220a1b18386985cac85bb13722dbb7b117f3fdf2b3ee4a
Deleted: sha256:0de73aab553a12b08ebba83ca0b39368a79db8edba8333201e7a5e75d92a716e
Deleted: sha256:fcf37686ff74d77b7e38e67a516cb87904d73ee205c759bdb12fd15e528ab517
Deleted: sha256:8c5a69f60e10fe24df906767fe225b83831c0c93516e86f8bb35f4ba673c4b34
Deleted: sha256:02bd304d6a0c4512083af2bfb696503cf2fedade82cf209af459447f85c74e17
Deleted: sha256:08d209adeae34b38577b4da445622849f14784c945c0e4c9c5d6dc5694dc34ca

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

- Mesos Reviewbot


On Aug. 19, 2019, 9:58 p.m., Joseph Wu wrote:
> 
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71318/
> -----------------------------------------------------------
> 
> (Updated Aug. 19, 2019, 9:58 p.m.)
> 
> 
> Review request for mesos, Benno Evers and Greg Mann.
> 
> 
> Bugs: MESOS-9892
>     https://issues.apache.org/jira/browse/MESOS-9892
> 
> 
> Repository: mesos
> 
> 
> Description
> -------
> 
> This adds an extra step to a couple of the agent draining tests,
> which calls REACTIVATE_AGENT at the end.
> 
> 
> Diffs
> -----
> 
>   src/tests/master_draining_tests.cpp PRE-CREATION 
> 
> 
> Diff: https://reviews.apache.org/r/71318/diff/1/
> 
> 
> Testing
> -------
> 
> make check
> 
> 
> Thanks,
> 
> Joseph Wu
> 
>

Reply via email to