You are viewing a plain text version of this content. The canonical link for it is here.
Posted to reviews@mesos.apache.org by Andrei Sekretenko <as...@mesosphere.io> on 2020/02/03 17:54:38 UTC
Review Request 72080: Added test for fetch from repositories not
providing scope/service.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72080/
-----------------------------------------------------------
Review request for mesos, Andrei Budnik and Qian Zhang.
Bugs: MESOS-10092
https://issues.apache.org/jira/browse/MESOS-10092
Repository: mesos
Description
-------
Added test for fetch from repositories not providing scope/service.
Diffs
-----
src/tests/uri_fetcher_tests.cpp 92f80626f4de8a2cc29760366ca568f9d794f472
Diff: https://reviews.apache.org/r/72080/diff/1/
Testing
-------
Thanks,
Andrei Sekretenko
Re: Review Request 72080: Added test for fetch from repositories not
providing scope/service.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72080/#review219507
-----------------------------------------------------------
Patch looks great!
Reviews applied: [72077, 72078, 72079, 72080]
Passed command: export OS='ubuntu:16.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/jenkins/buildbot.sh
- Mesos Reviewbot
On Feb. 5, 2020, 2:07 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72080/
> -----------------------------------------------------------
>
> (Updated Feb. 5, 2020, 2:07 p.m.)
>
>
> Review request for mesos, Andrei Budnik and Qian Zhang.
>
>
> Bugs: MESOS-10092
> https://issues.apache.org/jira/browse/MESOS-10092
>
>
> Repository: mesos
>
>
> Description
> -------
>
> Added test for fetch from repositories not providing scope/service.
>
>
> Diffs
> -----
>
> src/tests/uri_fetcher_tests.cpp 92f80626f4de8a2cc29760366ca568f9d794f472
>
>
> Diff: https://reviews.apache.org/r/72080/diff/3/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 72080: Added test for fetch from repositories not
providing scope/service.
Posted by Andrei Sekretenko <as...@mesosphere.io>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72080/
-----------------------------------------------------------
(Updated Feb. 5, 2020, 2:07 p.m.)
Review request for mesos, Andrei Budnik and Qian Zhang.
Bugs: MESOS-10092
https://issues.apache.org/jira/browse/MESOS-10092
Repository: mesos
Description
-------
Added test for fetch from repositories not providing scope/service.
Diffs (updated)
-----
src/tests/uri_fetcher_tests.cpp 92f80626f4de8a2cc29760366ca568f9d794f472
Diff: https://reviews.apache.org/r/72080/diff/3/
Changes: https://reviews.apache.org/r/72080/diff/2-3/
Testing
-------
Thanks,
Andrei Sekretenko
Re: Review Request 72080: Added test for fetch from repositories not
providing scope/service.
Posted by Andrei Sekretenko <as...@mesosphere.io>.
> On Feb. 5, 2020, 3:22 a.m., Qian Zhang wrote:
> > It seems this test will take 10+ seconds:
> > ```
> > [ RUN ] DockerFetcherPluginTest.INTERNET_CURL_GeneratedRepositoryScope
> > sh: hadoop: command not found
> > I0205 02:02:23.218667 5865 fetcher.cpp:68] Skipping URI fetcher plugin 'hadoop' as it could not be created: Failed to create HDFS client: Hadoop client is not available, exit status: 32512
> > W0205 02:02:23.721199 5871 docker.cpp:1175] Missing 'realm', 'service' or 'scope' in header WWW-Authenticate: Bearer realm="https://nvcr.io/proxy_auth?scope=repository:nvidia/k8s/cuda-sample:pull,push"
> > [ OK ] DockerFetcherPluginTest.INTERNET_CURL_GeneratedRepositoryScope (12176 ms)
> > ```
> >
> > It is a bit too long, is there a way to accelerate it?
The test spends most of the time uploading the 100Mb of image. Unfortunatley, there seems to be no smaller image on nvcr.io, and I 'm not aware of other repositories suitable for such test.
Ideally, we should have a mock repository for this (left a TODO in this patch).
- Andrei
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72080/#review219503
-----------------------------------------------------------
On Feb. 5, 2020, 2:07 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72080/
> -----------------------------------------------------------
>
> (Updated Feb. 5, 2020, 2:07 p.m.)
>
>
> Review request for mesos, Andrei Budnik and Qian Zhang.
>
>
> Bugs: MESOS-10092
> https://issues.apache.org/jira/browse/MESOS-10092
>
>
> Repository: mesos
>
>
> Description
> -------
>
> Added test for fetch from repositories not providing scope/service.
>
>
> Diffs
> -----
>
> src/tests/uri_fetcher_tests.cpp 92f80626f4de8a2cc29760366ca568f9d794f472
>
>
> Diff: https://reviews.apache.org/r/72080/diff/3/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 72080: Added test for fetch from repositories not
providing scope/service.
Posted by Qian Zhang <zh...@gmail.com>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72080/#review219503
-----------------------------------------------------------
Fix it, then Ship it!
It seems this test will take 10+ seconds:
```
[ RUN ] DockerFetcherPluginTest.INTERNET_CURL_GeneratedRepositoryScope
sh: hadoop: command not found
I0205 02:02:23.218667 5865 fetcher.cpp:68] Skipping URI fetcher plugin 'hadoop' as it could not be created: Failed to create HDFS client: Hadoop client is not available, exit status: 32512
W0205 02:02:23.721199 5871 docker.cpp:1175] Missing 'realm', 'service' or 'scope' in header WWW-Authenticate: Bearer realm="https://nvcr.io/proxy_auth?scope=repository:nvidia/k8s/cuda-sample:pull,push"
[ OK ] DockerFetcherPluginTest.INTERNET_CURL_GeneratedRepositoryScope (12176 ms)
```
It is a bit too long, is there a way to accelerate it?
src/tests/uri_fetcher_tests.cpp
Lines 416-417 (patched)
<https://reviews.apache.org/r/72080/#comment307703>
A newline between.
src/tests/uri_fetcher_tests.cpp
Lines 422-423 (patched)
<https://reviews.apache.org/r/72080/#comment307704>
Need 2 more spaces for indent.
- Qian Zhang
On Feb. 4, 2020, 8:01 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72080/
> -----------------------------------------------------------
>
> (Updated Feb. 4, 2020, 8:01 p.m.)
>
>
> Review request for mesos, Andrei Budnik and Qian Zhang.
>
>
> Bugs: MESOS-10092
> https://issues.apache.org/jira/browse/MESOS-10092
>
>
> Repository: mesos
>
>
> Description
> -------
>
> Added test for fetch from repositories not providing scope/service.
>
>
> Diffs
> -----
>
> src/tests/uri_fetcher_tests.cpp 92f80626f4de8a2cc29760366ca568f9d794f472
>
>
> Diff: https://reviews.apache.org/r/72080/diff/2/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 72080: Added test for fetch from repositories not
providing scope/service.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72080/#review219488
-----------------------------------------------------------
Bad patch!
Reviews applied: [72077, 72078, 72079, 72080]
Failed command: ['bash', '-c', "set -o pipefail; export OS='ubuntu:16.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/jenkins/buildbot.sh 2>&1 | tee build_72080"]
Error:
...<truncated>...
ED (Status UUID: e6eff69a-2c82-45d1-8aac-a3457325c4d3) for operation UUID b879b3d3-b53d-4339-816d-e807eb7753fb on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:48.917006 3172 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:44433/slave(1249)/api/v1/resource_provider
I0204 15:47:48.918260 3168 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider'
I0204 15:47:48.921514 3167 hierarchical.cpp:1853] Performed allocation for 1 agents in 998523ns
I0204 15:47:48.922123 3162 master.cpp:9974] Sending offers [ 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-O3 ] to framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 (default) at scheduler-e98b38c0-d8c0-4a71-ae14-6a5babf781ab@172.17.0.2:44433
I0204 15:47:48.922855 3163 sched.cpp:934] Scheduler::resourceOffers took 99316ns
I0204 15:47:48.926057 3174 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0204 15:47:48.928093 3169 http.cpp:1405] HTTP POST for /master/api/v1 from 172.17.0.2:39204
I0204 15:47:48.928339 3169 http.cpp:277] Processing call CREATE_VOLUMES
I0204 15:47:48.929183 3169 master.cpp:3712] Authorizing principal 'test-principal' to perform action CREATE_VOLUME on object {"value":"storage/default-role","resource":{"provider_id":{"value":"cfe52025-d8b3-4aea-be08-99f1dc0b80d7"},"name":"disk","type":"SCALAR","scalar":{"value":2048.0},"reservations":[{"type":"DYNAMIC","role":"storage"},{"type":"DYNAMIC","role":"storage/default-role","principal":"test-principal"}],"disk":{"persistence":{"id":"7748db52-d285-4a05-b574-5d28f6274ca5","principal":"test-principal"},"volume":{"mode":"RW","container_path":"volume"},"source":{"type":"MOUNT","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"vendor":"org.apache.mesos.csi.test.local","id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_r2PJa4/2GB-f163e411-1a6d-4dfb-a439-117c41570df5","profile":"test"}}}}
I0204 15:47:48.930765 3163 sched.cpp:960] Rescinded offer 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-O3
I0204 15:47:48.930907 3163 sched.cpp:971] Scheduler::offerRescinded took 71537ns
I0204 15:47:48.931430 3165 hierarchical.cpp:1576] 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_r2PJa4/2GB-f163e411-1a6d-4dfb-a439-117c41570df5,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_r2PJa4/2GB-f163e411-1a6d-4dfb-a439-117c41570df5,test)]:2048, offered or allocated: {}) on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 from framework 0da87
a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000
I0204 15:47:48.931573 3167 master.cpp:12273] Removing offer 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-O3
I0204 15:47:48.933208 3165 hierarchical.cpp:1625] Framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 filtered agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 for 5secs
I0204 15:47:48.936033 3175 master.cpp:12138] Sending operation '' (uuid: 78a80050-e5e6-40b6-89a1-49212c17143d) to agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 at slave(1249)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:48.936775 3174 slave.cpp:4434] Ignoring new checkpointed resources and operations identical to the current version
I0204 15:47:48.939947 3170 provider.cpp:498] Received APPLY_OPERATION event
I0204 15:47:48.939991 3170 provider.cpp:1351] Received CREATE operation '' (uuid: 78a80050-e5e6-40b6-89a1-49212c17143d)
I0204 15:47:48.944433 3177 master.cpp:5958] Processing REVIVE call for framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 (default) at scheduler-e98b38c0-d8c0-4a71-ae14-6a5babf781ab@172.17.0.2:44433
I0204 15:47:48.944926 3166 hierarchical.cpp:1721] Unsuppressed offers and cleared filters for roles { storage/default-role } of framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000
I0204 15:47:48.946213 3166 hierarchical.cpp:1853] Performed allocation for 1 agents in 1.116444ms
I0204 15:47:48.946605 3166 hierarchical.cpp:1853] Performed allocation for 1 agents in 153807ns
I0204 15:47:48.947091 3164 master.cpp:9974] Sending offers [ 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-O4 ] to framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 (default) at scheduler-e98b38c0-d8c0-4a71-ae14-6a5babf781ab@172.17.0.2:44433
I0204 15:47:48.947800 3164 sched.cpp:934] Scheduler::resourceOffers took 94419ns
I0204 15:47:48.960276 3163 http.cpp:1405] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.2:39198
I0204 15:47:48.961525 3162 slave.cpp:8565] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: b879b3d3-b53d-4339-816d-e807eb7753fb) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0204 15:47:48.961755 3162 slave.cpp:9018] Updating the state of operation with no ID (uuid: b879b3d3-b53d-4339-816d-e807eb7753fb) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0204 15:47:48.961818 3162 slave.cpp:8772] Forwarding status update of operation with no ID (operation_uuid: b879b3d3-b53d-4339-816d-e807eb7753fb) for an operator API call
I0204 15:47:48.962195 3173 master.cpp:11790] Updating the state of operation '' (uuid: b879b3d3-b53d-4339-816d-e807eb7753fb) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0204 15:47:48.962890 3177 slave.cpp:4434] Ignoring new checkpointed resources and operations identical to the current version
I0204 15:47:49.046970 3163 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: c182b8ce-8bf3-4d39-9753-7b1d7db27c02) for operation UUID 78a80050-e5e6-40b6-89a1-49212c17143d on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.047034 3163 status_update_manager_process.hpp:414] Creating operation status update stream 78a80050-e5e6-40b6-89a1-49212c17143d checkpoint=true
I0204 15:47:49.047070 3170 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0204 15:47:49.047322 3163 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: c182b8ce-8bf3-4d39-9753-7b1d7db27c02) for operation UUID 78a80050-e5e6-40b6-89a1-49212c17143d on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.113898 3163 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: c182b8ce-8bf3-4d39-9753-7b1d7db27c02) for operation UUID 78a80050-e5e6-40b6-89a1-49212c17143d on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.114290 3163 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: e6eff69a-2c82-45d1-8aac-a3457325c4d3) for stream b879b3d3-b53d-4339-816d-e807eb7753fb
I0204 15:47:49.114369 3163 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: e6eff69a-2c82-45d1-8aac-a3457325c4d3) for operation UUID b879b3d3-b53d-4339-816d-e807eb7753fb on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.115128 3165 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:44433/slave(1249)/api/v1/resource_provider
I0204 15:47:49.116390 3177 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider'
I0204 15:47:49.160105 3174 http.cpp:1405] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.2:39198
I0204 15:47:49.161020 3171 slave.cpp:8565] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 78a80050-e5e6-40b6-89a1-49212c17143d) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0204 15:47:49.161197 3171 slave.cpp:9018] Updating the state of operation with no ID (uuid: 78a80050-e5e6-40b6-89a1-49212c17143d) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0204 15:47:49.161242 3171 slave.cpp:8772] Forwarding status update of operation with no ID (operation_uuid: 78a80050-e5e6-40b6-89a1-49212c17143d) for an operator API call
I0204 15:47:49.161552 3170 master.cpp:11790] Updating the state of operation '' (uuid: 78a80050-e5e6-40b6-89a1-49212c17143d) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0204 15:47:49.162024 3165 slave.cpp:4434] Ignoring new checkpointed resources and operations identical to the current version
I0204 15:47:49.163692 3174 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0204 15:47:49.172319 3163 status_update_manager_process.hpp:490] Cleaning up operation status update stream b879b3d3-b53d-4339-816d-e807eb7753fb
I0204 15:47:49.172523 3163 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: c182b8ce-8bf3-4d39-9753-7b1d7db27c02) for stream 78a80050-e5e6-40b6-89a1-49212c17143d
I0204 15:47:49.172603 3163 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: c182b8ce-8bf3-4d39-9753-7b1d7db27c02) for operation UUID 78a80050-e5e6-40b6-89a1-49212c17143d on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.239614 3163 status_update_manager_process.hpp:490] Cleaning up operation status update stream 78a80050-e5e6-40b6-89a1-49212c17143d
I0204 15:47:49.288213 3170 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0204 15:47:49.290452 3166 http.cpp:1405] HTTP POST for /master/api/v1 from 172.17.0.2:39206
I0204 15:47:49.290729 3166 http.cpp:277] Processing call DESTROY_VOLUMES
I0204 15:47:49.291733 3166 master.cpp:3712] Authorizing principal 'test-principal' to perform action DESTROY_VOLUME on object {"value":"test-principal","resource":{"provider_id":{"value":"cfe52025-d8b3-4aea-be08-99f1dc0b80d7"},"name":"disk","type":"SCALAR","scalar":{"value":2048.0},"reservations":[{"type":"DYNAMIC","role":"storage"},{"type":"DYNAMIC","role":"storage/default-role","principal":"test-principal"}],"disk":{"persistence":{"id":"7748db52-d285-4a05-b574-5d28f6274ca5","principal":"test-principal"},"volume":{"mode":"RW","container_path":"volume"},"source":{"type":"MOUNT","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"vendor":"org.apache.mesos.csi.test.local","id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_r2PJa4/2GB-f163e411-1a6d-4dfb-a439-117c41570df5","profile":"test"}}}}
I0204 15:47:49.293561 3163 sched.cpp:960] Rescinded offer 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-O4
I0204 15:47:49.293663 3163 sched.cpp:971] Scheduler::offerRescinded took 28860ns
I0204 15:47:49.294116 3172 master.cpp:12273] Removing offer 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-O4
I0204 15:47:49.294103 3162 hierarchical.cpp:1576] 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_r2PJa4/2GB-f163e411-1a6d-4dfb-a439-117c41570df5,test),7748db52-d285-4a05-b574-5d28f6274ca5: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_r2PJa4/2GB-f163e411-1a6d-4dfb-a439-117c41570df5,test),7748db52-d285-4a05-b574-5d28f6274ca5:volume]:2048, offered
or allocated: {}) on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 from framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000
I0204 15:47:49.296074 3162 hierarchical.cpp:1625] Framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 filtered agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 for 5secs
I0204 15:47:49.299448 3170 master.cpp:12138] Sending operation '' (uuid: 814dfdd0-5f6b-47f6-87ec-9c1458652425) to agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 at slave(1249)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:49.300052 3164 slave.cpp:4434] Ignoring new checkpointed resources and operations identical to the current version
I0204 15:47:49.303601 3165 provider.cpp:498] Received APPLY_OPERATION event
I0204 15:47:49.303647 3165 provider.cpp:1351] Received DESTROY operation '' (uuid: 814dfdd0-5f6b-47f6-87ec-9c1458652425)
I0204 15:47:49.308828 3175 hierarchical.cpp:1853] Performed allocation for 1 agents in 1.270048ms
I0204 15:47:49.309614 3170 master.cpp:9974] Sending offers [ 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-O5 ] to framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 (default) at scheduler-e98b38c0-d8c0-4a71-ae14-6a5babf781ab@172.17.0.2:44433
I0204 15:47:49.310333 3168 sched.cpp:934] Scheduler::resourceOffers took 90771ns
I0204 15:47:49.394486 3167 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 1f078ee2-6682-4998-992b-216c16f33976) for operation UUID 814dfdd0-5f6b-47f6-87ec-9c1458652425 on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.394541 3167 status_update_manager_process.hpp:414] Creating operation status update stream 814dfdd0-5f6b-47f6-87ec-9c1458652425 checkpoint=true
I0204 15:47:49.394780 3167 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 1f078ee2-6682-4998-992b-216c16f33976) for operation UUID 814dfdd0-5f6b-47f6-87ec-9c1458652425 on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.444828 3167 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 1f078ee2-6682-4998-992b-216c16f33976) for operation UUID 814dfdd0-5f6b-47f6-87ec-9c1458652425 on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.445713 3176 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:44433/slave(1249)/api/v1/resource_provider
I0204 15:47:49.446982 3171 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider'
I0204 15:47:49.450472 3174 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0204 15:47:49.452761 3168 http.cpp:1405] HTTP POST for /master/api/v1 from 172.17.0.2:39208
I0204 15:47:49.453052 3168 http.cpp:277] Processing call UNRESERVE_RESOURCES
I0204 15:47:49.453948 3168 master.cpp:3712] Authorizing principal 'test-principal' to perform action UNRESERVE_RESOURCES on object {"value":"test-principal","resource":{"provider_id":{"value":"cfe52025-d8b3-4aea-be08-99f1dc0b80d7"},"name":"disk","type":"SCALAR","scalar":{"value":2048.0},"reservations":[{"type":"DYNAMIC","role":"storage"},{"type":"DYNAMIC","role":"storage/default-role","principal":"test-principal"}],"disk":{"source":{"type":"MOUNT","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"vendor":"org.apache.mesos.csi.test.local","id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_r2PJa4/2GB-f163e411-1a6d-4dfb-a439-117c41570df5","profile":"test"}}}}
I0204 15:47:49.455827 3169 sched.cpp:960] Rescinded offer 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-O5
I0204 15:47:49.455935 3169 sched.cpp:971] Scheduler::offerRescinded took 30870ns
I0204 15:47:49.456367 3171 hierarchical.cpp:1576] 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_r2PJa4/2GB-f163e411-1a6d-4dfb-a439-117c41570df5,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_r2PJa4/2GB-f163e411-1a6d-4dfb-a439-117c41570df5,test)]:2048, offered or allocated: {}) on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 from framework 0da87
a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000
I0204 15:47:49.456492 3176 master.cpp:12273] Removing offer 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-O5
I0204 15:47:49.458014 3171 hierarchical.cpp:1625] Framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 filtered agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 for 5secs
I0204 15:47:49.460569 3174 master.cpp:12138] Sending operation '' (uuid: 0a64b265-d7ae-4fca-a0a1-8b21a697c750) to agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 at slave(1249)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:49.461215 3177 slave.cpp:4434] Ignoring new checkpointed resources and operations identical to the current version
I0204 15:47:49.464347 3163 provider.cpp:498] Received APPLY_OPERATION event
I0204 15:47:49.464395 3163 provider.cpp:1351] Received UNRESERVE operation '' (uuid: 0a64b265-d7ae-4fca-a0a1-8b21a697c750)
I0204 15:47:49.471086 3175 hierarchical.cpp:1853] Performed allocation for 1 agents in 1.25492ms
I0204 15:47:49.471838 3162 master.cpp:9974] Sending offers [ 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-O6 ] to framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 (default) at scheduler-e98b38c0-d8c0-4a71-ae14-6a5babf781ab@172.17.0.2:44433
I0204 15:47:49.472548 3162 sched.cpp:934] Scheduler::resourceOffers took 96323ns
I0204 15:47:49.488134 3165 http.cpp:1405] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.2:39198
I0204 15:47:49.489135 3169 slave.cpp:8565] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 814dfdd0-5f6b-47f6-87ec-9c1458652425) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0204 15:47:49.489375 3169 slave.cpp:9018] Updating the state of operation with no ID (uuid: 814dfdd0-5f6b-47f6-87ec-9c1458652425) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0204 15:47:49.489454 3169 slave.cpp:8772] Forwarding status update of operation with no ID (operation_uuid: 814dfdd0-5f6b-47f6-87ec-9c1458652425) for an operator API call
I0204 15:47:49.489856 3164 master.cpp:11790] Updating the state of operation '' (uuid: 814dfdd0-5f6b-47f6-87ec-9c1458652425) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0204 15:47:49.490600 3171 slave.cpp:4434] Ignoring new checkpointed resources and operations identical to the current version
I0204 15:47:49.574844 3165 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 5363293a-64d9-4a5d-ba92-196be029e820) for operation UUID 0a64b265-d7ae-4fca-a0a1-8b21a697c750 on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.574904 3165 status_update_manager_process.hpp:414] Creating operation status update stream 0a64b265-d7ae-4fca-a0a1-8b21a697c750 checkpoint=true
I0204 15:47:49.574910 3163 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0204 15:47:49.575155 3165 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 5363293a-64d9-4a5d-ba92-196be029e820) for operation UUID 0a64b265-d7ae-4fca-a0a1-8b21a697c750 on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.650156 3165 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 5363293a-64d9-4a5d-ba92-196be029e820) for operation UUID 0a64b265-d7ae-4fca-a0a1-8b21a697c750 on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.650511 3165 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 1f078ee2-6682-4998-992b-216c16f33976) for stream 814dfdd0-5f6b-47f6-87ec-9c1458652425
I0204 15:47:49.650588 3165 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 1f078ee2-6682-4998-992b-216c16f33976) for operation UUID 814dfdd0-5f6b-47f6-87ec-9c1458652425 on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.651139 3172 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:44433/slave(1249)/api/v1/resource_provider
I0204 15:47:49.652218 3175 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider'
I0204 15:47:49.696290 3167 http.cpp:1405] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.2:39198
I0204 15:47:49.697265 3166 slave.cpp:8565] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 0a64b265-d7ae-4fca-a0a1-8b21a697c750) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0204 15:47:49.697525 3166 slave.cpp:9018] Updating the state of operation with no ID (uuid: 0a64b265-d7ae-4fca-a0a1-8b21a697c750) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0204 15:47:49.697587 3166 slave.cpp:8772] Forwarding status update of operation with no ID (operation_uuid: 0a64b265-d7ae-4fca-a0a1-8b21a697c750) for an operator API call
I0204 15:47:49.697904 3163 master.cpp:11790] Updating the state of operation '' (uuid: 0a64b265-d7ae-4fca-a0a1-8b21a697c750) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0204 15:47:49.698562 3172 slave.cpp:4434] Ignoring new checkpointed resources and operations identical to the current version
I0204 15:47:49.700371 3167 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0204 15:47:49.716994 3165 status_update_manager_process.hpp:490] Cleaning up operation status update stream 814dfdd0-5f6b-47f6-87ec-9c1458652425
I0204 15:47:49.717253 3165 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 5363293a-64d9-4a5d-ba92-196be029e820) for stream 0a64b265-d7ae-4fca-a0a1-8b21a697c750
I0204 15:47:49.717324 3165 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 5363293a-64d9-4a5d-ba92-196be029e820) for operation UUID 0a64b265-d7ae-4fca-a0a1-8b21a697c750 on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.778802 3165 status_update_manager_process.hpp:490] Cleaning up operation status update stream 0a64b265-d7ae-4fca-a0a1-8b21a697c750
I0204 15:47:49.830283 3164 master.cpp:1414] Framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 (default) at scheduler-e98b38c0-d8c0-4a71-ae14-6a5babf781ab@172.17.0.2:44433 disconnected
I0204 15:47:49.830323 3164 master.cpp:3333] Deactivating framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 (default) at scheduler-e98b38c0-d8c0-4a71-ae14-6a5babf781ab@172.17.0.2:44433
I0204 15:47:49.830801 3174 hierarchical.cpp:813] Deactivated framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000
I0204 15:47:49.831140 3177 slave.cpp:995] Agent terminating
I0204 15:47:49.831389 3164 master.cpp:12273] Removing offer 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-O6
I0204 15:47:49.831502 3164 master.cpp:3310] Disconnecting framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 (default) at scheduler-e98b38c0-d8c0-4a71-ae14-6a5babf781ab@172.17.0.2:44433
I0204 15:47:49.831476 3174 hierarchical.cpp:1576] 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_r2PJa4/2GB-f163e411-1a6d-4dfb-a439-117c41570df5,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_r2PJa4/2GB-f163e411-1a6d-4dfb-a439-117c41570df5,test)]:2048, offered or allocated: {}) on agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 from framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000
I0204 15:47:49.831568 3164 master.cpp:1429] Giving framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 (default) at scheduler-e98b38c0-d8c0-4a71-ae14-6a5babf781ab@172.17.0.2:44433 0ns to failover
I0204 15:47:49.832020 3177 manager.cpp:127] Terminating resource provider cfe52025-d8b3-4aea-be08-99f1dc0b80d7
I0204 15:47:49.832424 3167 master.cpp:1299] Agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 at slave(1249)@172.17.0.2:44433 (69bfc788b585) disconnected
I0204 15:47:49.832453 3167 master.cpp:3368] Disconnecting agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 at slave(1249)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:49.832525 3167 master.cpp:3387] Deactivating agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 at slave(1249)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:49.832720 3167 master.cpp:9760] Framework failover timeout, removing framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 (default) at scheduler-e98b38c0-d8c0-4a71-ae14-6a5babf781ab@172.17.0.2:44433
I0204 15:47:49.832754 3167 master.cpp:10762] Removing framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000 (default) at scheduler-e98b38c0-d8c0-4a71-ae14-6a5babf781ab@172.17.0.2:44433
E0204 15:47:49.832865 3176 http_connection.hpp:449] End-Of-File received
I0204 15:47:49.833034 3174 hierarchical.cpp:1156] Agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0 deactivated
I0204 15:47:49.833114 3174 hierarchical.cpp:1777] Allocation paused
I0204 15:47:49.833474 3176 http_connection.hpp:217] Re-detecting endpoint
I0204 15:47:49.833626 3174 hierarchical.cpp:757] Removed framework 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-0000
I0204 15:47:49.833743 3174 hierarchical.cpp:1787] Allocation resumed
I0204 15:47:49.833904 3176 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0204 15:47:49.833986 3176 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0204 15:47:49.834045 3166 provider.cpp:488] Disconnected from resource provider manager
I0204 15:47:49.834074 3176 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:44433/slave(1249)/api/v1/resource_provider
I0204 15:47:49.834148 3171 status_update_manager_process.hpp:379] Pausing operation status update manager
I0204 15:47:49.835410 3175 containerizer.cpp:2619] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0204 15:47:49.835464 3175 containerizer.cpp:3317] 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.468429952secs
I0204 15:47:49.835884 3175 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:49.837702 3168 hierarchical.cpp:1853] Performed allocation for 1 agents in 176491ns
I0204 15:47:49.838105 3168 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:44433/slave(1249)/api/v1/resource_provider
I0204 15:47:49.838904 3170 provider.cpp:476] Connected to resource provider manager
I0204 15:47:49.839576 3174 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:44433/slave(1249)/api/v1/resource_provider
I0204 15:47:49.840556 3178 process.cpp:2781] Returning '404 Not Found' for '/slave(1249)/api/v1/resource_provider'
E0204 15:47:49.842022 3162 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0204 15:47:49.889225 3167 hierarchical.cpp:1853] Performed allocation for 1 agents in 218366ns
I0204 15:47:49.939316 3164 containerizer.cpp:3155] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0204 15:47:49.940774 3170 hierarchical.cpp:1853] Performed allocation for 1 agents in 130967ns
I0204 15:47:49.941252 3175 provisioner.cpp:652] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:49.944378 3162 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'
I0204 15:47:49.944628 3162 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-SsTXeS/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:49.944880 3170 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0204 15:47:49.947768 3178 process.cpp:2781] Returning '404 Not Found' for '/slave(1249)/api/v1'
I0204 15:47:49.960295 3161 master.cpp:1140] Master terminating
I0204 15:47:49.961192 3164 hierarchical.cpp:1132] Removed all filters for agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
I0204 15:47:49.961216 3164 hierarchical.cpp:1008] Removed agent 0da87a4f-2cc4-4f3f-afd8-d6ce75a6b52c-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (2353 ms)
[ RUN ] CSIVersion/StorageLocalResourceProviderTest.Update/v0
I0204 15:47:49.977284 3161 cluster.cpp:186] Creating default 'local' authorizer
I0204 15:47:49.982690 3162 master.cpp:443] Master d79ed308-c569-4f2b-b1fe-0df2bdf31265 (69bfc788b585) started on 172.17.0.2:44433
I0204 15:47:49.982719 3162 master.cpp:446] 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/BVIu5U/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="/tmp/SRC/build/mesos-1.10.0/_inst/share/mesos/webui" --work_dir="/tmp/BVIu5U/master" --zk_session_timeout="10secs"
I0204 15:47:49.983060 3162 master.cpp:495] Master only allowing authenticated frameworks to register
I0204 15:47:49.983098 3162 master.cpp:501] Master only allowing authenticated agents to register
I0204 15:47:49.983110 3162 master.cpp:507] Master only allowing authenticated HTTP frameworks to register
I0204 15:47:49.983139 3162 credentials.hpp:37] Loading credentials for authentication from '/tmp/BVIu5U/credentials'
I0204 15:47:49.983402 3162 master.cpp:551] Using default 'crammd5' authenticator
I0204 15:47:49.983623 3162 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0204 15:47:49.983867 3162 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0204 15:47:49.984071 3162 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0204 15:47:49.984268 3162 master.cpp:632] Authorization enabled
I0204 15:47:49.984664 3163 whitelist_watcher.cpp:77] No whitelist given
I0204 15:47:49.984668 3176 hierarchical.cpp:567] Initialized hierarchical allocator process
I0204 15:47:49.987980 3164 master.cpp:2172] Elected as the leading master!
I0204 15:47:49.988025 3164 master.cpp:1668] Recovering from registrar
I0204 15:47:49.988251 3171 registrar.cpp:339] Recovering registrar
I0204 15:47:49.989169 3171 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0204 15:47:49.989318 3171 registrar.cpp:487] Applied 1 operations in 47063ns; attempting to update the registry
I0204 15:47:49.990077 3171 registrar.cpp:544] Successfully updated the registry in 0ns
I0204 15:47:49.990242 3171 registrar.cpp:416] Successfully recovered registrar
I0204 15:47:49.990774 3163 master.cpp:1821] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I0204 15:47:49.990790 3176 hierarchical.cpp:606] Skipping recovery of hierarchical allocator: nothing to recover
W0204 15:47:49.996870 3161 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:44433
I0204 15:47:49.998201 3161 containerizer.cpp:317] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0204 15:47:49.998780 3161 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0204 15:47:49.998811 3161 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0204 15:47:49.998826 3161 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0204 15:47:49.998855 3161 provisioner.cpp:294] Using default backend 'copy'
I0204 15:47:50.001385 3161 cluster.cpp:533] Creating default 'local' authorizer
I0204 15:47:50.003808 3172 slave.cpp:274] Mesos agent started on (1250)@172.17.0.2:44433
I0204 15:47:50.003845 3172 slave.cpp:275] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/BVIu5U/z5ZOxl/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/BVIu5U/z5ZOxl/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/BVIu5U/z5ZOxl/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/BVIu5U/z5ZOxl/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/BVIu5U/z5ZOxl/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/BVIu5U/z5ZOxl/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posi
x" --launcher_dir="/tmp/SRC/build/mesos-1.10.0/_build/sub/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/BVIu5U/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_KDyQpZ" --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_StorageLoca
lResourceProviderTest_Update_v0_NvNShD" --zk_session_timeout="10secs"
I0204 15:47:50.004562 3172 credentials.hpp:86] Loading credential for authentication from '/tmp/BVIu5U/z5ZOxl/credential'
I0204 15:47:50.004775 3172 slave.cpp:307] Agent using credential for: test-principal
I0204 15:47:50.004817 3172 credentials.hpp:37] Loading credentials for authentication from '/tmp/BVIu5U/z5ZOxl/http_credentials'
I0204 15:47:50.005125 3172 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0204 15:47:50.005597 3172 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0204 15:47:50.007169 3165 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I0204 15:47:50.007511 3172 slave.cpp:622] 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"}]
I0204 15:47:50.007835 3172 slave.cpp:630] Agent attributes: [ ]
I0204 15:47:50.007858 3172 slave.cpp:639] Agent hostname: 69bfc788b585
I0204 15:47:50.008101 3162 status_update_manager_process.hpp:379] Pausing operation status update manager
I0204 15:47:50.008121 3167 task_status_update_manager.cpp:181] Pausing sending task status updates
I0204 15:47:50.009876 3166 state.cpp:68] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_NvNShD/meta'
I0204 15:47:50.010138 3177 slave.cpp:7574] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_NvNShD/meta', beginning agent recovery
I0204 15:47:50.010954 3173 task_status_update_manager.cpp:207] Recovering task status update manager
I0204 15:47:50.011617 3169 containerizer.cpp:820] Recovering Mesos containers
I0204 15:47:50.012079 3169 containerizer.cpp:1160] Recovering isolators
I0204 15:47:50.013067 3169 hierarchical.cpp:1853] Performed allocation for 0 agents in 98617ns
I0204 15:47:50.013417 3177 containerizer.cpp:1199] Recovering provisioner
I0204 15:47:50.014328 3173 provisioner.cpp:518] Provisioner recovery complete
I0204 15:47:50.015199 3165 composing.cpp:339] Finished recovering all containerizers
I0204 15:47:50.015509 3174 slave.cpp:8056] Recovering executors
I0204 15:47:50.015674 3174 slave.cpp:8209] Finished recovery
I0204 15:47:50.016592 3166 task_status_update_manager.cpp:181] Pausing sending task status updates
I0204 15:47:50.016636 3163 status_update_manager_process.hpp:379] Pausing operation status update manager
I0204 15:47:50.016695 3175 slave.cpp:1422] New master detected at master@172.17.0.2:44433
I0204 15:47:50.016834 3175 slave.cpp:1487] Detecting new master
I0204 15:47:50.027351 3167 slave.cpp:1514] Authenticating with master master@172.17.0.2:44433
I0204 15:47:50.027489 3167 slave.cpp:1523] Using default CRAM-MD5 authenticatee
I0204 15:47:50.027876 3176 authenticatee.cpp:121] Creating new client SASL connection
I0204 15:47:50.028275 3176 master.cpp:10159] Authenticating slave(1250)@172.17.0.2:44433
I0204 15:47:50.028461 3162 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2110)@172.17.0.2:44433
I0204 15:47:50.028849 3173 authenticator.cpp:98] Creating new server SASL connection
I0204 15:47:50.029103 3165 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0204 15:47:50.029153 3165 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0204 15:47:50.029330 3168 authenticator.cpp:204] Received SASL authentication start
I0204 15:47:50.029422 3168 authenticator.cpp:326] Authentication requires more steps
I0204 15:47:50.029609 3174 authenticatee.cpp:259] Received SASL authentication step
I0204 15:47:50.029803 3169 authenticator.cpp:232] Received SASL authentication step
I0204 15:47:50.029851 3169 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '69bfc788b585' server FQDN: '69bfc788b585' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0204 15:47:50.029881 3169 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0204 15:47:50.029939 3169 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0204 15:47:50.029986 3169 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '69bfc788b585' server FQDN: '69bfc788b585' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0204 15:47:50.030009 3169 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0204 15:47:50.030025 3169 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0204 15:47:50.030047 3169 authenticator.cpp:318] Authentication success
I0204 15:47:50.030174 3177 authenticatee.cpp:299] Authentication success
I0204 15:47:50.030287 3166 master.cpp:10191] Successfully authenticated principal 'test-principal' at slave(1250)@172.17.0.2:44433
I0204 15:47:50.030344 3163 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2110)@172.17.0.2:44433
I0204 15:47:50.030728 3175 slave.cpp:1614] Successfully authenticated with master master@172.17.0.2:44433
I0204 15:47:50.031210 3175 slave.cpp:2064] Will retry registration in 3.404806ms if necessary
I0204 15:47:50.031441 3176 master.cpp:6629] Received register agent message from slave(1250)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:50.031944 3176 master.cpp:3712] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I0204 15:47:50.032747 3168 master.cpp:6696] Authorized registration of agent at slave(1250)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:50.032869 3168 master.cpp:6808] Registering agent at slave(1250)@172.17.0.2:44433 (69bfc788b585) with id d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0
I0204 15:47:50.033624 3174 registrar.cpp:487] Applied 1 operations in 264367ns; attempting to update the registry
I0204 15:47:50.034433 3174 registrar.cpp:544] Successfully updated the registry in 700160ns
I0204 15:47:50.034672 3172 master.cpp:6856] Admitted agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0 at slave(1250)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:50.035542 3172 master.cpp:6901] Registered agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0 at slave(1250)@172.17.0.2:44433 (69bfc788b585) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0204 15:47:50.035810 3167 slave.cpp:1647] Registered with master master@172.17.0.2:44433; given agent ID d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0
I0204 15:47:50.035871 3163 hierarchical.cpp:959] Added agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0 (69bfc788b585) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I0204 15:47:50.035977 3173 task_status_update_manager.cpp:188] Resuming sending task status updates
I0204 15:47:50.036350 3163 hierarchical.cpp:1853] Performed allocation for 1 agents in 196506ns
I0204 15:47:50.036437 3167 slave.cpp:1682] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_NvNShD/meta/slaves/d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0/slave.info'
I0204 15:47:50.036511 3176 status_update_manager_process.hpp:385] Resuming operation status update manager
I0204 15:47:50.037699 3167 slave.cpp:1734] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"SG+GNeBsS4KkO2Epqr0uPA=="},"slave_id":{"value":"d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0"},"update_oversubscribed_resources":false}
I0204 15:47:50.038544 3171 master.cpp:8039] Ignoring update on agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0 at slave(1250)@172.17.0.2:44433 (69bfc788b585) as it reports no changes
I0204 15:47:50.043120 3166 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1'
I0204 15:47:50.044677 3177 http.cpp:1405] HTTP POST for /slave(1250)/api/v1 from 172.17.0.2:39216
I0204 15:47:50.045195 3177 http.cpp:2146] Processing GET_CONTAINERS call
I0204 15:47:50.064420 3177 hierarchical.cpp:1853] Performed allocation for 1 agents in 142190ns
I0204 15:47:50.065181 3172 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0204 15:47:50.067836 3165 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1'
I0204 15:47:50.069162 3166 http.cpp:1405] HTTP POST for /slave(1250)/api/v1 from 172.17.0.2:39218
I0204 15:47:50.070003 3166 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'
I0204 15:47:50.071190 3164 http.cpp:2710] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_NvNShD/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0204 15:47:50.077898 3172 containerizer.cpp:1395] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:50.078651 3172 containerizer.cpp:3317] 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 369152ns
I0204 15:47:50.079526 3172 containerizer.cpp:1573] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_KDyQpZ/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0204 15:47:50.079587 3172 containerizer.cpp:3317] 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 938752ns
I0204 15:47:50.083300 3163 containerizer.cpp:2099] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_wZeW9g","--available_capacity=0B","--volumes=","--forward=unix:///tmp/BVIu5U/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_NvNShD/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-h1X1AM/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_NvNShD/containers/o
rg-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="110" --pipe_write="111" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_KDyQpZ/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I0204 15:47:50.095211 3163 launcher.cpp:145] Forked child with pid '14788' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0204 15:47:50.096155 3163 containerizer.cpp:3317] 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 16.55808ms
I0204 15:47:50.097966 3173 containerizer.cpp:3317] 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 1.586176ms
I0204 15:47:50.098462 3175 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_NvNShD/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:50.099768 3168 containerizer.cpp:3317] 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 1.915904ms
I0204 15:47:50.103235 3177 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'
I0204 15:47:50.103608 3164 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-h1X1AM/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:50.116379 3173 hierarchical.cpp:1853] Performed allocation for 1 agents in 191130ns
I0204 15:47:50.168257 3169 hierarchical.cpp:1853] Performed allocation for 1 agents in 209047ns
I0204 15:47:50.219183 3164 hierarchical.cpp:1853] Performed allocation for 1 agents in 144089ns
I0204 15:47:50.270483 3169 hierarchical.cpp:1853] Performed allocation for 1 agents in 161629ns
I0204 15:47:50.321964 3164 hierarchical.cpp:1853] Performed allocation for 1 agents in 193098ns
I0204 15:47:50.373381 3170 hierarchical.cpp:1853] Performed allocation for 1 agents in 197968ns
I0204 15:47:50.424829 3171 hierarchical.cpp:1853] Performed allocation for 1 agents in 223129ns
I0204 15:47:50.436681 3164 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-h1X1AM/endpoint.sock' with CSI v1
I0204 15:47:50.439539 3162 service_manager.cpp:532] Probing endpoint 'unix:///tmp/mesos-csi-h1X1AM/endpoint.sock' with CSI v0
I0204 15:47:50.440958 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/Probe call
I0204 15:47:50.443994 3165 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0204 15:47:50.446938 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginCapabilities call
I0204 15:47:50.447659 3166 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1'
I0204 15:47:50.448976 3170 http.cpp:1405] HTTP POST for /slave(1250)/api/v1 from 172.17.0.2:39220
I0204 15:47:50.449493 3170 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'
I0204 15:47:50.451036 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginInfo call
I0204 15:47:50.451352 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginInfo call
I0204 15:47:50.453037 3172 v0_volume_manager.cpp:628] NODE_SERVICE loaded: {}
I0204 15:47:50.453609 3172 v0_volume_manager.cpp:628] CONTROLLER_SERVICE loaded: {}
I0204 15:47:50.455916 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ControllerGetCapabilities call
I0204 15:47:50.459797 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Node/NodeGetCapabilities call
I0204 15:47:50.463356 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Node/NodeGetId call
I0204 15:47:50.465870 3169 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0204 15:47:50.466059 3176 status_update_manager_process.hpp:379] Pausing operation status update manager
I0204 15:47:50.466449 3165 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:44433/slave(1250)/api/v1/resource_provider
I0204 15:47:50.469406 3162 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:44433/slave(1250)/api/v1/resource_provider
I0204 15:47:50.470108 3172 provider.cpp:476] Connected to resource provider manager
I0204 15:47:50.470852 3176 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:44433/slave(1250)/api/v1/resource_provider
I0204 15:47:50.472009 3174 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1/resource_provider'
I0204 15:47:50.473933 3163 http.cpp:1405] HTTP POST for /slave(1250)/api/v1/resource_provider from 172.17.0.2:39224
I0204 15:47:50.474710 3173 manager.cpp:779] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_wZeW9g","--available_capacity=0B","--volumes=","--forward=unix:///tmp/BVIu5U/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/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"}
I0204 15:47:50.476143 3164 hierarchical.cpp:1853] Performed allocation for 1 agents in 176692ns
I0204 15:47:50.515574 3165 slave.cpp:8565] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"3a3675df-daaf-4863-9eaf-25b9374c8f50"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_wZeW9g","--available_capacity=0B","--volumes=","--forward=unix:///tmp/BVIu5U/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/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"}'
I0204 15:47:50.517350 3164 provider.cpp:498] Received SUBSCRIBED event
I0204 15:47:50.517395 3164 provider.cpp:1309] Subscribed with ID 3a3675df-daaf-4863-9eaf-25b9374c8f50
I0204 15:47:50.518234 3168 status_update_manager_process.hpp:314] Recovering operation status update manager
I0204 15:47:50.527499 3175 hierarchical.cpp:1853] Performed allocation for 1 agents in 143972ns
I0204 15:47:50.565608 3172 provider.cpp:790] Reconciling storage pools and volumes
I0204 15:47:50.568009 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I0204 15:47:50.571218 3166 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0
I0204 15:47:50.571597 3169 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.2:44433/slave(1250)/api/v1/resource_provider
I0204 15:47:50.571660 3166 provider.cpp:748] Resource provider 3a3675df-daaf-4863-9eaf-25b9374c8f50 is in READY state
I0204 15:47:50.571727 3172 status_update_manager_process.hpp:385] Resuming operation status update manager
I0204 15:47:50.572588 3162 provider.cpp:1235] Updating profiles { test } for resource provider 3a3675df-daaf-4863-9eaf-25b9374c8f50
I0204 15:47:50.572630 3173 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1/resource_provider'
I0204 15:47:50.573846 3172 provider.cpp:790] Reconciling storage pools and volumes
I0204 15:47:50.574446 3170 http.cpp:1405] HTTP POST for /slave(1250)/api/v1/resource_provider from 172.17.0.2:39222
I0204 15:47:50.575093 3177 manager.cpp:1011] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 3a3675df-daaf-4863-9eaf-25b9374c8f50
I0204 15:47:50.575377 3175 slave.cpp:8565] Handling resource provider message 'UPDATE_STATE: 3a3675df-daaf-4863-9eaf-25b9374c8f50 {}'
I0204 15:47:50.575489 3175 slave.cpp:8685] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0204 15:47:50.576375 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I0204 15:47:50.576853 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/GetCapacity call
I0204 15:47:50.576964 3170 hierarchical.cpp:1110] Grew agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0 by {} (total), { } (used)
I0204 15:47:50.577464 3170 hierarchical.cpp:1067] Agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0 (69bfc788b585) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0204 15:47:50.578689 3174 hierarchical.cpp:1853] Performed allocation for 1 agents in 159442ns
I0204 15:47:50.583706 3163 hierarchical.cpp:1853] Performed allocation for 1 agents in 137761ns
I0204 15:47:50.584159 3171 provider.cpp:790] Reconciling storage pools and volumes
I0204 15:47:50.586313 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I0204 15:47:50.586628 14792 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/GetCapacity call
I0204 15:47:50.597393 3161 slave.cpp:995] Agent terminating
I0204 15:47:50.598356 3161 manager.cpp:127] Terminating resource provider 3a3675df-daaf-4863-9eaf-25b9374c8f50
I0204 15:47:50.598912 3164 master.cpp:1299] Agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0 at slave(1250)@172.17.0.2:44433 (69bfc788b585) disconnected
I0204 15:47:50.598956 3164 master.cpp:3368] Disconnecting agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0 at slave(1250)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:50.599043 3164 master.cpp:3387] Deactivating agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0 at slave(1250)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:50.599195 3166 hierarchical.cpp:1156] Agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0 deactivated
E0204 15:47:50.599640 3172 http_connection.hpp:449] End-Of-File received
I0204 15:47:50.600155 3172 http_connection.hpp:217] Re-detecting endpoint
I0204 15:47:50.600742 3172 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0204 15:47:50.600826 3171 provider.cpp:488] Disconnected from resource provider manager
I0204 15:47:50.600865 3172 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0204 15:47:50.600948 3171 status_update_manager_process.hpp:379] Pausing operation status update manager
I0204 15:47:50.600950 3172 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:44433/slave(1250)/api/v1/resource_provider
I0204 15:47:50.602813 3167 containerizer.cpp:2619] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0204 15:47:50.602875 3167 containerizer.cpp:3317] 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.503227904secs
I0204 15:47:50.603351 3167 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:50.604439 3165 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:44433/slave(1250)/api/v1/resource_provider
I0204 15:47:50.605106 3172 provider.cpp:476] Connected to resource provider manager
I0204 15:47:50.605728 3168 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:44433/slave(1250)/api/v1/resource_provider
I0204 15:47:50.606693 3178 process.cpp:2781] Returning '404 Not Found' for '/slave(1250)/api/v1/resource_provider'
E0204 15:47:50.607959 3170 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0204 15:47:50.630108 3163 hierarchical.cpp:1853] Performed allocation for 1 agents in 181017ns
I0204 15:47:50.679281 3176 containerizer.cpp:3155] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0204 15:47:50.681107 3172 provisioner.cpp:652] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:50.681699 3175 hierarchical.cpp:1853] Performed allocation for 1 agents in 113776ns
I0204 15:47:50.684278 3176 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'
I0204 15:47:50.684542 3170 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-h1X1AM/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:50.684820 3172 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0204 15:47:50.687815 3178 process.cpp:2781] Returning '404 Not Found' for '/slave(1250)/api/v1'
I0204 15:47:50.699259 3161 master.cpp:1140] Master terminating
I0204 15:47:50.699674 3167 hierarchical.cpp:1132] Removed all filters for agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0
I0204 15:47:50.699707 3167 hierarchical.cpp:1008] Removed agent d79ed308-c569-4f2b-b1fe-0df2bdf31265-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v0 (737 ms)
[ RUN ] CSIVersion/StorageLocalResourceProviderTest.Update/v1
I0204 15:47:50.715992 3161 cluster.cpp:186] Creating default 'local' authorizer
I0204 15:47:50.720912 3176 master.cpp:443] Master d4878aa1-ed35-4b49-9ccf-547b871a202b (69bfc788b585) started on 172.17.0.2:44433
I0204 15:47:50.720942 3176 master.cpp:446] 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/XBlXyZ/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="/tmp/SRC/build/mesos-1.10.0/_inst/share/mesos/webui" --work_dir="/tmp/XBlXyZ/master" --zk_session_timeout="10secs"
I0204 15:47:50.721370 3176 master.cpp:495] Master only allowing authenticated frameworks to register
I0204 15:47:50.721386 3176 master.cpp:501] Master only allowing authenticated agents to register
I0204 15:47:50.721398 3176 master.cpp:507] Master only allowing authenticated HTTP frameworks to register
I0204 15:47:50.721410 3176 credentials.hpp:37] Loading credentials for authentication from '/tmp/XBlXyZ/credentials'
I0204 15:47:50.721707 3176 master.cpp:551] Using default 'crammd5' authenticator
I0204 15:47:50.721946 3176 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0204 15:47:50.722179 3176 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0204 15:47:50.722378 3176 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0204 15:47:50.722604 3176 master.cpp:632] Authorization enabled
I0204 15:47:50.723032 3173 hierarchical.cpp:567] Initialized hierarchical allocator process
I0204 15:47:50.723080 3169 whitelist_watcher.cpp:77] No whitelist given
I0204 15:47:50.726662 3162 master.cpp:2172] Elected as the leading master!
I0204 15:47:50.726699 3162 master.cpp:1668] Recovering from registrar
I0204 15:47:50.726892 3170 registrar.cpp:339] Recovering registrar
I0204 15:47:50.727628 3170 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0204 15:47:50.727753 3170 registrar.cpp:487] Applied 1 operations in 39658ns; attempting to update the registry
I0204 15:47:50.728430 3169 registrar.cpp:544] Successfully updated the registry in 0ns
I0204 15:47:50.728600 3169 registrar.cpp:416] Successfully recovered registrar
I0204 15:47:50.729189 3168 master.cpp:1821] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I0204 15:47:50.729207 3176 hierarchical.cpp:606] Skipping recovery of hierarchical allocator: nothing to recover
W0204 15:47:50.735028 3161 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:44433
I0204 15:47:50.736483 3161 containerizer.cpp:317] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0204 15:47:50.737063 3161 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0204 15:47:50.737092 3161 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0204 15:47:50.737107 3161 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0204 15:47:50.737154 3161 provisioner.cpp:294] Using default backend 'copy'
I0204 15:47:50.739792 3161 cluster.cpp:533] Creating default 'local' authorizer
I0204 15:47:50.742236 3171 slave.cpp:274] Mesos agent started on (1251)@172.17.0.2:44433
I0204 15:47:50.742270 3171 slave.cpp:275] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/XBlXyZ/NQUXKx/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/XBlXyZ/NQUXKx/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/XBlXyZ/NQUXKx/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/XBlXyZ/NQUXKx/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/XBlXyZ/NQUXKx/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/XBlXyZ/NQUXKx/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posi
x" --launcher_dir="/tmp/SRC/build/mesos-1.10.0/_build/sub/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/XBlXyZ/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_gKl7G9" --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_StorageLoca
lResourceProviderTest_Update_v1_vAmhDL" --zk_session_timeout="10secs"
I0204 15:47:50.742944 3171 credentials.hpp:86] Loading credential for authentication from '/tmp/XBlXyZ/NQUXKx/credential'
I0204 15:47:50.743153 3171 slave.cpp:307] Agent using credential for: test-principal
I0204 15:47:50.743183 3171 credentials.hpp:37] Loading credentials for authentication from '/tmp/XBlXyZ/NQUXKx/http_credentials'
I0204 15:47:50.743429 3171 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0204 15:47:50.743875 3171 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0204 15:47:50.745719 3175 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I0204 15:47:50.745774 3171 slave.cpp:622] 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"}]
I0204 15:47:50.746084 3171 slave.cpp:630] Agent attributes: [ ]
I0204 15:47:50.746104 3171 slave.cpp:639] Agent hostname: 69bfc788b585
I0204 15:47:50.746330 3167 status_update_manager_process.hpp:379] Pausing operation status update manager
I0204 15:47:50.746340 3162 task_status_update_manager.cpp:181] Pausing sending task status updates
I0204 15:47:50.748205 3170 state.cpp:68] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_vAmhDL/meta'
I0204 15:47:50.748453 3164 slave.cpp:7574] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_vAmhDL/meta', beginning agent recovery
I0204 15:47:50.749137 3172 task_status_update_manager.cpp:207] Recovering task status update manager
I0204 15:47:50.749709 3169 containerizer.cpp:820] Recovering Mesos containers
I0204 15:47:50.750161 3169 containerizer.cpp:1160] Recovering isolators
I0204 15:47:50.751421 3170 containerizer.cpp:1199] Recovering provisioner
I0204 15:47:50.752377 3176 provisioner.cpp:518] Provisioner recovery complete
I0204 15:47:50.752611 3168 hierarchical.cpp:1853] Performed allocation for 0 agents in 90055ns
I0204 15:47:50.753386 3169 composing.cpp:339] Finished recovering all containerizers
I0204 15:47:50.753717 3167 slave.cpp:8056] Recovering executors
I0204 15:47:50.753866 3167 slave.cpp:8209] Finished recovery
I0204 15:47:50.754848 3170 task_status_update_manager.cpp:181] Pausing sending task status updates
I0204 15:47:50.754899 3174 status_update_manager_process.hpp:379] Pausing operation status update manager
I0204 15:47:50.754914 3164 slave.cpp:1422] New master detected at master@172.17.0.2:44433
I0204 15:47:50.755044 3164 slave.cpp:1487] Detecting new master
I0204 15:47:50.763562 3171 slave.cpp:1514] Authenticating with master master@172.17.0.2:44433
I0204 15:47:50.763710 3171 slave.cpp:1523] Using default CRAM-MD5 authenticatee
I0204 15:47:50.764113 3166 authenticatee.cpp:121] Creating new client SASL connection
I0204 15:47:50.764505 3162 master.cpp:10159] Authenticating slave(1251)@172.17.0.2:44433
I0204 15:47:50.764744 3175 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2111)@172.17.0.2:44433
I0204 15:47:50.765152 3177 authenticator.cpp:98] Creating new server SASL connection
I0204 15:47:50.765419 3169 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0204 15:47:50.765466 3169 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0204 15:47:50.765628 3173 authenticator.cpp:204] Received SASL authentication start
I0204 15:47:50.765712 3173 authenticator.cpp:326] Authentication requires more steps
I0204 15:47:50.765863 3173 authenticatee.cpp:259] Received SASL authentication step
I0204 15:47:50.766026 3173 authenticator.cpp:232] Received SASL authentication step
I0204 15:47:50.766070 3173 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '69bfc788b585' server FQDN: '69bfc788b585' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0204 15:47:50.766093 3173 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0204 15:47:50.766157 3173 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0204 15:47:50.766209 3173 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '69bfc788b585' server FQDN: '69bfc788b585' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0204 15:47:50.766233 3173 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0204 15:47:50.766247 3173 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0204 15:47:50.766268 3173 authenticator.cpp:318] Authentication success
I0204 15:47:50.766418 3167 authenticatee.cpp:299] Authentication success
I0204 15:47:50.766571 3172 master.cpp:10191] Successfully authenticated principal 'test-principal' at slave(1251)@172.17.0.2:44433
I0204 15:47:50.766630 3174 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2111)@172.17.0.2:44433
I0204 15:47:50.766913 3170 slave.cpp:1614] Successfully authenticated with master master@172.17.0.2:44433
I0204 15:47:50.767408 3170 slave.cpp:2064] Will retry registration in 9.308407ms if necessary
I0204 15:47:50.767612 3166 master.cpp:6629] Received register agent message from slave(1251)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:50.768082 3166 master.cpp:3712] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I0204 15:47:50.768862 3169 master.cpp:6696] Authorized registration of agent at slave(1251)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:50.768975 3169 master.cpp:6808] Registering agent at slave(1251)@172.17.0.2:44433 (69bfc788b585) with id d4878aa1-ed35-4b49-9ccf-547b871a202b-S0
I0204 15:47:50.769721 3176 registrar.cpp:487] Applied 1 operations in 257538ns; attempting to update the registry
I0204 15:47:50.770527 3176 registrar.cpp:544] Successfully updated the registry in 720128ns
I0204 15:47:50.770742 3171 master.cpp:6856] Admitted agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0 at slave(1251)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:50.771674 3171 master.cpp:6901] Registered agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0 at slave(1251)@172.17.0.2:44433 (69bfc788b585) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0204 15:47:50.771746 3174 slave.cpp:1647] Registered with master master@172.17.0.2:44433; given agent ID d4878aa1-ed35-4b49-9ccf-547b871a202b-S0
I0204 15:47:50.771919 3166 task_status_update_manager.cpp:188] Resuming sending task status updates
I0204 15:47:50.771898 3170 hierarchical.cpp:959] Added agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0 (69bfc788b585) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I0204 15:47:50.772347 3174 slave.cpp:1682] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_vAmhDL/meta/slaves/d4878aa1-ed35-4b49-9ccf-547b871a202b-S0/slave.info'
I0204 15:47:50.772349 3170 hierarchical.cpp:1853] Performed allocation for 1 agents in 163130ns
I0204 15:47:50.772419 3162 status_update_manager_process.hpp:385] Resuming operation status update manager
I0204 15:47:50.773689 3174 slave.cpp:1734] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"tf1vuKQ7S9aYziIdwafujA=="},"slave_id":{"value":"d4878aa1-ed35-4b49-9ccf-547b871a202b-S0"},"update_oversubscribed_resources":false}
I0204 15:47:50.774968 3174 master.cpp:8039] Ignoring update on agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0 at slave(1251)@172.17.0.2:44433 (69bfc788b585) as it reports no changes
I0204 15:47:50.779202 3177 process.cpp:3671] Handling HTTP event for process 'slave(1251)' with path: '/slave(1251)/api/v1'
I0204 15:47:50.780606 3173 http.cpp:1405] HTTP POST for /slave(1251)/api/v1 from 172.17.0.2:39232
I0204 15:47:50.781117 3173 http.cpp:2146] Processing GET_CONTAINERS call
I0204 15:47:50.803452 3174 hierarchical.cpp:1853] Performed allocation for 1 agents in 160204ns
I0204 15:47:50.805145 3173 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0204 15:47:50.808069 3163 process.cpp:3671] Handling HTTP event for process 'slave(1251)' with path: '/slave(1251)/api/v1'
I0204 15:47:50.809315 3169 http.cpp:1405] HTTP POST for /slave(1251)/api/v1 from 172.17.0.2:39234
I0204 15:47:50.810101 3169 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'
I0204 15:47:50.811203 3172 http.cpp:2710] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_vAmhDL/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0204 15:47:50.812109 3173 containerizer.cpp:1395] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:50.812851 3173 containerizer.cpp:3317] 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 295936ns
I0204 15:47:50.844945 3173 containerizer.cpp:1573] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_gKl7G9/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0204 15:47:50.845013 3173 containerizer.cpp:3317] 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 32.164096ms
I0204 15:47:50.848085 3162 containerizer.cpp:2099] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_MDnszn","--available_capacity=0B","--volumes=","--forward=unix:///tmp/XBlXyZ/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_vAmhDL/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-9nmZx6/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_vAmhDL/containers/o
rg-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="110" --pipe_write="111" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_gKl7G9/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I0204 15:47:50.858314 3162 launcher.cpp:145] Forked child with pid '14801' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0204 15:47:50.859388 3168 hierarchical.cpp:1853] Performed allocation for 1 agents in 277793ns
I0204 15:47:50.859418 3162 containerizer.cpp:3317] 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 14.399744ms
I0204 15:47:50.860988 3162 containerizer.cpp:3317] 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 1.567232ms
I0204 15:47:50.861271 3175 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_vAmhDL/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:50.862536 3173 containerizer.cpp:3317] 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 1.465088ms
I0204 15:47:50.865231 3167 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'
I0204 15:47:50.865435 3167 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-9nmZx6/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:50.910710 3177 hierarchical.cpp:1853] Performed allocation for 1 agents in 201178ns
I0204 15:47:50.962668 3171 hierarchical.cpp:1853] Performed allocation for 1 agents in 269365ns
I0204 15:47:51.013890 3173 hierarchical.cpp:1853] Performed allocation for 1 agents in 149224ns
I0204 15:47:51.065631 3172 hierarchical.cpp:1853] Performed allocation for 1 agents in 235084ns
I0204 15:47:51.117486 3170 hierarchical.cpp:1853] Performed allocation for 1 agents in 167059ns
I0204 15:47:51.169081 3174 hierarchical.cpp:1853] Performed allocation for 1 agents in 186767ns
I0204 15:47:51.198076 3176 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-9nmZx6/endpoint.sock' with CSI v1
I0204 15:47:51.200150 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/Probe call
I0204 15:47:51.203429 3170 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0204 15:47:51.206655 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginCapabilities call
I0204 15:47:51.207129 3163 process.cpp:3671] Handling HTTP event for process 'slave(1251)' with path: '/slave(1251)/api/v1'
I0204 15:47:51.208463 3162 http.cpp:1405] HTTP POST for /slave(1251)/api/v1 from 172.17.0.2:39236
I0204 15:47:51.209000 3162 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'
I0204 15:47:51.211714 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call
I0204 15:47:51.212051 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call
I0204 15:47:51.213795 3176 v1_volume_manager.cpp:649] NODE_SERVICE loaded: {}
I0204 15:47:51.214363 3176 v1_volume_manager.cpp:649] CONTROLLER_SERVICE loaded: {}
I0204 15:47:51.216504 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ControllerGetCapabilities call
I0204 15:47:51.220383 3167 hierarchical.cpp:1853] Performed allocation for 1 agents in 146939ns
I0204 15:47:51.220520 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetCapabilities call
I0204 15:47:51.224112 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetInfo call
I0204 15:47:51.226636 3169 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0204 15:47:51.226840 3173 status_update_manager_process.hpp:379] Pausing operation status update manager
I0204 15:47:51.227190 3170 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:44433/slave(1251)/api/v1/resource_provider
I0204 15:47:51.230305 3163 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:44433/slave(1251)/api/v1/resource_provider
I0204 15:47:51.231108 3175 provider.cpp:476] Connected to resource provider manager
I0204 15:47:51.231811 3177 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:44433/slave(1251)/api/v1/resource_provider
I0204 15:47:51.232971 3169 process.cpp:3671] Handling HTTP event for process 'slave(1251)' with path: '/slave(1251)/api/v1/resource_provider'
I0204 15:47:51.234956 3176 http.cpp:1405] HTTP POST for /slave(1251)/api/v1/resource_provider from 172.17.0.2:39240
I0204 15:47:51.235819 3171 manager.cpp:779] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_MDnszn","--available_capacity=0B","--volumes=","--forward=unix:///tmp/XBlXyZ/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/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"}
I0204 15:47:51.259766 3170 slave.cpp:8565] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"e7926012-3966-4eb5-b027-4efc2bf2e2a4"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_MDnszn","--available_capacity=0B","--volumes=","--forward=unix:///tmp/XBlXyZ/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/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"}'
I0204 15:47:51.261546 3171 provider.cpp:498] Received SUBSCRIBED event
I0204 15:47:51.261590 3171 provider.cpp:1309] Subscribed with ID e7926012-3966-4eb5-b027-4efc2bf2e2a4
I0204 15:47:51.262327 3162 status_update_manager_process.hpp:314] Recovering operation status update manager
I0204 15:47:51.271733 3175 hierarchical.cpp:1853] Performed allocation for 1 agents in 187323ns
I0204 15:47:51.318679 3177 provider.cpp:790] Reconciling storage pools and volumes
I0204 15:47:51.321064 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I0204 15:47:51.323369 3173 hierarchical.cpp:1853] Performed allocation for 1 agents in 164239ns
I0204 15:47:51.323866 3169 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0
I0204 15:47:51.324265 3169 provider.cpp:748] Resource provider e7926012-3966-4eb5-b027-4efc2bf2e2a4 is in READY state
I0204 15:47:51.324250 3177 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.2:44433/slave(1251)/api/v1/resource_provider
I0204 15:47:51.324350 3172 status_update_manager_process.hpp:385] Resuming operation status update manager
I0204 15:47:51.325055 3176 provider.cpp:1235] Updating profiles { test } for resource provider e7926012-3966-4eb5-b027-4efc2bf2e2a4
I0204 15:47:51.325383 3175 process.cpp:3671] Handling HTTP event for process 'slave(1251)' with path: '/slave(1251)/api/v1/resource_provider'
I0204 15:47:51.326292 3175 provider.cpp:790] Reconciling storage pools and volumes
I0204 15:47:51.327105 3165 http.cpp:1405] HTTP POST for /slave(1251)/api/v1/resource_provider from 172.17.0.2:39238
I0204 15:47:51.327647 3168 manager.cpp:1011] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider e7926012-3966-4eb5-b027-4efc2bf2e2a4
I0204 15:47:51.327895 3177 slave.cpp:8565] Handling resource provider message 'UPDATE_STATE: e7926012-3966-4eb5-b027-4efc2bf2e2a4 {}'
I0204 15:47:51.328012 3177 slave.cpp:8685] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0204 15:47:51.328204 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I0204 15:47:51.328925 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call
I0204 15:47:51.329572 3163 hierarchical.cpp:1110] Grew agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0 by {} (total), { } (used)
I0204 15:47:51.330040 3163 hierarchical.cpp:1067] Agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0 (69bfc788b585) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0204 15:47:51.334271 3165 hierarchical.cpp:1853] Performed allocation for 1 agents in 186260ns
I0204 15:47:51.334743 3167 provider.cpp:790] Reconciling storage pools and volumes
I0204 15:47:51.336683 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I0204 15:47:51.337200 14805 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call
I0204 15:47:51.347569 3162 slave.cpp:995] Agent terminating
I0204 15:47:51.348326 3162 manager.cpp:127] Terminating resource provider e7926012-3966-4eb5-b027-4efc2bf2e2a4
I0204 15:47:51.348801 3169 master.cpp:1299] Agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0 at slave(1251)@172.17.0.2:44433 (69bfc788b585) disconnected
I0204 15:47:51.348842 3169 master.cpp:3368] Disconnecting agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0 at slave(1251)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:51.348939 3169 master.cpp:3387] Deactivating agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0 at slave(1251)@172.17.0.2:44433 (69bfc788b585)
I0204 15:47:51.349061 3175 hierarchical.cpp:1156] Agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0 deactivated
E0204 15:47:51.349316 3177 http_connection.hpp:449] End-Of-File received
I0204 15:47:51.349849 3177 http_connection.hpp:217] Re-detecting endpoint
I0204 15:47:51.350275 3177 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0204 15:47:51.350351 3177 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0204 15:47:51.350437 3172 provider.cpp:488] Disconnected from resource provider manager
I0204 15:47:51.350479 3177 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:44433/slave(1251)/api/v1/resource_provider
I0204 15:47:51.350577 3162 status_update_manager_process.hpp:379] Pausing operation status update manager
I0204 15:47:51.352036 3168 containerizer.cpp:2619] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0204 15:47:51.352084 3168 containerizer.cpp:3317] 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.489645056secs
I0204 15:47:51.352569 3168 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:51.353277 3172 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:44433/slave(1251)/api/v1/resource_provider
I0204 15:47:51.353860 3170 provider.cpp:476] Connected to resource provider manager
I0204 15:47:51.354563 3177 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:44433/slave(1251)/api/v1/resource_provider
I0204 15:47:51.355458 3178 process.cpp:2781] Returning '404 Not Found' for '/slave(1251)/api/v1/resource_provider'
E0204 15:47:51.356667 3176 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0204 15:47:51.381976 3171 hierarchical.cpp:1853] Performed allocation for 1 agents in 151348ns
I0204 15:47:51.432060 3162 containerizer.cpp:3155] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0204 15:47:51.433712 3177 hierarchical.cpp:1853] Performed allocation for 1 agents in 168261ns
I0204 15:47:51.433964 3162 provisioner.cpp:652] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:51.436511 3170 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'
I0204 15:47:51.436704 3169 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-9nmZx6/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0204 15:47:51.436925 3177 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0204 15:47:51.439730 3178 process.cpp:2781] Returning '404 Not Found' for '/slave(1251)/api/v1'
I0204 15:47:51.451002 3169 master.cpp:1140] Master terminating
I0204 15:47:51.451442 3163 hierarchical.cpp:1132] Removed all filters for agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0
I0204 15:47:51.451475 3163 hierarchical.cpp:1008] Removed agent d4878aa1-ed35-4b49-9ccf-547b871a202b-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v1 (750 ms)
[----------] 54 tests from CSIVersion/StorageLocalResourceProviderTest (95507 ms total)
[----------] Global test environment tear-down
[==========] 2321 tests from 222 test cases ran. (1231952 ms total)
[ PASSED ] 2320 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] OversubscriptionTest.FixedResourceEstimator
1 FAILED TEST
YOU HAVE 34 DISABLED TESTS
I0204 15:47:51.542740 3178 process.cpp:935] Stopped the socket accept loop
Makefile:15957: recipe for target 'check-local' failed
make[4]: *** [check-local] Error 1
make[4]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub/src'
Makefile:15073: recipe for target 'check-am' failed
make[3]: *** [check-am] Error 2
make[3]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub/src'
Makefile:15077: recipe for target 'check' failed
make[2]: *** [check] Error 2
make[2]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub/src'
Makefile:791: recipe for target 'check-recursive' failed
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub'
Makefile:997: recipe for target 'distcheck' failed
make: *** [distcheck] Error 1
Untagged: mesos/mesos-build:ubuntu-16.04
Untagged: mesos/mesos-build@sha256:fa967cbcfb44f55708a3cbc87f245c6d29dd891464db558af56a03ee321526bb
Deleted: sha256:e895c0531b9a9a288fabe479a49f7059aed83645351ac99ec2ea2616822c9f97
Deleted: sha256:09119b0b314a69ba6ec6251f2e89f4199fe1e874c84f9abf07dcbd23dbc3f1c1
Deleted: sha256:562fe6af5a3883058be9c784a839392215ed4185a21d21f1d99df0d17f3ae6e7
Deleted: sha256:0dcdfbe322a4f332f73ac70905d557300ec6dae3bd19586758772c750c7b4a19
Deleted: sha256:c66652d605f01094e2db53d62505dbd524e076d5aa69b89d5e620003803eb149
Deleted: sha256:a2cf79bfb9593c05fd7142ddb49afef77ea4ad5d2464e841f09fe62ffee396e0
Deleted: sha256:f7a904214b390f39d98573882f631dc908df8b2b540cf04e1062f8182c1efffd
Deleted: sha256:ce1f6fcaa83dfce189d76e08f184085732eab4eeb2562d2399953958405c5bec
Deleted: sha256:cce92fda689ab9033f0b8db214bc63edd1ae3e05831a0f3a9418976d7dc7ccdd
Deleted: sha256:d22094bbd65447c59a42c580eaa3a44cee9cd855f00905f59409be21bcefc745
Deleted: sha256:b8976847450013f3eb5e9a81a5778f73ed7bef67e6393049712ef17102b4b7b7
Deleted: sha256:b8c891f0ffec910a12757d733b178e3f62d81dbbde2b31d3b754071c416108ed
Full log: https://builds.apache.org/job/Mesos-Reviewbot-Linux/6994/console
- Mesos Reviewbot
On Feb. 4, 2020, 12:01 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72080/
> -----------------------------------------------------------
>
> (Updated Feb. 4, 2020, 12:01 p.m.)
>
>
> Review request for mesos, Andrei Budnik and Qian Zhang.
>
>
> Bugs: MESOS-10092
> https://issues.apache.org/jira/browse/MESOS-10092
>
>
> Repository: mesos
>
>
> Description
> -------
>
> Added test for fetch from repositories not providing scope/service.
>
>
> Diffs
> -----
>
> src/tests/uri_fetcher_tests.cpp 92f80626f4de8a2cc29760366ca568f9d794f472
>
>
> Diff: https://reviews.apache.org/r/72080/diff/2/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 72080: Added test for fetch from repositories not
providing scope/service.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72080/#review219484
-----------------------------------------------------------
Bad review!
Reviews applied: [72080, 72079, 72078, 72077]
Error:
2020-02-04 13:07:44 URL:https://reviews.apache.org/r/72079/diff/raw/ [10979/10979] -> "72079.patch" [1]
error: patch failed: src/uri/fetchers/docker.cpp:468
error: src/uri/fetchers/docker.cpp: patch does not apply
- Mesos Reviewbot
On Feb. 4, 2020, 12:01 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72080/
> -----------------------------------------------------------
>
> (Updated Feb. 4, 2020, 12:01 p.m.)
>
>
> Review request for mesos, Andrei Budnik and Qian Zhang.
>
>
> Bugs: MESOS-10092
> https://issues.apache.org/jira/browse/MESOS-10092
>
>
> Repository: mesos
>
>
> Description
> -------
>
> Added test for fetch from repositories not providing scope/service.
>
>
> Diffs
> -----
>
> src/tests/uri_fetcher_tests.cpp 92f80626f4de8a2cc29760366ca568f9d794f472
>
>
> Diff: https://reviews.apache.org/r/72080/diff/2/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 72080: Added test for fetch from repositories not
providing scope/service.
Posted by Andrei Sekretenko <as...@mesosphere.io>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72080/
-----------------------------------------------------------
(Updated Feb. 4, 2020, 12:01 p.m.)
Review request for mesos, Andrei Budnik and Qian Zhang.
Bugs: MESOS-10092
https://issues.apache.org/jira/browse/MESOS-10092
Repository: mesos
Description
-------
Added test for fetch from repositories not providing scope/service.
Diffs (updated)
-----
src/tests/uri_fetcher_tests.cpp 92f80626f4de8a2cc29760366ca568f9d794f472
Diff: https://reviews.apache.org/r/72080/diff/2/
Changes: https://reviews.apache.org/r/72080/diff/1-2/
Testing
-------
Thanks,
Andrei Sekretenko
Re: Review Request 72080: Added test for fetch from repositories not
providing scope/service.
Posted by Qian Zhang <zh...@gmail.com>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72080/#review219482
-----------------------------------------------------------
src/tests/uri_fetcher_tests.cpp
Lines 398 (patched)
<https://reviews.apache.org/r/72080/#comment307660>
IIUC, `nvcr.io` is the registry, instead `nvidia/k8s/cuda-sample:nbody` is the repository.
src/tests/uri_fetcher_tests.cpp
Lines 399 (patched)
<https://reviews.apache.org/r/72080/#comment307661>
How do we know it does not provide scope on its own and our code logic for generating repository scope is hit? I think we need to verify it in the test.
- Qian Zhang
On Feb. 4, 2020, 1:54 a.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72080/
> -----------------------------------------------------------
>
> (Updated Feb. 4, 2020, 1:54 a.m.)
>
>
> Review request for mesos, Andrei Budnik and Qian Zhang.
>
>
> Bugs: MESOS-10092
> https://issues.apache.org/jira/browse/MESOS-10092
>
>
> Repository: mesos
>
>
> Description
> -------
>
> Added test for fetch from repositories not providing scope/service.
>
>
> Diffs
> -----
>
> src/tests/uri_fetcher_tests.cpp 92f80626f4de8a2cc29760366ca568f9d794f472
>
>
> Diff: https://reviews.apache.org/r/72080/diff/1/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 72080: Added test for fetch from repositories not
providing scope/service.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72080/#review219476
-----------------------------------------------------------
Patch looks great!
Reviews applied: [72077, 72078, 72079, 72080]
Passed command: export OS='ubuntu:16.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/jenkins/buildbot.sh
- Mesos Reviewbot
On Feb. 3, 2020, 5:54 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72080/
> -----------------------------------------------------------
>
> (Updated Feb. 3, 2020, 5:54 p.m.)
>
>
> Review request for mesos, Andrei Budnik and Qian Zhang.
>
>
> Bugs: MESOS-10092
> https://issues.apache.org/jira/browse/MESOS-10092
>
>
> Repository: mesos
>
>
> Description
> -------
>
> Added test for fetch from repositories not providing scope/service.
>
>
> Diffs
> -----
>
> src/tests/uri_fetcher_tests.cpp 92f80626f4de8a2cc29760366ca568f9d794f472
>
>
> Diff: https://reviews.apache.org/r/72080/diff/1/
>
>
> Testing
> -------
>
>
> Thanks,
>
> Andrei Sekretenko
>
>