mesos-reviews mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Mesos Reviewbot <revi...@mesos.apache.org>
Subject Re: Review Request 71639: Added an benchmark for `allocator->UpdateAllocation()`.
Date Thu, 24 Oct 2019 09:27:12 GMT

-----------------------------------------------------------
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
> 
>


Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message