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...@apache.org> on 2020/10/01 14:01:58 UTC
Review Request 72922: Re-added the obsolete `updateFramework`
signature into libmesos-java.so.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72922/
-----------------------------------------------------------
Review request for mesos and Benjamin Mahler.
Bugs: MESOS-10189
https://issues.apache.org/jira/browse/MESOS-10189
Repository: mesos
Description
-------
This patch converts the implementation of the obsolete 2-parameter
`SchedulerDriver.updateFramework(frameworkInfo, suppressedRoles)`
from a wrapper around the new signature back into a JNI method
that 930c7e98d17e71192dae1d49b4b2217cc2dbd8b2 attempted to remove.
This is needed to keep compatibility between older versions of
`mesos.jar` and newer versions of `libmesos-java.so`.
Diffs
-----
src/java/jni/org_apache_mesos_MesosSchedulerDriver.cpp 4efde3083bb62253f3ad512b40a291fd7f7f7a78
src/java/src/org/apache/mesos/MesosSchedulerDriver.java 4fdae338491709574775c52438e41d03b39917bd
Diff: https://reviews.apache.org/r/72922/diff/1/
Testing
-------
`make check`
Thanks,
Andrei Sekretenko
Re: Review Request 72922: Re-added the obsolete `updateFramework`
signature into libmesos-java.so.
Posted by Andrei Sekretenko <as...@apache.org>.
> On Oct. 1, 2020, 10:19 p.m., Benjamin Mahler wrote:
> > src/java/src/org/apache/mesos/MesosSchedulerDriver.java
> > Lines 416-418 (patched)
> > <https://reviews.apache.org/r/72922/diff/1/?file=2240239#file2240239line416>
> >
> > Use javadoc style here? maybe make this clear that it's a note for us and not the user looking at the interface?
Changed style.
Starts with `/*` and not with `/**`, so that javadoc does not generate documentation, regardless of whatever flags governing doc generation for private methods. Also seems to trigger different highlighting in some editors.
Given that the method is private, it should be more or less clear that this is not for user.
Now I've moved the public 3-argument `updateFramework()` higher up, next to the deprecated 2-parameter one, hopefully this will help avoid confusing users.
- Andrei
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72922/#review221984
-----------------------------------------------------------
On Oct. 2, 2020, 2:09 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72922/
> -----------------------------------------------------------
>
> (Updated Oct. 2, 2020, 2:09 p.m.)
>
>
> Review request for mesos and Benjamin Mahler.
>
>
> Bugs: MESOS-10189
> https://issues.apache.org/jira/browse/MESOS-10189
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch converts the implementation of the obsolete 2-parameter
> `SchedulerDriver.updateFramework(frameworkInfo, suppressedRoles)`
> from a wrapper around the new signature back into a JNI method
> that 930c7e98d17e71192dae1d49b4b2217cc2dbd8b2 attempted to remove.
>
> This is needed to keep compatibility between older versions of
> `mesos.jar` and newer versions of `libmesos-java.so`.
>
>
> Diffs
> -----
>
> src/java/jni/org_apache_mesos_MesosSchedulerDriver.cpp 4efde3083bb62253f3ad512b40a291fd7f7f7a78
> src/java/src/org/apache/mesos/MesosSchedulerDriver.java 4fdae338491709574775c52438e41d03b39917bd
>
>
> Diff: https://reviews.apache.org/r/72922/diff/2/
>
>
> Testing
> -------
>
> `make check`
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 72922: Re-added the obsolete `updateFramework`
signature into libmesos-java.so.
Posted by Benjamin Mahler <bm...@apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72922/#review221984
-----------------------------------------------------------
Fix it, then Ship it!
src/java/src/org/apache/mesos/MesosSchedulerDriver.java
Line 411 (original), 411-414 (patched)
<https://reviews.apache.org/r/72922/#comment311059>
Use javadoc style here?
Also, can we put a @deprecated attribute?
src/java/src/org/apache/mesos/MesosSchedulerDriver.java
Lines 416-418 (patched)
<https://reviews.apache.org/r/72922/#comment311060>
Use javadoc style here? maybe make this clear that it's a note for us and not the user looking at the interface?
- Benjamin Mahler
On Oct. 1, 2020, 2:01 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72922/
> -----------------------------------------------------------
>
> (Updated Oct. 1, 2020, 2:01 p.m.)
>
>
> Review request for mesos and Benjamin Mahler.
>
>
> Bugs: MESOS-10189
> https://issues.apache.org/jira/browse/MESOS-10189
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch converts the implementation of the obsolete 2-parameter
> `SchedulerDriver.updateFramework(frameworkInfo, suppressedRoles)`
> from a wrapper around the new signature back into a JNI method
> that 930c7e98d17e71192dae1d49b4b2217cc2dbd8b2 attempted to remove.
>
> This is needed to keep compatibility between older versions of
> `mesos.jar` and newer versions of `libmesos-java.so`.
>
>
> Diffs
> -----
>
> src/java/jni/org_apache_mesos_MesosSchedulerDriver.cpp 4efde3083bb62253f3ad512b40a291fd7f7f7a78
> src/java/src/org/apache/mesos/MesosSchedulerDriver.java 4fdae338491709574775c52438e41d03b39917bd
>
>
> Diff: https://reviews.apache.org/r/72922/diff/1/
>
>
> Testing
> -------
>
> `make check`
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 72922: Re-added the obsolete `updateFramework`
signature into libmesos-java.so.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72922/#review221988
-----------------------------------------------------------
Patch looks great!
Reviews applied: [72922]
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 Oct. 2, 2020, 12:09 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72922/
> -----------------------------------------------------------
>
> (Updated Oct. 2, 2020, 12:09 p.m.)
>
>
> Review request for mesos and Benjamin Mahler.
>
>
> Bugs: MESOS-10189
> https://issues.apache.org/jira/browse/MESOS-10189
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch converts the implementation of the obsolete 2-parameter
> `SchedulerDriver.updateFramework(frameworkInfo, suppressedRoles)`
> from a wrapper around the new signature back into a JNI method
> that 930c7e98d17e71192dae1d49b4b2217cc2dbd8b2 attempted to remove.
>
> This is needed to keep compatibility between older versions of
> `mesos.jar` and newer versions of `libmesos-java.so`.
>
>
> Diffs
> -----
>
> src/java/jni/org_apache_mesos_MesosSchedulerDriver.cpp 4efde3083bb62253f3ad512b40a291fd7f7f7a78
> src/java/src/org/apache/mesos/MesosSchedulerDriver.java 4fdae338491709574775c52438e41d03b39917bd
>
>
> Diff: https://reviews.apache.org/r/72922/diff/2/
>
>
> Testing
> -------
>
> `make check`
>
>
> Thanks,
>
> Andrei Sekretenko
>
>
Re: Review Request 72922: Re-added the obsolete `updateFramework`
signature into libmesos-java.so.
Posted by Andrei Sekretenko <as...@apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72922/
-----------------------------------------------------------
(Updated Oct. 2, 2020, 2:09 p.m.)
Review request for mesos and Benjamin Mahler.
Changes
-------
Changed comments style, added deprecation labels to the 2-parameter signature.
Bugs: MESOS-10189
https://issues.apache.org/jira/browse/MESOS-10189
Repository: mesos
Description
-------
This patch converts the implementation of the obsolete 2-parameter
`SchedulerDriver.updateFramework(frameworkInfo, suppressedRoles)`
from a wrapper around the new signature back into a JNI method
that 930c7e98d17e71192dae1d49b4b2217cc2dbd8b2 attempted to remove.
This is needed to keep compatibility between older versions of
`mesos.jar` and newer versions of `libmesos-java.so`.
Diffs (updated)
-----
src/java/jni/org_apache_mesos_MesosSchedulerDriver.cpp 4efde3083bb62253f3ad512b40a291fd7f7f7a78
src/java/src/org/apache/mesos/MesosSchedulerDriver.java 4fdae338491709574775c52438e41d03b39917bd
Diff: https://reviews.apache.org/r/72922/diff/2/
Changes: https://reviews.apache.org/r/72922/diff/1-2/
Testing
-------
`make check`
Thanks,
Andrei Sekretenko
Re: Review Request 72922: Re-added the obsolete `updateFramework`
signature into libmesos-java.so.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72922/#review221983
-----------------------------------------------------------
Bad patch!
Reviews applied: [72922]
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_72922"]
Error:
...<truncated>...
urceProviderTest_OperatorOperationsWithResourceProviderResources_v1_veS9qF/2GB-d4391ddc-fb38-4008-84fd-9b88de3bec09,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_veS9qF/2GB-d4391ddc-fb38-4008-84fd-9b88de3bec09,test)]:2048, offered or allocated: {}) on agent c99d5606-f994-4763-9b89-727b120219a3-S0 from framework c99d5606-f994-4763-9b89-727b120219a3-0000
I1001 17:19:09.191968 4237 master.cpp:11878] Removing offer c99d5606-f994-4763-9b89-727b120219a3-O3
I1001 17:19:09.194526 4215 hierarchical.cpp:1725] Framework c99d5606-f994-4763-9b89-727b120219a3-0000 filtered agent c99d5606-f994-4763-9b89-727b120219a3-S0 for 5secs
I1001 17:19:09.198184 4225 master.cpp:11743] Sending operation '' (uuid: 168cf993-f4ab-4ebd-bfff-426277ff7973) to agent c99d5606-f994-4763-9b89-727b120219a3-S0 at slave(1248)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:09.199028 4218 slave.cpp:4576] Ignoring new checkpointed resources and operations identical to the current version
I1001 17:19:09.203171 4226 provider.cpp:498] Received APPLY_OPERATION event
I1001 17:19:09.203235 4226 provider.cpp:1352] Received CREATE operation '' (uuid: 168cf993-f4ab-4ebd-bfff-426277ff7973)
I1001 17:19:09.203455 4214 master.cpp:5622] Processing REVIVE call for framework c99d5606-f994-4763-9b89-727b120219a3-0000 (default) at scheduler-5b2ec02f-494d-4385-9fa4-12aca29ce565@172.17.0.2:42997
I1001 17:19:09.204115 4214 hierarchical.cpp:1821] Unsuppressed offers and cleared filters for roles { storage/default-role } of framework c99d5606-f994-4763-9b89-727b120219a3-0000
I1001 17:19:09.206825 4214 hierarchical.cpp:1953] Performed allocation for 1 agents in 2.365724ms
I1001 17:19:09.207392 4214 hierarchical.cpp:1953] Performed allocation for 1 agents in 220667ns
I1001 17:19:09.207789 4237 master.cpp:9579] Sending offers [ c99d5606-f994-4763-9b89-727b120219a3-O4 ] to framework c99d5606-f994-4763-9b89-727b120219a3-0000 (default) at scheduler-5b2ec02f-494d-4385-9fa4-12aca29ce565@172.17.0.2:42997
I1001 17:19:09.208570 4222 sched.cpp:937] Scheduler::resourceOffers took 90272ns
I1001 17:19:09.218515 4229 http.cpp:1436] HTTP POST for /slave(1248)/api/v1/resource_provider from 172.17.0.2:45986
I1001 17:19:09.220041 4235 slave.cpp:8733] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 4c05a3f5-3afd-4e98-b8c9-e16897f9d2ca) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I1001 17:19:09.220289 4235 slave.cpp:9186] Updating the state of operation with no ID (uuid: 4c05a3f5-3afd-4e98-b8c9-e16897f9d2ca) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I1001 17:19:09.220348 4235 slave.cpp:8940] Forwarding status update of operation with no ID (operation_uuid: 4c05a3f5-3afd-4e98-b8c9-e16897f9d2ca) for an operator API call
I1001 17:19:09.220696 4223 master.cpp:11395] Updating the state of operation '' (uuid: 4c05a3f5-3afd-4e98-b8c9-e16897f9d2ca) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I1001 17:19:09.221287 4233 slave.cpp:4576] Ignoring new checkpointed resources and operations identical to the current version
I1001 17:19:09.324309 4222 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: ed599d37-596e-4f97-b17a-08b72c985140) for operation UUID 168cf993-f4ab-4ebd-bfff-426277ff7973 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:09.324409 4222 status_update_manager_process.hpp:414] Creating operation status update stream 168cf993-f4ab-4ebd-bfff-426277ff7973 checkpoint=true
I1001 17:19:09.324478 4226 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I1001 17:19:09.324823 4222 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: ed599d37-596e-4f97-b17a-08b72c985140) for operation UUID 168cf993-f4ab-4ebd-bfff-426277ff7973 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:09.391073 4222 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: ed599d37-596e-4f97-b17a-08b72c985140) for operation UUID 168cf993-f4ab-4ebd-bfff-426277ff7973 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:09.391536 4222 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 47190517-5871-448f-b13e-2c96a72a9e9e) for stream 4c05a3f5-3afd-4e98-b8c9-e16897f9d2ca
I1001 17:19:09.391608 4222 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 47190517-5871-448f-b13e-2c96a72a9e9e) for operation UUID 4c05a3f5-3afd-4e98-b8c9-e16897f9d2ca on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:09.392114 4228 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:42997/slave(1248)/api/v1/resource_provider
I1001 17:19:09.393296 4217 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1/resource_provider'
I1001 17:19:09.438199 4219 http.cpp:1436] HTTP POST for /slave(1248)/api/v1/resource_provider from 172.17.0.2:45986
I1001 17:19:09.439337 4216 slave.cpp:8733] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 168cf993-f4ab-4ebd-bfff-426277ff7973) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I1001 17:19:09.439553 4216 slave.cpp:9186] Updating the state of operation with no ID (uuid: 168cf993-f4ab-4ebd-bfff-426277ff7973) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I1001 17:19:09.439605 4216 slave.cpp:8940] Forwarding status update of operation with no ID (operation_uuid: 168cf993-f4ab-4ebd-bfff-426277ff7973) for an operator API call
I1001 17:19:09.439954 4233 master.cpp:11395] Updating the state of operation '' (uuid: 168cf993-f4ab-4ebd-bfff-426277ff7973) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I1001 17:19:09.440526 4234 slave.cpp:4576] Ignoring new checkpointed resources and operations identical to the current version
I1001 17:19:09.442112 4225 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I1001 17:19:09.457902 4222 status_update_manager_process.hpp:490] Cleaning up operation status update stream 4c05a3f5-3afd-4e98-b8c9-e16897f9d2ca
I1001 17:19:09.458163 4222 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: ed599d37-596e-4f97-b17a-08b72c985140) for stream 168cf993-f4ab-4ebd-bfff-426277ff7973
I1001 17:19:09.458251 4222 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: ed599d37-596e-4f97-b17a-08b72c985140) for operation UUID 168cf993-f4ab-4ebd-bfff-426277ff7973 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:09.549970 4222 status_update_manager_process.hpp:490] Cleaning up operation status update stream 168cf993-f4ab-4ebd-bfff-426277ff7973
I1001 17:19:09.620975 4218 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I1001 17:19:09.623090 4221 http.cpp:1436] HTTP POST for /master/api/v1 from 172.17.0.2:45994
I1001 17:19:09.623389 4221 http.cpp:277] Processing call DESTROY_VOLUMES
I1001 17:19:09.624529 4221 master.cpp:3794] Authorizing principal 'test-principal' to perform action DESTROY_VOLUME on object {"value":"test-principal","resource":{"provider_id":{"value":"cf88a5d7-0eee-4e5b-a00c-249b1fd5438d"},"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":"25bb6e4e-d7be-4d87-a0a1-57c9edc33022","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_veS9qF/2GB-d4391ddc-fb38-4008-84fd-9b88de3bec09","profile":"test"}}}}
I1001 17:19:09.626415 4231 sched.cpp:963] Rescinded offer c99d5606-f994-4763-9b89-727b120219a3-O4
I1001 17:19:09.626514 4231 sched.cpp:974] Scheduler::offerRescinded took 26807ns
I1001 17:19:09.627233 4226 hierarchical.cpp:1676] 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_veS9qF/2GB-d4391ddc-fb38-4008-84fd-9b88de3bec09,test),25bb6e4e-d7be-4d87-a0a1-57c9edc33022: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_veS9qF/2GB-d4391ddc-fb38-4008-84fd-9b88de3bec09,test),25bb6e4e-d7be-4d87-a0a1-57c9edc33022:volume]:2048, offered
or allocated: {}) on agent c99d5606-f994-4763-9b89-727b120219a3-S0 from framework c99d5606-f994-4763-9b89-727b120219a3-0000
I1001 17:19:09.627385 4234 master.cpp:11878] Removing offer c99d5606-f994-4763-9b89-727b120219a3-O4
I1001 17:19:09.630453 4226 hierarchical.cpp:1725] Framework c99d5606-f994-4763-9b89-727b120219a3-0000 filtered agent c99d5606-f994-4763-9b89-727b120219a3-S0 for 5secs
I1001 17:19:09.634534 4228 master.cpp:11743] Sending operation '' (uuid: fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9) to agent c99d5606-f994-4763-9b89-727b120219a3-S0 at slave(1248)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:09.635355 4225 slave.cpp:4576] Ignoring new checkpointed resources and operations identical to the current version
I1001 17:19:09.639714 4230 provider.cpp:498] Received APPLY_OPERATION event
I1001 17:19:09.639767 4230 provider.cpp:1352] Received DESTROY operation '' (uuid: fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9)
I1001 17:19:09.642024 4221 hierarchical.cpp:1953] Performed allocation for 1 agents in 1.62617ms
I1001 17:19:09.642917 4220 master.cpp:9579] Sending offers [ c99d5606-f994-4763-9b89-727b120219a3-O5 ] to framework c99d5606-f994-4763-9b89-727b120219a3-0000 (default) at scheduler-5b2ec02f-494d-4385-9fa4-12aca29ce565@172.17.0.2:42997
I1001 17:19:09.643816 4232 sched.cpp:937] Scheduler::resourceOffers took 145774ns
I1001 17:19:09.743603 4231 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: a0cedba0-2047-4dc0-9cc5-4a75365d8803) for operation UUID fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:09.743666 4231 status_update_manager_process.hpp:414] Creating operation status update stream fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9 checkpoint=true
I1001 17:19:09.743960 4231 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: a0cedba0-2047-4dc0-9cc5-4a75365d8803) for operation UUID fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:09.810468 4231 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: a0cedba0-2047-4dc0-9cc5-4a75365d8803) for operation UUID fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:09.811345 4214 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:42997/slave(1248)/api/v1/resource_provider
I1001 17:19:09.812383 4226 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1/resource_provider'
I1001 17:19:09.815798 4222 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I1001 17:19:09.817979 4219 http.cpp:1436] HTTP POST for /master/api/v1 from 172.17.0.2:45996
I1001 17:19:09.818257 4219 http.cpp:277] Processing call UNRESERVE_RESOURCES
I1001 17:19:09.819118 4219 master.cpp:3794] Authorizing principal 'test-principal' to perform action UNRESERVE_RESOURCES on object {"value":"test-principal","resource":{"provider_id":{"value":"cf88a5d7-0eee-4e5b-a00c-249b1fd5438d"},"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_veS9qF/2GB-d4391ddc-fb38-4008-84fd-9b88de3bec09","profile":"test"}}}}
I1001 17:19:09.820667 4221 sched.cpp:963] Rescinded offer c99d5606-f994-4763-9b89-727b120219a3-O5
I1001 17:19:09.820781 4221 sched.cpp:974] Scheduler::offerRescinded took 44778ns
I1001 17:19:09.821550 4220 hierarchical.cpp:1676] 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_veS9qF/2GB-d4391ddc-fb38-4008-84fd-9b88de3bec09,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_veS9qF/2GB-d4391ddc-fb38-4008-84fd-9b88de3bec09,test)]:2048, offered or allocated: {}) on agent c99d5606-f994-4763-9b89-727b120219a3-S0 from framework c99d5
606-f994-4763-9b89-727b120219a3-0000
I1001 17:19:09.821928 4216 master.cpp:11878] Removing offer c99d5606-f994-4763-9b89-727b120219a3-O5
I1001 17:19:09.824553 4220 hierarchical.cpp:1725] Framework c99d5606-f994-4763-9b89-727b120219a3-0000 filtered agent c99d5606-f994-4763-9b89-727b120219a3-S0 for 5secs
I1001 17:19:09.827997 4231 master.cpp:11743] Sending operation '' (uuid: f709c014-af42-4c6c-9d40-107bb22ed0b2) to agent c99d5606-f994-4763-9b89-727b120219a3-S0 at slave(1248)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:09.828792 4237 slave.cpp:4576] Ignoring new checkpointed resources and operations identical to the current version
I1001 17:19:09.832592 4227 provider.cpp:498] Received APPLY_OPERATION event
I1001 17:19:09.832656 4227 provider.cpp:1352] Received UNRESERVE operation '' (uuid: f709c014-af42-4c6c-9d40-107bb22ed0b2)
I1001 17:19:09.837518 4223 hierarchical.cpp:1953] Performed allocation for 1 agents in 2.229791ms
I1001 17:19:09.838523 4233 master.cpp:9579] Sending offers [ c99d5606-f994-4763-9b89-727b120219a3-O6 ] to framework c99d5606-f994-4763-9b89-727b120219a3-0000 (default) at scheduler-5b2ec02f-494d-4385-9fa4-12aca29ce565@172.17.0.2:42997
I1001 17:19:09.839507 4221 sched.cpp:937] Scheduler::resourceOffers took 120368ns
I1001 17:19:09.854053 4215 http.cpp:1436] HTTP POST for /slave(1248)/api/v1/resource_provider from 172.17.0.2:45986
I1001 17:19:09.855121 4226 slave.cpp:8733] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I1001 17:19:09.855356 4226 slave.cpp:9186] Updating the state of operation with no ID (uuid: fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I1001 17:19:09.855418 4226 slave.cpp:8940] Forwarding status update of operation with no ID (operation_uuid: fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9) for an operator API call
I1001 17:19:09.855785 4237 master.cpp:11395] Updating the state of operation '' (uuid: fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I1001 17:19:09.856607 4236 slave.cpp:4576] Ignoring new checkpointed resources and operations identical to the current version
I1001 17:19:09.961553 4221 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: a3c01d23-fdf5-49c2-80b8-2f7714495f29) for operation UUID f709c014-af42-4c6c-9d40-107bb22ed0b2 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:09.961616 4221 status_update_manager_process.hpp:414] Creating operation status update stream f709c014-af42-4c6c-9d40-107bb22ed0b2 checkpoint=true
I1001 17:19:09.961707 4227 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I1001 17:19:09.961894 4221 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: a3c01d23-fdf5-49c2-80b8-2f7714495f29) for operation UUID f709c014-af42-4c6c-9d40-107bb22ed0b2 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:10.028369 4221 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: a3c01d23-fdf5-49c2-80b8-2f7714495f29) for operation UUID f709c014-af42-4c6c-9d40-107bb22ed0b2 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:10.028707 4221 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: a0cedba0-2047-4dc0-9cc5-4a75365d8803) for stream fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9
I1001 17:19:10.028785 4221 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: a0cedba0-2047-4dc0-9cc5-4a75365d8803) for operation UUID fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:10.029153 4232 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:42997/slave(1248)/api/v1/resource_provider
I1001 17:19:10.030061 4220 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1/resource_provider'
I1001 17:19:10.073796 4228 http.cpp:1436] HTTP POST for /slave(1248)/api/v1/resource_provider from 172.17.0.2:45986
I1001 17:19:10.074757 4225 slave.cpp:8733] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: f709c014-af42-4c6c-9d40-107bb22ed0b2) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I1001 17:19:10.074937 4225 slave.cpp:9186] Updating the state of operation with no ID (uuid: f709c014-af42-4c6c-9d40-107bb22ed0b2) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I1001 17:19:10.074990 4225 slave.cpp:8940] Forwarding status update of operation with no ID (operation_uuid: f709c014-af42-4c6c-9d40-107bb22ed0b2) for an operator API call
I1001 17:19:10.075340 4222 master.cpp:11395] Updating the state of operation '' (uuid: f709c014-af42-4c6c-9d40-107bb22ed0b2) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I1001 17:19:10.075947 4218 slave.cpp:4576] Ignoring new checkpointed resources and operations identical to the current version
I1001 17:19:10.077751 4234 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I1001 17:19:10.095172 4221 status_update_manager_process.hpp:490] Cleaning up operation status update stream fbaad6da-bd2a-4e7b-b6fc-4fb87ec4f0b9
I1001 17:19:10.095415 4221 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: a3c01d23-fdf5-49c2-80b8-2f7714495f29) for stream f709c014-af42-4c6c-9d40-107bb22ed0b2
I1001 17:19:10.095485 4221 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: a3c01d23-fdf5-49c2-80b8-2f7714495f29) for operation UUID f709c014-af42-4c6c-9d40-107bb22ed0b2 on agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:10.179009 4221 status_update_manager_process.hpp:490] Cleaning up operation status update stream f709c014-af42-4c6c-9d40-107bb22ed0b2
I1001 17:19:10.254209 4217 master.cpp:1418] Framework c99d5606-f994-4763-9b89-727b120219a3-0000 (default) at scheduler-5b2ec02f-494d-4385-9fa4-12aca29ce565@172.17.0.2:42997 disconnected
I1001 17:19:10.254285 4217 master.cpp:3427] Deactivating framework c99d5606-f994-4763-9b89-727b120219a3-0000 (default) at scheduler-5b2ec02f-494d-4385-9fa4-12aca29ce565@172.17.0.2:42997
I1001 17:19:10.254670 4226 hierarchical.cpp:902] Deactivated framework c99d5606-f994-4763-9b89-727b120219a3-0000
I1001 17:19:10.255154 4229 slave.cpp:1002] Agent terminating
I1001 17:19:10.255389 4224 hierarchical.cpp:1676] 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_veS9qF/2GB-d4391ddc-fb38-4008-84fd-9b88de3bec09,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_veS9qF/2GB-d4391ddc-fb38-4008-84fd-9b88de3bec09,test)]:2048, offered or allocated: {}) on agent c99d5606-f994-4763-9b89-727b120219a3-S0 from framework c99d5606-f994-4763-9b89-727b120219a3-0000
I1001 17:19:10.255511 4217 master.cpp:11878] Removing offer c99d5606-f994-4763-9b89-727b120219a3-O6
I1001 17:19:10.255654 4217 master.cpp:3411] Disconnecting framework c99d5606-f994-4763-9b89-727b120219a3-0000 (default) at scheduler-5b2ec02f-494d-4385-9fa4-12aca29ce565@172.17.0.2:42997
I1001 17:19:10.255856 4217 master.cpp:1433] Giving framework c99d5606-f994-4763-9b89-727b120219a3-0000 (default) at scheduler-5b2ec02f-494d-4385-9fa4-12aca29ce565@172.17.0.2:42997 0ns to failover
I1001 17:19:10.256094 4229 manager.cpp:127] Terminating resource provider cf88a5d7-0eee-4e5b-a00c-249b1fd5438d
I1001 17:19:10.256625 4221 master.cpp:1303] Agent c99d5606-f994-4763-9b89-727b120219a3-S0 at slave(1248)@172.17.0.2:42997 (efbfcd8a60cb) disconnected
I1001 17:19:10.256680 4221 master.cpp:3462] Disconnecting agent c99d5606-f994-4763-9b89-727b120219a3-S0 at slave(1248)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:10.256790 4221 master.cpp:3481] Deactivating agent c99d5606-f994-4763-9b89-727b120219a3-S0 at slave(1248)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:10.257030 4221 master.cpp:9363] Framework failover timeout, removing framework c99d5606-f994-4763-9b89-727b120219a3-0000 (default) at scheduler-5b2ec02f-494d-4385-9fa4-12aca29ce565@172.17.0.2:42997
I1001 17:19:10.257062 4221 master.cpp:10374] Removing framework c99d5606-f994-4763-9b89-727b120219a3-0000 (default) at scheduler-5b2ec02f-494d-4385-9fa4-12aca29ce565@172.17.0.2:42997
E1001 17:19:10.257128 4236 http_connection.hpp:449] End-Of-File received
I1001 17:19:10.257665 4236 http_connection.hpp:217] Re-detecting endpoint
I1001 17:19:10.257731 4224 hierarchical.cpp:1256] Agent c99d5606-f994-4763-9b89-727b120219a3-S0 deactivated
I1001 17:19:10.257841 4224 hierarchical.cpp:1877] Allocation paused
I1001 17:19:10.258273 4236 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1001 17:19:10.258333 4236 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1001 17:19:10.258388 4227 provider.cpp:488] Disconnected from resource provider manager
I1001 17:19:10.258399 4236 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:42997/slave(1248)/api/v1/resource_provider
I1001 17:19:10.258397 4224 hierarchical.cpp:846] Removed framework c99d5606-f994-4763-9b89-727b120219a3-0000
I1001 17:19:10.258544 4224 hierarchical.cpp:1887] Allocation resumed
I1001 17:19:10.258595 4227 status_update_manager_process.hpp:379] Pausing operation status update manager
I1001 17:19:10.259891 4225 containerizer.cpp:2716] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I1001 17:19:10.259961 4225 containerizer.cpp:3414] 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.789917056secs
I1001 17:19:10.260459 4225 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:10.261353 4237 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:42997/slave(1248)/api/v1/resource_provider
I1001 17:19:10.261950 4218 provider.cpp:476] Connected to resource provider manager
I1001 17:19:10.262419 4222 hierarchical.cpp:1953] Performed allocation for 1 agents in 165723ns
I1001 17:19:10.262782 4230 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:42997/slave(1248)/api/v1/resource_provider
E1001 17:19:10.263352 4230 provider.cpp:722] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Cannot process 'SUBSCRIBE' call as the driver is in state SUBSCRIBING
I1001 17:19:10.263550 4238 process.cpp:2781] Returning '404 Not Found' for '/slave(1248)/api/v1/resource_provider'
E1001 17:19:10.264729 4236 provider.cpp:722] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I1001 17:19:10.313756 4214 hierarchical.cpp:1953] Performed allocation for 1 agents in 159067ns
I1001 17:19:10.364406 4226 containerizer.cpp:3252] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I1001 17:19:10.365623 4235 hierarchical.cpp:1953] Performed allocation for 1 agents in 179363ns
I1001 17:19:10.366628 4218 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
I1001 17:19:10.369890 4220 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'
I1001 17:19:10.370162 4228 service_manager.cpp:815] Disconnected from endpoint 'unix:///tmp/mesos-csi-L0U7Dm/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:10.370458 4237 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:10.373745 4238 process.cpp:2781] Returning '404 Not Found' for '/slave(1248)/api/v1'
I1001 17:19:10.387238 4213 master.cpp:1151] Master terminating
I1001 17:19:10.388075 4226 hierarchical.cpp:1232] Removed all filters for agent c99d5606-f994-4763-9b89-727b120219a3-S0
I1001 17:19:10.388105 4226 hierarchical.cpp:1108] Removed agent c99d5606-f994-4763-9b89-727b120219a3-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (2678 ms)
[ RUN ] CSIVersion/StorageLocalResourceProviderTest.Update/v0
I1001 17:19:10.406513 4213 cluster.cpp:195] Creating default 'local' authorizer
I1001 17:19:10.412331 4220 master.cpp:450] Master 3173386a-7ded-41e1-a50a-0d0ee721280a (efbfcd8a60cb) started on 172.17.0.2:42997
I1001 17:19:10.412361 4220 master.cpp:453] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --allocator_agent_recovery_factor="0.8" --allocator_recovery_timeout="10mins" --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/11Sjgk/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_allocatable_resources="cpus:0.01|mem:32" --offer_constraints_re2_max_mem="4KB" --offer_constraints_re2_max_program_size="100" --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.11.0/_inst/share/mesos/webui" --work_dir="/tmp/11Sjgk/master" --zk_session_timeout="10secs"
I1001 17:19:10.412787 4220 master.cpp:502] Master only allowing authenticated frameworks to register
I1001 17:19:10.412804 4220 master.cpp:508] Master only allowing authenticated agents to register
I1001 17:19:10.412815 4220 master.cpp:514] Master only allowing authenticated HTTP frameworks to register
I1001 17:19:10.412827 4220 credentials.hpp:37] Loading credentials for authentication from '/tmp/11Sjgk/credentials'
I1001 17:19:10.413111 4220 master.cpp:558] Using default 'crammd5' authenticator
I1001 17:19:10.413336 4220 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1001 17:19:10.413584 4220 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1001 17:19:10.413807 4220 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1001 17:19:10.413985 4220 master.cpp:639] Authorization enabled
I1001 17:19:10.414384 4234 whitelist_watcher.cpp:77] No whitelist given
I1001 17:19:10.414590 4219 hierarchical.cpp:656] Initialized hierarchical allocator process
I1001 17:19:10.417907 4214 master.cpp:2176] Elected as the leading master!
I1001 17:19:10.417946 4214 master.cpp:1672] Recovering from registrar
I1001 17:19:10.418205 4218 registrar.cpp:339] Recovering registrar
I1001 17:19:10.419304 4218 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I1001 17:19:10.419520 4218 registrar.cpp:487] Applied 1 operations in 82914ns; attempting to update the registry
I1001 17:19:10.420562 4218 registrar.cpp:544] Successfully updated the registry in 0ns
I1001 17:19:10.420801 4218 registrar.cpp:416] Successfully recovered registrar
I1001 17:19:10.421466 4223 master.cpp:1825] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I1001 17:19:10.421497 4221 hierarchical.cpp:695] Skipping recovery of hierarchical allocator: nothing to recover
W1001 17:19:10.428171 4213 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:42997
I1001 17:19:10.429078 4213 resolver.cpp:69] Creating default secret resolver
I1001 17:19:10.429953 4213 containerizer.cpp:320] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1001 17:19:10.430660 4213 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W1001 17:19:10.430691 4213 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1001 17:19:10.430712 4213 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1001 17:19:10.430748 4213 provisioner.cpp:294] Using default backend 'copy'
I1001 17:19:10.433830 4213 cluster.cpp:620] Creating default 'local' authorizer
I1001 17:19:10.436707 4222 slave.cpp:281] Mesos agent started on (1249)@172.17.0.2:42997
I1001 17:19:10.436736 4222 slave.cpp:282] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/11Sjgk/1DMu2f/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/11Sjgk/1DMu2f/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/11Sjgk/1DMu2f/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/11Sjgk/1DMu2f/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/11Sjgk/1DMu2f/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/11Sjgk/1DMu2f/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.11.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/11Sjgk/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_Mbc54L" --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_1ChG7h" --zk_session_timeout="10secs"
I1001 17:19:10.437250 4222 credentials.hpp:73] Loading credential for authentication from '/tmp/11Sjgk/1DMu2f/credential'
I1001 17:19:10.437410 4222 slave.cpp:314] Agent using credential for: test-principal
I1001 17:19:10.437441 4222 credentials.hpp:37] Loading credentials for authentication from '/tmp/11Sjgk/1DMu2f/http_credentials'
I1001 17:19:10.437635 4222 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1001 17:19:10.438009 4222 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I1001 17:19:10.439723 4220 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I1001 17:19:10.440075 4222 slave.cpp:629] 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"}]
I1001 17:19:10.440366 4222 slave.cpp:637] Agent attributes: [ ]
I1001 17:19:10.440383 4222 slave.cpp:646] Agent hostname: efbfcd8a60cb
I1001 17:19:10.440549 4214 status_update_manager_process.hpp:379] Pausing operation status update manager
I1001 17:19:10.440582 4232 task_status_update_manager.cpp:181] Pausing sending task status updates
I1001 17:19:10.442107 4231 hierarchical.cpp:1953] Performed allocation for 0 agents in 104730ns
I1001 17:19:10.442787 4217 state.cpp:68] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_1ChG7h/meta'
I1001 17:19:10.443112 4225 slave.cpp:7742] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_1ChG7h/meta', beginning agent recovery
I1001 17:19:10.443856 4228 task_status_update_manager.cpp:207] Recovering task status update manager
I1001 17:19:10.444658 4218 containerizer.cpp:830] Recovering Mesos containers
I1001 17:19:10.445237 4218 containerizer.cpp:1170] Recovering isolators
I1001 17:19:10.446651 4220 containerizer.cpp:1209] Recovering provisioner
I1001 17:19:10.447592 4231 provisioner.cpp:518] Provisioner recovery complete
I1001 17:19:10.448801 4228 composing.cpp:343] Finished recovering all containerizers
I1001 17:19:10.449229 4223 slave.cpp:8224] Recovering executors
I1001 17:19:10.449385 4223 slave.cpp:8377] Finished recovery
I1001 17:19:10.450484 4216 task_status_update_manager.cpp:181] Pausing sending task status updates
I1001 17:19:10.450491 4223 slave.cpp:1473] New master detected at master@172.17.0.2:42997
I1001 17:19:10.450531 4234 status_update_manager_process.hpp:379] Pausing operation status update manager
I1001 17:19:10.450670 4223 slave.cpp:1538] Detecting new master
I1001 17:19:10.452023 4227 slave.cpp:1565] Authenticating with master master@172.17.0.2:42997
I1001 17:19:10.452180 4227 slave.cpp:1574] Using default CRAM-MD5 authenticatee
I1001 17:19:10.452728 4237 authenticatee.cpp:121] Creating new client SASL connection
I1001 17:19:10.453289 4221 master.cpp:9770] Authenticating slave(1249)@172.17.0.2:42997
I1001 17:19:10.453497 4232 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2113)@172.17.0.2:42997
I1001 17:19:10.453930 4220 authenticator.cpp:98] Creating new server SASL connection
I1001 17:19:10.454284 4214 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1001 17:19:10.454334 4214 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1001 17:19:10.454510 4231 authenticator.cpp:204] Received SASL authentication start
I1001 17:19:10.454623 4231 authenticator.cpp:326] Authentication requires more steps
I1001 17:19:10.454838 4235 authenticatee.cpp:259] Received SASL authentication step
I1001 17:19:10.455054 4225 authenticator.cpp:232] Received SASL authentication step
I1001 17:19:10.455109 4225 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'efbfcd8a60cb' server FQDN: 'efbfcd8a60cb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1001 17:19:10.455135 4225 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1001 17:19:10.455209 4225 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1001 17:19:10.455257 4225 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'efbfcd8a60cb' server FQDN: 'efbfcd8a60cb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1001 17:19:10.455281 4225 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1001 17:19:10.455296 4225 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1001 17:19:10.455329 4225 authenticator.cpp:318] Authentication success
I1001 17:19:10.455523 4230 authenticatee.cpp:299] Authentication success
I1001 17:19:10.455641 4222 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2113)@172.17.0.2:42997
I1001 17:19:10.455651 4215 master.cpp:9802] Successfully authenticated principal 'test-principal' at slave(1249)@172.17.0.2:42997
I1001 17:19:10.456148 4217 slave.cpp:1665] Successfully authenticated with master master@172.17.0.2:42997
I1001 17:19:10.456902 4217 slave.cpp:2131] Will retry registration in 4.673295ms if necessary
I1001 17:19:10.457224 4224 master.cpp:6263] Received register agent message from slave(1249)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:10.457981 4224 master.cpp:3794] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I1001 17:19:10.458856 4234 master.cpp:6330] Authorized registration of agent at slave(1249)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:10.459040 4234 master.cpp:6442] Registering agent at slave(1249)@172.17.0.2:42997 (efbfcd8a60cb) with id 3173386a-7ded-41e1-a50a-0d0ee721280a-S0
I1001 17:19:10.460435 4223 registrar.cpp:487] Applied 1 operations in 536963ns; attempting to update the registry
I1001 17:19:10.461408 4237 registrar.cpp:544] Successfully updated the registry in 866048ns
I1001 17:19:10.461720 4226 master.cpp:6490] Admitted agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 at slave(1249)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:10.462900 4226 master.cpp:6535] Registered agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 at slave(1249)@172.17.0.2:42997 (efbfcd8a60cb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1001 17:19:10.463100 4220 slave.cpp:2131] Will retry registration in 39.828599ms if necessary
I1001 17:19:10.463176 4231 hierarchical.cpp:1059] Added agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 (efbfcd8a60cb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I1001 17:19:10.463366 4235 master.cpp:6263] Received register agent message from slave(1249)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:10.463502 4220 slave.cpp:1698] Registered with master master@172.17.0.2:42997; given agent ID 3173386a-7ded-41e1-a50a-0d0ee721280a-S0
I1001 17:19:10.463654 4231 hierarchical.cpp:1953] Performed allocation for 1 agents in 186480ns
I1001 17:19:10.463737 4233 task_status_update_manager.cpp:188] Resuming sending task status updates
I1001 17:19:10.463923 4235 master.cpp:3794] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I1001 17:19:10.464087 4220 slave.cpp:1733] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_1ChG7h/meta/slaves/3173386a-7ded-41e1-a50a-0d0ee721280a-S0/slave.info'
I1001 17:19:10.464383 4215 status_update_manager_process.hpp:385] Resuming operation status update manager
I1001 17:19:10.464769 4222 master.cpp:6330] Authorized registration of agent at slave(1249)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:10.464898 4222 master.cpp:6421] Agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 at slave(1249)@172.17.0.2:42997 (efbfcd8a60cb) already registered, resending acknowledgement
I1001 17:19:10.465754 4220 slave.cpp:1793] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"PhFbNt1tRHale5sVsUn2Ow=="},"slave_id":{"value":"3173386a-7ded-41e1-a50a-0d0ee721280a-S0"},"update_oversubscribed_resources":false}
W1001 17:19:10.466061 4220 slave.cpp:1775] Already registered with master master@172.17.0.2:42997
I1001 17:19:10.466285 4220 slave.cpp:1793] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"PhFbNt1tRHale5sVsUn2Ow=="},"slave_id":{"value":"3173386a-7ded-41e1-a50a-0d0ee721280a-S0"},"update_oversubscribed_resources":false}
I1001 17:19:10.467072 4223 master.cpp:7678] Ignoring update on agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 at slave(1249)@172.17.0.2:42997 (efbfcd8a60cb) as it reports no changes
I1001 17:19:10.467942 4223 master.cpp:7678] Ignoring update on agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 at slave(1249)@172.17.0.2:42997 (efbfcd8a60cb) as it reports no changes
I1001 17:19:10.473111 4236 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1'
I1001 17:19:10.474917 4222 http.cpp:1436] HTTP POST for /slave(1249)/api/v1 from 172.17.0.2:46004
I1001 17:19:10.475679 4222 http.cpp:2828] Processing GET_CONTAINERS call
I1001 17:19:10.484592 4233 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:10.488384 4236 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1'
I1001 17:19:10.490056 4222 http.cpp:1436] HTTP POST for /slave(1249)/api/v1 from 172.17.0.2:46006
I1001 17:19:10.491214 4222 http.cpp:3289] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:10.492789 4234 http.cpp:3399] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_1ChG7h/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:10.493952 4221 hierarchical.cpp:1953] Performed allocation for 1 agents in 211781ns
I1001 17:19:10.494060 4227 containerizer.cpp:1405] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:10.495059 4227 containerizer.cpp:3414] 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 432896ns
I1001 17:19:10.496387 4227 containerizer.cpp:1584] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_Mbc54L/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I1001 17:19:10.496475 4227 containerizer.cpp:3414] 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 1.420032ms
I1001 17:19:10.501518 4225 containerizer.cpp:2110] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/tmp/SRC/build/mesos-1.11.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_IShiaO","--available_capacity=0B","--volumes=","--forward=unix:///tmp/11Sjgk/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.11.0/_build/sub/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_1ChG7h/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-EwjRhc/endpoint.sock"},{"name":"MESOS_AGENT_ID","type":"VALUE","value":"3173386a-7ded-41e1-a50a-0d0ee721280a-S0"}]},"task_environment":{},"working
_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_1ChG7h/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="111" --pipe_write="112" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_Mbc54L/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I1001 17:19:10.517823 4225 launcher.cpp:145] Forked child with pid '18642' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:10.519498 4225 containerizer.cpp:3414] 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 23.021056ms
I1001 17:19:10.521721 4222 containerizer.cpp:3414] 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 2.078976ms
I1001 17:19:10.522173 4220 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_1ChG7h/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:10.523485 4234 containerizer.cpp:3414] 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.789952ms
I1001 17:19:10.528296 4218 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'
I1001 17:19:10.528556 4226 service_manager.cpp:795] Connecting to endpoint 'unix:///tmp/mesos-csi-EwjRhc/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:10.545657 4235 hierarchical.cpp:1953] Performed allocation for 1 agents in 221375ns
I1001 17:19:10.597503 4216 hierarchical.cpp:1953] Performed allocation for 1 agents in 200503ns
I1001 17:19:10.649274 4223 hierarchical.cpp:1953] Performed allocation for 1 agents in 196891ns
I1001 17:19:10.700327 4215 hierarchical.cpp:1953] Performed allocation for 1 agents in 273867ns
I1001 17:19:10.751519 4224 hierarchical.cpp:1953] Performed allocation for 1 agents in 166837ns
I1001 17:19:10.803416 4221 hierarchical.cpp:1953] Performed allocation for 1 agents in 237245ns
I1001 17:19:10.855263 4237 hierarchical.cpp:1953] Performed allocation for 1 agents in 178467ns
I1001 17:19:10.906316 4235 hierarchical.cpp:1953] Performed allocation for 1 agents in 130685ns
I1001 17:19:10.957548 4216 hierarchical.cpp:1953] Performed allocation for 1 agents in 185588ns
I1001 17:19:10.966972 4222 service_manager.cpp:622] Probing endpoint 'unix:///tmp/mesos-csi-EwjRhc/endpoint.sock' with CSI v1
I1001 17:19:10.970357 4234 service_manager.cpp:609] Probing endpoint 'unix:///tmp/mesos-csi-EwjRhc/endpoint.sock' with CSI v0
I1001 17:19:10.971948 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Identity/Probe call
I1001 17:19:10.975363 4237 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:10.979686 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Identity/GetPluginCapabilities call
I1001 17:19:10.980703 4217 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1'
I1001 17:19:10.982594 4222 http.cpp:1436] HTTP POST for /slave(1249)/api/v1 from 172.17.0.2:46008
I1001 17:19:10.983479 4222 http.cpp:3513] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:10.985038 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Identity/GetPluginInfo call
I1001 17:19:10.985544 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Identity/GetPluginInfo call
I1001 17:19:10.987717 4226 v0_volume_manager.cpp:656] NODE_SERVICE loaded: {}
I1001 17:19:10.988569 4226 v0_volume_manager.cpp:656] CONTROLLER_SERVICE loaded: {}
I1001 17:19:10.991606 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Controller/ControllerGetCapabilities call
I1001 17:19:10.996887 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Node/NodeGetCapabilities call
I1001 17:19:11.002195 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Node/NodeGetId call
I1001 17:19:11.005825 4231 provider.cpp:677] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I1001 17:19:11.006086 4214 status_update_manager_process.hpp:379] Pausing operation status update manager
I1001 17:19:11.006698 4218 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:42997/slave(1249)/api/v1/resource_provider
I1001 17:19:11.009332 4226 hierarchical.cpp:1953] Performed allocation for 1 agents in 254277ns
I1001 17:19:11.011320 4230 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:42997/slave(1249)/api/v1/resource_provider
I1001 17:19:11.012313 4220 provider.cpp:476] Connected to resource provider manager
I1001 17:19:11.013401 4219 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:42997/slave(1249)/api/v1/resource_provider
I1001 17:19:11.015098 4232 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider'
I1001 17:19:11.017817 4231 http.cpp:1436] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.2:46012
I1001 17:19:11.019032 4233 manager.cpp:779] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.11.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_IShiaO","--available_capacity=0B","--volumes=","--forward=unix:///tmp/11Sjgk/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.11.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"}
I1001 17:19:11.050822 4230 slave.cpp:8733] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"4f1a79fc-562d-475a-a69c-5462a501a1f1"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.11.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_IShiaO","--available_capacity=0B","--volumes=","--forward=unix:///tmp/11Sjgk/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.11.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"}'
I1001 17:19:11.053305 4232 provider.cpp:498] Received SUBSCRIBED event
I1001 17:19:11.053388 4232 provider.cpp:1310] Subscribed with ID 4f1a79fc-562d-475a-a69c-5462a501a1f1
I1001 17:19:11.054596 4214 status_update_manager_process.hpp:314] Recovering operation status update manager
I1001 17:19:11.061415 4233 hierarchical.cpp:1953] Performed allocation for 1 agents in 229427ns
I1001 17:19:11.108637 4237 provider.cpp:791] Reconciling storage pools and volumes
I1001 17:19:11.111788 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Controller/ListVolumes call
I1001 17:19:11.112741 4235 hierarchical.cpp:1953] Performed allocation for 1 agents in 176850ns
I1001 17:19:11.115881 4223 provider.cpp:2218] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0
I1001 17:19:11.116369 4232 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.2:42997/slave(1249)/api/v1/resource_provider
I1001 17:19:11.116447 4223 provider.cpp:749] Resource provider 4f1a79fc-562d-475a-a69c-5462a501a1f1 is in READY state
I1001 17:19:11.116544 4214 status_update_manager_process.hpp:385] Resuming operation status update manager
I1001 17:19:11.117591 4218 provider.cpp:1236] Updating profiles { test } for resource provider 4f1a79fc-562d-475a-a69c-5462a501a1f1
I1001 17:19:11.117669 4226 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider'
I1001 17:19:11.119367 4225 provider.cpp:791] Reconciling storage pools and volumes
I1001 17:19:11.120059 4227 http.cpp:1436] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.2:46010
I1001 17:19:11.121050 4231 manager.cpp:1011] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 4f1a79fc-562d-475a-a69c-5462a501a1f1
I1001 17:19:11.121448 4228 slave.cpp:8733] Handling resource provider message 'UPDATE_STATE: 4f1a79fc-562d-475a-a69c-5462a501a1f1 {}'
I1001 17:19:11.121624 4228 slave.cpp:8853] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1001 17:19:11.122714 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Controller/ListVolumes call
I1001 17:19:11.124191 4217 hierarchical.cpp:1210] Grew agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 by {} (total), { } (used)
I1001 17:19:11.124387 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Controller/GetCapacity call
I1001 17:19:11.124809 4217 hierarchical.cpp:1167] Agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 (efbfcd8a60cb) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1001 17:19:11.131963 4236 hierarchical.cpp:1953] Performed allocation for 1 agents in 189792ns
I1001 17:19:11.132537 4237 provider.cpp:791] Reconciling storage pools and volumes
I1001 17:19:11.135807 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Controller/ListVolumes call
I1001 17:19:11.136442 18646 test_csi_plugin.cpp:1968] Forwarding /csi.v0.Controller/GetCapacity call
I1001 17:19:11.147557 4213 slave.cpp:1002] Agent terminating
I1001 17:19:11.148813 4213 manager.cpp:127] Terminating resource provider 4f1a79fc-562d-475a-a69c-5462a501a1f1
I1001 17:19:11.149482 4215 master.cpp:1303] Agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 at slave(1249)@172.17.0.2:42997 (efbfcd8a60cb) disconnected
I1001 17:19:11.149538 4215 master.cpp:3462] Disconnecting agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 at slave(1249)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:11.149674 4215 master.cpp:3481] Deactivating agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 at slave(1249)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:11.149873 4218 hierarchical.cpp:1256] Agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0 deactivated
E1001 17:19:11.150192 4228 http_connection.hpp:449] End-Of-File received
I1001 17:19:11.150864 4228 http_connection.hpp:217] Re-detecting endpoint
I1001 17:19:11.151546 4228 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1001 17:19:11.151666 4233 provider.cpp:488] Disconnected from resource provider manager
I1001 17:19:11.151707 4228 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1001 17:19:11.151847 4229 status_update_manager_process.hpp:379] Pausing operation status update manager
I1001 17:19:11.151896 4228 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:42997/slave(1249)/api/v1/resource_provider
I1001 17:19:11.154048 4225 containerizer.cpp:2716] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I1001 17:19:11.154135 4225 containerizer.cpp:3414] 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.630772992secs
I1001 17:19:11.154832 4225 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:11.156241 4221 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:42997/slave(1249)/api/v1/resource_provider
I1001 17:19:11.157166 4216 provider.cpp:476] Connected to resource provider manager
I1001 17:19:11.158063 4230 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:42997/slave(1249)/api/v1/resource_provider
I1001 17:19:11.159440 4238 process.cpp:2781] Returning '404 Not Found' for '/slave(1249)/api/v1/resource_provider'
E1001 17:19:11.161295 4237 provider.cpp:722] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I1001 17:19:11.178243 4228 hierarchical.cpp:1953] Performed allocation for 1 agents in 144066ns
I1001 17:19:11.227948 4218 containerizer.cpp:3252] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I1001 17:19:11.230238 4214 hierarchical.cpp:1953] Performed allocation for 1 agents in 141996ns
I1001 17:19:11.230986 4224 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
I1001 17:19:11.234987 4223 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'
I1001 17:19:11.235340 4232 service_manager.cpp:815] Disconnected from endpoint 'unix:///tmp/mesos-csi-EwjRhc/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:11.235687 4234 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:11.239568 4238 process.cpp:2781] Returning '404 Not Found' for '/slave(1249)/api/v1'
I1001 17:19:11.255486 4213 master.cpp:1151] Master terminating
I1001 17:19:11.255854 4231 hierarchical.cpp:1232] Removed all filters for agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0
I1001 17:19:11.255885 4231 hierarchical.cpp:1108] Removed agent 3173386a-7ded-41e1-a50a-0d0ee721280a-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v0 (866 ms)
[ RUN ] CSIVersion/StorageLocalResourceProviderTest.Update/v1
I1001 17:19:11.276149 4213 cluster.cpp:195] Creating default 'local' authorizer
I1001 17:19:11.281714 4214 master.cpp:450] Master b5789b9f-38e4-49ac-aad6-6b7161584002 (efbfcd8a60cb) started on 172.17.0.2:42997
I1001 17:19:11.281746 4214 master.cpp:453] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --allocator_agent_recovery_factor="0.8" --allocator_recovery_timeout="10mins" --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/to9c79/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_allocatable_resources="cpus:0.01|mem:32" --offer_constraints_re2_max_mem="4KB" --offer_constraints_re2_max_program_size="100" --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.11.0/_inst/share/mesos/webui" --work_dir="/tmp/to9c79/master" --zk_session_timeout="10secs"
I1001 17:19:11.282270 4214 master.cpp:502] Master only allowing authenticated frameworks to register
I1001 17:19:11.282289 4214 master.cpp:508] Master only allowing authenticated agents to register
I1001 17:19:11.282300 4214 master.cpp:514] Master only allowing authenticated HTTP frameworks to register
I1001 17:19:11.282317 4214 credentials.hpp:37] Loading credentials for authentication from '/tmp/to9c79/credentials'
I1001 17:19:11.282641 4214 master.cpp:558] Using default 'crammd5' authenticator
I1001 17:19:11.282905 4214 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1001 17:19:11.283191 4214 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1001 17:19:11.283401 4214 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1001 17:19:11.283598 4214 master.cpp:639] Authorization enabled
I1001 17:19:11.284082 4224 whitelist_watcher.cpp:77] No whitelist given
I1001 17:19:11.284154 4222 hierarchical.cpp:656] Initialized hierarchical allocator process
I1001 17:19:11.288332 4228 master.cpp:2176] Elected as the leading master!
I1001 17:19:11.288373 4228 master.cpp:1672] Recovering from registrar
I1001 17:19:11.288612 4234 registrar.cpp:339] Recovering registrar
I1001 17:19:11.289510 4234 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I1001 17:19:11.289669 4234 registrar.cpp:487] Applied 1 operations in 50686ns; attempting to update the registry
I1001 17:19:11.290442 4234 registrar.cpp:544] Successfully updated the registry in 0ns
I1001 17:19:11.290596 4234 registrar.cpp:416] Successfully recovered registrar
I1001 17:19:11.291116 4217 master.cpp:1825] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I1001 17:19:11.291141 4233 hierarchical.cpp:695] Skipping recovery of hierarchical allocator: nothing to recover
W1001 17:19:11.298005 4213 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:42997
I1001 17:19:11.298746 4213 resolver.cpp:69] Creating default secret resolver
I1001 17:19:11.299615 4213 containerizer.cpp:320] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1001 17:19:11.300329 4213 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W1001 17:19:11.300364 4213 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1001 17:19:11.300382 4213 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1001 17:19:11.300420 4213 provisioner.cpp:294] Using default backend 'copy'
I1001 17:19:11.303508 4213 cluster.cpp:620] Creating default 'local' authorizer
I1001 17:19:11.306342 4220 slave.cpp:281] Mesos agent started on (1250)@172.17.0.2:42997
I1001 17:19:11.306375 4220 slave.cpp:282] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/to9c79/08PqQd/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/to9c79/08PqQd/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/to9c79/08PqQd/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/to9c79/08PqQd/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/to9c79/08PqQd/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/to9c79/08PqQd/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.11.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/to9c79/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_ZFOITH" --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_iVt1Wb" --zk_session_timeout="10secs"
I1001 17:19:11.306890 4220 credentials.hpp:73] Loading credential for authentication from '/tmp/to9c79/08PqQd/credential'
I1001 17:19:11.307055 4220 slave.cpp:314] Agent using credential for: test-principal
I1001 17:19:11.307083 4220 credentials.hpp:37] Loading credentials for authentication from '/tmp/to9c79/08PqQd/http_credentials'
I1001 17:19:11.307281 4220 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1001 17:19:11.307668 4220 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I1001 17:19:11.309489 4232 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I1001 17:19:11.309703 4228 hierarchical.cpp:1953] Performed allocation for 0 agents in 91232ns
I1001 17:19:11.309502 4220 slave.cpp:629] 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"}]
I1001 17:19:11.309759 4220 slave.cpp:637] Agent attributes: [ ]
I1001 17:19:11.309782 4220 slave.cpp:646] Agent hostname: efbfcd8a60cb
I1001 17:19:11.309971 4215 status_update_manager_process.hpp:379] Pausing operation status update manager
I1001 17:19:11.309994 4221 task_status_update_manager.cpp:181] Pausing sending task status updates
I1001 17:19:11.312342 4225 state.cpp:68] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_iVt1Wb/meta'
I1001 17:19:11.312745 4235 slave.cpp:7742] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_iVt1Wb/meta', beginning agent recovery
I1001 17:19:11.313486 4230 task_status_update_manager.cpp:207] Recovering task status update manager
I1001 17:19:11.314329 4233 containerizer.cpp:830] Recovering Mesos containers
I1001 17:19:11.314826 4233 containerizer.cpp:1170] Recovering isolators
I1001 17:19:11.315860 4215 containerizer.cpp:1209] Recovering provisioner
I1001 17:19:11.316804 4236 provisioner.cpp:518] Provisioner recovery complete
I1001 17:19:11.317857 4225 composing.cpp:343] Finished recovering all containerizers
I1001 17:19:11.318217 4216 slave.cpp:8224] Recovering executors
I1001 17:19:11.318349 4216 slave.cpp:8377] Finished recovery
I1001 17:19:11.319515 4222 slave.cpp:1473] New master detected at master@172.17.0.2:42997
I1001 17:19:11.319551 4214 status_update_manager_process.hpp:379] Pausing operation status update manager
I1001 17:19:11.319588 4227 task_status_update_manager.cpp:181] Pausing sending task status updates
I1001 17:19:11.319710 4222 slave.cpp:1538] Detecting new master
I1001 17:19:11.329403 4217 slave.cpp:1565] Authenticating with master master@172.17.0.2:42997
I1001 17:19:11.329561 4217 slave.cpp:1574] Using default CRAM-MD5 authenticatee
I1001 17:19:11.330062 4221 authenticatee.cpp:121] Creating new client SASL connection
I1001 17:19:11.330471 4228 master.cpp:9770] Authenticating slave(1250)@172.17.0.2:42997
I1001 17:19:11.330670 4232 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2114)@172.17.0.2:42997
I1001 17:19:11.331080 4223 authenticator.cpp:98] Creating new server SASL connection
I1001 17:19:11.331416 4236 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1001 17:19:11.331468 4236 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1001 17:19:11.331660 4220 authenticator.cpp:204] Received SASL authentication start
I1001 17:19:11.331773 4220 authenticator.cpp:326] Authentication requires more steps
I1001 17:19:11.331933 4220 authenticatee.cpp:259] Received SASL authentication step
I1001 17:19:11.332149 4235 authenticator.cpp:232] Received SASL authentication step
I1001 17:19:11.332240 4235 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'efbfcd8a60cb' server FQDN: 'efbfcd8a60cb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1001 17:19:11.332276 4235 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1001 17:19:11.332346 4235 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1001 17:19:11.332384 4235 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'efbfcd8a60cb' server FQDN: 'efbfcd8a60cb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1001 17:19:11.332402 4235 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1001 17:19:11.332417 4235 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1001 17:19:11.332442 4235 authenticator.cpp:318] Authentication success
I1001 17:19:11.332602 4229 authenticatee.cpp:299] Authentication success
I1001 17:19:11.332758 4218 master.cpp:9802] Successfully authenticated principal 'test-principal' at slave(1250)@172.17.0.2:42997
I1001 17:19:11.332793 4230 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2114)@172.17.0.2:42997
I1001 17:19:11.333144 4225 slave.cpp:1665] Successfully authenticated with master master@172.17.0.2:42997
I1001 17:19:11.333755 4225 slave.cpp:2131] Will retry registration in 12.355879ms if necessary
I1001 17:19:11.334017 4237 master.cpp:6263] Received register agent message from slave(1250)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:11.334614 4237 master.cpp:3794] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I1001 17:19:11.335631 4222 master.cpp:6330] Authorized registration of agent at slave(1250)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:11.335777 4222 master.cpp:6442] Registering agent at slave(1250)@172.17.0.2:42997 (efbfcd8a60cb) with id b5789b9f-38e4-49ac-aad6-6b7161584002-S0
I1001 17:19:11.336844 4215 registrar.cpp:487] Applied 1 operations in 383525ns; attempting to update the registry
I1001 17:19:11.337782 4215 registrar.cpp:544] Successfully updated the registry in 839168ns
I1001 17:19:11.338040 4223 master.cpp:6490] Admitted agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0 at slave(1250)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:11.339159 4223 master.cpp:6535] Registered agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0 at slave(1250)@172.17.0.2:42997 (efbfcd8a60cb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1001 17:19:11.339305 4231 slave.cpp:1698] Registered with master master@172.17.0.2:42997; given agent ID b5789b9f-38e4-49ac-aad6-6b7161584002-S0
I1001 17:19:11.339396 4220 hierarchical.cpp:1059] Added agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0 (efbfcd8a60cb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I1001 17:19:11.339480 4218 task_status_update_manager.cpp:188] Resuming sending task status updates
I1001 17:19:11.339813 4220 hierarchical.cpp:1953] Performed allocation for 1 agents in 165642ns
I1001 17:19:11.339913 4231 slave.cpp:1733] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_iVt1Wb/meta/slaves/b5789b9f-38e4-49ac-aad6-6b7161584002-S0/slave.info'
I1001 17:19:11.339983 4220 status_update_manager_process.hpp:385] Resuming operation status update manager
I1001 17:19:11.341607 4231 slave.cpp:1793] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"c1y5zfMeRUCw6smVkTqk6w=="},"slave_id":{"value":"b5789b9f-38e4-49ac-aad6-6b7161584002-S0"},"update_oversubscribed_resources":false}
I1001 17:19:11.342420 4214 master.cpp:7678] Ignoring update on agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0 at slave(1250)@172.17.0.2:42997 (efbfcd8a60cb) as it reports no changes
I1001 17:19:11.348166 4215 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1'
I1001 17:19:11.350170 4219 http.cpp:1436] HTTP POST for /slave(1250)/api/v1 from 172.17.0.2:46020
I1001 17:19:11.350873 4219 http.cpp:2828] Processing GET_CONTAINERS call
I1001 17:19:11.359721 4228 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:11.360764 4235 hierarchical.cpp:1953] Performed allocation for 1 agents in 181091ns
I1001 17:19:11.363445 4218 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1'
I1001 17:19:11.365026 4226 http.cpp:1436] HTTP POST for /slave(1250)/api/v1 from 172.17.0.2:46022
I1001 17:19:11.366370 4226 http.cpp:3289] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:11.368063 4226 http.cpp:3399] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_iVt1Wb/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:11.369275 4214 containerizer.cpp:1405] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:11.370266 4214 containerizer.cpp:3414] 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 414720ns
I1001 17:19:11.371544 4214 containerizer.cpp:1584] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_ZFOITH/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I1001 17:19:11.371630 4214 containerizer.cpp:3414] 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 1.368064ms
I1001 17:19:11.376483 4236 containerizer.cpp:2110] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/tmp/SRC/build/mesos-1.11.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_jB4k0F","--available_capacity=0B","--volumes=","--forward=unix:///tmp/to9c79/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.11.0/_build/sub/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_iVt1Wb/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-AV8i5h/endpoint.sock"},{"name":"MESOS_AGENT_ID","type":"VALUE","value":"b5789b9f-38e4-49ac-aad6-6b7161584002-S0"}]},"task_environment":{},"working
_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_iVt1Wb/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="111" --pipe_write="112" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_ZFOITH/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I1001 17:19:11.392099 4236 launcher.cpp:145] Forked child with pid '18656' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:11.393088 4236 containerizer.cpp:3414] 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 21.459968ms
I1001 17:19:11.394685 4236 containerizer.cpp:3414] 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.594112ms
I1001 17:19:11.395074 4230 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_iVt1Wb/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:11.396697 4231 containerizer.cpp:3414] 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.935872ms
I1001 17:19:11.400876 4221 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'
I1001 17:19:11.401428 4227 service_manager.cpp:795] Connecting to endpoint 'unix:///tmp/mesos-csi-AV8i5h/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:11.412699 4235 hierarchical.cpp:1953] Performed allocation for 1 agents in 210595ns
I1001 17:19:11.463970 4220 hierarchical.cpp:1953] Performed allocation for 1 agents in 218249ns
I1001 17:19:11.515249 4231 hierarchical.cpp:1953] Performed allocation for 1 agents in 205246ns
I1001 17:19:11.566534 4232 hierarchical.cpp:1953] Performed allocation for 1 agents in 229381ns
I1001 17:19:11.618158 4229 hierarchical.cpp:1953] Performed allocation for 1 agents in 255880ns
I1001 17:19:11.669937 4225 hierarchical.cpp:1953] Performed allocation for 1 agents in 272317ns
I1001 17:19:11.721190 4233 hierarchical.cpp:1953] Performed allocation for 1 agents in 145887ns
I1001 17:19:11.772608 4228 hierarchical.cpp:1953] Performed allocation for 1 agents in 178640ns
I1001 17:19:11.824368 4220 hierarchical.cpp:1953] Performed allocation for 1 agents in 212765ns
I1001 17:19:11.839361 4230 service_manager.cpp:622] Probing endpoint 'unix:///tmp/mesos-csi-AV8i5h/endpoint.sock' with CSI v1
I1001 17:19:11.841899 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Identity/Probe call
I1001 17:19:11.845671 4237 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:11.849046 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Identity/GetPluginCapabilities call
I1001 17:19:11.850222 4232 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1'
I1001 17:19:11.851696 4220 http.cpp:1436] HTTP POST for /slave(1250)/api/v1 from 172.17.0.2:46024
I1001 17:19:11.852355 4220 http.cpp:3513] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:11.855733 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Identity/GetPluginInfo call
I1001 17:19:11.856390 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Identity/GetPluginInfo call
I1001 17:19:11.859017 4221 v1_volume_manager.cpp:677] NODE_SERVICE loaded: {}
I1001 17:19:11.859836 4221 v1_volume_manager.cpp:677] CONTROLLER_SERVICE loaded: {}
I1001 17:19:11.862745 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Controller/ControllerGetCapabilities call
I1001 17:19:11.868016 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Node/NodeGetCapabilities call
I1001 17:19:11.872831 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Node/NodeGetInfo call
I1001 17:19:11.875708 4234 hierarchical.cpp:1953] Performed allocation for 1 agents in 248405ns
I1001 17:19:11.876471 4234 provider.cpp:677] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I1001 17:19:11.876621 4214 status_update_manager_process.hpp:379] Pausing operation status update manager
I1001 17:19:11.877310 4217 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:42997/slave(1250)/api/v1/resource_provider
I1001 17:19:11.882166 4218 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:42997/slave(1250)/api/v1/resource_provider
I1001 17:19:11.883154 4226 provider.cpp:476] Connected to resource provider manager
I1001 17:19:11.884305 4220 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:42997/slave(1250)/api/v1/resource_provider
I1001 17:19:11.885977 4230 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1/resource_provider'
I1001 17:19:11.888504 4233 http.cpp:1436] HTTP POST for /slave(1250)/api/v1/resource_provider from 172.17.0.2:46028
I1001 17:19:11.889654 4234 manager.cpp:779] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.11.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_jB4k0F","--available_capacity=0B","--volumes=","--forward=unix:///tmp/to9c79/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.11.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"}
I1001 17:19:11.927000 4228 hierarchical.cpp:1953] Performed allocation for 1 agents in 213479ns
I1001 17:19:11.937189 4219 slave.cpp:8733] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"9709d34b-a216-480d-bf3b-4a8913ca5327"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.11.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_jB4k0F","--available_capacity=0B","--volumes=","--forward=unix:///tmp/to9c79/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.11.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"}'
I1001 17:19:11.939471 4223 provider.cpp:498] Received SUBSCRIBED event
I1001 17:19:11.939543 4223 provider.cpp:1310] Subscribed with ID 9709d34b-a216-480d-bf3b-4a8913ca5327
I1001 17:19:11.940706 4233 status_update_manager_process.hpp:314] Recovering operation status update manager
I1001 17:19:11.978782 4221 hierarchical.cpp:1953] Performed allocation for 1 agents in 568900ns
I1001 17:19:11.994796 4234 provider.cpp:791] Reconciling storage pools and volumes
I1001 17:19:11.998208 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Controller/ListVolumes call
I1001 17:19:12.002156 4237 provider.cpp:2218] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0
I1001 17:19:12.002578 4231 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.2:42997/slave(1250)/api/v1/resource_provider
I1001 17:19:12.002663 4237 provider.cpp:749] Resource provider 9709d34b-a216-480d-bf3b-4a8913ca5327 is in READY state
I1001 17:19:12.002810 4214 status_update_manager_process.hpp:385] Resuming operation status update manager
I1001 17:19:12.003793 4221 provider.cpp:1236] Updating profiles { test } for resource provider 9709d34b-a216-480d-bf3b-4a8913ca5327
I1001 17:19:12.004401 4232 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1/resource_provider'
I1001 17:19:12.005580 4228 provider.cpp:791] Reconciling storage pools and volumes
I1001 17:19:12.006861 4230 http.cpp:1436] HTTP POST for /slave(1250)/api/v1/resource_provider from 172.17.0.2:46026
I1001 17:19:12.007606 4230 manager.cpp:1011] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 9709d34b-a216-480d-bf3b-4a8913ca5327
I1001 17:19:12.007951 4216 slave.cpp:8733] Handling resource provider message 'UPDATE_STATE: 9709d34b-a216-480d-bf3b-4a8913ca5327 {}'
I1001 17:19:12.008124 4216 slave.cpp:8853] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1001 17:19:12.008543 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Controller/ListVolumes call
I1001 17:19:12.009418 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Controller/GetCapacity call
I1001 17:19:12.011031 4226 hierarchical.cpp:1210] Grew agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0 by {} (total), { } (used)
I1001 17:19:12.011795 4226 hierarchical.cpp:1167] Agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0 (efbfcd8a60cb) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1001 17:19:12.018013 4234 hierarchical.cpp:1953] Performed allocation for 1 agents in 192132ns
I1001 17:19:12.018146 4223 provider.cpp:791] Reconciling storage pools and volumes
I1001 17:19:12.020658 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Controller/ListVolumes call
I1001 17:19:12.021211 18660 test_csi_plugin.cpp:1968] Forwarding /csi.v1.Controller/GetCapacity call
I1001 17:19:12.032435 4213 slave.cpp:1002] Agent terminating
I1001 17:19:12.033571 4213 manager.cpp:127] Terminating resource provider 9709d34b-a216-480d-bf3b-4a8913ca5327
I1001 17:19:12.034178 4214 master.cpp:1303] Agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0 at slave(1250)@172.17.0.2:42997 (efbfcd8a60cb) disconnected
I1001 17:19:12.034231 4214 master.cpp:3462] Disconnecting agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0 at slave(1250)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:12.034339 4214 master.cpp:3481] Deactivating agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0 at slave(1250)@172.17.0.2:42997 (efbfcd8a60cb)
I1001 17:19:12.034602 4233 hierarchical.cpp:1256] Agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0 deactivated
E1001 17:19:12.034946 4228 http_connection.hpp:449] End-Of-File received
I1001 17:19:12.035620 4228 http_connection.hpp:217] Re-detecting endpoint
I1001 17:19:12.036335 4228 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1001 17:19:12.036415 4228 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1001 17:19:12.036494 4222 provider.cpp:488] Disconnected from resource provider manager
I1001 17:19:12.036545 4228 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:42997/slave(1250)/api/v1/resource_provider
I1001 17:19:12.036687 4221 status_update_manager_process.hpp:379] Pausing operation status update manager
I1001 17:19:12.038642 4230 containerizer.cpp:2716] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I1001 17:19:12.038743 4230 containerizer.cpp:3414] 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.642118144secs
I1001 17:19:12.039438 4230 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:12.040738 4237 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:42997/slave(1250)/api/v1/resource_provider
I1001 17:19:12.041769 4222 provider.cpp:476] Connected to resource provider manager
I1001 17:19:12.042683 4218 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:42997/slave(1250)/api/v1/resource_provider
I1001 17:19:12.043911 4238 process.cpp:2781] Returning '404 Not Found' for '/slave(1250)/api/v1/resource_provider'
E1001 17:19:12.045644 4219 provider.cpp:722] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I1001 17:19:12.062553 4225 hierarchical.cpp:1953] Performed allocation for 1 agents in 107925ns
I1001 17:19:12.113469 4224 containerizer.cpp:3252] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I1001 17:19:12.113610 4236 hierarchical.cpp:1953] Performed allocation for 1 agents in 211751ns
I1001 17:19:12.116005 4218 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
I1001 17:19:12.119545 4233 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'
I1001 17:19:12.119925 4229 service_manager.cpp:815] Disconnected from endpoint 'unix:///tmp/mesos-csi-AV8i5h/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1001 17:19:12.120378 4216 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1001 17:19:12.124539 4238 process.cpp:2781] Returning '404 Not Found' for '/slave(1250)/api/v1'
I1001 17:19:12.137095 4213 master.cpp:1151] Master terminating
I1001 17:19:12.137441 4221 hierarchical.cpp:1232] Removed all filters for agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0
I1001 17:19:12.137478 4221 hierarchical.cpp:1108] Removed agent b5789b9f-38e4-49ac-aad6-6b7161584002-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v1 (878 ms)
[----------] 54 tests from CSIVersion/StorageLocalResourceProviderTest (107566 ms total)
[----------] Global test environment tear-down
[==========] 2339 tests from 224 test cases ran. (1215909 ms total)
[ PASSED ] 2338 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] DockerFetcherPluginTest.INTERNET_CURL_GeneratedRepositoryScope
1 FAILED TEST
YOU HAVE 34 DISABLED TESTS
I1001 17:19:12.254806 4238 process.cpp:935] Stopped the socket accept loop
Makefile:16043: recipe for target 'check-local' failed
make[4]: *** [check-local] Error 1
make[4]: Leaving directory '/tmp/SRC/build/mesos-1.11.0/_build/sub/src'
Makefile:15151: recipe for target 'check-am' failed
make[3]: *** [check-am] Error 2
make[3]: Leaving directory '/tmp/SRC/build/mesos-1.11.0/_build/sub/src'
Makefile:15155: recipe for target 'check' failed
make[2]: *** [check] Error 2
make[2]: Leaving directory '/tmp/SRC/build/mesos-1.11.0/_build/sub/src'
Makefile:785: recipe for target 'check-recursive' failed
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory '/tmp/SRC/build/mesos-1.11.0/_build/sub'
Makefile:991: 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://ci-builds.apache.org/job/Mesos/job/Mesos-Reviewbot/952/console
- Mesos Reviewbot
On Oct. 1, 2020, 2:01 p.m., Andrei Sekretenko wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72922/
> -----------------------------------------------------------
>
> (Updated Oct. 1, 2020, 2:01 p.m.)
>
>
> Review request for mesos and Benjamin Mahler.
>
>
> Bugs: MESOS-10189
> https://issues.apache.org/jira/browse/MESOS-10189
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This patch converts the implementation of the obsolete 2-parameter
> `SchedulerDriver.updateFramework(frameworkInfo, suppressedRoles)`
> from a wrapper around the new signature back into a JNI method
> that 930c7e98d17e71192dae1d49b4b2217cc2dbd8b2 attempted to remove.
>
> This is needed to keep compatibility between older versions of
> `mesos.jar` and newer versions of `libmesos-java.so`.
>
>
> Diffs
> -----
>
> src/java/jni/org_apache_mesos_MesosSchedulerDriver.cpp 4efde3083bb62253f3ad512b40a291fd7f7f7a78
> src/java/src/org/apache/mesos/MesosSchedulerDriver.java 4fdae338491709574775c52438e41d03b39917bd
>
>
> Diff: https://reviews.apache.org/r/72922/diff/1/
>
>
> Testing
> -------
>
> `make check`
>
>
> Thanks,
>
> Andrei Sekretenko
>
>