You are viewing a plain text version of this content. The canonical link for it is here.
Posted to reviews@mesos.apache.org by Benjamin Bannier <bb...@apache.org> on 2019/08/06 19:28:11 UTC
Review Request 71241: Added a `distcheck` target to the cmake build.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71241/
-----------------------------------------------------------
Review request for mesos, Benjamin Mahler and Till Toenshoff.
Repository: mesos
Description
-------
This patch adds a `distcheck` target to the cmake build which mimics the
target of the same name provided by the autotools build. `distcheck`
depends on the `dist` target to create a distribution archive and then
ensures that with the distributed sources the `check` targets succeeds.
Diffs
-----
CMakeLists.txt 65bfbac0e2b6aec26a6d98ff96615661210ceac2
cmake/distcheck.sh PRE-CREATION
Diff: https://reviews.apache.org/r/71241/diff/1/
Testing
-------
`ninja distcheck` passes, no artifacts left around but tarball.
Thanks,
Benjamin Bannier
Re: Review Request 71241: Added a `distcheck` target to the cmake
build.
Posted by Benjamin Bannier <bb...@apache.org>.
> On Sept. 3, 2019, 3:08 p.m., Benno Evers wrote:
> > cmake/distcheck.sh
> > Lines 25 (patched)
> > <https://reviews.apache.org/r/71241/diff/1/?file=2159995#file2159995line25>
> >
> > I don't think we should unconditionally override the users environment like this in a support script - there's no guarantee that `clang` or `ccache` are even installed.
> >
> > If we have to specify `CMAKE_CXX_COMPILER` etc. at all, we should probably use `${CXX}` as default value and make sure that cmake sets the correct values when invoking the script.
Thanks for catching this. This isn't only not nice, but shouldn't have been there at all; I simply forgot implementing this part.
What I do now is to pass a shell variable `DISTCHECK_CMAKE_ARGS` (modelled after autoconf's `DISTCHECK_CONFIGURE_ARGS`) which can be filled with the kinds of arguments I passed above.
```
cmake .. ${DISTCHECK_CMAKE_FLAGS}
```
- Benjamin
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71241/#review217542
-----------------------------------------------------------
On Sept. 3, 2019, 3:52 p.m., Benjamin Bannier wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71241/
> -----------------------------------------------------------
>
> (Updated Sept. 3, 2019, 3:52 p.m.)
>
>
> Review request for mesos, Benjamin Mahler and Till Toenshoff.
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch adds a `distcheck` target to the cmake build which mimics the
> target of the same name provided by the autotools build. `distcheck`
> depends on the `dist` target to create a distribution archive and then
> ensures that with the distributed sources the `check` targets succeeds.
>
>
> Diffs
> -----
>
> CMakeLists.txt dc50dd457585c14a456ca710da4a16a0d45ef17a
> cmake/distcheck.sh PRE-CREATION
>
>
> Diff: https://reviews.apache.org/r/71241/diff/2/
>
>
> Testing
> -------
>
> `ninja distcheck` passes, no artifacts left around but tarball.
>
>
> Thanks,
>
> Benjamin Bannier
>
>
Re: Review Request 71241: Added a `distcheck` target to the cmake
build.
Posted by Benno Evers <be...@mesosphere.com>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71241/#review217542
-----------------------------------------------------------
cmake/distcheck.sh
Lines 22 (patched)
<https://reviews.apache.org/r/71241/#comment304796>
Probably makes no difference, but `mesos-${VERSION}` looks a bit safer.
cmake/distcheck.sh
Lines 25 (patched)
<https://reviews.apache.org/r/71241/#comment304795>
I don't think we should unconditionally override the users environment like this in a support script - there's no guarantee that `clang` or `ccache` are even installed.
If we have to specify `CMAKE_CXX_COMPILER` etc. at all, we should probably use `${CXX}` as default value and make sure that cmake sets the correct values when invoking the script.
- Benno Evers
On Aug. 6, 2019, 7:28 p.m., Benjamin Bannier wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71241/
> -----------------------------------------------------------
>
> (Updated Aug. 6, 2019, 7:28 p.m.)
>
>
> Review request for mesos, Benjamin Mahler and Till Toenshoff.
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch adds a `distcheck` target to the cmake build which mimics the
> target of the same name provided by the autotools build. `distcheck`
> depends on the `dist` target to create a distribution archive and then
> ensures that with the distributed sources the `check` targets succeeds.
>
>
> Diffs
> -----
>
> CMakeLists.txt 65bfbac0e2b6aec26a6d98ff96615661210ceac2
> cmake/distcheck.sh PRE-CREATION
>
>
> Diff: https://reviews.apache.org/r/71241/diff/1/
>
>
> Testing
> -------
>
> `ninja distcheck` passes, no artifacts left around but tarball.
>
>
> Thanks,
>
> Benjamin Bannier
>
>
Re: Review Request 71241: Added a `distcheck` target to the cmake
build.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71241/#review217107
-----------------------------------------------------------
Patch looks great!
Reviews applied: [71240, 71241]
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 Aug. 6, 2019, 7:28 p.m., Benjamin Bannier wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71241/
> -----------------------------------------------------------
>
> (Updated Aug. 6, 2019, 7:28 p.m.)
>
>
> Review request for mesos, Benjamin Mahler and Till Toenshoff.
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch adds a `distcheck` target to the cmake build which mimics the
> target of the same name provided by the autotools build. `distcheck`
> depends on the `dist` target to create a distribution archive and then
> ensures that with the distributed sources the `check` targets succeeds.
>
>
> Diffs
> -----
>
> CMakeLists.txt 65bfbac0e2b6aec26a6d98ff96615661210ceac2
> cmake/distcheck.sh PRE-CREATION
>
>
> Diff: https://reviews.apache.org/r/71241/diff/1/
>
>
> Testing
> -------
>
> `ninja distcheck` passes, no artifacts left around but tarball.
>
>
> Thanks,
>
> Benjamin Bannier
>
>
Re: Review Request 71241: Added a `distcheck` target to the cmake
build.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71241/#review217607
-----------------------------------------------------------
Bad patch!
Reviews applied: [71240, 71241]
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_71241"]
Error:
...<truncated>...
ramework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000 (default) at scheduler-c294e96f-a4dd-489c-be9d-e20c68060326@172.17.0.3:42379
I0906 12:42:00.742789 18628 sched.cpp:934] Scheduler::resourceOffers took 114067ns
I0906 12:42:00.748823 18626 http.cpp:1115] HTTP POST for /slave(1246)/api/v1/resource_provider from 172.17.0.3:33882
I0906 12:42:00.749876 18607 slave.cpp:8481] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: e237324c-6556-4c07-b596-ceea66137de5) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0906 12:42:00.750048 18607 slave.cpp:8934] Updating the state of operation with no ID (uuid: e237324c-6556-4c07-b596-ceea66137de5) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0906 12:42:00.750093 18607 slave.cpp:8688] Forwarding status update of operation with no ID (operation_uuid: e237324c-6556-4c07-b596-ceea66137de5) for an operator API call
I0906 12:42:00.750433 18619 master.cpp:12271] Updating the state of operation '' (uuid: e237324c-6556-4c07-b596-ceea66137de5) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0906 12:42:00.751109 18607 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I0906 12:42:00.826470 18622 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 0a86130b-e0a7-4709-8e5a-6f8f95c51e5e) for operation UUID 478d2252-ba1a-4da2-a023-4de0d3db7b1e on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:00.826575 18622 status_update_manager_process.hpp:414] Creating operation status update stream 478d2252-ba1a-4da2-a023-4de0d3db7b1e checkpoint=true
I0906 12:42:00.826617 18615 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0906 12:42:00.827093 18622 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 0a86130b-e0a7-4709-8e5a-6f8f95c51e5e) for operation UUID 478d2252-ba1a-4da2-a023-4de0d3db7b1e on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:00.909956 18622 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 0a86130b-e0a7-4709-8e5a-6f8f95c51e5e) for operation UUID 478d2252-ba1a-4da2-a023-4de0d3db7b1e on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:00.910375 18622 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 5bc541ef-92e0-4b05-ba4e-e4cfb499a7d5) for stream e237324c-6556-4c07-b596-ceea66137de5
I0906 12:42:00.910452 18622 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 5bc541ef-92e0-4b05-ba4e-e4cfb499a7d5) for operation UUID e237324c-6556-4c07-b596-ceea66137de5 on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:00.911002 18612 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.3:42379/slave(1246)/api/v1/resource_provider
I0906 12:42:00.912227 18627 process.cpp:3671] Handling HTTP event for process 'slave(1246)' with path: '/slave(1246)/api/v1/resource_provider'
I0906 12:42:00.952363 18625 http.cpp:1115] HTTP POST for /slave(1246)/api/v1/resource_provider from 172.17.0.3:33882
I0906 12:42:00.953371 18621 slave.cpp:8481] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 478d2252-ba1a-4da2-a023-4de0d3db7b1e) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0906 12:42:00.953565 18621 slave.cpp:8934] Updating the state of operation with no ID (uuid: 478d2252-ba1a-4da2-a023-4de0d3db7b1e) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0906 12:42:00.953629 18621 slave.cpp:8688] Forwarding status update of operation with no ID (operation_uuid: 478d2252-ba1a-4da2-a023-4de0d3db7b1e) for an operator API call
I0906 12:42:00.954083 18607 master.cpp:12271] Updating the state of operation '' (uuid: 478d2252-ba1a-4da2-a023-4de0d3db7b1e) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0906 12:42:00.954618 18620 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I0906 12:42:00.955955 18609 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0906 12:42:00.960182 18622 status_update_manager_process.hpp:490] Cleaning up operation status update stream e237324c-6556-4c07-b596-ceea66137de5
I0906 12:42:00.960394 18622 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 0a86130b-e0a7-4709-8e5a-6f8f95c51e5e) for stream 478d2252-ba1a-4da2-a023-4de0d3db7b1e
I0906 12:42:00.960464 18622 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 0a86130b-e0a7-4709-8e5a-6f8f95c51e5e) for operation UUID 478d2252-ba1a-4da2-a023-4de0d3db7b1e on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:01.060760 18622 status_update_manager_process.hpp:490] Cleaning up operation status update stream 478d2252-ba1a-4da2-a023-4de0d3db7b1e
I0906 12:42:01.124150 18619 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0906 12:42:01.126152 18606 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.3:33894
I0906 12:42:01.126492 18606 http.cpp:263] Processing call DESTROY_VOLUMES
I0906 12:42:01.127413 18606 master.cpp:3998] Authorizing principal 'test-principal' to destroy volumes '[{"disk":{"persistence":{"id":"f6896553-7ab1-4c3a-ad71-c04ad06fc01b","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_B5crby/2GB-54391f4c-b2f8-4781-9880-017a433a4d80","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":"1f7ae4b6-e62b-4b61-b51e-7b2cca8bad9a"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0906 12:42:01.129427 18614 master.cpp:12724] Removing offer aa177ea5-65f5-46eb-9a91-32a999ab669d-O4
I0906 12:42:01.129580 18611 sched.cpp:960] Rescinded offer aa177ea5-65f5-46eb-9a91-32a999ab669d-O4
I0906 12:42:01.129686 18611 sched.cpp:971] Scheduler::offerRescinded took 45797ns
I0906 12:42:01.130216 18618 hierarchical.cpp:1451] Recovered ports(allocated: storage/default-role):[31000-32000]; 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_B5crby/2GB-54391f4c-b2f8-4781-9880-017a433a4d80,test),f6896553-7ab1-4c3a-ad71-c04ad06fc01b:volume]:2048; 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),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_B5crby/2GB-54391f4c-b2f8-4781-9880-017a433a4d80,test),f6896553-7ab1-4c3a-ad71-c04ad06fc01b:volume]:2048, offered
or allocated: {}) on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0 from framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000
I0906 12:42:01.130318 18618 hierarchical.cpp:1498] Framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000 filtered agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0 for 5secs
I0906 12:42:01.133013 18628 master.cpp:12615] Sending operation '' (uuid: e48cd312-2044-4965-b1e2-9ff8458df7fe) to agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0 at slave(1246)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:01.133564 18627 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I0906 12:42:01.136265 18621 provider.cpp:498] Received APPLY_OPERATION event
I0906 12:42:01.136308 18621 provider.cpp:1351] Received DESTROY operation '' (uuid: e48cd312-2044-4965-b1e2-9ff8458df7fe)
I0906 12:42:01.145169 18610 hierarchical.cpp:1726] Performed allocation for 1 agents in 1.511309ms
I0906 12:42:01.145783 18606 master.cpp:10432] Sending offers [ aa177ea5-65f5-46eb-9a91-32a999ab669d-O5 ] to framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000 (default) at scheduler-c294e96f-a4dd-489c-be9d-e20c68060326@172.17.0.3:42379
I0906 12:42:01.146672 18620 sched.cpp:934] Scheduler::resourceOffers took 117965ns
I0906 12:42:01.246989 18623 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 453c0b12-5706-4240-bdde-d843c161b79c) for operation UUID e48cd312-2044-4965-b1e2-9ff8458df7fe on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:01.247120 18623 status_update_manager_process.hpp:414] Creating operation status update stream e48cd312-2044-4965-b1e2-9ff8458df7fe checkpoint=true
I0906 12:42:01.247578 18623 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 453c0b12-5706-4240-bdde-d843c161b79c) for operation UUID e48cd312-2044-4965-b1e2-9ff8458df7fe on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:01.313849 18623 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 453c0b12-5706-4240-bdde-d843c161b79c) for operation UUID e48cd312-2044-4965-b1e2-9ff8458df7fe on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:01.314862 18614 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.3:42379/slave(1246)/api/v1/resource_provider
I0906 12:42:01.316081 18617 process.cpp:3671] Handling HTTP event for process 'slave(1246)' with path: '/slave(1246)/api/v1/resource_provider'
I0906 12:42:01.319257 18627 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0906 12:42:01.320825 18625 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.3:33896
I0906 12:42:01.321063 18625 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0906 12:42:01.321781 18625 master.cpp:3890] Authorizing principal 'test-principal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_B5crby/2GB-54391f4c-b2f8-4781-9880-017a433a4d80","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":"1f7ae4b6-e62b-4b61-b51e-7b2cca8bad9a"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0906 12:42:01.323554 18616 master.cpp:12724] Removing offer aa177ea5-65f5-46eb-9a91-32a999ab669d-O5
I0906 12:42:01.323693 18606 sched.cpp:960] Rescinded offer aa177ea5-65f5-46eb-9a91-32a999ab669d-O5
I0906 12:42:01.323772 18606 sched.cpp:971] Scheduler::offerRescinded took 28552ns
I0906 12:42:01.324385 18610 hierarchical.cpp:1451] Recovered ports(allocated: storage/default-role):[31000-32000]; 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_B5crby/2GB-54391f4c-b2f8-4781-9880-017a433a4d80,test)]:2048; 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),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_B5crby/2GB-54391f4c-b2f8-4781-9880-017a433a4d80,test)]:2048, offered or allocated: {}) on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0 from framework aa177
ea5-65f5-46eb-9a91-32a999ab669d-0000
I0906 12:42:01.324533 18610 hierarchical.cpp:1498] Framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000 filtered agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0 for 5secs
I0906 12:42:01.326588 18620 master.cpp:12615] Sending operation '' (uuid: f9e85028-bd94-460e-b7ce-75616e823cbd) to agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0 at slave(1246)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:01.327212 18611 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I0906 12:42:01.329560 18609 hierarchical.cpp:1726] Performed allocation for 1 agents in 1.051601ms
I0906 12:42:01.329869 18619 provider.cpp:498] Received APPLY_OPERATION event
I0906 12:42:01.329910 18619 provider.cpp:1351] Received UNRESERVE operation '' (uuid: f9e85028-bd94-460e-b7ce-75616e823cbd)
I0906 12:42:01.330111 18627 master.cpp:10432] Sending offers [ aa177ea5-65f5-46eb-9a91-32a999ab669d-O6 ] to framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000 (default) at scheduler-c294e96f-a4dd-489c-be9d-e20c68060326@172.17.0.3:42379
I0906 12:42:01.330657 18625 sched.cpp:934] Scheduler::resourceOffers took 74808ns
I0906 12:42:01.356148 18614 http.cpp:1115] HTTP POST for /slave(1246)/api/v1/resource_provider from 172.17.0.3:33882
I0906 12:42:01.357007 18620 slave.cpp:8481] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: e48cd312-2044-4965-b1e2-9ff8458df7fe) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0906 12:42:01.357169 18620 slave.cpp:8934] Updating the state of operation with no ID (uuid: e48cd312-2044-4965-b1e2-9ff8458df7fe) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0906 12:42:01.357219 18620 slave.cpp:8688] Forwarding status update of operation with no ID (operation_uuid: e48cd312-2044-4965-b1e2-9ff8458df7fe) for an operator API call
I0906 12:42:01.357594 18623 master.cpp:12271] Updating the state of operation '' (uuid: e48cd312-2044-4965-b1e2-9ff8458df7fe) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0906 12:42:01.358098 18628 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I0906 12:42:01.431797 18625 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 5d99b34d-a88d-4e43-8f46-da21377158bc) for operation UUID f9e85028-bd94-460e-b7ce-75616e823cbd on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:01.431855 18625 status_update_manager_process.hpp:414] Creating operation status update stream f9e85028-bd94-460e-b7ce-75616e823cbd checkpoint=true
I0906 12:42:01.431890 18619 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0906 12:42:01.432301 18625 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 5d99b34d-a88d-4e43-8f46-da21377158bc) for operation UUID f9e85028-bd94-460e-b7ce-75616e823cbd on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:01.482233 18625 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 5d99b34d-a88d-4e43-8f46-da21377158bc) for operation UUID f9e85028-bd94-460e-b7ce-75616e823cbd on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:01.482667 18625 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 453c0b12-5706-4240-bdde-d843c161b79c) for stream e48cd312-2044-4965-b1e2-9ff8458df7fe
I0906 12:42:01.482736 18625 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 453c0b12-5706-4240-bdde-d843c161b79c) for operation UUID e48cd312-2044-4965-b1e2-9ff8458df7fe on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:01.483165 18608 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.3:42379/slave(1246)/api/v1/resource_provider
I0906 12:42:01.484308 18610 process.cpp:3671] Handling HTTP event for process 'slave(1246)' with path: '/slave(1246)/api/v1/resource_provider'
I0906 12:42:01.524325 18617 http.cpp:1115] HTTP POST for /slave(1246)/api/v1/resource_provider from 172.17.0.3:33882
I0906 12:42:01.525228 18611 slave.cpp:8481] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: f9e85028-bd94-460e-b7ce-75616e823cbd) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0906 12:42:01.525393 18611 slave.cpp:8934] Updating the state of operation with no ID (uuid: f9e85028-bd94-460e-b7ce-75616e823cbd) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0906 12:42:01.525434 18611 slave.cpp:8688] Forwarding status update of operation with no ID (operation_uuid: f9e85028-bd94-460e-b7ce-75616e823cbd) for an operator API call
I0906 12:42:01.525746 18628 master.cpp:12271] Updating the state of operation '' (uuid: f9e85028-bd94-460e-b7ce-75616e823cbd) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0906 12:42:01.526255 18622 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I0906 12:42:01.527635 18606 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0906 12:42:01.574497 18625 status_update_manager_process.hpp:490] Cleaning up operation status update stream e48cd312-2044-4965-b1e2-9ff8458df7fe
I0906 12:42:01.574708 18625 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 5d99b34d-a88d-4e43-8f46-da21377158bc) for stream f9e85028-bd94-460e-b7ce-75616e823cbd
I0906 12:42:01.574780 18625 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 5d99b34d-a88d-4e43-8f46-da21377158bc) for operation UUID f9e85028-bd94-460e-b7ce-75616e823cbd on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:01.675483 18625 status_update_manager_process.hpp:490] Cleaning up operation status update stream f9e85028-bd94-460e-b7ce-75616e823cbd
I0906 12:42:01.769165 18620 master.cpp:1412] Framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000 (default) at scheduler-c294e96f-a4dd-489c-be9d-e20c68060326@172.17.0.3:42379 disconnected
I0906 12:42:01.769206 18620 master.cpp:3362] Deactivating framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000 (default) at scheduler-c294e96f-a4dd-489c-be9d-e20c68060326@172.17.0.3:42379
I0906 12:42:01.769511 18623 hierarchical.cpp:711] Deactivated framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000
I0906 12:42:01.770053 18620 master.cpp:12724] Removing offer aa177ea5-65f5-46eb-9a91-32a999ab669d-O6
I0906 12:42:01.770124 18620 master.cpp:3339] Disconnecting framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000 (default) at scheduler-c294e96f-a4dd-489c-be9d-e20c68060326@172.17.0.3:42379
I0906 12:42:01.770160 18626 slave.cpp:924] Agent terminating
I0906 12:42:01.770195 18620 master.cpp:1427] Giving framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000 (default) at scheduler-c294e96f-a4dd-489c-be9d-e20c68060326@172.17.0.3:42379 0ns to failover
I0906 12:42:01.770701 18623 hierarchical.cpp:1451] Recovered ports(allocated: storage/default-role):[31000-32000]; disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_B5crby/2GB-54391f4c-b2f8-4781-9880-017a433a4d80,test)]:2048; 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)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_B5crby/2GB-54391f4c-b2f8-4781-9880-017a433a4d80,test)]:2048, offered or allocated: {}) on agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0 from framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000
I0906 12:42:01.770921 18626 manager.cpp:163] Terminating resource provider 1f7ae4b6-e62b-4b61-b51e-7b2cca8bad9a
I0906 12:42:01.771284 18621 master.cpp:1297] Agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0 at slave(1246)@172.17.0.3:42379 (b0b8d2993b8d) disconnected
I0906 12:42:01.771313 18621 master.cpp:3399] Disconnecting agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0 at slave(1246)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:01.771392 18621 master.cpp:3418] Deactivating agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0 at slave(1246)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:01.771510 18617 hierarchical.cpp:1038] Agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0 deactivated
I0906 12:42:01.771617 18621 master.cpp:10224] Framework failover timeout, removing framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000 (default) at scheduler-c294e96f-a4dd-489c-be9d-e20c68060326@172.17.0.3:42379
I0906 12:42:01.771647 18621 master.cpp:11223] Removing framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000 (default) at scheduler-c294e96f-a4dd-489c-be9d-e20c68060326@172.17.0.3:42379
E0906 12:42:01.771672 18622 http_connection.hpp:452] End-Of-File received
I0906 12:42:01.771988 18624 hierarchical.cpp:1650] Allocation paused
I0906 12:42:01.772110 18622 http_connection.hpp:217] Re-detecting endpoint
I0906 12:42:01.772514 18624 hierarchical.cpp:655] Removed framework aa177ea5-65f5-46eb-9a91-32a999ab669d-0000
I0906 12:42:01.772518 18622 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0906 12:42:01.772565 18616 provider.cpp:488] Disconnected from resource provider manager
I0906 12:42:01.772567 18624 hierarchical.cpp:1660] Allocation resumed
I0906 12:42:01.772598 18622 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0906 12:42:01.772686 18622 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:42379/slave(1246)/api/v1/resource_provider
I0906 12:42:01.772701 18606 status_update_manager_process.hpp:379] Pausing operation status update manager
I0906 12:42:01.773972 18612 containerizer.cpp:2620] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0906 12:42:01.774013 18612 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 2.671960192secs
I0906 12:42:01.774436 18612 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:01.775194 18627 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.3:42379/slave(1246)/api/v1/resource_provider
I0906 12:42:01.775687 18616 provider.cpp:476] Connected to resource provider manager
I0906 12:42:01.776124 18610 hierarchical.cpp:1726] Performed allocation for 1 agents in 139199ns
I0906 12:42:01.776190 18614 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.3:42379/slave(1246)/api/v1/resource_provider
E0906 12:42:01.776643 18614 provider.cpp:721] 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
I0906 12:42:01.776851 18629 process.cpp:2781] Returning '404 Not Found' for '/slave(1246)/api/v1/resource_provider'
E0906 12:42:01.777782 18622 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0906 12:42:01.827857 18615 hierarchical.cpp:1726] Performed allocation for 1 agents in 221131ns
I0906 12:42:01.878170 18628 containerizer.cpp:3161] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0906 12:42:01.879540 18627 hierarchical.cpp:1726] Performed allocation for 1 agents in 206290ns
I0906 12:42:01.879748 18610 provisioner.cpp:612] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:01.882222 18605 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'
I0906 12:42:01.882405 18621 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-5t0b7F/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:01.882649 18609 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:01.885139 18629 process.cpp:2781] Returning '404 Not Found' for '/slave(1246)/api/v1'
I0906 12:42:01.895411 18604 master.cpp:1137] Master terminating
I0906 12:42:01.896224 18624 hierarchical.cpp:1014] Removed all filters for agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
I0906 12:42:01.896260 18624 hierarchical.cpp:891] Removed agent aa177ea5-65f5-46eb-9a91-32a999ab669d-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (2556 ms)
[ RUN ] CSIVersion/StorageLocalResourceProviderTest.Update/v0
I0906 12:42:01.918799 18604 cluster.cpp:177] Creating default 'local' authorizer
I0906 12:42:01.923483 18613 master.cpp:440] Master 3e3c2426-bdc4-42da-80ef-fd10de7096af (b0b8d2993b8d) started on 172.17.0.3:42379
I0906 12:42:01.923511 18613 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/MiblS6/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.10.0/_inst/share/mesos/webui" --work_dir="/tmp/MiblS6/master" --zk_session_timeout="10secs"
I0906 12:42:01.923849 18613 master.cpp:492] Master only allowing authenticated frameworks to register
I0906 12:42:01.923869 18613 master.cpp:498] Master only allowing authenticated agents to register
I0906 12:42:01.923883 18613 master.cpp:504] Master only allowing authenticated HTTP frameworks to register
I0906 12:42:01.923893 18613 credentials.hpp:37] Loading credentials for authentication from '/tmp/MiblS6/credentials'
I0906 12:42:01.924196 18613 master.cpp:548] Using default 'crammd5' authenticator
I0906 12:42:01.924391 18613 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0906 12:42:01.924612 18613 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0906 12:42:01.924775 18613 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0906 12:42:01.924943 18613 master.cpp:629] Authorization enabled
I0906 12:42:01.925357 18625 whitelist_watcher.cpp:77] No whitelist given
I0906 12:42:01.925370 18628 hierarchical.cpp:474] Initialized hierarchical allocator process
I0906 12:42:01.928027 18627 master.cpp:2170] Elected as the leading master!
I0906 12:42:01.928059 18627 master.cpp:1666] Recovering from registrar
I0906 12:42:01.928370 18609 registrar.cpp:339] Recovering registrar
I0906 12:42:01.929554 18609 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0906 12:42:01.929695 18609 registrar.cpp:487] Applied 1 operations in 38567ns; attempting to update the registry
I0906 12:42:01.930389 18609 registrar.cpp:544] Successfully updated the registry in 0ns
I0906 12:42:01.930517 18609 registrar.cpp:416] Successfully recovered registrar
I0906 12:42:01.930985 18615 master.cpp:1819] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I0906 12:42:01.931000 18621 hierarchical.cpp:513] Skipping recovery of hierarchical allocator: nothing to recover
W0906 12:42:01.937510 18604 process.cpp:2877] Attempted to spawn already running process files@172.17.0.3:42379
I0906 12:42:01.939009 18604 containerizer.cpp:318] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0906 12:42:01.939546 18604 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0906 12:42:01.939574 18604 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0906 12:42:01.939702 18604 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0906 12:42:01.939740 18604 provisioner.cpp:300] Using default backend 'copy'
I0906 12:42:01.942122 18604 cluster.cpp:518] Creating default 'local' authorizer
I0906 12:42:01.944344 18606 slave.cpp:267] Mesos agent started on (1247)@172.17.0.3:42379
I0906 12:42:01.944367 18606 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/MiblS6/atDUDy/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/MiblS6/atDUDy/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/MiblS6/atDUDy/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MiblS6/atDUDy/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/MiblS6/atDUDy/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/MiblS6/atDUDy/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.10.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/MiblS6/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_Update_v0_RZoLGr" --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_Update_v0_YNOCJk" --zk_sessio
n_timeout="10secs"
I0906 12:42:01.944790 18606 credentials.hpp:86] Loading credential for authentication from '/tmp/MiblS6/atDUDy/credential'
I0906 12:42:01.944993 18606 slave.cpp:300] Agent using credential for: test-principal
I0906 12:42:01.945017 18606 credentials.hpp:37] Loading credentials for authentication from '/tmp/MiblS6/atDUDy/http_credentials'
I0906 12:42:01.945248 18606 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0906 12:42:01.945679 18606 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0906 12:42:01.947237 18628 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I0906 12:42:01.947578 18606 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0906 12:42:01.947770 18606 slave.cpp:623] Agent attributes: [ ]
I0906 12:42:01.947785 18606 slave.cpp:632] Agent hostname: b0b8d2993b8d
I0906 12:42:01.947968 18610 task_status_update_manager.cpp:181] Pausing sending task status updates
I0906 12:42:01.947968 18613 status_update_manager_process.hpp:379] Pausing operation status update manager
I0906 12:42:01.949707 18626 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_YNOCJk/meta'
I0906 12:42:01.950014 18624 slave.cpp:7491] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_YNOCJk/meta', beginning agent recovery
I0906 12:42:01.950692 18618 task_status_update_manager.cpp:207] Recovering task status update manager
I0906 12:42:01.951201 18620 containerizer.cpp:821] Recovering Mesos containers
I0906 12:42:01.951591 18620 containerizer.cpp:1161] Recovering isolators
I0906 12:42:01.952581 18628 containerizer.cpp:1200] Recovering provisioner
I0906 12:42:01.953233 18627 provisioner.cpp:500] Provisioner recovery complete
I0906 12:42:01.953996 18611 composing.cpp:339] Finished recovering all containerizers
I0906 12:42:01.954283 18616 slave.cpp:7972] Recovering executors
I0906 12:42:01.954402 18616 slave.cpp:8125] Finished recovery
I0906 12:42:01.955431 18618 task_status_update_manager.cpp:181] Pausing sending task status updates
I0906 12:42:01.955483 18605 status_update_manager_process.hpp:379] Pausing operation status update manager
I0906 12:42:01.955513 18617 slave.cpp:1351] New master detected at master@172.17.0.3:42379
I0906 12:42:01.955721 18617 slave.cpp:1416] Detecting new master
I0906 12:42:01.957008 18625 slave.cpp:1443] Authenticating with master master@172.17.0.3:42379
I0906 12:42:01.957116 18625 slave.cpp:1452] Using default CRAM-MD5 authenticatee
I0906 12:42:01.957531 18620 authenticatee.cpp:121] Creating new client SASL connection
I0906 12:42:01.957918 18610 master.cpp:10617] Authenticating slave(1247)@172.17.0.3:42379
I0906 12:42:01.958072 18628 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2102)@172.17.0.3:42379
I0906 12:42:01.958366 18613 authenticator.cpp:98] Creating new server SASL connection
I0906 12:42:01.958616 18622 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0906 12:42:01.958650 18622 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0906 12:42:01.958796 18627 authenticator.cpp:204] Received SASL authentication start
I0906 12:42:01.958874 18627 authenticator.cpp:326] Authentication requires more steps
I0906 12:42:01.959010 18608 authenticatee.cpp:259] Received SASL authentication step
I0906 12:42:01.959158 18606 authenticator.cpp:232] Received SASL authentication step
I0906 12:42:01.959193 18606 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b0b8d2993b8d' server FQDN: 'b0b8d2993b8d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0906 12:42:01.959218 18606 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0906 12:42:01.959272 18606 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0906 12:42:01.959311 18606 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b0b8d2993b8d' server FQDN: 'b0b8d2993b8d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0906 12:42:01.959329 18606 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0906 12:42:01.959349 18606 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0906 12:42:01.959373 18606 authenticator.cpp:318] Authentication success
I0906 12:42:01.959522 18626 authenticatee.cpp:299] Authentication success
I0906 12:42:01.959597 18612 master.cpp:10649] Successfully authenticated principal 'test-principal' at slave(1247)@172.17.0.3:42379
I0906 12:42:01.959620 18624 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2102)@172.17.0.3:42379
I0906 12:42:01.960057 18614 slave.cpp:1543] Successfully authenticated with master master@172.17.0.3:42379
I0906 12:42:01.960495 18614 slave.cpp:1993] Will retry registration in 7.575022ms if necessary
I0906 12:42:01.960660 18616 master.cpp:7088] Received register agent message from slave(1247)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:01.960942 18616 master.cpp:4204] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I0906 12:42:01.961661 18605 master.cpp:7155] Authorized registration of agent at slave(1247)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:01.961786 18605 master.cpp:7267] Registering agent at slave(1247)@172.17.0.3:42379 (b0b8d2993b8d) with id 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0
I0906 12:42:01.962460 18607 registrar.cpp:487] Applied 1 operations in 229043ns; attempting to update the registry
I0906 12:42:01.963155 18607 registrar.cpp:544] Successfully updated the registry in 0ns
I0906 12:42:01.963336 18610 master.cpp:7315] Admitted agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0 at slave(1247)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:01.964082 18610 master.cpp:7360] Registered agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0 at slave(1247)@172.17.0.3:42379 (b0b8d2993b8d) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0906 12:42:01.964121 18622 slave.cpp:1576] Registered with master master@172.17.0.3:42379; given agent ID 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0
I0906 12:42:01.964222 18606 task_status_update_manager.cpp:188] Resuming sending task status updates
I0906 12:42:01.964207 18627 hierarchical.cpp:854] Added agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0 (b0b8d2993b8d) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I0906 12:42:01.964526 18627 hierarchical.cpp:1726] Performed allocation for 1 agents in 132102ns
I0906 12:42:01.964612 18622 slave.cpp:1611] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_YNOCJk/meta/slaves/3e3c2426-bdc4-42da-80ef-fd10de7096af-S0/slave.info'
I0906 12:42:01.964656 18612 status_update_manager_process.hpp:385] Resuming operation status update manager
I0906 12:42:01.966012 18622 slave.cpp:1663] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"m14m5chhQI+NdgfZQKAQnw=="},"slave_id":{"value":"3e3c2426-bdc4-42da-80ef-fd10de7096af-S0"},"update_oversubscribed_resources":false}
I0906 12:42:01.966819 18614 master.cpp:8487] Ignoring update on agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0 at slave(1247)@172.17.0.3:42379 (b0b8d2993b8d) as it reports no changes
I0906 12:42:01.970518 18613 process.cpp:3671] Handling HTTP event for process 'slave(1247)' with path: '/slave(1247)/api/v1'
I0906 12:42:01.971590 18611 http.cpp:1115] HTTP POST for /slave(1247)/api/v1 from 172.17.0.3:33904
I0906 12:42:01.972026 18611 http.cpp:2146] Processing GET_CONTAINERS call
I0906 12:42:01.977366 18607 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:01.979414 18610 process.cpp:3671] Handling HTTP event for process 'slave(1247)' with path: '/slave(1247)/api/v1'
I0906 12:42:01.980262 18609 http.cpp:1115] HTTP POST for /slave(1247)/api/v1 from 172.17.0.3:33906
I0906 12:42:01.981235 18609 http.cpp:2606] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:01.982102 18615 http.cpp:2710] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_YNOCJk/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:01.982760 18614 containerizer.cpp:1396] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:01.983394 18614 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from STARTING to PROVISIONING after 0ns
I0906 12:42:01.984086 18614 containerizer.cpp:1574] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_RZoLGr/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0906 12:42:01.984143 18614 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PROVISIONING to PREPARING after 0ns
I0906 12:42:01.986994 18623 containerizer.cpp:2100] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_yyLvMd","--available_capacity=0B","--volumes=","--forward=unix:///tmp/MiblS6/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.0/_build/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_YNOCJk/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-PCLlL0/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_YNOCJk/containers/org-apache-mesos-rp-local
-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="94" --pipe_write="95" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_RZoLGr/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I0906 12:42:01.995570 18623 launcher.cpp:145] Forked child with pid '32848' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:01.996384 18623 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PREPARING to ISOLATING after 0ns
I0906 12:42:01.997705 18623 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from ISOLATING to FETCHING after 0ns
I0906 12:42:01.998095 18611 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_Update_v0_YNOCJk/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:01.999359 18619 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from FETCHING to RUNNING after 0ns
I0906 12:42:02.002265 18625 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'
I0906 12:42:02.002583 18624 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-PCLlL0/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:02.163106 18606 hierarchical.cpp:1726] Performed allocation for 1 agents in 232883ns
I0906 12:42:02.214924 18617 hierarchical.cpp:1726] Performed allocation for 1 agents in 292468ns
I0906 12:42:02.266762 18605 hierarchical.cpp:1726] Performed allocation for 1 agents in 342783ns
I0906 12:42:02.318245 18621 hierarchical.cpp:1726] Performed allocation for 1 agents in 365723ns
I0906 12:42:02.369729 18627 hierarchical.cpp:1726] Performed allocation for 1 agents in 206362ns
I0906 12:42:02.420950 18622 hierarchical.cpp:1726] Performed allocation for 1 agents in 335973ns
I0906 12:42:02.437477 18618 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-PCLlL0/endpoint.sock' with CSI v1
I0906 12:42:02.439700 18628 service_manager.cpp:532] Probing endpoint 'unix:///tmp/mesos-csi-PCLlL0/endpoint.sock' with CSI v0
I0906 12:42:02.440604 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/Probe call
I0906 12:42:02.442960 18621 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:02.445487 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginCapabilities call
I0906 12:42:02.446571 18617 process.cpp:3671] Handling HTTP event for process 'slave(1247)' with path: '/slave(1247)/api/v1'
I0906 12:42:02.447819 18618 http.cpp:1115] HTTP POST for /slave(1247)/api/v1 from 172.17.0.3:33908
I0906 12:42:02.448361 18618 http.cpp:2824] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:02.449398 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginInfo call
I0906 12:42:02.449730 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginInfo call
I0906 12:42:02.451301 18610 v0_volume_manager.cpp:628] NODE_SERVICE loaded: {}
I0906 12:42:02.451892 18610 v0_volume_manager.cpp:628] CONTROLLER_SERVICE loaded: {}
I0906 12:42:02.453821 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ControllerGetCapabilities call
I0906 12:42:02.456802 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Node/NodeGetCapabilities call
I0906 12:42:02.459712 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Node/NodeGetId call
I0906 12:42:02.461704 18624 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0906 12:42:02.461820 18613 status_update_manager_process.hpp:379] Pausing operation status update manager
I0906 12:42:02.462265 18608 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:42379/slave(1247)/api/v1/resource_provider
I0906 12:42:02.465452 18627 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.3:42379/slave(1247)/api/v1/resource_provider
I0906 12:42:02.466053 18614 provider.cpp:476] Connected to resource provider manager
I0906 12:42:02.466625 18625 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.3:42379/slave(1247)/api/v1/resource_provider
I0906 12:42:02.467666 18618 process.cpp:3671] Handling HTTP event for process 'slave(1247)' with path: '/slave(1247)/api/v1/resource_provider'
I0906 12:42:02.469472 18607 http.cpp:1115] HTTP POST for /slave(1247)/api/v1/resource_provider from 172.17.0.3:33912
I0906 12:42:02.470176 18612 manager.cpp:813] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_yyLvMd","--available_capacity=0B","--volumes=","--forward=unix:///tmp/MiblS6/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.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"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}
I0906 12:42:02.472374 18622 hierarchical.cpp:1726] Performed allocation for 1 agents in 159246ns
I0906 12:42:02.508023 18627 slave.cpp:8481] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"980fbb82-62c1-4094-b0de-dbfd2338e3c1"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_yyLvMd","--available_capacity=0B","--volumes=","--forward=unix:///tmp/MiblS6/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.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"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}'
I0906 12:42:02.509766 18621 provider.cpp:498] Received SUBSCRIBED event
I0906 12:42:02.509810 18621 provider.cpp:1309] Subscribed with ID 980fbb82-62c1-4094-b0de-dbfd2338e3c1
I0906 12:42:02.510690 18624 status_update_manager_process.hpp:314] Recovering operation status update manager
I0906 12:42:02.523972 18612 hierarchical.cpp:1726] Performed allocation for 1 agents in 226491ns
I0906 12:42:02.549901 18607 provider.cpp:790] Reconciling storage pools and volumes
I0906 12:42:02.552440 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I0906 12:42:02.554921 18615 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0
I0906 12:42:02.555251 18626 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.3:42379/slave(1247)/api/v1/resource_provider
I0906 12:42:02.555336 18615 provider.cpp:748] Resource provider 980fbb82-62c1-4094-b0de-dbfd2338e3c1 is in READY state
I0906 12:42:02.555418 18614 status_update_manager_process.hpp:385] Resuming operation status update manager
I0906 12:42:02.556071 18628 provider.cpp:1235] Updating profiles { test } for resource provider 980fbb82-62c1-4094-b0de-dbfd2338e3c1
I0906 12:42:02.556471 18621 process.cpp:3671] Handling HTTP event for process 'slave(1247)' with path: '/slave(1247)/api/v1/resource_provider'
I0906 12:42:02.557231 18611 provider.cpp:790] Reconciling storage pools and volumes
I0906 12:42:02.558223 18605 http.cpp:1115] HTTP POST for /slave(1247)/api/v1/resource_provider from 172.17.0.3:33910
I0906 12:42:02.558838 18623 manager.cpp:1045] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 980fbb82-62c1-4094-b0de-dbfd2338e3c1
I0906 12:42:02.559078 18613 slave.cpp:8481] Handling resource provider message 'UPDATE_STATE: 980fbb82-62c1-4094-b0de-dbfd2338e3c1 {}'
I0906 12:42:02.559180 18613 slave.cpp:8601] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0906 12:42:02.559327 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I0906 12:42:02.559605 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/GetCapacity call
I0906 12:42:02.560801 18615 hierarchical.cpp:992] Grew agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0 by {} (total), { } (used)
I0906 12:42:02.561121 18615 hierarchical.cpp:950] Agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0 (b0b8d2993b8d) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0906 12:42:02.562871 18613 provider.cpp:808] Removing '{}' and adding 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001' to the total resources
I0906 12:42:02.616967 18613 provider.cpp:2217] Sending UPDATE_STATE call with resources 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001' and 0 operations to agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0
I0906 12:42:02.618309 18624 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.3:42379/slave(1247)/api/v1/resource_provider
I0906 12:42:02.619462 18618 process.cpp:3671] Handling HTTP event for process 'slave(1247)' with path: '/slave(1247)/api/v1/resource_provider'
I0906 12:42:02.621795 18616 hierarchical.cpp:1726] Performed allocation for 1 agents in 170036ns
I0906 12:42:02.622164 18605 provider.cpp:790] Reconciling storage pools and volumes
I0906 12:42:02.624562 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I0906 12:42:02.624848 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/GetCapacity call
I0906 12:42:02.628722 18617 provider.cpp:808] Removing '{}' and adding 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:0.001' to the total resources
I0906 12:42:02.664762 18611 http.cpp:1115] HTTP POST for /slave(1247)/api/v1/resource_provider from 172.17.0.3:33910
I0906 12:42:02.665537 18614 manager.cpp:1045] Received UPDATE_STATE call with resources '[{"disk":{"source":{"id":"volume1","type":"RAW","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"980fbb82-62c1-4094-b0de-dbfd2338e3c1"},"reservations":[{"role":"storage","type":"DYNAMIC"}],"scalar":{"value":0.0009765625},"type":"SCALAR"}]' and 0 operations from resource provider 980fbb82-62c1-4094-b0de-dbfd2338e3c1
I0906 12:42:02.666040 18623 slave.cpp:8481] Handling resource provider message 'UPDATE_STATE: 980fbb82-62c1-4094-b0de-dbfd2338e3c1 disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001'
I0906 12:42:02.666190 18623 slave.cpp:8601] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001
I0906 12:42:02.667641 18617 provider.cpp:2217] Sending UPDATE_STATE call with resources 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:0.001' and 0 operations to agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0
I0906 12:42:02.668095 18613 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.3:42379/slave(1247)/api/v1/resource_provider
I0906 12:42:02.668992 18627 process.cpp:3671] Handling HTTP event for process 'slave(1247)' with path: '/slave(1247)/api/v1/resource_provider'
I0906 12:42:02.669323 18625 hierarchical.cpp:950] Agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0 (b0b8d2993b8d) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001
I0906 12:42:02.669843 18625 hierarchical.cpp:1726] Performed allocation for 1 agents in 268895ns
I0906 12:42:02.671722 18618 hierarchical.cpp:1726] Performed allocation for 1 agents in 218724ns
I0906 12:42:02.671759 18610 provider.cpp:790] Reconciling storage pools and volumes
I0906 12:42:02.673920 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I0906 12:42:02.674188 32852 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/GetCapacity call
I0906 12:42:02.684528 18609 slave.cpp:924] Agent terminating
I0906 12:42:02.685395 18609 manager.cpp:163] Terminating resource provider 980fbb82-62c1-4094-b0de-dbfd2338e3c1
I0906 12:42:02.685889 18605 master.cpp:1297] Agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0 at slave(1247)@172.17.0.3:42379 (b0b8d2993b8d) disconnected
I0906 12:42:02.685925 18605 master.cpp:3399] Disconnecting agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0 at slave(1247)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:02.686003 18605 master.cpp:3418] Deactivating agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0 at slave(1247)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:02.686221 18624 hierarchical.cpp:1038] Agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0 deactivated
E0906 12:42:02.686519 18627 http_connection.hpp:452] End-Of-File received
I0906 12:42:02.687024 18627 http_connection.hpp:217] Re-detecting endpoint
E0906 12:42:02.687161 18612 provider.cpp:2225] Failed to update state for resource provider 980fbb82-62c1-4094-b0de-dbfd2338e3c1: Disconnected
I0906 12:42:02.688093 18607 containerizer.cpp:2620] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0906 12:42:02.688143 18607 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 30.774151936secs
I0906 12:42:02.688580 18607 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:02.690793 18605 hierarchical.cpp:1726] Performed allocation for 1 agents in 210669ns
I0906 12:42:02.741955 18613 hierarchical.cpp:1726] Performed allocation for 1 agents in 223610ns
I0906 12:42:02.792230 18608 containerizer.cpp:3161] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0906 12:42:02.793699 18618 provisioner.cpp:612] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:02.793766 18616 hierarchical.cpp:1726] Performed allocation for 1 agents in 192999ns
I0906 12:42:02.796598 18626 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'
I0906 12:42:02.796811 18622 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-PCLlL0/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:02.797046 18615 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:02.800105 18629 process.cpp:2781] Returning '404 Not Found' for '/slave(1247)/api/v1'
I0906 12:42:02.809408 18604 master.cpp:1137] Master terminating
I0906 12:42:02.810211 18609 hierarchical.cpp:1014] Removed all filters for agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0
I0906 12:42:02.810252 18609 hierarchical.cpp:891] Removed agent 3e3c2426-bdc4-42da-80ef-fd10de7096af-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v0 (905 ms)
[ RUN ] CSIVersion/StorageLocalResourceProviderTest.Update/v1
I0906 12:42:02.827318 18604 cluster.cpp:177] Creating default 'local' authorizer
I0906 12:42:02.832113 18612 master.cpp:440] Master 0800cfbb-0643-438e-a4d1-32c7ed75b837 (b0b8d2993b8d) started on 172.17.0.3:42379
I0906 12:42:02.832146 18612 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/WSY7e1/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.10.0/_inst/share/mesos/webui" --work_dir="/tmp/WSY7e1/master" --zk_session_timeout="10secs"
I0906 12:42:02.832597 18612 master.cpp:492] Master only allowing authenticated frameworks to register
I0906 12:42:02.832618 18612 master.cpp:498] Master only allowing authenticated agents to register
I0906 12:42:02.832629 18612 master.cpp:504] Master only allowing authenticated HTTP frameworks to register
I0906 12:42:02.832643 18612 credentials.hpp:37] Loading credentials for authentication from '/tmp/WSY7e1/credentials'
I0906 12:42:02.833007 18612 master.cpp:548] Using default 'crammd5' authenticator
I0906 12:42:02.833218 18612 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0906 12:42:02.833461 18612 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0906 12:42:02.833638 18612 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0906 12:42:02.833811 18612 master.cpp:629] Authorization enabled
I0906 12:42:02.834225 18614 hierarchical.cpp:474] Initialized hierarchical allocator process
I0906 12:42:02.834234 18620 whitelist_watcher.cpp:77] No whitelist given
I0906 12:42:02.837548 18626 master.cpp:2170] Elected as the leading master!
I0906 12:42:02.837596 18626 master.cpp:1666] Recovering from registrar
I0906 12:42:02.837801 18621 registrar.cpp:339] Recovering registrar
I0906 12:42:02.838675 18621 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0906 12:42:02.838835 18621 registrar.cpp:487] Applied 1 operations in 51357ns; attempting to update the registry
I0906 12:42:02.839530 18621 registrar.cpp:544] Successfully updated the registry in 0ns
I0906 12:42:02.839666 18621 registrar.cpp:416] Successfully recovered registrar
I0906 12:42:02.840152 18616 hierarchical.cpp:513] Skipping recovery of hierarchical allocator: nothing to recover
I0906 12:42:02.840147 18618 master.cpp:1819] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
W0906 12:42:02.846344 18604 process.cpp:2877] Attempted to spawn already running process files@172.17.0.3:42379
I0906 12:42:02.847717 18604 containerizer.cpp:318] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0906 12:42:02.848296 18604 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0906 12:42:02.848325 18604 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0906 12:42:02.848453 18604 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0906 12:42:02.848491 18604 provisioner.cpp:300] Using default backend 'copy'
I0906 12:42:02.850987 18604 cluster.cpp:518] Creating default 'local' authorizer
I0906 12:42:02.853251 18617 slave.cpp:267] Mesos agent started on (1248)@172.17.0.3:42379
I0906 12:42:02.853281 18617 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/WSY7e1/9pZXjB/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/WSY7e1/9pZXjB/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/WSY7e1/9pZXjB/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/WSY7e1/9pZXjB/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/WSY7e1/9pZXjB/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/WSY7e1/9pZXjB/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.10.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/WSY7e1/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_Update_v1_kThZhs" --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_Update_v1_o9q1fj" --zk_sessio
n_timeout="10secs"
I0906 12:42:02.853817 18617 credentials.hpp:86] Loading credential for authentication from '/tmp/WSY7e1/9pZXjB/credential'
I0906 12:42:02.854041 18617 slave.cpp:300] Agent using credential for: test-principal
I0906 12:42:02.854065 18617 credentials.hpp:37] Loading credentials for authentication from '/tmp/WSY7e1/9pZXjB/http_credentials'
I0906 12:42:02.854301 18617 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0906 12:42:02.854787 18617 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0906 12:42:02.856364 18614 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I0906 12:42:02.856425 18617 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0906 12:42:02.856629 18617 slave.cpp:623] Agent attributes: [ ]
I0906 12:42:02.856645 18617 slave.cpp:632] Agent hostname: b0b8d2993b8d
I0906 12:42:02.856838 18612 status_update_manager_process.hpp:379] Pausing operation status update manager
I0906 12:42:02.856845 18613 task_status_update_manager.cpp:181] Pausing sending task status updates
I0906 12:42:02.858803 18622 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_o9q1fj/meta'
I0906 12:42:02.859047 18626 slave.cpp:7491] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_o9q1fj/meta', beginning agent recovery
I0906 12:42:02.859663 18615 task_status_update_manager.cpp:207] Recovering task status update manager
I0906 12:42:02.860132 18611 containerizer.cpp:821] Recovering Mesos containers
I0906 12:42:02.860622 18611 containerizer.cpp:1161] Recovering isolators
I0906 12:42:02.861639 18612 containerizer.cpp:1200] Recovering provisioner
I0906 12:42:02.862416 18628 provisioner.cpp:500] Provisioner recovery complete
I0906 12:42:02.863258 18610 composing.cpp:339] Finished recovering all containerizers
I0906 12:42:02.863561 18615 slave.cpp:7972] Recovering executors
I0906 12:42:02.863683 18615 slave.cpp:8125] Finished recovery
I0906 12:42:02.864578 18618 task_status_update_manager.cpp:181] Pausing sending task status updates
I0906 12:42:02.864622 18614 status_update_manager_process.hpp:379] Pausing operation status update manager
I0906 12:42:02.864665 18606 slave.cpp:1351] New master detected at master@172.17.0.3:42379
I0906 12:42:02.864835 18606 slave.cpp:1416] Detecting new master
I0906 12:42:02.866271 18611 slave.cpp:1443] Authenticating with master master@172.17.0.3:42379
I0906 12:42:02.866369 18611 slave.cpp:1452] Using default CRAM-MD5 authenticatee
I0906 12:42:02.866780 18605 authenticatee.cpp:121] Creating new client SASL connection
I0906 12:42:02.867131 18608 master.cpp:10617] Authenticating slave(1248)@172.17.0.3:42379
I0906 12:42:02.867274 18613 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2103)@172.17.0.3:42379
I0906 12:42:02.867599 18607 authenticator.cpp:98] Creating new server SASL connection
I0906 12:42:02.867884 18617 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0906 12:42:02.867916 18617 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0906 12:42:02.868053 18628 authenticator.cpp:204] Received SASL authentication start
I0906 12:42:02.868132 18628 authenticator.cpp:326] Authentication requires more steps
I0906 12:42:02.868268 18622 authenticatee.cpp:259] Received SASL authentication step
I0906 12:42:02.868417 18623 authenticator.cpp:232] Received SASL authentication step
I0906 12:42:02.868453 18623 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b0b8d2993b8d' server FQDN: 'b0b8d2993b8d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0906 12:42:02.868471 18623 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0906 12:42:02.868525 18623 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0906 12:42:02.868554 18623 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b0b8d2993b8d' server FQDN: 'b0b8d2993b8d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0906 12:42:02.868567 18623 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0906 12:42:02.868583 18623 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0906 12:42:02.868611 18623 authenticator.cpp:318] Authentication success
I0906 12:42:02.868736 18627 authenticatee.cpp:299] Authentication success
I0906 12:42:02.868855 18626 master.cpp:10649] Successfully authenticated principal 'test-principal' at slave(1248)@172.17.0.3:42379
I0906 12:42:02.868929 18625 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2103)@172.17.0.3:42379
I0906 12:42:02.869201 18619 slave.cpp:1543] Successfully authenticated with master master@172.17.0.3:42379
I0906 12:42:02.869594 18619 slave.cpp:1993] Will retry registration in 855196ns if necessary
I0906 12:42:02.869819 18624 master.cpp:7088] Received register agent message from slave(1248)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:02.870100 18624 master.cpp:4204] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I0906 12:42:02.870810 18614 master.cpp:7155] Authorized registration of agent at slave(1248)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:02.870931 18614 master.cpp:7267] Registering agent at slave(1248)@172.17.0.3:42379 (b0b8d2993b8d) with id 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0
I0906 12:42:02.871639 18609 registrar.cpp:487] Applied 1 operations in 235973ns; attempting to update the registry
I0906 12:42:02.872356 18609 registrar.cpp:544] Successfully updated the registry in 0ns
I0906 12:42:02.872542 18613 master.cpp:7315] Admitted agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0 at slave(1248)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:02.873360 18613 master.cpp:7360] Registered agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0 at slave(1248)@172.17.0.3:42379 (b0b8d2993b8d) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0906 12:42:02.873478 18617 slave.cpp:1576] Registered with master master@172.17.0.3:42379; given agent ID 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0
I0906 12:42:02.873483 18628 hierarchical.cpp:854] Added agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0 (b0b8d2993b8d) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I0906 12:42:02.873641 18610 task_status_update_manager.cpp:188] Resuming sending task status updates
I0906 12:42:02.873847 18628 hierarchical.cpp:1726] Performed allocation for 1 agents in 148831ns
I0906 12:42:02.874176 18617 slave.cpp:1611] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_o9q1fj/meta/slaves/0800cfbb-0643-438e-a4d1-32c7ed75b837-S0/slave.info'
I0906 12:42:02.874207 18626 status_update_manager_process.hpp:385] Resuming operation status update manager
I0906 12:42:02.875860 18617 slave.cpp:1663] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"YQMTm66LQYCRUjwoBdn8jw=="},"slave_id":{"value":"0800cfbb-0643-438e-a4d1-32c7ed75b837-S0"},"update_oversubscribed_resources":false}
I0906 12:42:02.876638 18619 master.cpp:8487] Ignoring update on agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0 at slave(1248)@172.17.0.3:42379 (b0b8d2993b8d) as it reports no changes
I0906 12:42:02.880406 18613 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1'
I0906 12:42:02.881646 18616 http.cpp:1115] HTTP POST for /slave(1248)/api/v1 from 172.17.0.3:33916
I0906 12:42:02.882218 18616 http.cpp:2146] Processing GET_CONTAINERS call
I0906 12:42:02.887442 18608 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:02.889590 18628 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1'
I0906 12:42:02.890489 18617 http.cpp:1115] HTTP POST for /slave(1248)/api/v1 from 172.17.0.3:33918
I0906 12:42:02.891353 18617 http.cpp:2606] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:02.892120 18620 http.cpp:2710] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_o9q1fj/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:02.892761 18625 containerizer.cpp:1396] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:02.893337 18625 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from STARTING to PROVISIONING after 0ns
I0906 12:42:02.894024 18625 containerizer.cpp:1574] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_kThZhs/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0906 12:42:02.894068 18625 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PROVISIONING to PREPARING after 0ns
I0906 12:42:02.896878 18607 containerizer.cpp:2100] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_6j74da","--available_capacity=0B","--volumes=","--forward=unix:///tmp/WSY7e1/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.0/_build/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_o9q1fj/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-xAw9Ea/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_o9q1fj/containers/org-apache-mesos-rp-local
-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="94" --pipe_write="95" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_kThZhs/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I0906 12:42:02.905542 18607 launcher.cpp:145] Forked child with pid '32863' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:02.906441 18607 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PREPARING to ISOLATING after 0ns
I0906 12:42:02.907933 18607 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from ISOLATING to FETCHING after 0ns
I0906 12:42:02.908268 18617 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_Update_v1_o9q1fj/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:02.909324 18623 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from FETCHING to RUNNING after 0ns
I0906 12:42:02.912415 18614 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'
I0906 12:42:02.912708 18609 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-xAw9Ea/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:03.060276 18628 hierarchical.cpp:1726] Performed allocation for 1 agents in 225321ns
I0906 12:42:03.111940 18620 hierarchical.cpp:1726] Performed allocation for 1 agents in 204818ns
I0906 12:42:03.163275 18612 hierarchical.cpp:1726] Performed allocation for 1 agents in 191889ns
I0906 12:42:03.214723 18610 hierarchical.cpp:1726] Performed allocation for 1 agents in 236130ns
I0906 12:42:03.266089 18627 hierarchical.cpp:1726] Performed allocation for 1 agents in 242069ns
I0906 12:42:03.303999 18623 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-xAw9Ea/endpoint.sock' with CSI v1
I0906 12:42:03.305826 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/Probe call
I0906 12:42:03.308341 18614 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:03.311414 18615 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1'
I0906 12:42:03.312052 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginCapabilities call
I0906 12:42:03.312685 18627 http.cpp:1115] HTTP POST for /slave(1248)/api/v1 from 172.17.0.3:33920
I0906 12:42:03.313378 18627 http.cpp:2824] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:03.316349 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call
I0906 12:42:03.316673 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call
I0906 12:42:03.317653 18609 hierarchical.cpp:1726] Performed allocation for 1 agents in 189529ns
I0906 12:42:03.318158 18605 v1_volume_manager.cpp:649] NODE_SERVICE loaded: {}
I0906 12:42:03.318563 18605 v1_volume_manager.cpp:649] CONTROLLER_SERVICE loaded: {}
I0906 12:42:03.320776 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ControllerGetCapabilities call
I0906 12:42:03.325410 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetCapabilities call
I0906 12:42:03.328856 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetInfo call
I0906 12:42:03.331248 18620 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0906 12:42:03.331408 18611 status_update_manager_process.hpp:379] Pausing operation status update manager
I0906 12:42:03.331890 18607 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:42379/slave(1248)/api/v1/resource_provider
I0906 12:42:03.335443 18605 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.3:42379/slave(1248)/api/v1/resource_provider
I0906 12:42:03.336180 18624 provider.cpp:476] Connected to resource provider manager
I0906 12:42:03.337005 18617 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.3:42379/slave(1248)/api/v1/resource_provider
I0906 12:42:03.338146 18625 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1/resource_provider'
I0906 12:42:03.340219 18620 http.cpp:1115] HTTP POST for /slave(1248)/api/v1/resource_provider from 172.17.0.3:33924
I0906 12:42:03.340854 18614 manager.cpp:813] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_6j74da","--available_capacity=0B","--volumes=","--forward=unix:///tmp/WSY7e1/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.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"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}
I0906 12:42:03.368428 18616 hierarchical.cpp:1726] Performed allocation for 1 agents in 188028ns
I0906 12:42:03.373984 18628 slave.cpp:8481] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"f029e9ee-97c3-4c4f-adb6-25baace6875d"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_6j74da","--available_capacity=0B","--volumes=","--forward=unix:///tmp/WSY7e1/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.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"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}'
I0906 12:42:03.375968 18606 provider.cpp:498] Received SUBSCRIBED event
I0906 12:42:03.376006 18606 provider.cpp:1309] Subscribed with ID f029e9ee-97c3-4c4f-adb6-25baace6875d
I0906 12:42:03.376955 18620 status_update_manager_process.hpp:314] Recovering operation status update manager
I0906 12:42:03.420028 18607 hierarchical.cpp:1726] Performed allocation for 1 agents in 186129ns
I0906 12:42:03.423630 18614 provider.cpp:790] Reconciling storage pools and volumes
I0906 12:42:03.426362 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I0906 12:42:03.429085 18626 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0
I0906 12:42:03.429420 18624 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.3:42379/slave(1248)/api/v1/resource_provider
I0906 12:42:03.429543 18626 provider.cpp:748] Resource provider f029e9ee-97c3-4c4f-adb6-25baace6875d is in READY state
I0906 12:42:03.429607 18618 status_update_manager_process.hpp:385] Resuming operation status update manager
I0906 12:42:03.430327 18619 provider.cpp:1235] Updating profiles { test } for resource provider f029e9ee-97c3-4c4f-adb6-25baace6875d
I0906 12:42:03.430929 18620 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1/resource_provider'
I0906 12:42:03.431437 18615 provider.cpp:790] Reconciling storage pools and volumes
I0906 12:42:03.432833 18617 http.cpp:1115] HTTP POST for /slave(1248)/api/v1/resource_provider from 172.17.0.3:33922
I0906 12:42:03.433446 18624 manager.cpp:1045] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider f029e9ee-97c3-4c4f-adb6-25baace6875d
I0906 12:42:03.433696 18619 slave.cpp:8481] Handling resource provider message 'UPDATE_STATE: f029e9ee-97c3-4c4f-adb6-25baace6875d {}'
I0906 12:42:03.433801 18619 slave.cpp:8601] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0906 12:42:03.434670 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I0906 12:42:03.435149 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call
I0906 12:42:03.436036 18609 hierarchical.cpp:992] Grew agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0 by {} (total), { } (used)
I0906 12:42:03.436420 18609 hierarchical.cpp:950] Agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0 (b0b8d2993b8d) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0906 12:42:03.438630 18622 provider.cpp:808] Removing '{}' and adding 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001' to the total resources
I0906 12:42:03.491163 18622 provider.cpp:2217] Sending UPDATE_STATE call with resources 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001' and 0 operations to agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0
I0906 12:42:03.491995 18627 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.3:42379/slave(1248)/api/v1/resource_provider
I0906 12:42:03.493253 18611 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1/resource_provider'
I0906 12:42:03.495570 18610 hierarchical.cpp:1726] Performed allocation for 1 agents in 224349ns
I0906 12:42:03.495838 18609 provider.cpp:790] Reconciling storage pools and volumes
I0906 12:42:03.498790 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I0906 12:42:03.499825 32867 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call
I0906 12:42:03.503031 18613 provider.cpp:808] Removing '{}' and adding 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:0.001' to the total resources
I0906 12:42:03.532891 18605 http.cpp:1115] HTTP POST for /slave(1248)/api/v1/resource_provider from 172.17.0.3:33922
I0906 12:42:03.533785 18605 manager.cpp:1045] Received UPDATE_STATE call with resources '[{"disk":{"source":{"id":"volume1","type":"RAW","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"f029e9ee-97c3-4c4f-adb6-25baace6875d"},"reservations":[{"role":"storage","type":"DYNAMIC"}],"scalar":{"value":0.0009765625},"type":"SCALAR"}]' and 0 operations from resource provider f029e9ee-97c3-4c4f-adb6-25baace6875d
I0906 12:42:03.534358 18628 slave.cpp:8481] Handling resource provider message 'UPDATE_STATE: f029e9ee-97c3-4c4f-adb6-25baace6875d disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001'
I0906 12:42:03.534579 18628 slave.cpp:8601] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001
I0906 12:42:03.537329 18617 hierarchical.cpp:950] Agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0 (b0b8d2993b8d) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001
I0906 12:42:03.537742 18617 hierarchical.cpp:1726] Performed allocation for 1 agents in 200854ns
I0906 12:42:03.541637 18613 provider.cpp:2217] Sending UPDATE_STATE call with resources 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,volume1,)]:0.001; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:0.001' and 0 operations to agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0
I0906 12:42:03.542156 18626 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.3:42379/slave(1248)/api/v1/resource_provider
I0906 12:42:03.543391 18627 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1/resource_provider'
../../src/tests/storage_local_resource_provider_tests.cpp:6986: Failure
Value of: updateSlave3.isPending()
Actual: false
Expected: true
I0906 12:42:03.544616 18618 slave.cpp:924] Agent terminating
I0906 12:42:03.545356 18618 manager.cpp:163] Terminating resource provider f029e9ee-97c3-4c4f-adb6-25baace6875d
I0906 12:42:03.545843 18619 master.cpp:1297] Agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0 at slave(1248)@172.17.0.3:42379 (b0b8d2993b8d) disconnected
I0906 12:42:03.545956 18619 master.cpp:3399] Disconnecting agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0 at slave(1248)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:03.546070 18619 master.cpp:3418] Deactivating agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0 at slave(1248)@172.17.0.3:42379 (b0b8d2993b8d)
I0906 12:42:03.546288 18613 hierarchical.cpp:1038] Agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0 deactivated
E0906 12:42:03.546555 18613 http_connection.hpp:452] End-Of-File received
I0906 12:42:03.547132 18613 http_connection.hpp:217] Re-detecting endpoint
E0906 12:42:03.547713 18610 provider.cpp:2225] Failed to update state for resource provider f029e9ee-97c3-4c4f-adb6-25baace6875d: Disconnected
I0906 12:42:03.547833 18613 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:42379/slave(1248)/api/v1/resource_provider
I0906 12:42:03.548871 18609 containerizer.cpp:2620] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0906 12:42:03.548936 18609 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 15.726584832secs
I0906 12:42:03.549378 18609 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:03.551091 18622 hierarchical.cpp:1726] Performed allocation for 1 agents in 211861ns
I0906 12:42:03.602633 18626 hierarchical.cpp:1726] Performed allocation for 1 agents in 261599ns
I0906 12:42:03.652989 18611 containerizer.cpp:3161] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0906 12:42:03.654167 18606 hierarchical.cpp:1726] Performed allocation for 1 agents in 210762ns
I0906 12:42:03.655057 18610 provisioner.cpp:612] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:03.657793 18626 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'
I0906 12:42:03.658004 18625 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-xAw9Ea/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0906 12:42:03.658303 18621 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0906 12:42:03.661365 18629 process.cpp:2781] Returning '404 Not Found' for '/slave(1248)/api/v1'
I0906 12:42:03.669828 18622 master.cpp:1137] Master terminating
I0906 12:42:03.670648 18605 hierarchical.cpp:1014] Removed all filters for agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0
I0906 12:42:03.670673 18605 hierarchical.cpp:891] Removed agent 0800cfbb-0643-438e-a4d1-32c7ed75b837-S0
[ FAILED ] CSIVersion/StorageLocalResourceProviderTest.Update/v1, where GetParam() = "v1" (859 ms)
[----------] 54 tests from CSIVersion/StorageLocalResourceProviderTest (102965 ms total)
[----------] Global test environment tear-down
[==========] 2317 tests from 221 test cases ran. (1096383 ms total)
[ PASSED ] 2316 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] CSIVersion/StorageLocalResourceProviderTest.Update/v1, where GetParam() = "v1"
1 FAILED TEST
YOU HAVE 32 DISABLED TESTS
I0906 12:42:03.779199 18629 process.cpp:935] Stopped the socket accept loop
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-1.10.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.10.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.10.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.10.0/_build'
make: *** [distcheck] Error 1
+ docker rmi --force mesos-1567764829-10634
Untagged: mesos-1567764829-10634:latest
Deleted: sha256:63fc7b29af0a26a0bd8c0a03e358fa899185784404015b57eae03c5fdaa1da0b
Deleted: sha256:db466ce436c2543b476fb6db803032b7418787f4f66d8139b16c2e4b6c184741
Deleted: sha256:1003803b3d3703955f98b3e76c49e2b8138dcbf8de1bc26ca98e0d5ab9177e69
Deleted: sha256:451a64cfd01b9ab011e01610c8ad703ee086978d9791c26d702cc021db8e1988
Deleted: sha256:0b1a253e1e2f1fd040c22cf17c00b15a0e018640d5fba3df63101d588d0b11f2
Deleted: sha256:b11580d33afb63e8ce13c3c509e29ca80284337bfb4fceb4f62df25af2351a3d
Deleted: sha256:4fca5f55db8c6c6f0f4faa7f0a69bc002d91c6b101ec50e3abd2090d1f5e89be
Deleted: sha256:e66e6d345105a5919bf5ffdb86518e4b44f2f79bf584b22f46f80c5a9f671b25
Deleted: sha256:8ce83dc043159d82079967944236a84ba574b2931a5bf8d493ab7dafd5ae1e08
Deleted: sha256:c0b41c9a56b67ee55ac491512242240a11e347847c6cef9b39fe7b86b2fb5fa9
Deleted: sha256:be76b3c10e20c3bc67166b62a5c06a1b8cb26795b98b43fd8e447a0db7eab6c1
Deleted: sha256:1d07c30a98c9800e40a18bbf01b5388e0038b432a82a40b204d071b7ae6bc960
Deleted: sha256:06040f3a8704e742d80c7bdbc68728e1b89fa541050d16149f146347fc520bf9
Deleted: sha256:eab38965fb21babf9fb39e1b6c1b633797f333532f7c1589c0f99567c219643b
Deleted: sha256:6abae74a112422e1c2792c721f1df7ae02b913a05c79070925d48b5f79fe291b
Deleted: sha256:666b03c5a1b91dcfb2b9c9a4b5d488a5b0d4e6d31c62ed8d5bb6d07a03362d95
Deleted: sha256:730f5989d54f66a2136e43477cb95e8ed4ea30f06682ca91411d3cb9a9f44ed0
Deleted: sha256:2e7ac7bcc5da058c2a64088a3b41a95b279d7525f0d7e926f87407adf12805c2
Deleted: sha256:19bd5108bd50e632e576cd98ab63abef067102d0dac735ce0624d3a17366f1b7
Deleted: sha256:1f656be247c4cf2a15850bd0d51cea09a713c2fd40f726b2ead796d0b27e4fcc
Deleted: sha256:9c3a69c9c5529c704b28fe84b81af7ef2dcb77eb8b5895dae389697afe0b46d4
Deleted: sha256:66bf8922425a9de5cdd2a34302b4ee089fda74bd9a689f0f94216ebd10aaa365
Deleted: sha256:54124c50dfda6d467c5e83d97398049180f624733ee5146a85a541fc7808c18e
Deleted: sha256:e77148fb48ca8748c08b1cbc369939705f09f8590c89498c9766384f75db8f13
Deleted: sha256:19742b8ce1e81a458795091b21173a7f3155a937ae47fc749c3fa20828d2187c
Deleted: sha256:5553b28a1a583125316c20048b82d8ad460f86c29545be1b731701c1b89bbe31
Deleted: sha256:319014d7bc0933eb96ec97897006151ae78d906082cd793c9871ae8bc18453f1
Deleted: sha256:102ad0ff094b44f0081f0f8b60974a37a118bb0f880524f58310a6e1eec45a8b
Deleted: sha256:0cb80140b81bcda87307d555b29eca6ea4874b288a79833ae4c7ec3926f735ca
Deleted: sha256:46c7c7e2d63d58e17fbe4ae9aa1c927be6e104150d4e93d434e0484a147d3286
Full log: https://builds.apache.org/job/Mesos-Reviewbot-Linux/3525/console
- Mesos Reviewbot
On Sept. 3, 2019, 2:51 p.m., Benjamin Bannier wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71241/
> -----------------------------------------------------------
>
> (Updated Sept. 3, 2019, 2:51 p.m.)
>
>
> Review request for mesos, Benjamin Mahler and Till Toenshoff.
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch adds a `distcheck` target to the cmake build which mimics the
> target of the same name provided by the autotools build. `distcheck`
> depends on the `dist` target to create a distribution archive and then
> ensures that with the distributed sources the `check` targets succeeds.
>
>
> Diffs
> -----
>
> CMakeLists.txt dc50dd457585c14a456ca710da4a16a0d45ef17a
> cmake/distcheck.sh PRE-CREATION
>
>
> Diff: https://reviews.apache.org/r/71241/diff/3/
>
>
> Testing
> -------
>
> `ninja distcheck` passes, no artifacts left around but tarball.
>
>
> Thanks,
>
> Benjamin Bannier
>
>
Re: Review Request 71241: Added a `distcheck` target to the cmake
build.
Posted by Till Toenshoff via Review Board <no...@reviews.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71241/#review217580
-----------------------------------------------------------
Ship it!
Ship It!
- Till Toenshoff
On Sept. 3, 2019, 2:51 p.m., Benjamin Bannier wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71241/
> -----------------------------------------------------------
>
> (Updated Sept. 3, 2019, 2:51 p.m.)
>
>
> Review request for mesos, Benjamin Mahler and Till Toenshoff.
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch adds a `distcheck` target to the cmake build which mimics the
> target of the same name provided by the autotools build. `distcheck`
> depends on the `dist` target to create a distribution archive and then
> ensures that with the distributed sources the `check` targets succeeds.
>
>
> Diffs
> -----
>
> CMakeLists.txt dc50dd457585c14a456ca710da4a16a0d45ef17a
> cmake/distcheck.sh PRE-CREATION
>
>
> Diff: https://reviews.apache.org/r/71241/diff/3/
>
>
> Testing
> -------
>
> `ninja distcheck` passes, no artifacts left around but tarball.
>
>
> Thanks,
>
> Benjamin Bannier
>
>
Re: Review Request 71241: Added a `distcheck` target to the cmake
build.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71241/#review217554
-----------------------------------------------------------
Patch looks great!
Reviews applied: [71240, 71241]
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 Sept. 3, 2019, 2:51 p.m., Benjamin Bannier wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71241/
> -----------------------------------------------------------
>
> (Updated Sept. 3, 2019, 2:51 p.m.)
>
>
> Review request for mesos, Benjamin Mahler and Till Toenshoff.
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch adds a `distcheck` target to the cmake build which mimics the
> target of the same name provided by the autotools build. `distcheck`
> depends on the `dist` target to create a distribution archive and then
> ensures that with the distributed sources the `check` targets succeeds.
>
>
> Diffs
> -----
>
> CMakeLists.txt dc50dd457585c14a456ca710da4a16a0d45ef17a
> cmake/distcheck.sh PRE-CREATION
>
>
> Diff: https://reviews.apache.org/r/71241/diff/3/
>
>
> Testing
> -------
>
> `ninja distcheck` passes, no artifacts left around but tarball.
>
>
> Thanks,
>
> Benjamin Bannier
>
>
Re: Review Request 71241: Added a `distcheck` target to the cmake
build.
Posted by Benjamin Bannier <bb...@apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71241/
-----------------------------------------------------------
(Updated Sept. 3, 2019, 4:51 p.m.)
Review request for mesos, Benjamin Mahler and Till Toenshoff.
Changes
-------
Add a `TODO` on checking `install` target
Repository: mesos
Description
-------
This patch adds a `distcheck` target to the cmake build which mimics the
target of the same name provided by the autotools build. `distcheck`
depends on the `dist` target to create a distribution archive and then
ensures that with the distributed sources the `check` targets succeeds.
Diffs (updated)
-----
CMakeLists.txt dc50dd457585c14a456ca710da4a16a0d45ef17a
cmake/distcheck.sh PRE-CREATION
Diff: https://reviews.apache.org/r/71241/diff/3/
Changes: https://reviews.apache.org/r/71241/diff/2-3/
Testing
-------
`ninja distcheck` passes, no artifacts left around but tarball.
Thanks,
Benjamin Bannier
Re: Review Request 71241: Added a `distcheck` target to the cmake
build.
Posted by Benjamin Bannier <bb...@apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71241/
-----------------------------------------------------------
(Updated Sept. 3, 2019, 3:52 p.m.)
Review request for mesos, Benjamin Mahler and Till Toenshoff.
Changes
-------
Address issues raised by Benno
Repository: mesos
Description
-------
This patch adds a `distcheck` target to the cmake build which mimics the
target of the same name provided by the autotools build. `distcheck`
depends on the `dist` target to create a distribution archive and then
ensures that with the distributed sources the `check` targets succeeds.
Diffs (updated)
-----
CMakeLists.txt dc50dd457585c14a456ca710da4a16a0d45ef17a
cmake/distcheck.sh PRE-CREATION
Diff: https://reviews.apache.org/r/71241/diff/2/
Changes: https://reviews.apache.org/r/71241/diff/1-2/
Testing
-------
`ninja distcheck` passes, no artifacts left around but tarball.
Thanks,
Benjamin Bannier