You are viewing a plain text version of this content. The canonical link for it is here.
Posted to reviews@mesos.apache.org by Benno Evers <be...@mesosphere.com> on 2019/07/10 14:58:04 UTC

Re: Review Request 70528: Updated release guide.

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

(Updated July 10, 2019, 2:58 p.m.)


Review request for mesos, Greg Mann, Joseph Wu, and Till Toenshoff.


Summary (updated)
-----------------

Updated release guide.


Repository: mesos


Description (updated)
-------

Updated the release guide in `docs/release-guide.md` to match
the de-facto process we're using to release new versions.

Also mentioned some additional third-party tooling to the post-release
desription.


Diffs (updated)
-----

  docs/release-guide.md a3ad2668a1953a7f20dd7209e122481ad8b30f17 


Diff: https://reviews.apache.org/r/70528/diff/3/

Changes: https://reviews.apache.org/r/70528/diff/2-3/


Testing (updated)
-------

Released Mesos 1.8.0 according to this procedure.


Thanks,

Benno Evers


Re: Review Request 70528: Updated release guide.

Posted by Gastón Kleiman <ga...@mesosphere.io>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/70528/#review216515
-----------------------------------------------------------


Fix it, then Ship it!





docs/release-guide.md
Lines 69 (patched)
<https://reviews.apache.org/r/70528/#comment303732>

    Super minor nit: s/  / / =)


- Gastón Kleiman


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


Re: Review Request 70528: Updated release guide.

Posted by Vinod Kone <vi...@apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/70528/#review216485
-----------------------------------------------------------


Ship it!




- Vinod Kone


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


Re: Review Request 70528: Updated release guide.

Posted by Vinod Kone <vi...@apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/70528/#review216486
-----------------------------------------------------------


Ship it!




Ship It!

- Vinod Kone


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


Re: Review Request 70528: Updated release guide.

Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/70528/#review216492
-----------------------------------------------------------



Bad patch!

Reviews applied: [70526, 70527, 70528]

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

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

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

 2 FAILED TESTS
  YOU HAVE 31 DISABLED TESTS

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

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

- Mesos Reviewbot


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