You are viewing a plain text version of this content. The canonical link for it is here.
Posted to reviews@mesos.apache.org by Andrei Sekretenko <as...@mesosphere.io> on 2019/07/16 15:14:09 UTC
Review Request 71084: Added unsuppressing via `updateFramework()` to
python example framework.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71084/
-----------------------------------------------------------
Review request for mesos, Benjamin Mahler and Meng Zhu.
Bugs: MESOS-9864
https://issues.apache.org/jira/browse/MESOS-9864
Repository: mesos
Description
-------
This patch ensures that the list of suppressed roles is passed through
the `updateFramework()` of python V0 bindings. Now the framework
subscribes with all roles suppressed and after that issues
UPDATE_FRAMEWORK call to unsuppress offers.
Diffs
-----
src/examples/python/test_framework.py 27bc052dc4e57e0290ef58a39b2f1ac82fdb42fd
Diff: https://reviews.apache.org/r/71084/diff/1/
Testing
-------
Thanks,
Andrei Sekretenko
Re: Review Request 71084: Added unsuppressing via `updateFramework()`
to python example framework.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71084/#review216834
-----------------------------------------------------------
Patch looks great!
Reviews applied: [71082, 71083, 71084]
Passed command: 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
- Mesos Reviewbot
On July 16, 2019, 3:14 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71084/
> -----------------------------------------------------------
>
> (Updated July 16, 2019, 3:14 p.m.)
>
>
> Review request for mesos, Benjamin Mahler and Meng Zhu.
>
>
> Bugs: MESOS-9864
> https://issues.apache.org/jira/browse/MESOS-9864
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch ensures that the list of suppressed roles is passed through
> the `updateFramework()` of python V0 bindings. Now the framework
> subscribes with all roles suppressed and after that issues
> UPDATE_FRAMEWORK call to unsuppress offers.
>
>
> Diffs
> -----
>
> src/examples/python/test_framework.py 27bc052dc4e57e0290ef58a39b2f1ac82fdb42fd
>
>
> Diff: https://reviews.apache.org/r/71084/diff/1/
>
>
> Testing
> -------
>
> `./bin/mesos-tests.sh --gtest_filter="ExamplesTest.PythonFramework*" --gtest_break_on_failure --gtest_repeat=5`
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 71084: Added unsuppressing via `updateFramework()`
to python example framework.
Posted by Benjamin Mahler <bm...@apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71084/#review216738
-----------------------------------------------------------
Ship it!
Can you clarify the 'Testing Done'? Did you actually run this?
src/examples/python/test_framework.py
Lines 46 (patched)
<https://reviews.apache.org/r/71084/#comment303926>
How about a comment saying that once registered we unsuppress the roles? It's a little hard for the reader to see this here I think
- Benjamin Mahler
On July 16, 2019, 3:14 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71084/
> -----------------------------------------------------------
>
> (Updated July 16, 2019, 3:14 p.m.)
>
>
> Review request for mesos, Benjamin Mahler and Meng Zhu.
>
>
> Bugs: MESOS-9864
> https://issues.apache.org/jira/browse/MESOS-9864
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch ensures that the list of suppressed roles is passed through
> the `updateFramework()` of python V0 bindings. Now the framework
> subscribes with all roles suppressed and after that issues
> UPDATE_FRAMEWORK call to unsuppress offers.
>
>
> Diffs
> -----
>
> src/examples/python/test_framework.py 27bc052dc4e57e0290ef58a39b2f1ac82fdb42fd
>
>
> Diff: https://reviews.apache.org/r/71084/diff/1/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 71084: Added unsuppressing via `updateFramework()`
to python example framework.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71084/#review216669
-----------------------------------------------------------
Bad patch!
Reviews applied: [71082, 71083, 71084]
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_71084"]
Error:
...<truncated>...
rincipal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_VWiO1O/2GB-a0a7196d-a71f-4ed5-9d44-7fc69c0c3be9","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":"5bb7e656-5587-46e6-b2ad-cd91014c6d43"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0716 21:57:22.628011 18266 master.cpp:12570] Removing offer d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-O5
I0716 21:57:22.628144 18253 sched.cpp:960] Rescinded offer d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-O5
I0716 21:57:22.628232 18253 sched.cpp:971] Scheduler::offerRescinded took 24832ns
I0716 21:57:22.628726 18251 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_VWiO1O/2GB-a0a7196d-a71f-4ed5-9d44-7fc69c0c3be9,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_VWiO1O/2GB-a0a7196d-a71f-4ed5-9d44-7fc69c0c3be9,test)]:2048, allocated: {}) on agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0 from framework d1a6937f-9b05-47
a5-84b3-c6b4fe7e2506-0000
I0716 21:57:22.628844 18251 hierarchical.cpp:1264] Framework d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-0000 filtered agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0 for 5secs
I0716 21:57:22.631119 18261 master.cpp:12461] Sending operation '' (uuid: 8c25b812-7b4f-4093-9861-e7a100c49580) to agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0 at slave(1207)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:22.631690 18256 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:22.634292 18250 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.303204ms
I0716 21:57:22.634611 18264 provider.cpp:481] Received APPLY_OPERATION event
I0716 21:57:22.634662 18264 provider.cpp:1295] Received UNRESERVE operation '' (uuid: 8c25b812-7b4f-4093-9861-e7a100c49580)
I0716 21:57:22.635051 18249 master.cpp:10295] Sending offers [ d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-O6 ] to framework d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-0000 (default) at scheduler-8051dc15-afe9-4a8b-b17e-94a2736dc2f5@172.17.0.2:40657
I0716 21:57:22.635673 18252 sched.cpp:934] Scheduler::resourceOffers took 73858ns
I0716 21:57:22.660260 18261 http.cpp:1115] HTTP POST for /slave(1207)/api/v1/resource_provider from 172.17.0.2:47338
I0716 21:57:22.661211 18268 slave.cpp:8402] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 41646e39-3593-4653-b45d-bc930208a6b5) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0716 21:57:22.661394 18268 slave.cpp:8855] Updating the state of operation with no ID (uuid: 41646e39-3593-4653-b45d-bc930208a6b5) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0716 21:57:22.661450 18268 slave.cpp:8609] Forwarding status update of operation with no ID (operation_uuid: 41646e39-3593-4653-b45d-bc930208a6b5) for an operator API call
I0716 21:57:22.661839 18257 master.cpp:12117] Updating the state of operation '' (uuid: 41646e39-3593-4653-b45d-bc930208a6b5) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0716 21:57:22.662359 18255 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:22.736649 18252 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 37a49945-de61-448f-8626-a9370d4e9523) for operation UUID 8c25b812-7b4f-4093-9861-e7a100c49580 on agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0
I0716 21:57:22.736789 18252 status_update_manager_process.hpp:414] Creating operation status update stream 8c25b812-7b4f-4093-9861-e7a100c49580 checkpoint=true
I0716 21:57:22.736853 18264 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0716 21:57:22.737248 18252 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 37a49945-de61-448f-8626-a9370d4e9523) for operation UUID 8c25b812-7b4f-4093-9861-e7a100c49580 on agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0
I0716 21:57:22.819865 18252 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 37a49945-de61-448f-8626-a9370d4e9523) for operation UUID 8c25b812-7b4f-4093-9861-e7a100c49580 on agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0
I0716 21:57:22.820176 18252 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: a08e5b00-2053-47d0-8a0d-b676cc400647) for stream 41646e39-3593-4653-b45d-bc930208a6b5
I0716 21:57:22.820238 18252 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: a08e5b00-2053-47d0-8a0d-b676cc400647) for operation UUID 41646e39-3593-4653-b45d-bc930208a6b5 on agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0
I0716 21:57:22.820611 18262 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40657/slave(1207)/api/v1/resource_provider
I0716 21:57:22.821790 18251 process.cpp:3671] Handling HTTP event for process 'slave(1207)' with path: '/slave(1207)/api/v1/resource_provider'
I0716 21:57:22.860272 18260 http.cpp:1115] HTTP POST for /slave(1207)/api/v1/resource_provider from 172.17.0.2:47338
I0716 21:57:22.861137 18255 slave.cpp:8402] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 8c25b812-7b4f-4093-9861-e7a100c49580) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0716 21:57:22.861295 18255 slave.cpp:8855] Updating the state of operation with no ID (uuid: 8c25b812-7b4f-4093-9861-e7a100c49580) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0716 21:57:22.861336 18255 slave.cpp:8609] Forwarding status update of operation with no ID (operation_uuid: 8c25b812-7b4f-4093-9861-e7a100c49580) for an operator API call
I0716 21:57:22.861665 18267 master.cpp:12117] Updating the state of operation '' (uuid: 8c25b812-7b4f-4093-9861-e7a100c49580) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0716 21:57:22.862154 18270 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:22.863479 18266 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0716 21:57:22.886776 18252 status_update_manager_process.hpp:490] Cleaning up operation status update stream 41646e39-3593-4653-b45d-bc930208a6b5
I0716 21:57:22.886977 18252 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 37a49945-de61-448f-8626-a9370d4e9523) for stream 8c25b812-7b4f-4093-9861-e7a100c49580
I0716 21:57:22.887042 18252 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 37a49945-de61-448f-8626-a9370d4e9523) for operation UUID 8c25b812-7b4f-4093-9861-e7a100c49580 on agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0
I0716 21:57:22.987253 18252 status_update_manager_process.hpp:490] Cleaning up operation status update stream 8c25b812-7b4f-4093-9861-e7a100c49580
I0716 21:57:23.055747 18254 master.cpp:1410] Framework d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-0000 (default) at scheduler-8051dc15-afe9-4a8b-b17e-94a2736dc2f5@172.17.0.2:40657 disconnected
I0716 21:57:23.055793 18254 master.cpp:3342] Deactivating framework d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-0000 (default) at scheduler-8051dc15-afe9-4a8b-b17e-94a2736dc2f5@172.17.0.2:40657
I0716 21:57:23.056190 18260 hierarchical.cpp:475] Deactivated framework d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-0000
I0716 21:57:23.056771 18254 master.cpp:12570] Removing offer d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-O6
I0716 21:57:23.056838 18258 slave.cpp:914] Agent terminating
I0716 21:57:23.056856 18254 master.cpp:3319] Disconnecting framework d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-0000 (default) at scheduler-8051dc15-afe9-4a8b-b17e-94a2736dc2f5@172.17.0.2:40657
I0716 21:57:23.056919 18254 master.cpp:1425] Giving framework d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-0000 (default) at scheduler-8051dc15-afe9-4a8b-b17e-94a2736dc2f5@172.17.0.2:40657 0ns to failover
I0716 21:57:23.057431 18260 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_VWiO1O/2GB-a0a7196d-a71f-4ed5-9d44-7fc69c0c3be9,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_VWiO1O/2GB-a0a7196d-a71f-4ed5-9d44-7fc69c0c3be9,test)]:2048, allocated: {}) on agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0 from framework d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-0000
I0716 21:57:23.057804 18258 manager.cpp:163] Terminating resource provider 5bb7e656-5587-46e6-b2ad-cd91014c6d43
I0716 21:57:23.058197 18261 master.cpp:1295] Agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0 at slave(1207)@172.17.0.2:40657 (12367fa3ab0f) disconnected
I0716 21:57:23.058228 18261 master.cpp:3379] Disconnecting agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0 at slave(1207)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:23.058313 18261 master.cpp:3398] Deactivating agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0 at slave(1207)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:23.058535 18257 hierarchical.cpp:799] Agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0 deactivated
I0716 21:57:23.058626 18261 master.cpp:10087] Framework failover timeout, removing framework d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-0000 (default) at scheduler-8051dc15-afe9-4a8b-b17e-94a2736dc2f5@172.17.0.2:40657
I0716 21:57:23.058713 18261 master.cpp:11079] Removing framework d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-0000 (default) at scheduler-8051dc15-afe9-4a8b-b17e-94a2736dc2f5@172.17.0.2:40657
E0716 21:57:23.058791 18257 http_connection.hpp:452] End-Of-File received
I0716 21:57:23.059304 18256 hierarchical.cpp:1432] Allocation paused
I0716 21:57:23.059320 18257 http_connection.hpp:217] Re-detecting endpoint
I0716 21:57:23.059844 18256 hierarchical.cpp:417] Removed framework d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-0000
I0716 21:57:23.059908 18256 hierarchical.cpp:1442] Allocation resumed
I0716 21:57:23.060112 18257 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0716 21:57:23.060185 18257 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0716 21:57:23.060263 18253 provider.cpp:471] Disconnected from resource provider manager
I0716 21:57:23.060325 18257 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:40657/slave(1207)/api/v1/resource_provider
I0716 21:57:23.060376 18251 status_update_manager_process.hpp:379] Pausing operation status update manager
I0716 21:57:23.061801 18254 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
I0716 21:57:23.061836 18254 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
I0716 21:57:23.062222 18254 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0716 21:57:23.063632 18265 hierarchical.cpp:1508] Performed allocation for 1 agents in 146327ns
I0716 21:57:23.063980 18264 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:40657/slave(1207)/api/v1/resource_provider
I0716 21:57:23.064544 18268 provider.cpp:459] Connected to resource provider manager
I0716 21:57:23.065088 18251 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:40657/slave(1207)/api/v1/resource_provider
I0716 21:57:23.065764 18273 process.cpp:2781] Returning '404 Not Found' for '/slave(1207)/api/v1/resource_provider'
E0716 21:57:23.066794 18250 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0716 21:57:23.114470 18267 hierarchical.cpp:1508] Performed allocation for 1 agents in 104830ns
I0716 21:57:23.165685 18259 containerizer.cpp:3116] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0716 21:57:23.165911 18249 hierarchical.cpp:1508] Performed allocation for 1 agents in 102132ns
I0716 21:57:23.167346 18264 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
I0716 21:57:23.170018 18271 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'
I0716 21:57:23.170290 18267 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-5fyYPw/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0716 21:57:23.170547 18270 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0716 21:57:23.172938 18273 process.cpp:2781] Returning '404 Not Found' for '/slave(1207)/api/v1'
I0716 21:57:23.184044 18248 master.cpp:1135] Master terminating
I0716 21:57:23.184769 18262 hierarchical.cpp:775] Removed all filters for agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0
I0716 21:57:23.184796 18262 hierarchical.cpp:650] Removed agent d1a6937f-9b05-47a5-84b3-c6b4fe7e2506-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v0 (2531 ms)
[ RUN ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1
I0716 21:57:23.200975 18248 cluster.cpp:176] Creating default 'local' authorizer
I0716 21:57:23.205673 18261 master.cpp:440] Master 56f0e2b7-a7d3-428e-b1e9-c33450fc492e (12367fa3ab0f) started on 172.17.0.2:40657
I0716 21:57:23.205703 18261 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/vwIcA0/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/vwIcA0/master" --zk_session_timeout="10secs"
I0716 21:57:23.206074 18261 master.cpp:492] Master only allowing authenticated frameworks to register
I0716 21:57:23.206089 18261 master.cpp:498] Master only allowing authenticated agents to register
I0716 21:57:23.206097 18261 master.cpp:504] Master only allowing authenticated HTTP frameworks to register
I0716 21:57:23.206115 18261 credentials.hpp:37] Loading credentials for authentication from '/tmp/vwIcA0/credentials'
I0716 21:57:23.206425 18261 master.cpp:548] Using default 'crammd5' authenticator
I0716 21:57:23.206641 18261 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0716 21:57:23.206892 18261 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0716 21:57:23.207206 18261 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0716 21:57:23.207377 18261 master.cpp:629] Authorization enabled
I0716 21:57:23.207777 18249 hierarchical.cpp:241] Initialized hierarchical allocator process
I0716 21:57:23.207788 18259 whitelist_watcher.cpp:77] No whitelist given
I0716 21:57:23.210685 18262 master.cpp:2150] Elected as the leading master!
I0716 21:57:23.210722 18262 master.cpp:1664] Recovering from registrar
I0716 21:57:23.210944 18254 registrar.cpp:339] Recovering registrar
I0716 21:57:23.211712 18254 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0716 21:57:23.211848 18254 registrar.cpp:487] Applied 1 operations in 41078ns; attempting to update the registry
I0716 21:57:23.212515 18254 registrar.cpp:544] Successfully updated the registry in 0ns
I0716 21:57:23.212658 18254 registrar.cpp:416] Successfully recovered registrar
I0716 21:57:23.213090 18256 master.cpp:1799] Recovered 0 agents from the registry (143B); allowing 10mins for agents to reregister
I0716 21:57:23.213116 18252 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover
W0716 21:57:23.220230 18248 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:40657
I0716 21:57:23.221588 18248 containerizer.cpp:314] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0716 21:57:23.222194 18248 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0716 21:57:23.222231 18248 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0716 21:57:23.222379 18248 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0716 21:57:23.222431 18248 provisioner.cpp:298] Using default backend 'copy'
I0716 21:57:23.224994 18248 cluster.cpp:510] Creating default 'local' authorizer
I0716 21:57:23.227407 18270 slave.cpp:265] Mesos agent started on (1208)@172.17.0.2:40657
I0716 21:57:23.227437 18270 slave.cpp:266] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/vwIcA0/LKOdj4/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/vwIcA0/LKOdj4/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/vwIcA0/LKOdj4/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/vwIcA0/LKOdj4/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/vwIcA0/LKOdj4/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/vwIcA0/LKOdj4/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/vwIcA0/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_1bZKRi" --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_tFOiqx" --zk_session_timeout="10secs"
I0716 21:57:23.227880 18270 credentials.hpp:86] Loading credential for authentication from '/tmp/vwIcA0/LKOdj4/credential'
I0716 21:57:23.228114 18270 slave.cpp:298] Agent using credential for: test-principal
I0716 21:57:23.228139 18270 credentials.hpp:37] Loading credentials for authentication from '/tmp/vwIcA0/LKOdj4/http_credentials'
I0716 21:57:23.228374 18270 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0716 21:57:23.228785 18270 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0716 21:57:23.230541 18270 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"}]
I0716 21:57:23.230756 18270 slave.cpp:621] Agent attributes: [ ]
I0716 21:57:23.230809 18270 slave.cpp:630] Agent hostname: 12367fa3ab0f
I0716 21:57:23.230980 18271 task_status_update_manager.cpp:181] Pausing sending task status updates
I0716 21:57:23.231027 18265 status_update_manager_process.hpp:379] Pausing operation status update manager
I0716 21:57:23.231911 18263 process.cpp:3671] Handling HTTP event for process 'test-disk-profile-server' with path: '/test-disk-profile-server/profiles'
I0716 21:57:23.232883 18267 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_tFOiqx/meta'
I0716 21:57:23.233137 18251 slave.cpp:7429] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_tFOiqx/meta', beginning agent recovery
I0716 21:57:23.233801 18272 task_status_update_manager.cpp:207] Recovering task status update manager
I0716 21:57:23.234269 18259 containerizer.cpp:796] Recovering Mesos containers
I0716 21:57:23.234726 18259 containerizer.cpp:1122] Recovering isolators
I0716 21:57:23.235541 18267 containerizer.cpp:1161] Recovering provisioner
I0716 21:57:23.236093 18261 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I0716 21:57:23.236325 18254 provisioner.cpp:498] Provisioner recovery complete
I0716 21:57:23.237069 18268 composing.cpp:339] Finished recovering all containerizers
I0716 21:57:23.237393 18271 slave.cpp:7893] Recovering executors
I0716 21:57:23.237509 18271 slave.cpp:8046] Finished recovery
I0716 21:57:23.238457 18257 task_status_update_manager.cpp:181] Pausing sending task status updates
I0716 21:57:23.238482 18263 status_update_manager_process.hpp:379] Pausing operation status update manager
I0716 21:57:23.238502 18255 slave.cpp:1340] New master detected at master@172.17.0.2:40657
I0716 21:57:23.238656 18255 slave.cpp:1405] Detecting new master
I0716 21:57:23.239917 18259 slave.cpp:1432] Authenticating with master master@172.17.0.2:40657
I0716 21:57:23.240027 18259 slave.cpp:1441] Using default CRAM-MD5 authenticatee
I0716 21:57:23.240389 18260 authenticatee.cpp:121] Creating new client SASL connection
I0716 21:57:23.240733 18267 master.cpp:10480] Authenticating slave(1208)@172.17.0.2:40657
I0716 21:57:23.240882 18261 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2056)@172.17.0.2:40657
I0716 21:57:23.241190 18253 authenticator.cpp:98] Creating new server SASL connection
I0716 21:57:23.241458 18252 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0716 21:57:23.241497 18252 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0716 21:57:23.241647 18264 authenticator.cpp:204] Received SASL authentication start
I0716 21:57:23.241716 18264 authenticator.cpp:326] Authentication requires more steps
I0716 21:57:23.241850 18256 authenticatee.cpp:259] Received SASL authentication step
I0716 21:57:23.241989 18251 authenticator.cpp:232] Received SASL authentication step
I0716 21:57:23.242022 18251 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '12367fa3ab0f' server FQDN: '12367fa3ab0f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0716 21:57:23.242039 18251 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0716 21:57:23.242081 18251 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0716 21:57:23.242110 18251 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '12367fa3ab0f' server FQDN: '12367fa3ab0f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0716 21:57:23.242123 18251 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0716 21:57:23.242132 18251 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0716 21:57:23.242149 18251 authenticator.cpp:318] Authentication success
I0716 21:57:23.242300 18269 authenticatee.cpp:299] Authentication success
I0716 21:57:23.242354 18265 master.cpp:10512] Successfully authenticated principal 'test-principal' at slave(1208)@172.17.0.2:40657
I0716 21:57:23.242378 18272 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2056)@172.17.0.2:40657
I0716 21:57:23.242696 18254 slave.cpp:1532] Successfully authenticated with master master@172.17.0.2:40657
I0716 21:57:23.243093 18254 slave.cpp:1982] Will retry registration in 2.130838ms if necessary
I0716 21:57:23.243276 18262 master.cpp:7000] Received register agent message from slave(1208)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:23.243589 18262 master.cpp:4199] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I0716 21:57:23.244272 18263 master.cpp:7067] Authorized registration of agent at slave(1208)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:23.244364 18263 master.cpp:7182] Registering agent at slave(1208)@172.17.0.2:40657 (12367fa3ab0f) with id 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:23.245010 18270 registrar.cpp:487] Applied 1 operations in 187514ns; attempting to update the registry
I0716 21:57:23.245790 18270 registrar.cpp:544] Successfully updated the registry in 0ns
I0716 21:57:23.245996 18261 master.cpp:7230] Admitted agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:23.246783 18261 master.cpp:7275] Registered agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0716 21:57:23.246917 18252 slave.cpp:1565] Registered with master master@172.17.0.2:40657; given agent ID 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:23.246909 18264 hierarchical.cpp:617] Added agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 (12367fa3ab0f) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I0716 21:57:23.247056 18251 task_status_update_manager.cpp:188] Resuming sending task status updates
I0716 21:57:23.247259 18264 hierarchical.cpp:1508] Performed allocation for 1 agents in 144287ns
I0716 21:57:23.247465 18252 slave.cpp:1600] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_tFOiqx/meta/slaves/56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0/slave.info'
I0716 21:57:23.247517 18268 status_update_manager_process.hpp:385] Resuming operation status update manager
I0716 21:57:23.248704 18252 slave.cpp:1652] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"9waRmiu5RxqbgqsZu4Ly1Q=="},"slave_id":{"value":"56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0"},"update_oversubscribed_resources":false}
I0716 21:57:23.249425 18254 master.cpp:8361] Ignoring update on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f) as it reports no changes
I0716 21:57:23.253649 18253 process.cpp:3671] Handling HTTP event for process 'slave(1208)' with path: '/slave(1208)/api/v1'
I0716 21:57:23.254693 18265 http.cpp:1115] HTTP POST for /slave(1208)/api/v1 from 172.17.0.2:47358
I0716 21:57:23.255188 18265 http.cpp:2131] Processing GET_CONTAINERS call
I0716 21:57:23.260285 18267 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0716 21:57:23.262493 18256 process.cpp:3671] Handling HTTP event for process 'slave(1208)' with path: '/slave(1208)/api/v1'
I0716 21:57:23.263402 18272 http.cpp:1115] HTTP POST for /slave(1208)/api/v1 from 172.17.0.2:47360
I0716 21:57:23.264137 18272 http.cpp:2497] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0716 21:57:23.265043 18250 http.cpp:2601] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_tFOiqx/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0716 21:57:23.265704 18254 containerizer.cpp:1357] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0716 21:57:23.266909 18254 containerizer.cpp:1529] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_1bZKRi/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0716 21:57:23.266952 18254 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
I0716 21:57:23.269640 18263 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_vXKRYL","--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_tFOiqx/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-mfHgo8/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperat
ionsWithResourceProviderResources_v1_tFOiqx/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="76" --pipe_write="77" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_1bZKRi/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I0716 21:57:23.277972 18263 launcher.cpp:145] Forked child with pid '31983' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0716 21:57:23.278713 18263 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
I0716 21:57:23.280438 18263 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
I0716 21:57:23.280900 18253 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_tFOiqx/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0716 21:57:23.282142 18256 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
I0716 21:57:23.285183 18269 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'
I0716 21:57:23.285460 18271 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-mfHgo8/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0716 21:57:23.423873 18270 hierarchical.cpp:1508] Performed allocation for 1 agents in 204546ns
I0716 21:57:23.475203 18256 hierarchical.cpp:1508] Performed allocation for 1 agents in 196106ns
I0716 21:57:23.526872 18269 hierarchical.cpp:1508] Performed allocation for 1 agents in 264389ns
I0716 21:57:23.578217 18262 hierarchical.cpp:1508] Performed allocation for 1 agents in 209110ns
I0716 21:57:23.629830 18261 hierarchical.cpp:1508] Performed allocation for 1 agents in 203313ns
I0716 21:57:23.681602 18264 hierarchical.cpp:1508] Performed allocation for 1 agents in 238654ns
I0716 21:57:23.686851 18252 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-mfHgo8/endpoint.sock' with CSI v1
I0716 21:57:23.703668 31987 test_csi_plugin.cpp:909] ProbeRequest '{}'
I0716 21:57:23.705494 18255 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0716 21:57:23.707882 31988 test_csi_plugin.cpp:895] GetPluginCapabilitiesRequest '{}'
I0716 21:57:23.708731 18261 process.cpp:3671] Handling HTTP event for process 'slave(1208)' with path: '/slave(1208)/api/v1'
I0716 21:57:23.709913 18251 http.cpp:1115] HTTP POST for /slave(1208)/api/v1 from 172.17.0.2:47362
I0716 21:57:23.710397 18251 http.cpp:2715] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0716 21:57:23.711424 31987 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0716 21:57:23.711607 31988 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0716 21:57:23.712867 18262 v1_volume_manager.cpp:648] NODE_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"}
I0716 21:57:23.713352 18262 v1_volume_manager.cpp:648] CONTROLLER_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"}
I0716 21:57:23.715139 31987 test_csi_plugin.cpp:1105] ControllerGetCapabilitiesRequest '{}'
I0716 21:57:23.718212 31989 test_csi_plugin.cpp:1241] NodeGetCapabilitiesRequest '{}'
I0716 21:57:23.720932 31989 test_csi_plugin.cpp:1255] NodeGetInfoRequest '{}'
I0716 21:57:23.722760 18255 provider.cpp:659] Finished recovery for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0716 21:57:23.722884 18259 status_update_manager_process.hpp:379] Pausing operation status update manager
I0716 21:57:23.723276 18269 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:23.726111 18270 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:23.726629 18268 provider.cpp:459] Connected to resource provider manager
I0716 21:57:23.727267 18265 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:23.728216 18267 process.cpp:3671] Handling HTTP event for process 'slave(1208)' with path: '/slave(1208)/api/v1/resource_provider'
I0716 21:57:23.729718 18255 http.cpp:1115] HTTP POST for /slave(1208)/api/v1/resource_provider from 172.17.0.2:47366
I0716 21:57:23.730355 18258 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_vXKRYL","--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"}
I0716 21:57:23.732564 18263 hierarchical.cpp:1508] Performed allocation for 1 agents in 187183ns
I0716 21:57:23.767110 18270 slave.cpp:8402] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9"},"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_vXKRYL","--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"}'
I0716 21:57:23.769076 18271 provider.cpp:481] Received SUBSCRIBED event
I0716 21:57:23.769119 18271 provider.cpp:1255] Subscribed with ID 7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9
I0716 21:57:23.770028 18272 status_update_manager_process.hpp:314] Recovering operation status update manager
I0716 21:57:23.784087 18258 hierarchical.cpp:1508] Performed allocation for 1 agents in 109913ns
I0716 21:57:23.818576 31989 test_csi_plugin.cpp:1050] ListVolumesRequest '{}'
I0716 21:57:23.821278 18270 provider.cpp:2145] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:23.821588 18270 provider.cpp:745] Resource provider 7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9 is in READY state
I0716 21:57:23.821633 18264 http_connection.hpp:131] Sending 3 call to http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:23.821660 18268 status_update_manager_process.hpp:385] Resuming operation status update manager
I0716 21:57:23.822221 18265 provider.cpp:1181] Updating profiles { test } for resource provider 7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9
I0716 21:57:23.822731 18258 process.cpp:3671] Handling HTTP event for process 'slave(1208)' with path: '/slave(1208)/api/v1/resource_provider'
I0716 21:57:23.824384 18253 http.cpp:1115] HTTP POST for /slave(1208)/api/v1/resource_provider from 172.17.0.2:47364
I0716 21:57:23.824892 18264 manager.cpp:1039] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9
I0716 21:57:23.825054 18252 slave.cpp:8402] Handling resource provider message 'UPDATE_STATE: 7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9 {}'
I0716 21:57:23.825129 18252 slave.cpp:8522] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0716 21:57:23.825660 31987 test_csi_plugin.cpp:1078] GetCapacityRequest '{"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0716 21:57:23.827016 18269 hierarchical.cpp:753] Grew agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 by {} (total), { } (used)
I0716 21:57:23.827445 18269 hierarchical.cpp:710] Agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 (12367fa3ab0f) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
W0716 21:57:23.828568 18248 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:40657
I0716 21:57:23.829988 18263 provider.cpp:933] Removing '{}' and adding 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' to the total resources
I0716 21:57:23.830112 18248 sched.cpp:239] Version: 1.9.0
I0716 21:57:23.831068 18268 sched.cpp:343] New master detected at master@172.17.0.2:40657
I0716 21:57:23.831282 18268 sched.cpp:408] Authenticating with master master@172.17.0.2:40657
I0716 21:57:23.831321 18268 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0716 21:57:23.831835 18264 authenticatee.cpp:121] Creating new client SASL connection
I0716 21:57:23.832136 18270 hierarchical.cpp:1508] Performed allocation for 1 agents in 186465ns
I0716 21:57:23.832218 18265 master.cpp:10480] Authenticating scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:23.832453 18251 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2057)@172.17.0.2:40657
I0716 21:57:23.832857 18257 authenticator.cpp:98] Creating new server SASL connection
I0716 21:57:23.833220 18259 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0716 21:57:23.833258 18259 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0716 21:57:23.833442 18250 authenticator.cpp:204] Received SASL authentication start
I0716 21:57:23.833521 18250 authenticator.cpp:326] Authentication requires more steps
I0716 21:57:23.833698 18252 authenticatee.cpp:259] Received SASL authentication step
I0716 21:57:23.833889 18255 authenticator.cpp:232] Received SASL authentication step
I0716 21:57:23.833936 18255 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '12367fa3ab0f' server FQDN: '12367fa3ab0f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0716 21:57:23.833956 18255 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0716 21:57:23.834014 18255 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0716 21:57:23.834045 18255 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '12367fa3ab0f' server FQDN: '12367fa3ab0f' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0716 21:57:23.834060 18255 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0716 21:57:23.834071 18255 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0716 21:57:23.834095 18255 authenticator.cpp:318] Authentication success
I0716 21:57:23.834228 18267 authenticatee.cpp:299] Authentication success
I0716 21:57:23.834338 18269 master.cpp:10512] Successfully authenticated principal 'test-principal' at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:23.834399 18258 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2057)@172.17.0.2:40657
I0716 21:57:23.834735 18249 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:40657
I0716 21:57:23.834791 18249 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:40657
I0716 21:57:23.834985 18249 sched.cpp:870] Will retry registration in 1.835857005secs if necessary
I0716 21:57:23.835218 18256 master.cpp:2890] Received SUBSCRIBE call for framework 'default' at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:23.835260 18256 master.cpp:2222] Authorizing framework principal 'test-principal' to receive offers for roles '{ storage/default-role }'
I0716 21:57:23.835896 18271 master.cpp:2977] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0716 21:57:23.838418 18271 master.cpp:10710] Adding framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657 with roles { } suppressed
I0716 21:57:23.838927 18270 sched.cpp:751] Framework registered with 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:23.838980 18270 sched.cpp:770] Scheduler::registered took 27843ns
I0716 21:57:23.839242 18268 hierarchical.cpp:368] Added framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:23.840276 18268 hierarchical.cpp:1508] Performed allocation for 1 agents in 911289ns
I0716 21:57:23.840703 18257 master.cpp:10295] Sending offers [ 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O0 ] to framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:23.841212 18259 sched.cpp:934] Scheduler::resourceOffers took 116784ns
I0716 21:57:23.841524 18259 master.cpp:6219] Processing DECLINE call for offers: [ 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O0 ] for framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657 with 5 seconds filter
I0716 21:57:23.841995 18259 master.cpp:12570] Removing offer 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O0
I0716 21:57:23.842586 18252 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 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 from framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:23.842651 18252 hierarchical.cpp:1264] Framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 filtered agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for 5secs
I0716 21:57:23.883349 18263 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 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:23.883791 18255 http_connection.hpp:131] Sending 3 call to http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:23.884616 18254 process.cpp:3671] Handling HTTP event for process 'slave(1208)' with path: '/slave(1208)/api/v1/resource_provider'
I0716 21:57:23.924691 18256 http.cpp:1115] HTTP POST for /slave(1208)/api/v1/resource_provider from 172.17.0.2:47364
I0716 21:57:23.925282 18253 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":"7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9"},"reservations":[{"role":"storage","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]' and 0 operations from resource provider 7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9
I0716 21:57:23.925737 18264 slave.cpp:8402] Handling resource provider message 'UPDATE_STATE: 7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9 disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048'
I0716 21:57:23.925860 18264 slave.cpp:8522] 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
I0716 21:57:23.927640 18251 hierarchical.cpp:710] Agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 (12367fa3ab0f) 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
I0716 21:57:23.928721 18251 hierarchical.cpp:1508] Performed allocation for 1 agents in 921664ns
I0716 21:57:23.929220 18268 master.cpp:10295] Sending offers [ 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O1 ] to framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:23.929703 18257 sched.cpp:934] Scheduler::resourceOffers took 66175ns
I0716 21:57:23.936873 18255 master.cpp:12570] Removing offer 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O1
I0716 21:57:23.937155 18255 master.cpp:4736] Processing ACCEPT call for offers: [ 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O1 ] on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f) for framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:23.937242 18255 master.cpp:4109] 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'
I0716 21:57:23.937397 18266 hierarchical.cpp:1508] Performed allocation for 1 agents in 202433ns
I0716 21:57:23.938081 18262 master.cpp:6011] 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 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657 to agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:23.938572 18262 master.cpp:12461] Sending operation '' (uuid: 1a453f14-8783-4d43-8aaa-52e1e170234c) to agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:23.938874 18258 hierarchical.cpp:1432] Allocation paused
I0716 21:57:23.939013 18261 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:23.940243 18258 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 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 from framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:23.940341 18258 hierarchical.cpp:1264] Framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 filtered agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for 5secs
I0716 21:57:23.940595 18258 hierarchical.cpp:1442] Allocation resumed
I0716 21:57:23.941340 18251 provider.cpp:481] Received APPLY_OPERATION event
I0716 21:57:23.941385 18251 provider.cpp:1295] Received CREATE_DISK operation '' (uuid: 1a453f14-8783-4d43-8aaa-52e1e170234c)
I0716 21:57:23.988418 18257 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for role storage/default-role of framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:23.988517 18257 hierarchical.cpp:1508] Performed allocation for 1 agents in 408212ns
I0716 21:57:23.992592 18259 v1_volume_manager.cpp:292] Creating volume with name '1a453f14-8783-4d43-8aaa-52e1e170234c'
I0716 21:57:23.995229 31987 test_csi_plugin.cpp:922] CreateVolumeRequest '{"name":"1a453f14-8783-4d43-8aaa-52e1e170234c","capacityRange":{"requiredBytes":"2147483648","limitBytes":"2147483648"},"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0716 21:57:24.039588 18260 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for role storage/default-role of framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:24.039710 18260 hierarchical.cpp:1508] Performed allocation for 1 agents in 466783ns
I0716 21:57:24.077229 18262 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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,test)]:2048' for operation (uuid: 1a453f14-8783-4d43-8aaa-52e1e170234c)
I0716 21:57:24.090919 18261 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for role storage/default-role of framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:24.091056 18261 hierarchical.cpp:1508] Performed allocation for 1 agents in 599395ns
I0716 21:57:24.127382 18249 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 70ad0ffb-2231-4e30-8c2a-e46416b0b3bf) for operation UUID 1a453f14-8783-4d43-8aaa-52e1e170234c of framework '56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000' on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.127458 18249 status_update_manager_process.hpp:414] Creating operation status update stream 1a453f14-8783-4d43-8aaa-52e1e170234c checkpoint=true
I0716 21:57:24.127992 18249 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 70ad0ffb-2231-4e30-8c2a-e46416b0b3bf) for operation UUID 1a453f14-8783-4d43-8aaa-52e1e170234c of framework '56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000' on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.142232 18253 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for role storage/default-role of framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:24.142340 18253 hierarchical.cpp:1508] Performed allocation for 1 agents in 428403ns
I0716 21:57:24.193688 18264 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for role storage/default-role of framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:24.193882 18264 hierarchical.cpp:1508] Performed allocation for 1 agents in 729187ns
I0716 21:57:24.211047 18249 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 70ad0ffb-2231-4e30-8c2a-e46416b0b3bf) for operation UUID 1a453f14-8783-4d43-8aaa-52e1e170234c of framework '56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000' on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.212152 18265 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:24.213083 18272 process.cpp:3671] Handling HTTP event for process 'slave(1208)' with path: '/slave(1208)/api/v1/resource_provider'
I0716 21:57:24.245187 18257 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for role storage/default-role of framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:24.245285 18257 hierarchical.cpp:1508] Performed allocation for 1 agents in 400856ns
I0716 21:57:24.252261 18263 http.cpp:1115] HTTP POST for /slave(1208)/api/v1/resource_provider from 172.17.0.2:47364
I0716 21:57:24.253178 18267 slave.cpp:8402] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 1a453f14-8783-4d43-8aaa-52e1e170234c) for framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0716 21:57:24.253353 18267 slave.cpp:8855] Updating the state of operation with no ID (uuid: 1a453f14-8783-4d43-8aaa-52e1e170234c) for framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0716 21:57:24.253654 18267 slave.cpp:8609] Forwarding status update of operation with no ID (operation_uuid: 1a453f14-8783-4d43-8aaa-52e1e170234c) for framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:24.253970 18260 master.cpp:12117] Updating the state of operation '' (uuid: 1a453f14-8783-4d43-8aaa-52e1e170234c) for framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0716 21:57:24.254957 18262 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:24.255617 18261 hierarchical.cpp:956] Updated allocation of framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,test)]:2048
I0716 21:57:24.256203 18272 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0716 21:57:24.256219 18261 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,test)]:2048, allocated: {}) on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 from framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:24.256439 18271 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 70ad0ffb-2231-4e30-8c2a-e46416b0b3bf) for stream 1a453f14-8783-4d43-8aaa-52e1e170234c
I0716 21:57:24.256546 18271 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 70ad0ffb-2231-4e30-8c2a-e46416b0b3bf) for operation UUID 1a453f14-8783-4d43-8aaa-52e1e170234c of framework '56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000' on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.297135 18251 hierarchical.cpp:1508] Performed allocation for 1 agents in 966177ns
I0716 21:57:24.297711 18252 master.cpp:10295] Sending offers [ 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O2 ] to framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:24.298338 18250 sched.cpp:934] Scheduler::resourceOffers took 122199ns
I0716 21:57:24.302047 18269 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0716 21:57:24.304003 18265 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:47368
I0716 21:57:24.304230 18265 http.cpp:263] Processing call RESERVE_RESOURCES
I0716 21:57:24.304915 18265 master.cpp:3821] 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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,test)]:2048'
I0716 21:57:24.306450 18261 master.cpp:12570] Removing offer 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O2
I0716 21:57:24.306568 18251 sched.cpp:960] Rescinded offer 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O2
I0716 21:57:24.306654 18251 sched.cpp:971] Scheduler::offerRescinded took 31455ns
I0716 21:57:24.307162 18272 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,test)]:2048, allocated: {}) on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 from framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:24.307252 18272 hierarchical.cpp:1264] Framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 filtered agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for 5secs
I0716 21:57:24.309571 18252 master.cpp:12461] Sending operation '' (uuid: a79b9752-fc53-475d-8993-5f88a248349b) to agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:24.310153 18254 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:24.312850 18249 provider.cpp:481] Received APPLY_OPERATION event
I0716 21:57:24.312885 18249 provider.cpp:1295] Received RESERVE operation '' (uuid: a79b9752-fc53-475d-8993-5f88a248349b)
I0716 21:57:24.336175 18271 status_update_manager_process.hpp:490] Cleaning up operation status update stream 1a453f14-8783-4d43-8aaa-52e1e170234c
I0716 21:57:24.420676 18265 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: a2420d7f-ec6f-4938-a7a6-1f3d47160ade) for operation UUID a79b9752-fc53-475d-8993-5f88a248349b on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.420737 18265 status_update_manager_process.hpp:414] Creating operation status update stream a79b9752-fc53-475d-8993-5f88a248349b checkpoint=true
I0716 21:57:24.421195 18265 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: a2420d7f-ec6f-4938-a7a6-1f3d47160ade) for operation UUID a79b9752-fc53-475d-8993-5f88a248349b on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.496126 18265 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: a2420d7f-ec6f-4938-a7a6-1f3d47160ade) for operation UUID a79b9752-fc53-475d-8993-5f88a248349b on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.497083 18249 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:24.497993 18251 process.cpp:3671] Handling HTTP event for process 'slave(1208)' with path: '/slave(1208)/api/v1/resource_provider'
I0716 21:57:24.500928 18272 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.087888ms
I0716 21:57:24.501523 18250 master.cpp:10295] Sending offers [ 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O3 ] to framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:24.502121 18259 sched.cpp:934] Scheduler::resourceOffers took 77991ns
I0716 21:57:24.505733 18252 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0716 21:57:24.507772 18256 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:47370
I0716 21:57:24.508111 18256 http.cpp:263] Processing call CREATE_VOLUMES
I0716 21:57:24.508949 18256 master.cpp:3948] Authorizing principal 'test-principal' to create volumes '[{"disk":{"persistence":{"id":"8fa86f97-3590-4f31-985a-872046dc2e83","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c","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":"7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0716 21:57:24.511538 18253 master.cpp:12570] Removing offer 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O3
I0716 21:57:24.511647 18265 sched.cpp:960] Rescinded offer 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O3
I0716 21:57:24.511715 18265 sched.cpp:971] Scheduler::offerRescinded took 25046ns
I0716 21:57:24.512310 18271 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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,test)]:2048, allocated: {}) on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 from framework 56f0e2b7-a7d3-42
8e-b1e9-c33450fc492e-0000
I0716 21:57:24.512423 18271 hierarchical.cpp:1264] Framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 filtered agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for 5secs
I0716 21:57:24.515496 18270 master.cpp:12461] Sending operation '' (uuid: 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7) to agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:24.515977 18257 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:24.518299 18269 provider.cpp:481] Received APPLY_OPERATION event
I0716 21:57:24.518335 18269 provider.cpp:1295] Received CREATE operation '' (uuid: 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7)
I0716 21:57:24.523800 18252 master.cpp:6333] Processing REVIVE call for framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:24.524279 18252 hierarchical.cpp:1365] Unsuppressed offers for roles { storage/default-role } of framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:24.524304 18252 hierarchical.cpp:1387] Revived roles { storage/default-role } of framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:24.525528 18252 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.097356ms
I0716 21:57:24.525913 18252 hierarchical.cpp:1508] Performed allocation for 1 agents in 193113ns
I0716 21:57:24.526159 18262 master.cpp:10295] Sending offers [ 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O4 ] to framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:24.526844 18258 sched.cpp:934] Scheduler::resourceOffers took 126869ns
I0716 21:57:24.536188 18251 http.cpp:1115] HTTP POST for /slave(1208)/api/v1/resource_provider from 172.17.0.2:47364
I0716 21:57:24.537040 18268 slave.cpp:8402] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: a79b9752-fc53-475d-8993-5f88a248349b) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0716 21:57:24.537245 18268 slave.cpp:8855] Updating the state of operation with no ID (uuid: a79b9752-fc53-475d-8993-5f88a248349b) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0716 21:57:24.537300 18268 slave.cpp:8609] Forwarding status update of operation with no ID (operation_uuid: a79b9752-fc53-475d-8993-5f88a248349b) for an operator API call
I0716 21:57:24.537631 18272 master.cpp:12117] Updating the state of operation '' (uuid: a79b9752-fc53-475d-8993-5f88a248349b) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0716 21:57:24.538064 18259 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:24.622298 18258 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 0c8d7a24-be43-48e1-b040-796c7615eec7) for operation UUID 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7 on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.622354 18258 status_update_manager_process.hpp:414] Creating operation status update stream 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7 checkpoint=true
I0716 21:57:24.622376 18269 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0716 21:57:24.622782 18258 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 0c8d7a24-be43-48e1-b040-796c7615eec7) for operation UUID 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7 on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.689234 18258 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 0c8d7a24-be43-48e1-b040-796c7615eec7) for operation UUID 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7 on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.689724 18258 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: a2420d7f-ec6f-4938-a7a6-1f3d47160ade) for stream a79b9752-fc53-475d-8993-5f88a248349b
I0716 21:57:24.689802 18258 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: a2420d7f-ec6f-4938-a7a6-1f3d47160ade) for operation UUID a79b9752-fc53-475d-8993-5f88a248349b on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.690383 18253 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:24.691622 18249 process.cpp:3671] Handling HTTP event for process 'slave(1208)' with path: '/slave(1208)/api/v1/resource_provider'
I0716 21:57:24.732381 18263 http.cpp:1115] HTTP POST for /slave(1208)/api/v1/resource_provider from 172.17.0.2:47364
I0716 21:57:24.733443 18254 slave.cpp:8402] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0716 21:57:24.733662 18254 slave.cpp:8855] Updating the state of operation with no ID (uuid: 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0716 21:57:24.733713 18254 slave.cpp:8609] Forwarding status update of operation with no ID (operation_uuid: 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7) for an operator API call
I0716 21:57:24.734040 18259 master.cpp:12117] Updating the state of operation '' (uuid: 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0716 21:57:24.734501 18255 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:24.735945 18271 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0716 21:57:24.756057 18258 status_update_manager_process.hpp:490] Cleaning up operation status update stream a79b9752-fc53-475d-8993-5f88a248349b
I0716 21:57:24.756294 18258 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 0c8d7a24-be43-48e1-b040-796c7615eec7) for stream 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7
I0716 21:57:24.756362 18258 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 0c8d7a24-be43-48e1-b040-796c7615eec7) for operation UUID 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7 on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:24.848186 18258 status_update_manager_process.hpp:490] Cleaning up operation status update stream 3b3c31b9-f1da-4ab2-b4a5-b8acd81f14b7
I0716 21:57:24.927309 18257 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0716 21:57:24.928812 18259 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:47372
I0716 21:57:24.929055 18259 http.cpp:263] Processing call DESTROY_VOLUMES
I0716 21:57:24.929746 18259 master.cpp:3993] Authorizing principal 'test-principal' to destroy volumes '[{"disk":{"persistence":{"id":"8fa86f97-3590-4f31-985a-872046dc2e83","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c","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":"7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0716 21:57:24.931771 18256 master.cpp:12570] Removing offer 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O4
I0716 21:57:24.931883 18262 sched.cpp:960] Rescinded offer 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O4
I0716 21:57:24.931959 18262 sched.cpp:971] Scheduler::offerRescinded took 23992ns
I0716 21:57:24.932637 18260 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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,test),8fa86f97-3590-4f31-985a-872046dc2e83: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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,test),8fa86f97-3590-4f31-985a-872046dc2e83:volume]:2048, allocat
ed: {}) on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 from framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:24.932819 18260 hierarchical.cpp:1264] Framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 filtered agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for 5secs
I0716 21:57:24.935570 18252 master.cpp:12461] Sending operation '' (uuid: 86a3a2fb-9067-4316-b34f-ede4a73ab52d) to agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:24.936007 18270 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:24.938519 18250 provider.cpp:481] Received APPLY_OPERATION event
I0716 21:57:24.938562 18250 provider.cpp:1295] Received DESTROY operation '' (uuid: 86a3a2fb-9067-4316-b34f-ede4a73ab52d)
I0716 21:57:24.947994 18255 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.05211ms
I0716 21:57:24.948560 18259 master.cpp:10295] Sending offers [ 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O5 ] to framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:24.949110 18264 sched.cpp:934] Scheduler::resourceOffers took 74134ns
I0716 21:57:25.041906 18267 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 7e262d42-2870-4016-9734-66b2dd8034d0) for operation UUID 86a3a2fb-9067-4316-b34f-ede4a73ab52d on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:25.041971 18267 status_update_manager_process.hpp:414] Creating operation status update stream 86a3a2fb-9067-4316-b34f-ede4a73ab52d checkpoint=true
I0716 21:57:25.042397 18267 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 7e262d42-2870-4016-9734-66b2dd8034d0) for operation UUID 86a3a2fb-9067-4316-b34f-ede4a73ab52d on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:25.108827 18267 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 7e262d42-2870-4016-9734-66b2dd8034d0) for operation UUID 86a3a2fb-9067-4316-b34f-ede4a73ab52d on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:25.109573 18256 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:25.110467 18269 process.cpp:3671] Handling HTTP event for process 'slave(1208)' with path: '/slave(1208)/api/v1/resource_provider'
I0716 21:57:25.112984 18249 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0716 21:57:25.114428 18257 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:47374
I0716 21:57:25.114629 18257 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0716 21:57:25.115320 18257 master.cpp:3885] Authorizing principal 'test-principal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c","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":"7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0716 21:57:25.116950 18263 master.cpp:12570] Removing offer 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O5
I0716 21:57:25.117069 18255 sched.cpp:960] Rescinded offer 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O5
I0716 21:57:25.117130 18255 sched.cpp:971] Scheduler::offerRescinded took 18594ns
I0716 21:57:25.117596 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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,test)]:2048, allocated: {}) on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 from framework 56f0e2b7-a7d3-42
8e-b1e9-c33450fc492e-0000
I0716 21:57:25.117698 18266 hierarchical.cpp:1264] Framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 filtered agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 for 5secs
I0716 21:57:25.119681 18259 master.cpp:12461] Sending operation '' (uuid: 5479206b-d293-4ba3-ba8f-bfb9e5833031) to agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:25.120111 18264 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:25.123230 18258 provider.cpp:481] Received APPLY_OPERATION event
I0716 21:57:25.123266 18258 provider.cpp:1295] Received UNRESERVE operation '' (uuid: 5479206b-d293-4ba3-ba8f-bfb9e5833031)
I0716 21:57:25.123576 18251 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.283129ms
I0716 21:57:25.124096 18272 master.cpp:10295] Sending offers [ 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O6 ] to framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:25.124652 18257 sched.cpp:934] Scheduler::resourceOffers took 92218ns
I0716 21:57:25.148102 18262 http.cpp:1115] HTTP POST for /slave(1208)/api/v1/resource_provider from 172.17.0.2:47364
I0716 21:57:25.148957 18259 slave.cpp:8402] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 86a3a2fb-9067-4316-b34f-ede4a73ab52d) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0716 21:57:25.149102 18259 slave.cpp:8855] Updating the state of operation with no ID (uuid: 86a3a2fb-9067-4316-b34f-ede4a73ab52d) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0716 21:57:25.149144 18259 slave.cpp:8609] Forwarding status update of operation with no ID (operation_uuid: 86a3a2fb-9067-4316-b34f-ede4a73ab52d) for an operator API call
I0716 21:57:25.149442 18250 master.cpp:12117] Updating the state of operation '' (uuid: 86a3a2fb-9067-4316-b34f-ede4a73ab52d) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0716 21:57:25.149889 18265 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:25.227097 18257 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 0110fbde-2802-4987-bc39-bba03f5574b0) for operation UUID 5479206b-d293-4ba3-ba8f-bfb9e5833031 on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:25.227175 18257 status_update_manager_process.hpp:414] Creating operation status update stream 5479206b-d293-4ba3-ba8f-bfb9e5833031 checkpoint=true
I0716 21:57:25.227252 18258 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0716 21:57:25.227615 18257 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 0110fbde-2802-4987-bc39-bba03f5574b0) for operation UUID 5479206b-d293-4ba3-ba8f-bfb9e5833031 on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:25.293835 18257 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 0110fbde-2802-4987-bc39-bba03f5574b0) for operation UUID 5479206b-d293-4ba3-ba8f-bfb9e5833031 on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:25.294157 18257 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 7e262d42-2870-4016-9734-66b2dd8034d0) for stream 86a3a2fb-9067-4316-b34f-ede4a73ab52d
I0716 21:57:25.294222 18257 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 7e262d42-2870-4016-9734-66b2dd8034d0) for operation UUID 86a3a2fb-9067-4316-b34f-ede4a73ab52d on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:25.294512 18254 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:25.295310 18263 process.cpp:3671] Handling HTTP event for process 'slave(1208)' with path: '/slave(1208)/api/v1/resource_provider'
I0716 21:57:25.336288 18260 http.cpp:1115] HTTP POST for /slave(1208)/api/v1/resource_provider from 172.17.0.2:47364
I0716 21:57:25.337108 18265 slave.cpp:8402] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 5479206b-d293-4ba3-ba8f-bfb9e5833031) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0716 21:57:25.337275 18265 slave.cpp:8855] Updating the state of operation with no ID (uuid: 5479206b-d293-4ba3-ba8f-bfb9e5833031) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0716 21:57:25.337327 18265 slave.cpp:8609] Forwarding status update of operation with no ID (operation_uuid: 5479206b-d293-4ba3-ba8f-bfb9e5833031) for an operator API call
I0716 21:57:25.337574 18253 master.cpp:12117] Updating the state of operation '' (uuid: 5479206b-d293-4ba3-ba8f-bfb9e5833031) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0716 21:57:25.337980 18270 slave.cpp:4335] Ignoring new checkpointed resources and operations identical to the current version
I0716 21:57:25.339192 18255 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0716 21:57:25.377296 18257 status_update_manager_process.hpp:490] Cleaning up operation status update stream 86a3a2fb-9067-4316-b34f-ede4a73ab52d
I0716 21:57:25.377504 18257 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 0110fbde-2802-4987-bc39-bba03f5574b0) for stream 5479206b-d293-4ba3-ba8f-bfb9e5833031
I0716 21:57:25.377566 18257 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 0110fbde-2802-4987-bc39-bba03f5574b0) for operation UUID 5479206b-d293-4ba3-ba8f-bfb9e5833031 on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:25.487773 18257 status_update_manager_process.hpp:490] Cleaning up operation status update stream 5479206b-d293-4ba3-ba8f-bfb9e5833031
I0716 21:57:25.572739 18259 master.cpp:1410] Framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657 disconnected
I0716 21:57:25.572777 18259 master.cpp:3342] Deactivating framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:25.573091 18260 hierarchical.cpp:475] Deactivated framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:25.573565 18259 master.cpp:12570] Removing offer 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-O6
I0716 21:57:25.573611 18271 slave.cpp:914] Agent terminating
I0716 21:57:25.573633 18259 master.cpp:3319] Disconnecting framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:25.573693 18259 master.cpp:1425] Giving framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657 0ns to failover
I0716 21:57:25.574334 18260 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,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_vXKRYL/2GB-1a453f14-8783-4d43-8aaa-52e1e170234c,test)]:2048, allocated: {}) on agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 from framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:25.574412 18271 manager.cpp:163] Terminating resource provider 7ac238d2-c7ea-4aeb-9efd-c3a7b2cc06e9
I0716 21:57:25.574793 18257 master.cpp:10087] Framework failover timeout, removing framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
I0716 21:57:25.574826 18257 master.cpp:11079] Removing framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000 (default) at scheduler-f3371e27-6d91-4fb6-98d6-a9ce9eda6ddd@172.17.0.2:40657
E0716 21:57:25.575181 18250 http_connection.hpp:452] End-Of-File received
I0716 21:57:25.575222 18269 hierarchical.cpp:1432] Allocation paused
I0716 21:57:25.575263 18257 master.cpp:1295] Agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f) disconnected
I0716 21:57:25.575297 18257 master.cpp:3379] Disconnecting agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:25.575435 18257 master.cpp:3398] Deactivating agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 at slave(1208)@172.17.0.2:40657 (12367fa3ab0f)
I0716 21:57:25.575618 18269 hierarchical.cpp:417] Removed framework 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-0000
I0716 21:57:25.575662 18269 hierarchical.cpp:1442] Allocation resumed
I0716 21:57:25.575660 18250 http_connection.hpp:217] Re-detecting endpoint
I0716 21:57:25.575736 18269 hierarchical.cpp:799] Agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0 deactivated
I0716 21:57:25.576017 18250 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0716 21:57:25.576084 18266 provider.cpp:471] Disconnected from resource provider manager
I0716 21:57:25.576103 18250 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0716 21:57:25.576189 18250 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:25.576195 18251 status_update_manager_process.hpp:379] Pausing operation status update manager
I0716 21:57:25.577394 18265 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
I0716 21:57:25.577426 18265 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
I0716 21:57:25.577783 18265 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0716 21:57:25.578742 18269 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
I0716 21:57:25.579253 18249 provider.cpp:459] Connected to resource provider manager
I0716 21:57:25.579715 18266 hierarchical.cpp:1508] Performed allocation for 1 agents in 130715ns
I0716 21:57:25.579843 18258 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:40657/slave(1208)/api/v1/resource_provider
E0716 21:57:25.580307 18258 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Cannot process 'SUBSCRIBE' call as the driver is in state SUBSCRIBING
I0716 21:57:25.580528 18273 process.cpp:2781] Returning '404 Not Found' for '/slave(1208)/api/v1/resource_provider'
E0716 21:57:25.581662 18250 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0716 21:57:25.631294 18262 hierarchical.cpp:1508] Performed allocation for 1 agents in 93894ns
I0716 21:57:25.681579 18256 containerizer.cpp:3116] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0716 21:57:25.681834 18267 hierarchical.cpp:1508] Performed allocation for 1 agents in 100553ns
I0716 21:57:25.682997 18269 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
I0716 21:57:25.685106 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'
I0716 21:57:25.685294 18263 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-mfHgo8/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0716 21:57:25.685508 18264 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0716 21:57:25.687341 18273 process.cpp:2781] Returning '404 Not Found' for '/slave(1208)/api/v1'
I0716 21:57:25.697322 18248 master.cpp:1135] Master terminating
I0716 21:57:25.697877 18272 hierarchical.cpp:775] Removed all filters for agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
I0716 21:57:25.697902 18272 hierarchical.cpp:650] Removed agent 56f0e2b7-a7d3-428e-b1e9-c33450fc492e-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (2509 ms)
[----------] 50 tests from CSIVersion/StorageLocalResourceProviderTest (120378 ms total)
[----------] Global test environment tear-down
[==========] 2273 tests from 216 test cases ran. (1218735 ms total)
[ PASSED ] 2271 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] ExamplesTest.PythonFramework
[ FAILED ] ParentChildContainerTypeAndContentType/AgentContainerAPITest.RecoverNestedContainer/4, where GetParam() = (0, 1, application/json, ("posix/cpu,posix/mem", "posix", ""))
2 FAILED TESTS
YOU HAVE 31 DISABLED TESTS
I0716 21:57:25.785575 18273 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-1563308145-27877
Untagged: mesos-1563308145-27877:latest
Deleted: sha256:ef05b52e45908b1f6bce1b4aa38b3ab2ac7f474c61d47b9aa4eb13783063a4d1
Deleted: sha256:550ea11fdea573c6e020e99b049b04dbe69b003acb17f663b5c01d622e3508c5
Deleted: sha256:7a0041f0e42c39e9e6243d16354cdea765d3e3f418b878ddefabe04f73e1b216
Deleted: sha256:a52f9489f38d4d097ae930a09be9828342c8d4d16ff06c7b1486cabd144a06b0
Deleted: sha256:5462dba3b0bc227dc84734f520348ddf372408133672e7dc5088d79a676300a4
Deleted: sha256:755eb4b26f1ab23ce97b5b31cf00bd77498956cda0c1774f693b08a0501cb27a
Deleted: sha256:f9504d6d1721228f1aa7b8776e777d75128db0ffc176bd1f48238df60c892bed
Deleted: sha256:b0ea72a789331c7694d9e9d6a86e9498cb596d2c7014b0a0d19d618b359d0298
Deleted: sha256:b349ca0f04b071170801277072efaec0bda1a9b01668fd52ccbf10f3ee5d0226
Deleted: sha256:3958e917c76717dd952c225a17c2d89eecb996a99cde0810f856ff9d47950403
Deleted: sha256:8d61d544325c66894f22e747b0f25460d5b3e838289006bce9c59bf71d2989ac
Deleted: sha256:83b4182bccb1592f447adf52f8e5117d275a262e0bf7203cea5b2ac8f992d02d
Deleted: sha256:e3d182c00cc37c0b3d12ca57278831fc719d2a619cfc156d566c9cbe846205ad
Deleted: sha256:9cc46bcad783d4763fdd76042a40cea8ec96f5d32f3d790324528bed9cf013a9
Deleted: sha256:0b94887d233b78b2e2a1b4ae77b5303df247d76a04eff840cb6c395990945c5f
Deleted: sha256:4250692b52e3f442ce468084c385bce401fa8abfc80fa46929f6ab919cc03699
Deleted: sha256:0381fc1844461290f5bc8e1ba243f74cbeb8722f50db7bf18122e20693241a0d
Deleted: sha256:5500d24c2e79234818cbedc5315ff8f9fc0559ac3e7c4514f8a565ac3f9f75c0
Deleted: sha256:8f9903c235a7ab1fa7b12fea84945726cb51664e4f69a4665d35aefe29ebc795
Deleted: sha256:fa6f0689ed65c127822b46035ebbc02972c3e738c7d57108c35c3c7ad193af13
Deleted: sha256:8b9bf3b792b42818a40c0557fd5bf1d9aef045d3de31c10a26cdabcc98a7ff8b
Deleted: sha256:26bfcf538a25f19cc7606436a430d25ec9c6f3cc8f979e50ce7c8efb1353ae67
Deleted: sha256:5e22d0b767190bbd3da887a8e5e43e108e64361d681668e3913edb85c6ab03cb
Deleted: sha256:c1c602ae79a445f368ceda4d2d0ee073e6b5807ac4843893de23eae4623fcacf
Deleted: sha256:14954c4e16651dfcb62f2057df871a7ad534e6ccfe216b3420a5ccc8aa9611a5
Deleted: sha256:e971c93265abfd918da677085caac40e45d6bb6e82fe088df2819fbaf83c1e9f
Deleted: sha256:722690e93b29788fcf736aea50093d10e48f541a096748a0f12dd340baabe44b
Deleted: sha256:941bae222505bdb2235f6c9595d92ad4eb70d116e7a0e8addde2d17099d51cb9
Deleted: sha256:fcfe77b48615c572930ed60d6760ed41a2015f362fab75947b37e6d9e3d1257b
Deleted: sha256:49dfff84757f4a41e59eb8325cd35bf46792e289de93c73157bee7dba0dab2de
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/2590/console
- Mesos Reviewbot
On July 16, 2019, 3:14 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71084/
> -----------------------------------------------------------
>
> (Updated July 16, 2019, 3:14 p.m.)
>
>
> Review request for mesos, Benjamin Mahler and Meng Zhu.
>
>
> Bugs: MESOS-9864
> https://issues.apache.org/jira/browse/MESOS-9864
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch ensures that the list of suppressed roles is passed through
> the `updateFramework()` of python V0 bindings. Now the framework
> subscribes with all roles suppressed and after that issues
> UPDATE_FRAMEWORK call to unsuppress offers.
>
>
> Diffs
> -----
>
> src/examples/python/test_framework.py 27bc052dc4e57e0290ef58a39b2f1ac82fdb42fd
>
>
> Diff: https://reviews.apache.org/r/71084/diff/1/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 71084: Added unsuppressing via `updateFramework()`
to python example framework.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71084/#review216814
-----------------------------------------------------------
Patch looks great!
Reviews applied: [71082, 71083, 71084]
Passed command: 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
- Mesos Reviewbot
On July 16, 2019, 3:14 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71084/
> -----------------------------------------------------------
>
> (Updated July 16, 2019, 3:14 p.m.)
>
>
> Review request for mesos, Benjamin Mahler and Meng Zhu.
>
>
> Bugs: MESOS-9864
> https://issues.apache.org/jira/browse/MESOS-9864
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch ensures that the list of suppressed roles is passed through
> the `updateFramework()` of python V0 bindings. Now the framework
> subscribes with all roles suppressed and after that issues
> UPDATE_FRAMEWORK call to unsuppress offers.
>
>
> Diffs
> -----
>
> src/examples/python/test_framework.py 27bc052dc4e57e0290ef58a39b2f1ac82fdb42fd
>
>
> Diff: https://reviews.apache.org/r/71084/diff/1/
>
>
> Testing
> -------
>
> `./bin/mesos-tests.sh --gtest_filter="ExamplesTest.PythonFramework*" --gtest_break_on_failure --gtest_repeat=5`
>
>
> Thanks,
>
> Andrei Sekretenko
>
>