You are viewing a plain text version of this content. The canonical link for it is here.
Posted to reviews@mesos.apache.org by Meng Zhu <mz...@mesosphere.io> on 2019/10/24 02:56:53 UTC
Re: Review Request 71639: Added an benchmark for
`allocator->UpdateAllocation()`.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71639/
-----------------------------------------------------------
(Updated Oct. 23, 2019, 7:56 p.m.)
Review request for mesos, Andrei Sekretenko and Benjamin Mahler.
Summary (updated)
-----------------
Added an benchmark for `allocator->UpdateAllocation()`.
Bugs: MESOS-10016
https://issues.apache.org/jira/browse/MESOS-10016
Repository: mesos
Description (updated)
-------
This benchmark evaluates the performance of
`allocator->UpdateAllocation()` where the agent has various
sizes of resource reservations.
Diffs (updated)
-----
src/tests/hierarchical_allocator_tests.cpp 38fd19cee6409e4daa5bb0ab523e8e464cdcc9a5
Diff: https://reviews.apache.org/r/71639/diff/2/
Changes: https://reviews.apache.org/r/71639/diff/1-2/
Testing (updated)
-------
On the master branch optimized build:
```
[ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/0
Agent resources size: 50 (50 roles, 1 reservations per role, 1 ranges per port resources)
20 reservation operations took 442.402455ms, each takes 22.120122ms
20 Unreservation operations took 464.085487ms, each takes 23.204274ms
[ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/1
Agent resources size: 100 (100 roles, 1 reservations per role, 1 ranges per port resources)
20 reservation operations took 1.321309035secs, each takes 66.065451ms
20 Unreservation operations took 1.311244246secs, each takes 65.562212ms
[ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/2
Agent resources size: 200 (200 roles, 1 reservations per role, 1 ranges per port resources)
20 reservation operations took 4.129166934secs, each takes 206.458346ms
20 Unreservation operations took 4.041358384secs, each takes 202.067919ms
[ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/3
Agent resources size: 400 (400 roles, 1 reservations per role, 1 ranges per port resources)
20 reservation operations took 15.011075671secs, each takes 750.553783ms
20 Unreservation operations took 15.41327483secs, each takes 770.663741ms
[ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/4
Agent resources size: 600 (600 roles, 1 reservations per role, 1 ranges per port resources)
20 reservation operations took 31.159754828secs, each takes 1.557987741secs
20 Unreservation operations took 30.69454178secs, each takes 1.534727089secs
```
Thanks,
Meng Zhu
Re: Review Request 71639: Added an benchmark for
`allocator->UpdateAllocation()`.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71639/#review218383
-----------------------------------------------------------
Bad patch!
Reviews applied: [71639]
Failed command: ['bash', '-c', "set -o pipefail; export OS='ubuntu:14.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/docker-build.sh 2>&1 | tee build_71639"]
Error:
...<truncated>...
/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_dGZkrA/2GB-7b4808f0-dd6c-4f19-a568-f6eb7e4d498d,test)]:2048, offered or allocated: {}) on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 from framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000
I1024 09:26:53.782852 18659 master.cpp:12706] Removing offer 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-O3
I1024 09:26:53.784651 18648 hierarchical.cpp:1615] Framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 filtered agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 for 5secs
I1024 09:26:53.787737 18652 master.cpp:12571] Sending operation '' (uuid: 0275ef53-2c46-4698-bf17-4746f9d0cec0) to agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 at slave(1247)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:53.788321 18669 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I1024 09:26:53.791106 18670 provider.cpp:498] Received APPLY_OPERATION event
I1024 09:26:53.791158 18670 provider.cpp:1351] Received CREATE operation '' (uuid: 0275ef53-2c46-4698-bf17-4746f9d0cec0)
I1024 09:26:53.795826 18661 master.cpp:6412] Processing REVIVE call for framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 (default) at scheduler-0032e2bc-1cba-4d8e-8c13-8a319b903637@172.17.0.3:34124
I1024 09:26:53.796336 18660 hierarchical.cpp:1711] Unsuppressed offers and cleared filters for roles { storage/default-role } of framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000
I1024 09:26:53.797616 18660 hierarchical.cpp:1843] Performed allocation for 1 agents in 1.08604ms
I1024 09:26:53.798040 18660 hierarchical.cpp:1843] Performed allocation for 1 agents in 198699ns
I1024 09:26:53.798362 18659 master.cpp:10409] Sending offers [ 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-O4 ] to framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 (default) at scheduler-0032e2bc-1cba-4d8e-8c13-8a319b903637@172.17.0.3:34124
I1024 09:26:53.799041 18664 sched.cpp:934] Scheduler::resourceOffers took 90724ns
I1024 09:26:53.809813 18663 http.cpp:1115] HTTP POST for /slave(1247)/api/v1/resource_provider from 172.17.0.3:40906
I1024 09:26:53.810912 18669 slave.cpp:8483] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: fdb16b44-2e73-498d-a925-cee7d7192d72) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I1024 09:26:53.811089 18669 slave.cpp:8936] Updating the state of operation with no ID (uuid: fdb16b44-2e73-498d-a925-cee7d7192d72) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I1024 09:26:53.811136 18669 slave.cpp:8690] Forwarding status update of operation with no ID (operation_uuid: fdb16b44-2e73-498d-a925-cee7d7192d72) for an operator API call
I1024 09:26:53.811465 18654 master.cpp:12223] Updating the state of operation '' (uuid: fdb16b44-2e73-498d-a925-cee7d7192d72) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I1024 09:26:53.812021 18657 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I1024 09:26:53.888097 18664 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 6e7ad38b-1d89-4ca0-8e77-0506cac3e8c9) for operation UUID 0275ef53-2c46-4698-bf17-4746f9d0cec0 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:53.888248 18664 status_update_manager_process.hpp:414] Creating operation status update stream 0275ef53-2c46-4698-bf17-4746f9d0cec0 checkpoint=true
I1024 09:26:53.888347 18670 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I1024 09:26:53.888806 18664 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 6e7ad38b-1d89-4ca0-8e77-0506cac3e8c9) for operation UUID 0275ef53-2c46-4698-bf17-4746f9d0cec0 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:53.938164 18664 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 6e7ad38b-1d89-4ca0-8e77-0506cac3e8c9) for operation UUID 0275ef53-2c46-4698-bf17-4746f9d0cec0 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:53.938642 18664 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 5fbba72b-8c56-48d4-ae24-439fb369954b) for stream fdb16b44-2e73-498d-a925-cee7d7192d72
I1024 09:26:53.938797 18664 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 5fbba72b-8c56-48d4-ae24-439fb369954b) for operation UUID fdb16b44-2e73-498d-a925-cee7d7192d72 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:53.939409 18648 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.3:34124/slave(1247)/api/v1/resource_provider
I1024 09:26:53.941040 18652 process.cpp:3671] Handling HTTP event for process 'slave(1247)' with path: '/slave(1247)/api/v1/resource_provider'
I1024 09:26:53.978719 18651 http.cpp:1115] HTTP POST for /slave(1247)/api/v1/resource_provider from 172.17.0.3:40906
I1024 09:26:53.980672 18668 slave.cpp:8483] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 0275ef53-2c46-4698-bf17-4746f9d0cec0) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I1024 09:26:53.981299 18668 slave.cpp:8936] Updating the state of operation with no ID (uuid: 0275ef53-2c46-4698-bf17-4746f9d0cec0) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I1024 09:26:53.981643 18668 slave.cpp:8690] Forwarding status update of operation with no ID (operation_uuid: 0275ef53-2c46-4698-bf17-4746f9d0cec0) for an operator API call
I1024 09:26:53.982553 18668 master.cpp:12223] Updating the state of operation '' (uuid: 0275ef53-2c46-4698-bf17-4746f9d0cec0) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I1024 09:26:53.983592 18658 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I1024 09:26:53.986027 18648 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I1024 09:26:54.004922 18664 status_update_manager_process.hpp:490] Cleaning up operation status update stream fdb16b44-2e73-498d-a925-cee7d7192d72
I1024 09:26:54.007071 18664 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 6e7ad38b-1d89-4ca0-8e77-0506cac3e8c9) for stream 0275ef53-2c46-4698-bf17-4746f9d0cec0
I1024 09:26:54.007153 18664 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 6e7ad38b-1d89-4ca0-8e77-0506cac3e8c9) for operation UUID 0275ef53-2c46-4698-bf17-4746f9d0cec0 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:54.105959 18664 status_update_manager_process.hpp:490] Cleaning up operation status update stream 0275ef53-2c46-4698-bf17-4746f9d0cec0
I1024 09:26:54.186816 18654 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I1024 09:26:54.188881 18662 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.3:40978
I1024 09:26:54.189191 18662 http.cpp:263] Processing call DESTROY_VOLUMES
I1024 09:26:54.190186 18662 master.cpp:3983] Authorizing principal 'test-principal' to destroy volumes '[{"disk":{"persistence":{"id":"866b0c6a-b609-4d18-a13b-3dd3ed5684df","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_dGZkrA/2GB-7b4808f0-dd6c-4f19-a568-f6eb7e4d498d","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"},"volume":{"container_path":"volume","mode":"RW"}},"name":"disk","provider_id":{"value":"8f1e8ddd-ccf6-4186-b855-6125fea0b309"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I1024 09:26:54.191857 18649 sched.cpp:960] Rescinded offer 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-O4
I1024 09:26:54.191970 18649 sched.cpp:971] Scheduler::offerRescinded took 44668ns
I1024 09:26:54.192505 18661 master.cpp:12706] Removing offer 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-O4
I1024 09:26:54.192452 18660 hierarchical.cpp:1566] 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_dGZkrA/2GB-7b4808f0-dd6c-4f19-a568-f6eb7e4d498d,test),866b0c6a-b609-4d18-a13b-3dd3ed5684df: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_dGZkrA/2GB-7b4808f0-dd6c-4f19-a568-f6eb7e4d498d,test),866b0c6a-b609-4d18-a13b-3dd3ed5684df:volume]:2048, offered
or allocated: {}) on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 from framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000
I1024 09:26:54.194239 18660 hierarchical.cpp:1615] Framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 filtered agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 for 5secs
I1024 09:26:54.197582 18659 master.cpp:12571] Sending operation '' (uuid: e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062) to agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 at slave(1247)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:54.198138 18664 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I1024 09:26:54.201134 18667 provider.cpp:498] Received APPLY_OPERATION event
I1024 09:26:54.201180 18667 provider.cpp:1351] Received DESTROY operation '' (uuid: e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062)
I1024 09:26:54.206956 18662 hierarchical.cpp:1843] Performed allocation for 1 agents in 1.134955ms
I1024 09:26:54.207664 18658 master.cpp:10409] Sending offers [ 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-O5 ] to framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 (default) at scheduler-0032e2bc-1cba-4d8e-8c13-8a319b903637@172.17.0.3:34124
I1024 09:26:54.208390 18656 sched.cpp:934] Scheduler::resourceOffers took 106234ns
I1024 09:26:54.358592 18649 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: b8e83070-eb34-4830-8cf4-94a96e3f2532) for operation UUID e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:54.358709 18649 status_update_manager_process.hpp:414] Creating operation status update stream e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062 checkpoint=true
I1024 09:26:54.359202 18649 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: b8e83070-eb34-4830-8cf4-94a96e3f2532) for operation UUID e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:54.437022 18649 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: b8e83070-eb34-4830-8cf4-94a96e3f2532) for operation UUID e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:54.438261 18670 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.3:34124/slave(1247)/api/v1/resource_provider
I1024 09:26:54.439622 18665 process.cpp:3671] Handling HTTP event for process 'slave(1247)' with path: '/slave(1247)/api/v1/resource_provider'
I1024 09:26:54.443110 18648 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I1024 09:26:54.445163 18657 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.3:40980
I1024 09:26:54.445436 18657 http.cpp:263] Processing call UNRESERVE_RESOURCES
I1024 09:26:54.446254 18657 master.cpp:3875] Authorizing principal 'test-principal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_dGZkrA/2GB-7b4808f0-dd6c-4f19-a568-f6eb7e4d498d","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"8f1e8ddd-ccf6-4186-b855-6125fea0b309"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I1024 09:26:54.447858 18668 sched.cpp:960] Rescinded offer 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-O5
I1024 09:26:54.447968 18668 sched.cpp:971] Scheduler::offerRescinded took 37739ns
I1024 09:26:54.448374 18662 hierarchical.cpp:1566] 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_dGZkrA/2GB-7b4808f0-dd6c-4f19-a568-f6eb7e4d498d,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_dGZkrA/2GB-7b4808f0-dd6c-4f19-a568-f6eb7e4d498d,test)]:2048, offered or allocated: {}) on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 from framework 7c8d3
337-ae4c-4b18-ae78-f8c28690dd61-0000
I1024 09:26:54.448510 18651 master.cpp:12706] Removing offer 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-O5
I1024 09:26:54.449749 18662 hierarchical.cpp:1615] Framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 filtered agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 for 5secs
I1024 09:26:54.452668 18667 master.cpp:12571] Sending operation '' (uuid: 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8) to agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 at slave(1247)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:54.453299 18661 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I1024 09:26:54.456511 18663 provider.cpp:498] Received APPLY_OPERATION event
I1024 09:26:54.456562 18663 provider.cpp:1351] Received UNRESERVE operation '' (uuid: 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8)
I1024 09:26:54.464303 18654 hierarchical.cpp:1843] Performed allocation for 1 agents in 1.388197ms
I1024 09:26:54.464969 18655 master.cpp:10409] Sending offers [ 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-O6 ] to framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 (default) at scheduler-0032e2bc-1cba-4d8e-8c13-8a319b903637@172.17.0.3:34124
I1024 09:26:54.465672 18668 sched.cpp:934] Scheduler::resourceOffers took 101119ns
I1024 09:26:54.477828 18660 http.cpp:1115] HTTP POST for /slave(1247)/api/v1/resource_provider from 172.17.0.3:40906
I1024 09:26:54.478878 18667 slave.cpp:8483] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I1024 09:26:54.479075 18667 slave.cpp:8936] Updating the state of operation with no ID (uuid: e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I1024 09:26:54.479130 18667 slave.cpp:8690] Forwarding status update of operation with no ID (operation_uuid: e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062) for an operator API call
I1024 09:26:54.479548 18661 master.cpp:12223] Updating the state of operation '' (uuid: e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I1024 09:26:54.480068 18659 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I1024 09:26:54.610182 18668 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 5ba3a5da-834d-4662-9e23-ddd7919b5353) for operation UUID 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:54.610271 18668 status_update_manager_process.hpp:414] Creating operation status update stream 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8 checkpoint=true
I1024 09:26:54.610347 18663 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I1024 09:26:54.610842 18668 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 5ba3a5da-834d-4662-9e23-ddd7919b5353) for operation UUID 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:54.693799 18668 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 5ba3a5da-834d-4662-9e23-ddd7919b5353) for operation UUID 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:54.694308 18668 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: b8e83070-eb34-4830-8cf4-94a96e3f2532) for stream e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062
I1024 09:26:54.694404 18668 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: b8e83070-eb34-4830-8cf4-94a96e3f2532) for operation UUID e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:54.695008 18658 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.3:34124/slave(1247)/api/v1/resource_provider
I1024 09:26:54.696405 18670 process.cpp:3671] Handling HTTP event for process 'slave(1247)' with path: '/slave(1247)/api/v1/resource_provider'
I1024 09:26:54.734133 18650 http.cpp:1115] HTTP POST for /slave(1247)/api/v1/resource_provider from 172.17.0.3:40906
I1024 09:26:54.735348 18648 slave.cpp:8483] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I1024 09:26:54.735539 18648 slave.cpp:8936] Updating the state of operation with no ID (uuid: 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I1024 09:26:54.735602 18648 slave.cpp:8690] Forwarding status update of operation with no ID (operation_uuid: 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8) for an operator API call
I1024 09:26:54.736263 18666 master.cpp:12223] Updating the state of operation '' (uuid: 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I1024 09:26:54.737013 18664 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version
I1024 09:26:54.738924 18662 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I1024 09:26:54.761766 18668 status_update_manager_process.hpp:490] Cleaning up operation status update stream e90c1e05-d1a4-41d5-b1b3-fffeb4b9f062
I1024 09:26:54.762084 18668 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 5ba3a5da-834d-4662-9e23-ddd7919b5353) for stream 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8
I1024 09:26:54.762157 18668 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 5ba3a5da-834d-4662-9e23-ddd7919b5353) for operation UUID 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8 on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:54.886745 18668 status_update_manager_process.hpp:490] Cleaning up operation status update stream 5c1a92b5-2b3e-4698-9ec6-6fa481cefca8
I1024 09:26:54.946542 18647 master.cpp:1411] Framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 (default) at scheduler-0032e2bc-1cba-4d8e-8c13-8a319b903637@172.17.0.3:34124 disconnected
I1024 09:26:54.946610 18647 master.cpp:3356] Deactivating framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 (default) at scheduler-0032e2bc-1cba-4d8e-8c13-8a319b903637@172.17.0.3:34124
I1024 09:26:54.947052 18650 hierarchical.cpp:813] Deactivated framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000
I1024 09:26:54.947660 18647 master.cpp:12706] Removing offer 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-O6
I1024 09:26:54.947639 18650 hierarchical.cpp:1566] 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_dGZkrA/2GB-7b4808f0-dd6c-4f19-a568-f6eb7e4d498d,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_dGZkrA/2GB-7b4808f0-dd6c-4f19-a568-f6eb7e4d498d,test)]:2048, offered or allocated: {}) on agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 from framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000
I1024 09:26:54.947759 18647 master.cpp:3333] Disconnecting framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 (default) at scheduler-0032e2bc-1cba-4d8e-8c13-8a319b903637@172.17.0.3:34124
I1024 09:26:54.947788 18646 slave.cpp:924] Agent terminating
I1024 09:26:54.947841 18647 master.cpp:1426] Giving framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 (default) at scheduler-0032e2bc-1cba-4d8e-8c13-8a319b903637@172.17.0.3:34124 0ns to failover
I1024 09:26:54.949091 18646 manager.cpp:163] Terminating resource provider 8f1e8ddd-ccf6-4186-b855-6125fea0b309
I1024 09:26:54.949462 18667 master.cpp:10195] Framework failover timeout, removing framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 (default) at scheduler-0032e2bc-1cba-4d8e-8c13-8a319b903637@172.17.0.3:34124
I1024 09:26:54.949519 18667 master.cpp:11197] Removing framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000 (default) at scheduler-0032e2bc-1cba-4d8e-8c13-8a319b903637@172.17.0.3:34124
I1024 09:26:54.950095 18665 hierarchical.cpp:1767] Allocation paused
I1024 09:26:54.950176 18667 master.cpp:1296] Agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 at slave(1247)@172.17.0.3:34124 (4208d5688280) disconnected
I1024 09:26:54.950208 18667 master.cpp:3391] Disconnecting agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 at slave(1247)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:54.950302 18667 master.cpp:3410] Deactivating agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 at slave(1247)@172.17.0.3:34124 (4208d5688280)
E1024 09:26:54.950448 18653 http_connection.hpp:452] End-Of-File received
I1024 09:26:54.950569 18665 hierarchical.cpp:757] Removed framework 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-0000
I1024 09:26:54.950659 18665 hierarchical.cpp:1777] Allocation resumed
I1024 09:26:54.950728 18665 hierarchical.cpp:1146] Agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0 deactivated
I1024 09:26:54.950992 18653 http_connection.hpp:217] Re-detecting endpoint
I1024 09:26:54.951416 18653 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1024 09:26:54.951514 18656 provider.cpp:488] Disconnected from resource provider manager
I1024 09:26:54.951653 18653 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1024 09:26:54.951685 18658 status_update_manager_process.hpp:379] Pausing operation status update manager
I1024 09:26:54.951738 18653 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:34124/slave(1247)/api/v1/resource_provider
I1024 09:26:54.953546 18666 containerizer.cpp:2620] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I1024 09:26:54.953634 18666 containerizer.cpp:3318] 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 3.000218752secs
I1024 09:26:54.954453 18666 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:54.955453 18664 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.3:34124/slave(1247)/api/v1/resource_provider
I1024 09:26:54.956058 18656 provider.cpp:476] Connected to resource provider manager
I1024 09:26:54.956780 18654 hierarchical.cpp:1843] Performed allocation for 1 agents in 191841ns
I1024 09:26:54.956784 18668 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.3:34124/slave(1247)/api/v1/resource_provider
I1024 09:26:54.957581 18671 process.cpp:2781] Returning '404 Not Found' for '/slave(1247)/api/v1/resource_provider'
E1024 09:26:54.958896 18653 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I1024 09:26:55.007939 18669 hierarchical.cpp:1843] Performed allocation for 1 agents in 220803ns
I1024 09:26:55.058106 18663 containerizer.cpp:3156] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I1024 09:26:55.059571 18662 hierarchical.cpp:1843] Performed allocation for 1 agents in 208622ns
I1024 09:26:55.059852 18656 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
I1024 09:26:55.062857 18665 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'
I1024 09:26:55.063066 18667 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-EE8DCK/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:55.063315 18647 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:55.066748 18671 process.cpp:2781] Returning '404 Not Found' for '/slave(1247)/api/v1'
I1024 09:26:55.078212 18646 master.cpp:1137] Master terminating
I1024 09:26:55.079527 18668 hierarchical.cpp:1122] Removed all filters for agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
I1024 09:26:55.079557 18668 hierarchical.cpp:998] Removed agent 7c8d3337-ae4c-4b18-ae78-f8c28690dd61-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (2889 ms)
[ RUN ] CSIVersion/StorageLocalResourceProviderTest.Update/v0
I1024 09:26:55.104512 18646 cluster.cpp:177] Creating default 'local' authorizer
I1024 09:26:55.111027 18655 master.cpp:440] Master 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba (4208d5688280) started on 172.17.0.3:34124
I1024 09:26:55.111063 18655 master.cpp:443] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/6cQ0Zj/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_alloca
table_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/mesos/mesos-1.10.0/_inst/share/mesos/webui" --work_dir="/tmp/6cQ0Zj/master" --zk_session_timeout="10secs"
I1024 09:26:55.111639 18655 master.cpp:492] Master only allowing authenticated frameworks to register
I1024 09:26:55.111665 18655 master.cpp:498] Master only allowing authenticated agents to register
I1024 09:26:55.111678 18655 master.cpp:504] Master only allowing authenticated HTTP frameworks to register
I1024 09:26:55.111696 18655 credentials.hpp:37] Loading credentials for authentication from '/tmp/6cQ0Zj/credentials'
I1024 09:26:55.112131 18655 master.cpp:548] Using default 'crammd5' authenticator
I1024 09:26:55.112409 18655 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1024 09:26:55.112648 18655 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1024 09:26:55.112821 18655 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1024 09:26:55.112985 18655 master.cpp:629] Authorization enabled
I1024 09:26:55.113477 18669 whitelist_watcher.cpp:77] No whitelist given
I1024 09:26:55.113498 18670 hierarchical.cpp:567] Initialized hierarchical allocator process
I1024 09:26:55.116487 18659 master.cpp:2169] Elected as the leading master!
I1024 09:26:55.116523 18659 master.cpp:1665] Recovering from registrar
I1024 09:26:55.116721 18665 registrar.cpp:339] Recovering registrar
I1024 09:26:55.117563 18665 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I1024 09:26:55.117703 18665 registrar.cpp:487] Applied 1 operations in 41904ns; attempting to update the registry
I1024 09:26:55.118386 18665 registrar.cpp:544] Successfully updated the registry in 0ns
I1024 09:26:55.118528 18665 registrar.cpp:416] Successfully recovered registrar
I1024 09:26:55.119019 18647 hierarchical.cpp:606] Skipping recovery of hierarchical allocator: nothing to recover
I1024 09:26:55.119029 18658 master.cpp:1818] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
W1024 09:26:55.125463 18646 process.cpp:2877] Attempted to spawn already running process files@172.17.0.3:34124
I1024 09:26:55.127017 18646 containerizer.cpp:318] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1024 09:26:55.127552 18646 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W1024 09:26:55.127580 18646 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1024 09:26:55.127724 18646 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1024 09:26:55.127768 18646 provisioner.cpp:294] Using default backend 'copy'
I1024 09:26:55.130486 18646 cluster.cpp:524] Creating default 'local' authorizer
I1024 09:26:55.133028 18650 slave.cpp:267] Mesos agent started on (1248)@172.17.0.3:34124
I1024 09:26:55.133057 18650 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/6cQ0Zj/SDORny/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/6cQ0Zj/SDORny/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/6cQ0Zj/SDORny/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/6cQ0Zj/SDORny/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/6cQ0Zj/SDORny/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/6cQ0Zj/SDORny/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.10.0/
_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/6cQ0Zj/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_0m63LZ" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_I45gar" --zk_sessio
n_timeout="10secs"
I1024 09:26:55.133553 18650 credentials.hpp:86] Loading credential for authentication from '/tmp/6cQ0Zj/SDORny/credential'
I1024 09:26:55.133756 18650 slave.cpp:300] Agent using credential for: test-principal
I1024 09:26:55.133785 18650 credentials.hpp:37] Loading credentials for authentication from '/tmp/6cQ0Zj/SDORny/http_credentials'
I1024 09:26:55.134032 18650 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1024 09:26:55.134425 18650 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I1024 09:26:55.136180 18654 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I1024 09:26:55.136143 18650 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I1024 09:26:55.136402 18650 slave.cpp:623] Agent attributes: [ ]
I1024 09:26:55.136420 18650 slave.cpp:632] Agent hostname: 4208d5688280
I1024 09:26:55.136570 18659 status_update_manager_process.hpp:379] Pausing operation status update manager
I1024 09:26:55.136615 18649 task_status_update_manager.cpp:181] Pausing sending task status updates
I1024 09:26:55.138536 18661 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_I45gar/meta'
I1024 09:26:55.138795 18667 slave.cpp:7492] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_I45gar/meta', beginning agent recovery
I1024 09:26:55.139415 18648 task_status_update_manager.cpp:207] Recovering task status update manager
I1024 09:26:55.139847 18665 containerizer.cpp:821] Recovering Mesos containers
I1024 09:26:55.140280 18665 containerizer.cpp:1161] Recovering isolators
I1024 09:26:55.140323 18656 hierarchical.cpp:1843] Performed allocation for 0 agents in 133031ns
I1024 09:26:55.141224 18659 containerizer.cpp:1200] Recovering provisioner
I1024 09:26:55.141978 18668 provisioner.cpp:518] Provisioner recovery complete
I1024 09:26:55.142714 18647 composing.cpp:339] Finished recovering all containerizers
I1024 09:26:55.143002 18663 slave.cpp:7974] Recovering executors
I1024 09:26:55.143118 18663 slave.cpp:8127] Finished recovery
I1024 09:26:55.144058 18670 task_status_update_manager.cpp:181] Pausing sending task status updates
I1024 09:26:55.144080 18654 status_update_manager_process.hpp:379] Pausing operation status update manager
I1024 09:26:55.144093 18669 slave.cpp:1351] New master detected at master@172.17.0.3:34124
I1024 09:26:55.144186 18669 slave.cpp:1416] Detecting new master
I1024 09:26:55.150506 18658 slave.cpp:1443] Authenticating with master master@172.17.0.3:34124
I1024 09:26:55.150642 18658 slave.cpp:1452] Using default CRAM-MD5 authenticatee
I1024 09:26:55.151024 18659 authenticatee.cpp:121] Creating new client SASL connection
I1024 09:26:55.151405 18653 master.cpp:10594] Authenticating slave(1248)@172.17.0.3:34124
I1024 09:26:55.151571 18666 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2103)@172.17.0.3:34124
I1024 09:26:55.151851 18652 authenticator.cpp:98] Creating new server SASL connection
I1024 09:26:55.152102 18668 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1024 09:26:55.152134 18668 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1024 09:26:55.152300 18661 authenticator.cpp:204] Received SASL authentication start
I1024 09:26:55.152384 18661 authenticator.cpp:326] Authentication requires more steps
I1024 09:26:55.152515 18650 authenticatee.cpp:259] Received SASL authentication step
I1024 09:26:55.152668 18667 authenticator.cpp:232] Received SASL authentication step
I1024 09:26:55.152716 18667 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4208d5688280' server FQDN: '4208d5688280' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1024 09:26:55.152750 18667 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1024 09:26:55.152801 18667 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1024 09:26:55.152842 18667 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4208d5688280' server FQDN: '4208d5688280' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1024 09:26:55.152865 18667 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1024 09:26:55.152881 18667 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1024 09:26:55.152918 18667 authenticator.cpp:318] Authentication success
I1024 09:26:55.153021 18648 authenticatee.cpp:299] Authentication success
I1024 09:26:55.153184 18657 master.cpp:10626] Successfully authenticated principal 'test-principal' at slave(1248)@172.17.0.3:34124
I1024 09:26:55.153246 18662 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2103)@172.17.0.3:34124
I1024 09:26:55.153527 18664 slave.cpp:1543] Successfully authenticated with master master@172.17.0.3:34124
I1024 09:26:55.153978 18664 slave.cpp:1993] Will retry registration in 2.784105ms if necessary
I1024 09:26:55.154181 18660 master.cpp:7083] Received register agent message from slave(1248)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:55.154546 18660 master.cpp:4189] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I1024 09:26:55.155230 18655 master.cpp:7150] Authorized registration of agent at slave(1248)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:55.155341 18655 master.cpp:7262] Registering agent at slave(1248)@172.17.0.3:34124 (4208d5688280) with id 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0
I1024 09:26:55.156023 18649 registrar.cpp:487] Applied 1 operations in 219630ns; attempting to update the registry
I1024 09:26:55.156790 18649 registrar.cpp:544] Successfully updated the registry in 689920ns
I1024 09:26:55.156966 18652 master.cpp:7310] Admitted agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 at slave(1248)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:55.157769 18668 slave.cpp:1993] Will retry registration in 17.273587ms if necessary
I1024 09:26:55.157771 18652 master.cpp:7355] Registered agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 at slave(1248)@172.17.0.3:34124 (4208d5688280) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1024 09:26:55.157995 18661 hierarchical.cpp:955] Added agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 (4208d5688280) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I1024 09:26:55.158051 18652 master.cpp:7083] Received register agent message from slave(1248)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:55.158196 18668 slave.cpp:1576] Registered with master master@172.17.0.3:34124; given agent ID 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0
I1024 09:26:55.158329 18657 task_status_update_manager.cpp:188] Resuming sending task status updates
I1024 09:26:55.158439 18652 master.cpp:4189] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I1024 09:26:55.158488 18661 hierarchical.cpp:1843] Performed allocation for 1 agents in 217035ns
I1024 09:26:55.158800 18668 slave.cpp:1611] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_I45gar/meta/slaves/9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0/slave.info'
I1024 09:26:55.158869 18648 status_update_manager_process.hpp:385] Resuming operation status update manager
I1024 09:26:55.159124 18667 master.cpp:7150] Authorized registration of agent at slave(1248)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:55.159229 18667 master.cpp:7241] Agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 at slave(1248)@172.17.0.3:34124 (4208d5688280) already registered, resending acknowledgement
I1024 09:26:55.160063 18668 slave.cpp:1663] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"GlxUGcGQSiiagKumu5daNg=="},"slave_id":{"value":"9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0"},"update_oversubscribed_resources":false}
W1024 09:26:55.160311 18668 slave.cpp:1645] Already registered with master master@172.17.0.3:34124
I1024 09:26:55.160419 18668 slave.cpp:1663] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"GlxUGcGQSiiagKumu5daNg=="},"slave_id":{"value":"9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0"},"update_oversubscribed_resources":false}
I1024 09:26:55.160817 18665 master.cpp:8474] Ignoring update on agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 at slave(1248)@172.17.0.3:34124 (4208d5688280) as it reports no changes
I1024 09:26:55.161357 18665 master.cpp:8474] Ignoring update on agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 at slave(1248)@172.17.0.3:34124 (4208d5688280) as it reports no changes
I1024 09:26:55.164644 18663 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1'
I1024 09:26:55.165753 18664 http.cpp:1115] HTTP POST for /slave(1248)/api/v1 from 172.17.0.3:41020
I1024 09:26:55.166239 18664 http.cpp:2146] Processing GET_CONTAINERS call
I1024 09:26:55.171159 18647 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:55.173410 18663 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1'
I1024 09:26:55.174278 18664 http.cpp:1115] HTTP POST for /slave(1248)/api/v1 from 172.17.0.3:41022
I1024 09:26:55.175092 18664 http.cpp:2606] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:55.176002 18670 http.cpp:2710] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_I45gar/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:55.176784 18653 containerizer.cpp:1396] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:55.177417 18653 containerizer.cpp:3318] 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 235008ns
I1024 09:26:55.178175 18653 containerizer.cpp:1574] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_0m63LZ/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I1024 09:26:55.178225 18653 containerizer.cpp:3318] 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 811008ns
I1024 09:26:55.181044 18657 containerizer.cpp:2100] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_YLrvyS","--available_capacity=0B","--volumes=","--forward=unix:///tmp/6cQ0Zj/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.0/_build/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_I45gar/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-bHOTaN/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_I45gar/containers/org-apache-mesos-rp-local
-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="92" --pipe_write="93" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_0m63LZ/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I1024 09:26:55.190501 18657 launcher.cpp:145] Forked child with pid '33001' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:55.191409 18657 containerizer.cpp:3318] 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 13.176832ms
I1024 09:26:55.192687 18663 hierarchical.cpp:1843] Performed allocation for 1 agents in 444299ns
I1024 09:26:55.193512 18657 containerizer.cpp:3318] 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.105088ms
I1024 09:26:55.193804 18655 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_I45gar/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:55.194928 18670 containerizer.cpp:3318] 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.348096ms
I1024 09:26:55.197687 18658 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'
I1024 09:26:55.197886 18661 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-bHOTaN/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:55.244613 18659 hierarchical.cpp:1843] Performed allocation for 1 agents in 212349ns
I1024 09:26:55.296241 18669 hierarchical.cpp:1843] Performed allocation for 1 agents in 255779ns
I1024 09:26:55.347633 18650 hierarchical.cpp:1843] Performed allocation for 1 agents in 233921ns
I1024 09:26:55.399303 18656 hierarchical.cpp:1843] Performed allocation for 1 agents in 229822ns
I1024 09:26:55.450539 18654 hierarchical.cpp:1843] Performed allocation for 1 agents in 239843ns
I1024 09:26:55.501646 18665 hierarchical.cpp:1843] Performed allocation for 1 agents in 216851ns
I1024 09:26:55.553339 18661 hierarchical.cpp:1843] Performed allocation for 1 agents in 224611ns
I1024 09:26:55.604688 18664 hierarchical.cpp:1843] Performed allocation for 1 agents in 145129ns
I1024 09:26:55.639371 18657 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-bHOTaN/endpoint.sock' with CSI v1
I1024 09:26:55.641963 18670 service_manager.cpp:532] Probing endpoint 'unix:///tmp/mesos-csi-bHOTaN/endpoint.sock' with CSI v0
I1024 09:26:55.642971 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/Probe call
I1024 09:26:55.645447 18650 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:55.647815 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginCapabilities call
I1024 09:26:55.648607 18664 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1'
I1024 09:26:55.649718 18657 http.cpp:1115] HTTP POST for /slave(1248)/api/v1 from 172.17.0.3:41024
I1024 09:26:55.650179 18657 http.cpp:2824] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:55.651577 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginInfo call
I1024 09:26:55.651896 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginInfo call
I1024 09:26:55.653353 18652 v0_volume_manager.cpp:628] NODE_SERVICE loaded: {}
I1024 09:26:55.653789 18652 v0_volume_manager.cpp:628] CONTROLLER_SERVICE loaded: {}
I1024 09:26:55.655534 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ControllerGetCapabilities call
I1024 09:26:55.655863 18654 hierarchical.cpp:1843] Performed allocation for 1 agents in 208635ns
I1024 09:26:55.658578 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Node/NodeGetCapabilities call
I1024 09:26:55.661603 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Node/NodeGetId call
I1024 09:26:55.663614 18660 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I1024 09:26:55.663719 18648 status_update_manager_process.hpp:379] Pausing operation status update manager
I1024 09:26:55.664121 18649 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:34124/slave(1248)/api/v1/resource_provider
I1024 09:26:55.666916 18663 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.3:34124/slave(1248)/api/v1/resource_provider
I1024 09:26:55.667469 18669 provider.cpp:476] Connected to resource provider manager
I1024 09:26:55.668040 18670 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.3:34124/slave(1248)/api/v1/resource_provider
I1024 09:26:55.668999 18668 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1/resource_provider'
I1024 09:26:55.670269 18661 http.cpp:1115] HTTP POST for /slave(1248)/api/v1/resource_provider from 172.17.0.3:41028
I1024 09:26:55.670871 18649 manager.cpp:813] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_YLrvyS","--available_capacity=0B","--volumes=","--forward=unix:///tmp/6cQ0Zj/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}
I1024 09:26:55.707345 18662 hierarchical.cpp:1843] Performed allocation for 1 agents in 227820ns
I1024 09:26:55.716635 18653 slave.cpp:8483] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"975d66c1-699f-41db-85a1-83f4b62d08fb"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_YLrvyS","--available_capacity=0B","--volumes=","--forward=unix:///tmp/6cQ0Zj/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}'
I1024 09:26:55.717934 18658 provider.cpp:498] Received SUBSCRIBED event
I1024 09:26:55.717972 18658 provider.cpp:1309] Subscribed with ID 975d66c1-699f-41db-85a1-83f4b62d08fb
I1024 09:26:55.718744 18660 status_update_manager_process.hpp:314] Recovering operation status update manager
I1024 09:26:55.758261 18652 hierarchical.cpp:1843] Performed allocation for 1 agents in 139958ns
I1024 09:26:55.809118 18651 hierarchical.cpp:1843] Performed allocation for 1 agents in 145852ns
I1024 09:26:55.847698 18661 provider.cpp:790] Reconciling storage pools and volumes
I1024 09:26:55.850342 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I1024 09:26:55.852715 18648 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0
I1024 09:26:55.852973 18658 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.3:34124/slave(1248)/api/v1/resource_provider
I1024 09:26:55.853065 18648 provider.cpp:748] Resource provider 975d66c1-699f-41db-85a1-83f4b62d08fb is in READY state
I1024 09:26:55.853106 18660 status_update_manager_process.hpp:385] Resuming operation status update manager
I1024 09:26:55.853687 18651 provider.cpp:1235] Updating profiles { test } for resource provider 975d66c1-699f-41db-85a1-83f4b62d08fb
I1024 09:26:55.854058 18667 process.cpp:3671] Handling HTTP event for process 'slave(1248)' with path: '/slave(1248)/api/v1/resource_provider'
I1024 09:26:55.854634 18655 provider.cpp:790] Reconciling storage pools and volumes
I1024 09:26:55.855628 18647 http.cpp:1115] HTTP POST for /slave(1248)/api/v1/resource_provider from 172.17.0.3:41026
I1024 09:26:55.856122 18648 manager.cpp:1045] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 975d66c1-699f-41db-85a1-83f4b62d08fb
I1024 09:26:55.856328 18651 slave.cpp:8483] Handling resource provider message 'UPDATE_STATE: 975d66c1-699f-41db-85a1-83f4b62d08fb {}'
I1024 09:26:55.856426 18651 slave.cpp:8603] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1024 09:26:55.856506 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I1024 09:26:55.856998 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/GetCapacity call
I1024 09:26:55.857911 18666 hierarchical.cpp:1100] Grew agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 by {} (total), { } (used)
I1024 09:26:55.858274 18666 hierarchical.cpp:1057] Agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 (4208d5688280) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1024 09:26:55.862646 18653 hierarchical.cpp:1843] Performed allocation for 1 agents in 152159ns
I1024 09:26:55.862957 18670 provider.cpp:790] Reconciling storage pools and volumes
I1024 09:26:55.864771 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I1024 09:26:55.865026 33005 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/GetCapacity call
I1024 09:26:55.875764 18646 slave.cpp:924] Agent terminating
I1024 09:26:55.876473 18646 manager.cpp:163] Terminating resource provider 975d66c1-699f-41db-85a1-83f4b62d08fb
I1024 09:26:55.876853 18647 master.cpp:1296] Agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 at slave(1248)@172.17.0.3:34124 (4208d5688280) disconnected
I1024 09:26:55.876889 18647 master.cpp:3391] Disconnecting agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 at slave(1248)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:55.876971 18647 master.cpp:3410] Deactivating agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 at slave(1248)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:55.877125 18652 hierarchical.cpp:1146] Agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0 deactivated
E1024 09:26:55.877409 18664 http_connection.hpp:452] End-Of-File received
I1024 09:26:55.877840 18664 http_connection.hpp:217] Re-detecting endpoint
I1024 09:26:55.878202 18664 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1024 09:26:55.878257 18664 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1024 09:26:55.878294 18653 provider.cpp:488] Disconnected from resource provider manager
I1024 09:26:55.878325 18664 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:34124/slave(1248)/api/v1/resource_provider
I1024 09:26:55.878433 18668 status_update_manager_process.hpp:379] Pausing operation status update manager
I1024 09:26:55.879746 18657 containerizer.cpp:2620] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I1024 09:26:55.879819 18657 containerizer.cpp:3318] 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.684957952secs
I1024 09:26:55.880259 18657 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:55.881187 18648 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.3:34124/slave(1248)/api/v1/resource_provider
I1024 09:26:55.881721 18662 provider.cpp:476] Connected to resource provider manager
I1024 09:26:55.882333 18666 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.3:34124/slave(1248)/api/v1/resource_provider
I1024 09:26:55.883061 18671 process.cpp:2781] Returning '404 Not Found' for '/slave(1248)/api/v1/resource_provider'
E1024 09:26:55.884171 18670 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I1024 09:26:55.910094 18650 hierarchical.cpp:1843] Performed allocation for 1 agents in 177063ns
I1024 09:26:55.959414 18658 containerizer.cpp:3156] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I1024 09:26:55.960762 18648 hierarchical.cpp:1843] Performed allocation for 1 agents in 97571ns
I1024 09:26:55.960917 18653 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
I1024 09:26:55.963222 18655 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'
I1024 09:26:55.963392 18649 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-bHOTaN/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:55.963590 18669 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:55.965903 18671 process.cpp:2781] Returning '404 Not Found' for '/slave(1248)/api/v1'
I1024 09:26:55.977000 18646 master.cpp:1137] Master terminating
I1024 09:26:55.977474 18658 hierarchical.cpp:1122] Removed all filters for agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0
I1024 09:26:55.977497 18658 hierarchical.cpp:998] Removed agent 9af3f603-5ae7-48d7-ab7d-ddb6ef8537ba-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v0 (891 ms)
[ RUN ] CSIVersion/StorageLocalResourceProviderTest.Update/v1
I1024 09:26:55.998915 18646 cluster.cpp:177] Creating default 'local' authorizer
I1024 09:26:56.004221 18653 master.cpp:440] Master 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f (4208d5688280) started on 172.17.0.3:34124
I1024 09:26:56.004272 18653 master.cpp:443] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/19xrJc/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_alloca
table_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/mesos/mesos-1.10.0/_inst/share/mesos/webui" --work_dir="/tmp/19xrJc/master" --zk_session_timeout="10secs"
I1024 09:26:56.004762 18653 master.cpp:492] Master only allowing authenticated frameworks to register
I1024 09:26:56.004781 18653 master.cpp:498] Master only allowing authenticated agents to register
I1024 09:26:56.004791 18653 master.cpp:504] Master only allowing authenticated HTTP frameworks to register
I1024 09:26:56.004803 18653 credentials.hpp:37] Loading credentials for authentication from '/tmp/19xrJc/credentials'
I1024 09:26:56.005204 18653 master.cpp:548] Using default 'crammd5' authenticator
I1024 09:26:56.005499 18653 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1024 09:26:56.005781 18653 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1024 09:26:56.005995 18653 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1024 09:26:56.006196 18653 master.cpp:629] Authorization enabled
I1024 09:26:56.006665 18670 hierarchical.cpp:567] Initialized hierarchical allocator process
I1024 09:26:56.006702 18668 whitelist_watcher.cpp:77] No whitelist given
I1024 09:26:56.010776 18656 master.cpp:2169] Elected as the leading master!
I1024 09:26:56.010810 18656 master.cpp:1665] Recovering from registrar
I1024 09:26:56.010995 18665 registrar.cpp:339] Recovering registrar
I1024 09:26:56.011801 18665 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I1024 09:26:56.011936 18665 registrar.cpp:487] Applied 1 operations in 39661ns; attempting to update the registry
I1024 09:26:56.012619 18665 registrar.cpp:544] Successfully updated the registry in 0ns
I1024 09:26:56.012763 18665 registrar.cpp:416] Successfully recovered registrar
I1024 09:26:56.013224 18652 hierarchical.cpp:606] Skipping recovery of hierarchical allocator: nothing to recover
I1024 09:26:56.013255 18655 master.cpp:1818] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
W1024 09:26:56.019343 18646 process.cpp:2877] Attempted to spawn already running process files@172.17.0.3:34124
I1024 09:26:56.020856 18646 containerizer.cpp:318] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W1024 09:26:56.021396 18646 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W1024 09:26:56.021426 18646 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W1024 09:26:56.021566 18646 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1024 09:26:56.021608 18646 provisioner.cpp:294] Using default backend 'copy'
I1024 09:26:56.024371 18646 cluster.cpp:524] Creating default 'local' authorizer
I1024 09:26:56.026846 18651 slave.cpp:267] Mesos agent started on (1249)@172.17.0.3:34124
I1024 09:26:56.026875 18651 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/19xrJc/XJGqiz/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/19xrJc/XJGqiz/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/19xrJc/XJGqiz/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/19xrJc/XJGqiz/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/19xrJc/XJGqiz/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/19xrJc/XJGqiz/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.10.0/
_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/19xrJc/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_1z0SDY" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TB8lZn" --zk_sessio
n_timeout="10secs"
I1024 09:26:56.027400 18651 credentials.hpp:86] Loading credential for authentication from '/tmp/19xrJc/XJGqiz/credential'
I1024 09:26:56.027611 18651 slave.cpp:300] Agent using credential for: test-principal
I1024 09:26:56.027637 18651 credentials.hpp:37] Loading credentials for authentication from '/tmp/19xrJc/XJGqiz/http_credentials'
I1024 09:26:56.027892 18651 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1024 09:26:56.028311 18651 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I1024 09:26:56.029958 18661 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I1024 09:26:56.030047 18651 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I1024 09:26:56.030294 18651 slave.cpp:623] Agent attributes: [ ]
I1024 09:26:56.030311 18651 slave.cpp:632] Agent hostname: 4208d5688280
I1024 09:26:56.030508 18667 task_status_update_manager.cpp:181] Pausing sending task status updates
I1024 09:26:56.030508 18657 status_update_manager_process.hpp:379] Pausing operation status update manager
I1024 09:26:56.032434 18658 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TB8lZn/meta'
I1024 09:26:56.032696 18650 slave.cpp:7492] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TB8lZn/meta', beginning agent recovery
I1024 09:26:56.033293 18666 task_status_update_manager.cpp:207] Recovering task status update manager
I1024 09:26:56.033802 18665 containerizer.cpp:821] Recovering Mesos containers
I1024 09:26:56.034235 18665 containerizer.cpp:1161] Recovering isolators
I1024 09:26:56.035149 18667 containerizer.cpp:1200] Recovering provisioner
I1024 09:26:56.035153 18653 hierarchical.cpp:1843] Performed allocation for 0 agents in 131370ns
I1024 09:26:56.035949 18656 provisioner.cpp:518] Provisioner recovery complete
I1024 09:26:56.036728 18652 composing.cpp:339] Finished recovering all containerizers
I1024 09:26:56.037031 18662 slave.cpp:7974] Recovering executors
I1024 09:26:56.037148 18662 slave.cpp:8127] Finished recovery
I1024 09:26:56.038085 18668 status_update_manager_process.hpp:379] Pausing operation status update manager
I1024 09:26:56.038089 18654 task_status_update_manager.cpp:181] Pausing sending task status updates
I1024 09:26:56.038120 18660 slave.cpp:1351] New master detected at master@172.17.0.3:34124
I1024 09:26:56.038290 18660 slave.cpp:1416] Detecting new master
I1024 09:26:56.045640 18665 slave.cpp:1443] Authenticating with master master@172.17.0.3:34124
I1024 09:26:56.045750 18665 slave.cpp:1452] Using default CRAM-MD5 authenticatee
I1024 09:26:56.046085 18661 authenticatee.cpp:121] Creating new client SASL connection
I1024 09:26:56.046428 18657 master.cpp:10594] Authenticating slave(1249)@172.17.0.3:34124
I1024 09:26:56.046583 18653 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2104)@172.17.0.3:34124
I1024 09:26:56.046869 18669 authenticator.cpp:98] Creating new server SASL connection
I1024 09:26:56.047107 18648 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1024 09:26:56.047140 18648 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1024 09:26:56.047279 18656 authenticator.cpp:204] Received SASL authentication start
I1024 09:26:56.047361 18656 authenticator.cpp:326] Authentication requires more steps
I1024 09:26:56.047497 18658 authenticatee.cpp:259] Received SASL authentication step
I1024 09:26:56.047647 18651 authenticator.cpp:232] Received SASL authentication step
I1024 09:26:56.047691 18651 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4208d5688280' server FQDN: '4208d5688280' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1024 09:26:56.047713 18651 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1024 09:26:56.047763 18651 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1024 09:26:56.047791 18651 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4208d5688280' server FQDN: '4208d5688280' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1024 09:26:56.047807 18651 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1024 09:26:56.047827 18651 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1024 09:26:56.047852 18651 authenticator.cpp:318] Authentication success
I1024 09:26:56.047966 18650 authenticatee.cpp:299] Authentication success
I1024 09:26:56.048063 18666 master.cpp:10626] Successfully authenticated principal 'test-principal' at slave(1249)@172.17.0.3:34124
I1024 09:26:56.048099 18664 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2104)@172.17.0.3:34124
I1024 09:26:56.048415 18659 slave.cpp:1543] Successfully authenticated with master master@172.17.0.3:34124
I1024 09:26:56.048842 18659 slave.cpp:1993] Will retry registration in 12.239783ms if necessary
I1024 09:26:56.049026 18663 master.cpp:7083] Received register agent message from slave(1249)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:56.049358 18663 master.cpp:4189] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I1024 09:26:56.050096 18649 master.cpp:7150] Authorized registration of agent at slave(1249)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:56.050204 18649 master.cpp:7262] Registering agent at slave(1249)@172.17.0.3:34124 (4208d5688280) with id 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0
I1024 09:26:56.050949 18665 registrar.cpp:487] Applied 1 operations in 252791ns; attempting to update the registry
I1024 09:26:56.051708 18665 registrar.cpp:544] Successfully updated the registry in 687872ns
I1024 09:26:56.051885 18648 master.cpp:7310] Admitted agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0 at slave(1249)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:56.052706 18648 master.cpp:7355] Registered agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0 at slave(1249)@172.17.0.3:34124 (4208d5688280) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1024 09:26:56.052836 18658 slave.cpp:1576] Registered with master master@172.17.0.3:34124; given agent ID 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0
I1024 09:26:56.052955 18666 task_status_update_manager.cpp:188] Resuming sending task status updates
I1024 09:26:56.052978 18656 hierarchical.cpp:955] Added agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0 (4208d5688280) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I1024 09:26:56.053351 18656 hierarchical.cpp:1843] Performed allocation for 1 agents in 181262ns
I1024 09:26:56.053365 18658 slave.cpp:1611] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TB8lZn/meta/slaves/6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0/slave.info'
I1024 09:26:56.053491 18647 status_update_manager_process.hpp:385] Resuming operation status update manager
I1024 09:26:56.054723 18658 slave.cpp:1663] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"cZjmMr9xRvmwecqevNJVgw=="},"slave_id":{"value":"6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0"},"update_oversubscribed_resources":false}
I1024 09:26:56.055409 18668 master.cpp:8474] Ignoring update on agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0 at slave(1249)@172.17.0.3:34124 (4208d5688280) as it reports no changes
I1024 09:26:56.059731 18665 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1'
I1024 09:26:56.060958 18647 http.cpp:1115] HTTP POST for /slave(1249)/api/v1 from 172.17.0.3:41036
I1024 09:26:56.061480 18647 http.cpp:2146] Processing GET_CONTAINERS call
I1024 09:26:56.066952 18661 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:56.069120 18665 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1'
I1024 09:26:56.070071 18647 http.cpp:1115] HTTP POST for /slave(1249)/api/v1 from 172.17.0.3:41038
I1024 09:26:56.070957 18647 http.cpp:2606] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:56.071818 18647 http.cpp:2710] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TB8lZn/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:56.072489 18663 containerizer.cpp:1396] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:56.073135 18663 containerizer.cpp:3318] 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 220928ns
I1024 09:26:56.073841 18663 containerizer.cpp:1574] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_1z0SDY/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I1024 09:26:56.073891 18663 containerizer.cpp:3318] 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 759040ns
I1024 09:26:56.076710 18649 containerizer.cpp:2100] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_XZfQkN","--available_capacity=0B","--volumes=","--forward=unix:///tmp/19xrJc/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.0/_build/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TB8lZn/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-AX52gW/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TB8lZn/containers/org-apache-mesos-rp-local
-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="92" --pipe_write="93" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_1z0SDY/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I1024 09:26:56.085572 18649 launcher.cpp:145] Forked child with pid '33014' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:56.086561 18649 containerizer.cpp:3318] 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 12.659968ms
I1024 09:26:56.087297 18651 hierarchical.cpp:1843] Performed allocation for 1 agents in 330677ns
I1024 09:26:56.088454 18649 containerizer.cpp:3318] 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.892864ms
I1024 09:26:56.088806 18658 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_TB8lZn/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:56.089926 18647 containerizer.cpp:3318] 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.407232ms
I1024 09:26:56.092527 18657 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'
I1024 09:26:56.092774 18667 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-AX52gW/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:56.138496 18665 hierarchical.cpp:1843] Performed allocation for 1 agents in 131385ns
I1024 09:26:56.190153 18660 hierarchical.cpp:1843] Performed allocation for 1 agents in 256517ns
I1024 09:26:56.241528 18657 hierarchical.cpp:1843] Performed allocation for 1 agents in 224737ns
I1024 09:26:56.293568 18655 hierarchical.cpp:1843] Performed allocation for 1 agents in 238750ns
I1024 09:26:56.345389 18651 hierarchical.cpp:1843] Performed allocation for 1 agents in 333249ns
I1024 09:26:56.397665 18647 hierarchical.cpp:1843] Performed allocation for 1 agents in 403025ns
I1024 09:26:56.449245 18661 hierarchical.cpp:1843] Performed allocation for 1 agents in 232899ns
I1024 09:26:56.500658 18656 hierarchical.cpp:1843] Performed allocation for 1 agents in 234769ns
I1024 09:26:56.552331 18660 hierarchical.cpp:1843] Performed allocation for 1 agents in 253469ns
I1024 09:26:56.589802 18659 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-AX52gW/endpoint.sock' with CSI v1
I1024 09:26:56.591579 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/Probe call
I1024 09:26:56.594182 18661 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:56.596518 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginCapabilities call
I1024 09:26:56.597790 18649 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1'
I1024 09:26:56.599040 18662 http.cpp:1115] HTTP POST for /slave(1249)/api/v1 from 172.17.0.3:41040
I1024 09:26:56.599599 18662 http.cpp:2824] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:56.600741 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call
I1024 09:26:56.601008 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call
I1024 09:26:56.602594 18666 v1_volume_manager.cpp:649] NODE_SERVICE loaded: {}
I1024 09:26:56.603049 18666 v1_volume_manager.cpp:649] CONTROLLER_SERVICE loaded: {}
I1024 09:26:56.603883 18652 hierarchical.cpp:1843] Performed allocation for 1 agents in 256681ns
I1024 09:26:56.605042 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ControllerGetCapabilities call
I1024 09:26:56.609086 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetCapabilities call
I1024 09:26:56.612920 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetInfo call
I1024 09:26:56.615535 18648 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I1024 09:26:56.615667 18661 status_update_manager_process.hpp:379] Pausing operation status update manager
I1024 09:26:56.616008 18653 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:34124/slave(1249)/api/v1/resource_provider
I1024 09:26:56.619716 18651 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.3:34124/slave(1249)/api/v1/resource_provider
I1024 09:26:56.620296 18664 provider.cpp:476] Connected to resource provider manager
I1024 09:26:56.620877 18663 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.3:34124/slave(1249)/api/v1/resource_provider
I1024 09:26:56.621924 18670 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider'
I1024 09:26:56.623591 18648 http.cpp:1115] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.3:41044
I1024 09:26:56.624259 18655 manager.cpp:813] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_XZfQkN","--available_capacity=0B","--volumes=","--forward=unix:///tmp/19xrJc/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}
I1024 09:26:56.655830 18649 hierarchical.cpp:1843] Performed allocation for 1 agents in 201268ns
I1024 09:26:56.673468 18647 slave.cpp:8483] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"a340197a-f6bf-4f1f-abd9-eca39d59403a"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_XZfQkN","--available_capacity=0B","--volumes=","--forward=unix:///tmp/19xrJc/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}'
I1024 09:26:56.674896 18654 provider.cpp:498] Received SUBSCRIBED event
I1024 09:26:56.674932 18654 provider.cpp:1309] Subscribed with ID a340197a-f6bf-4f1f-abd9-eca39d59403a
I1024 09:26:56.675777 18648 status_update_manager_process.hpp:314] Recovering operation status update manager
I1024 09:26:56.706900 18653 hierarchical.cpp:1843] Performed allocation for 1 agents in 117832ns
I1024 09:26:56.758548 18652 hierarchical.cpp:1843] Performed allocation for 1 agents in 114623ns
I1024 09:26:56.808665 18655 provider.cpp:790] Reconciling storage pools and volumes
I1024 09:26:56.809330 18658 hierarchical.cpp:1843] Performed allocation for 1 agents in 117293ns
I1024 09:26:56.810804 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I1024 09:26:56.813683 18661 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0
I1024 09:26:56.814069 18648 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.3:34124/slave(1249)/api/v1/resource_provider
I1024 09:26:56.814159 18661 provider.cpp:748] Resource provider a340197a-f6bf-4f1f-abd9-eca39d59403a is in READY state
I1024 09:26:56.814244 18653 status_update_manager_process.hpp:385] Resuming operation status update manager
I1024 09:26:56.814930 18656 provider.cpp:1235] Updating profiles { test } for resource provider a340197a-f6bf-4f1f-abd9-eca39d59403a
I1024 09:26:56.815984 18647 provider.cpp:790] Reconciling storage pools and volumes
I1024 09:26:56.816171 18660 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider'
I1024 09:26:56.817869 18652 http.cpp:1115] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.3:41042
I1024 09:26:56.818300 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I1024 09:26:56.818517 18656 manager.cpp:1045] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider a340197a-f6bf-4f1f-abd9-eca39d59403a
I1024 09:26:56.818625 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call
I1024 09:26:56.818809 18665 slave.cpp:8483] Handling resource provider message 'UPDATE_STATE: a340197a-f6bf-4f1f-abd9-eca39d59403a {}'
I1024 09:26:56.818910 18665 slave.cpp:8603] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1024 09:26:56.820508 18663 hierarchical.cpp:1100] Grew agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0 by {} (total), { } (used)
I1024 09:26:56.820888 18663 hierarchical.cpp:1057] Agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0 (4208d5688280) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I1024 09:26:56.825724 18651 hierarchical.cpp:1843] Performed allocation for 1 agents in 217313ns
I1024 09:26:56.826043 18658 provider.cpp:790] Reconciling storage pools and volumes
I1024 09:26:56.828099 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I1024 09:26:56.828959 33018 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call
I1024 09:26:56.839438 18651 slave.cpp:924] Agent terminating
I1024 09:26:56.840358 18651 manager.cpp:163] Terminating resource provider a340197a-f6bf-4f1f-abd9-eca39d59403a
I1024 09:26:56.840786 18652 master.cpp:1296] Agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0 at slave(1249)@172.17.0.3:34124 (4208d5688280) disconnected
I1024 09:26:56.840821 18652 master.cpp:3391] Disconnecting agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0 at slave(1249)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:56.840894 18652 master.cpp:3410] Deactivating agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0 at slave(1249)@172.17.0.3:34124 (4208d5688280)
I1024 09:26:56.841030 18649 hierarchical.cpp:1146] Agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0 deactivated
E1024 09:26:56.841241 18650 http_connection.hpp:452] End-Of-File received
I1024 09:26:56.841666 18650 http_connection.hpp:217] Re-detecting endpoint
I1024 09:26:56.842109 18650 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1024 09:26:56.842171 18667 provider.cpp:488] Disconnected from resource provider manager
I1024 09:26:56.842200 18650 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I1024 09:26:56.842293 18650 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:34124/slave(1249)/api/v1/resource_provider
I1024 09:26:56.842356 18667 status_update_manager_process.hpp:379] Pausing operation status update manager
I1024 09:26:56.843744 18653 containerizer.cpp:2620] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I1024 09:26:56.843807 18653 containerizer.cpp:3318] 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.753950976secs
I1024 09:26:56.844344 18653 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:56.846202 18656 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.3:34124/slave(1249)/api/v1/resource_provider
I1024 09:26:56.846734 18666 provider.cpp:476] Connected to resource provider manager
I1024 09:26:56.847295 18660 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.3:34124/slave(1249)/api/v1/resource_provider
I1024 09:26:56.848085 18671 process.cpp:2781] Returning '404 Not Found' for '/slave(1249)/api/v1/resource_provider'
E1024 09:26:56.849547 18663 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I1024 09:26:56.871626 18651 hierarchical.cpp:1843] Performed allocation for 1 agents in 153444ns
I1024 09:26:56.920689 18648 containerizer.cpp:3156] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I1024 09:26:56.922351 18670 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
I1024 09:26:56.923060 18659 hierarchical.cpp:1843] Performed allocation for 1 agents in 102342ns
I1024 09:26:56.924837 18655 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'
I1024 09:26:56.925015 18657 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-AX52gW/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I1024 09:26:56.925295 18648 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I1024 09:26:56.927742 18671 process.cpp:2781] Returning '404 Not Found' for '/slave(1249)/api/v1'
I1024 09:26:56.938822 18669 master.cpp:1137] Master terminating
I1024 09:26:56.939301 18657 hierarchical.cpp:1122] Removed all filters for agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0
I1024 09:26:56.939326 18657 hierarchical.cpp:998] Removed agent 6c384d3f-6e69-4154-a0bf-ecbc0c8b368f-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v1 (957 ms)
[----------] 54 tests from CSIVersion/StorageLocalResourceProviderTest (119189 ms total)
[----------] Global test environment tear-down
[==========] 2319 tests from 222 test cases ran. (1166438 ms total)
[ PASSED ] 2318 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ContentType/AgentAPITest.LaunchNestedContainerWithUnknownParent/1, where GetParam() = application/json
1 FAILED TEST
YOU HAVE 34 DISABLED TESTS
I1024 09:26:57.049013 18671 process.cpp:935] Stopped the socket accept loop
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-1.10.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.10.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.10.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.10.0/_build'
make: *** [distcheck] Error 1
+ docker rmi --force mesos-1571899339-20201
Untagged: mesos-1571899339-20201:latest
Deleted: sha256:6e6833ba3cc42a21ba020596dc8159627ea87134d15a1eec5b10d171787d1275
Deleted: sha256:c1d2ae4dfe6a2348dfa3448f25b07664ea6cb337c57b330007c3377d30429389
Deleted: sha256:93123b1c6d279a2514ef2a5bd28d5e3370e7fcb3cdb6da916e0cd0063fc8090a
Deleted: sha256:24c67047cd73b4556bb54ad4b87c51904ff66f3ff6dac3f97ba7e6c0614980e1
Deleted: sha256:a1f2934413989e96634692b8f41f899a363df2de448f4a085a8366b34906087b
Deleted: sha256:d0b7a68efd6f0bed166d3f7996bdd13a689eab3d172b04433fc6cd7f3b350d33
Deleted: sha256:7bcf62d89366232bb7c3ce300f5da9a3b282e5fd96dfa453c81ddff0f9c71521
Deleted: sha256:92fe231b79d783556cf26d8ed400b84fa260cb58682fb6ce165c5b07e5164047
Deleted: sha256:01e3a53af8385240af422f1cf8c2093886911564691e166649c8579c76c2aebf
Deleted: sha256:d7638dc1c8fe2b8e109a5ff317821d334799d224ce5d9d7be98d06a65056b42c
Deleted: sha256:4e009a1c58eb6e24d47191ef4b3405549e5f06998b2a7963e8942f9494a359ec
Deleted: sha256:4bf7f58e81f0d4f211de6de5186d13b2a45e2fc72ad353a7a11c78fe78d18737
Deleted: sha256:c231a348b1cf8780743a6425fbc7ff05c3d5b7c8ef8417be6b87a8a0f3ffab5a
Deleted: sha256:d03d90f82d5ed99e188014ddec340702d493ffbd6cfe5f171df836af7ae56824
Deleted: sha256:5a937a47efb134e78017daad5d7643da06baa33a576962755d472bf20ac3f155
Deleted: sha256:1285bbe0bf46827d16cc020de4fde28f28e8d14a2ccebb2ab739e7ccc4476bca
Deleted: sha256:5c27bcaaa948792296e516b39ac588ccf703efc3b1a93aa1c4097762fba4553f
Deleted: sha256:24d548e02ffbd3c7245a9fc39c16cd63c2fdb6ad7b8b786bb314e05515d888a6
Deleted: sha256:479fc29abbdc65815d35ef8c44987ea66d02fde988e85c1eb49cf4aca2802676
Deleted: sha256:43030c71e951fafa5e5afe9333ab61a3e384897b9b0d24b616a7e2956a7a324b
Deleted: sha256:5997a06c94094fdbf88851663f2b59a691d7cf6c07d6b99f862cbf9120110676
Deleted: sha256:aa8cb414b414309239ff2a39d383058c5827efbadad18e86ff1eb7f372bfb058
Deleted: sha256:7d3275545239a6d00e29f11c7fa2c23c47d8acd416c252d5359e4a74088093d5
Deleted: sha256:e1f0fa9edd3b3ca46bf3e11acde7f700ff3cf42ce326ec1f8a6092542ebb450b
Deleted: sha256:445f493607761021b80ecd93e5e0d8f33aa20529bcd13afcd7358eba9dce0881
Deleted: sha256:a96dd5011b482216d44a11933de07b441d809dbf8903bf479c71e0807fbe548d
Deleted: sha256:26936523a72f9197a3d34e53e8c424db26511d11eda3f8e66ad26f92ee4f0488
Deleted: sha256:0f7897da5877e5f2c817a3ebcb10258a5662bf212e87c17228f20e21a0c5c48c
Deleted: sha256:606a0f4cdd76c341a3211a5c976530d49d717aa7fb74e8222411684f32b17c50
Deleted: sha256:d05347878a614d0caa0c4a6e58fb4ea0f4311acd1c436d0cb04bf2866ba05ef7
Full log: https://builds.apache.org/job/Mesos-Reviewbot-Linux/4510/console
- Mesos Reviewbot
On Oct. 24, 2019, 2:56 a.m., Meng Zhu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71639/
> -----------------------------------------------------------
>
> (Updated Oct. 24, 2019, 2:56 a.m.)
>
>
> Review request for mesos, Andrei Sekretenko and Benjamin Mahler.
>
>
> Bugs: MESOS-10016
> https://issues.apache.org/jira/browse/MESOS-10016
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This benchmark evaluates the performance of
> `allocator->UpdateAllocation()` where the agent has various
> sizes of resource reservations.
>
>
> Diffs
> -----
>
> src/tests/hierarchical_allocator_tests.cpp 38fd19cee6409e4daa5bb0ab523e8e464cdcc9a5
>
>
> Diff: https://reviews.apache.org/r/71639/diff/2/
>
>
> Testing
> -------
>
> On the master branch optimized build:
>
> ```
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/0
> Agent resources size: 50 (50 roles, 1 reservations per role, 1 ranges per port resources)
> 20 reservation operations took 442.402455ms, each takes 22.120122ms
> 20 Unreservation operations took 464.085487ms, each takes 23.204274ms
>
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/1
> Agent resources size: 100 (100 roles, 1 reservations per role, 1 ranges per port resources)
> 20 reservation operations took 1.321309035secs, each takes 66.065451ms
> 20 Unreservation operations took 1.311244246secs, each takes 65.562212ms
>
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/2
> Agent resources size: 200 (200 roles, 1 reservations per role, 1 ranges per port resources)
> 20 reservation operations took 4.129166934secs, each takes 206.458346ms
> 20 Unreservation operations took 4.041358384secs, each takes 202.067919ms
>
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/3
> Agent resources size: 400 (400 roles, 1 reservations per role, 1 ranges per port resources)
> 20 reservation operations took 15.011075671secs, each takes 750.553783ms
> 20 Unreservation operations took 15.41327483secs, each takes 770.663741ms
>
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/4
> Agent resources size: 600 (600 roles, 1 reservations per role, 1 ranges per port resources)
> 20 reservation operations took 31.159754828secs, each takes 1.557987741secs
> 20 Unreservation operations took 30.69454178secs, each takes 1.534727089secs
> ```
>
>
> Thanks,
>
> Meng Zhu
>
>
Re: Review Request 71639: Added an benchmark for
`allocator->UpdateAllocation()`.
Posted by Meng Zhu <mz...@mesosphere.io>.
> On Oct. 24, 2019, 7:21 a.m., Andrei Sekretenko wrote:
> > src/tests/hierarchical_allocator_tests.cpp
> > Lines 8414 (patched)
> > <https://reviews.apache.org/r/71639/diff/2/?file=2170111#file2170111line8414>
> >
> > Wouldn't the order of parameters look more intuitive if it were (roleCount, reservationCount, portRangeCount)?
> >
> > After all, reservationCount is a count of reservations per role, and portRangeCount is per-reservation, right?
sounds good.
> On Oct. 24, 2019, 7:21 a.m., Andrei Sekretenko wrote:
> > src/tests/hierarchical_allocator_tests.cpp
> > Lines 8440 (patched)
> > <https://reviews.apache.org/r/71639/diff/2/?file=2170111#file2170111line8440>
> >
> > Why not just use UUIDs?
wanted to control the length of labels and etc.
> On Oct. 24, 2019, 7:21 a.m., Andrei Sekretenko wrote:
> > src/tests/hierarchical_allocator_tests.cpp
> > Lines 8464 (patched)
> > <https://reviews.apache.org/r/71639/diff/2/?file=2170111#file2170111line8464>
> >
> > All the roles will be the same, right?
> >
> > We should either generate different child roles, or use a single role, rename `rolesCount` into `frameworksCount` and reword the comments.
> >
> > (If I'm not missing something, under current architecture of the allocator performance of updateAllocation() doesn't repend on number of roles, but we should probably make this benchmark multi-role in case this changes in the future).
Thanks for catching this. I meant to use `std::generate`. Fixed.
> On Oct. 24, 2019, 7:21 a.m., Andrei Sekretenko wrote:
> > src/tests/hierarchical_allocator_tests.cpp
> > Lines 8528-8550 (patched)
> > <https://reviews.apache.org/r/71639/diff/2/?file=2170111#file2170111line8528>
> >
> > Looks very similar to the loop body - can't we reuse part of that code? or maybe just use the last reservation of the last added framework for the UNRESERVE/RESERVE loop?
Good point.
> On Oct. 24, 2019, 7:21 a.m., Andrei Sekretenko wrote:
> > src/tests/hierarchical_allocator_tests.cpp
> > Lines 8606 (patched)
> > <https://reviews.apache.org/r/71639/diff/2/?file=2170111#file2170111line8606>
> >
> > s/ranges per port resources/port range resources per reservation/ ?
I think it should be "ranges per port resource", ranges are combined into one port resource.
- Meng
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71639/#review218386
-----------------------------------------------------------
On Oct. 28, 2019, 8:43 p.m., Meng Zhu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71639/
> -----------------------------------------------------------
>
> (Updated Oct. 28, 2019, 8:43 p.m.)
>
>
> Review request for mesos, Andrei Sekretenko and Benjamin Mahler.
>
>
> Bugs: MESOS-10016
> https://issues.apache.org/jira/browse/MESOS-10016
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This benchmark evaluates the performance of
> `allocator->UpdateAllocation()` where the agent has various
> sizes of resource reservations.
>
>
> Diffs
> -----
>
> src/tests/hierarchical_allocator_tests.cpp 38fd19cee6409e4daa5bb0ab523e8e464cdcc9a5
>
>
> Diff: https://reviews.apache.org/r/71639/diff/3/
>
>
> Testing
> -------
>
> On the master branch optimized build:
>
> ```
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/0
> Agent resources size: 50 (50 roles, 1 reservations per role, 1 ranges per port resource)
> 20 RESERVE operations took 1.968569746secs, each takes 98.428487ms
> 20 UNRESERVE operations took 1.978470742secs, each takes 98.923537ms
> [ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/0 (3996 ms)
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/1
> Agent resources size: 100 (100 roles, 1 reservations per role, 1 ranges per port resource)
> 20 RESERVE operations took 10.094084426secs, each takes 504.704221ms
> 20 UNRESERVE operations took 10.293614069secs, each takes 514.680703ms
> [ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/1 (20584 ms)
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/2
> Agent resources size: 200 (200 roles, 1 reservations per role, 1 ranges per port resource)
> 20 RESERVE operations took 1.16018705933333mins, each takes 3.480561178secs
> 20 UNRESERVE operations took 1.17209781845mins, each takes 3.516293455secs
> [ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/2 (141363 ms)
> ```
>
>
> Thanks,
>
> Meng Zhu
>
>
Re: Review Request 71639: Added an benchmark for
`allocator->UpdateAllocation()`.
Posted by Andrei Sekretenko <as...@mesosphere.io>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71639/#review218386
-----------------------------------------------------------
Many thanks for this benchmark!
Even in its WIP version it already helped to understand what is wrong with `updateAllocation()`.
src/tests/hierarchical_allocator_tests.cpp
Lines 8414 (patched)
<https://reviews.apache.org/r/71639/#comment306089>
Wouldn't the order of parameters look more intuitive if it were (roleCount, reservationCount, portRangeCount)?
After all, reservationCount is a count of reservations per role, and portRangeCount is per-reservation, right?
src/tests/hierarchical_allocator_tests.cpp
Lines 8440 (patched)
<https://reviews.apache.org/r/71639/#comment306090>
Why not just use UUIDs?
src/tests/hierarchical_allocator_tests.cpp
Lines 8455 (patched)
<https://reviews.apache.org/r/71639/#comment306093>
const ?
src/tests/hierarchical_allocator_tests.cpp
Lines 8464 (patched)
<https://reviews.apache.org/r/71639/#comment306091>
All the roles will be the same, right?
We should either generate different child roles, or use a single role, rename `rolesCount` into `frameworksCount` and reword the comments.
(If I'm not missing something, under current architecture of the allocator performance of updateAllocation() doesn't repend on number of roles, but we should probably make this benchmark multi-role in case this changes in the future).
src/tests/hierarchical_allocator_tests.cpp
Lines 8473 (patched)
<https://reviews.apache.org/r/71639/#comment306092>
emplace(framework.id(), Resources()) ?
src/tests/hierarchical_allocator_tests.cpp
Lines 8528-8550 (patched)
<https://reviews.apache.org/r/71639/#comment306094>
Looks very similar to the loop body - can't we reuse part of that code? or maybe just use the last reservation of the last added framework for the UNRESERVE/RESERVE loop?
src/tests/hierarchical_allocator_tests.cpp
Lines 8606 (patched)
<https://reviews.apache.org/r/71639/#comment306096>
s/ranges per port resources/port range resources per reservation/ ?
src/tests/hierarchical_allocator_tests.cpp
Lines 8608-8611 (patched)
<https://reviews.apache.org/r/71639/#comment306095>
I would suggest `RESERVE operations` and `UNRESERVE operations` - we have terms for them, don't we?
- Andrei Sekretenko
On Oct. 24, 2019, 2:56 a.m., Meng Zhu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71639/
> -----------------------------------------------------------
>
> (Updated Oct. 24, 2019, 2:56 a.m.)
>
>
> Review request for mesos, Andrei Sekretenko and Benjamin Mahler.
>
>
> Bugs: MESOS-10016
> https://issues.apache.org/jira/browse/MESOS-10016
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This benchmark evaluates the performance of
> `allocator->UpdateAllocation()` where the agent has various
> sizes of resource reservations.
>
>
> Diffs
> -----
>
> src/tests/hierarchical_allocator_tests.cpp 38fd19cee6409e4daa5bb0ab523e8e464cdcc9a5
>
>
> Diff: https://reviews.apache.org/r/71639/diff/2/
>
>
> Testing
> -------
>
> On the master branch optimized build:
>
> ```
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/0
> Agent resources size: 50 (50 roles, 1 reservations per role, 1 ranges per port resources)
> 20 reservation operations took 442.402455ms, each takes 22.120122ms
> 20 Unreservation operations took 464.085487ms, each takes 23.204274ms
>
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/1
> Agent resources size: 100 (100 roles, 1 reservations per role, 1 ranges per port resources)
> 20 reservation operations took 1.321309035secs, each takes 66.065451ms
> 20 Unreservation operations took 1.311244246secs, each takes 65.562212ms
>
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/2
> Agent resources size: 200 (200 roles, 1 reservations per role, 1 ranges per port resources)
> 20 reservation operations took 4.129166934secs, each takes 206.458346ms
> 20 Unreservation operations took 4.041358384secs, each takes 202.067919ms
>
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/3
> Agent resources size: 400 (400 roles, 1 reservations per role, 1 ranges per port resources)
> 20 reservation operations took 15.011075671secs, each takes 750.553783ms
> 20 Unreservation operations took 15.41327483secs, each takes 770.663741ms
>
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/4
> Agent resources size: 600 (600 roles, 1 reservations per role, 1 ranges per port resources)
> 20 reservation operations took 31.159754828secs, each takes 1.557987741secs
> 20 Unreservation operations took 30.69454178secs, each takes 1.534727089secs
> ```
>
>
> Thanks,
>
> Meng Zhu
>
>
Re: Review Request 71639: Added an benchmark for
`allocator->UpdateAllocation()`.
Posted by Andrei Sekretenko <as...@mesosphere.io>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71639/#review218460
-----------------------------------------------------------
Fix it, then Ship it!
src/tests/hierarchical_allocator_tests.cpp
Lines 8384-8393 (patched)
<https://reviews.apache.org/r/71639/#comment306191>
Not sure that this is a right place for this comment, especially the part describing what each reservation contains. After all, things stated in this comment are not a responsibility of the `ResourceParam` struct. Rather, this is how `UpdateAllocation` behcnmark uses these parameters (which is described in the comments below).
src/tests/hierarchical_allocator_tests.cpp
Lines 8408 (patched)
<https://reviews.apache.org/r/71639/#comment306189>
Shouldn't that be "exactly", not "more than"?
Also, "unique"/"distinct"/"random" would probably be a better word than "various" (IMO, "various" does not indicate that all the individual `Resource`s have different metadata to make them non-addable).
src/tests/hierarchical_allocator_tests.cpp
Lines 8425-8427 (patched)
<https://reviews.apache.org/r/71639/#comment306190>
I would suggest slightly rewording this: "Each set of reservations contains some cpu, memory, disk and port (number of ranges is controlled by `portRangeCount`) with a random label, and is allocated to a framework."
src/tests/hierarchical_allocator_tests.cpp
Lines 8429 (patched)
<https://reviews.apache.org/r/71639/#comment306188>
s/a "loop" framework/one of the frameworks/ ?
src/tests/hierarchical_allocator_tests.cpp
Lines 8510 (patched)
<https://reviews.apache.org/r/71639/#comment306187>
Outdated comment? (There is no dedicated loop role now.)
src/tests/hierarchical_allocator_tests.cpp
Lines 8569 (patched)
<https://reviews.apache.org/r/71639/#comment306186>
If we want to print agent resources size, shouldn't that be `param.reservationCount * param.roleCount * RESOURCE_NAMES.size()` or `agentResources.size()`?
Alternatively, words `Agent resources size` can be replaced by more precise `Total number of reservations`.
- Andrei Sekretenko
On Oct. 29, 2019, 3:43 a.m., Meng Zhu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71639/
> -----------------------------------------------------------
>
> (Updated Oct. 29, 2019, 3:43 a.m.)
>
>
> Review request for mesos, Andrei Sekretenko and Benjamin Mahler.
>
>
> Bugs: MESOS-10016
> https://issues.apache.org/jira/browse/MESOS-10016
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This benchmark evaluates the performance of
> `allocator->UpdateAllocation()` where the agent has various
> sizes of resource reservations.
>
>
> Diffs
> -----
>
> src/tests/hierarchical_allocator_tests.cpp 38fd19cee6409e4daa5bb0ab523e8e464cdcc9a5
>
>
> Diff: https://reviews.apache.org/r/71639/diff/3/
>
>
> Testing
> -------
>
> On the master branch optimized build:
>
> ```
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/0
> Agent resources size: 50 (50 roles, 1 reservations per role, 1 ranges per port resource)
> 20 RESERVE operations took 1.968569746secs, each takes 98.428487ms
> 20 UNRESERVE operations took 1.978470742secs, each takes 98.923537ms
> [ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/0 (3996 ms)
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/1
> Agent resources size: 100 (100 roles, 1 reservations per role, 1 ranges per port resource)
> 20 RESERVE operations took 10.094084426secs, each takes 504.704221ms
> 20 UNRESERVE operations took 10.293614069secs, each takes 514.680703ms
> [ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/1 (20584 ms)
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/2
> Agent resources size: 200 (200 roles, 1 reservations per role, 1 ranges per port resource)
> 20 RESERVE operations took 1.16018705933333mins, each takes 3.480561178secs
> 20 UNRESERVE operations took 1.17209781845mins, each takes 3.516293455secs
> [ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/2 (141363 ms)
> ```
>
>
> Thanks,
>
> Meng Zhu
>
>
Re: Review Request 71639: Added an benchmark for
`allocator->UpdateAllocation()`.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71639/#review218432
-----------------------------------------------------------
Patch looks great!
Reviews applied: [71639]
Passed command: export OS='ubuntu:14.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/docker-build.sh
- Mesos Reviewbot
On Oct. 29, 2019, 3:43 a.m., Meng Zhu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71639/
> -----------------------------------------------------------
>
> (Updated Oct. 29, 2019, 3:43 a.m.)
>
>
> Review request for mesos, Andrei Sekretenko and Benjamin Mahler.
>
>
> Bugs: MESOS-10016
> https://issues.apache.org/jira/browse/MESOS-10016
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This benchmark evaluates the performance of
> `allocator->UpdateAllocation()` where the agent has various
> sizes of resource reservations.
>
>
> Diffs
> -----
>
> src/tests/hierarchical_allocator_tests.cpp 38fd19cee6409e4daa5bb0ab523e8e464cdcc9a5
>
>
> Diff: https://reviews.apache.org/r/71639/diff/3/
>
>
> Testing
> -------
>
> On the master branch optimized build:
>
> ```
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/0
> Agent resources size: 50 (50 roles, 1 reservations per role, 1 ranges per port resource)
> 20 RESERVE operations took 1.968569746secs, each takes 98.428487ms
> 20 UNRESERVE operations took 1.978470742secs, each takes 98.923537ms
> [ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/0 (3996 ms)
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/1
> Agent resources size: 100 (100 roles, 1 reservations per role, 1 ranges per port resource)
> 20 RESERVE operations took 10.094084426secs, each takes 504.704221ms
> 20 UNRESERVE operations took 10.293614069secs, each takes 514.680703ms
> [ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/1 (20584 ms)
> [ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/2
> Agent resources size: 200 (200 roles, 1 reservations per role, 1 ranges per port resource)
> 20 RESERVE operations took 1.16018705933333mins, each takes 3.480561178secs
> 20 UNRESERVE operations took 1.17209781845mins, each takes 3.516293455secs
> [ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/2 (141363 ms)
> ```
>
>
> Thanks,
>
> Meng Zhu
>
>
Re: Review Request 71639: Added an benchmark for
`allocator->UpdateAllocation()`.
Posted by Meng Zhu <mz...@mesosphere.io>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71639/
-----------------------------------------------------------
(Updated Oct. 28, 2019, 8:43 p.m.)
Review request for mesos, Andrei Sekretenko and Benjamin Mahler.
Changes
-------
Addressed Andrei's comment.
Bugs: MESOS-10016
https://issues.apache.org/jira/browse/MESOS-10016
Repository: mesos
Description
-------
This benchmark evaluates the performance of
`allocator->UpdateAllocation()` where the agent has various
sizes of resource reservations.
Diffs (updated)
-----
src/tests/hierarchical_allocator_tests.cpp 38fd19cee6409e4daa5bb0ab523e8e464cdcc9a5
Diff: https://reviews.apache.org/r/71639/diff/3/
Changes: https://reviews.apache.org/r/71639/diff/2-3/
Testing (updated)
-------
On the master branch optimized build:
```
[ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/0
Agent resources size: 50 (50 roles, 1 reservations per role, 1 ranges per port resource)
20 RESERVE operations took 1.968569746secs, each takes 98.428487ms
20 UNRESERVE operations took 1.978470742secs, each takes 98.923537ms
[ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/0 (3996 ms)
[ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/1
Agent resources size: 100 (100 roles, 1 reservations per role, 1 ranges per port resource)
20 RESERVE operations took 10.094084426secs, each takes 504.704221ms
20 UNRESERVE operations took 10.293614069secs, each takes 514.680703ms
[ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/1 (20584 ms)
[ RUN ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/2
Agent resources size: 200 (200 roles, 1 reservations per role, 1 ranges per port resource)
20 RESERVE operations took 1.16018705933333mins, each takes 3.480561178secs
20 UNRESERVE operations took 1.17209781845mins, each takes 3.516293455secs
[ OK ] ResourceParam/HierarchicalAllocator__BENCHMARK_WithResourceParam.UpdateAllocation/2 (141363 ms)
```
Thanks,
Meng Zhu