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 72233: Fixed undefined behavior in ActionObject::reserve.
Date Fri, 13 Mar 2020 00:07:03 GMT

-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/72233/#review219929
-----------------------------------------------------------



Bad patch!

Reviews applied: [72233]

Failed command: ['bash', '-c', "set -o pipefail; export OS='ubuntu:16.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/jenkins/buildbot.sh 2>&1 | tee build_72233"]

Error:
...<truncated>...
atus update OPERATION_FINISHED (Status UUID: 8bd91c02-2b7a-4d76-8a5b-4ac211bee585) for operation UUID 98d3bdb4-9d59-433b-adac-3668a25ed339 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.156639  3082 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:43769/slave(1237)/api/v1/resource_provider
I0313 00:06:49.158118  3096 process.cpp:3671] Handling HTTP event for process 'slave(1237)' with path: '/slave(1237)/api/v1/resource_provider'
I0313 00:06:49.162569  3088 hierarchical.cpp:1853] Performed allocation for 1 agents in 1.764905ms
I0313 00:06:49.163259  3092 master.cpp:9485] Sending offers [ a330d48b-9410-478c-8b3a-a92f5a5a0d6e-O3 ] to framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 (default) at scheduler-7415ea59-81b7-4f70-a422-878b18b00742@172.17.0.2:43769
I0313 00:06:49.163908  3092 sched.cpp:934] Scheduler::resourceOffers took 82296ns
I0313 00:06:49.167528  3085 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0313 00:06:49.170282  3083 http.cpp:1405] HTTP POST for /master/api/v1 from 172.17.0.2:59554
I0313 00:06:49.170552  3083 http.cpp:277] Processing call CREATE_VOLUMES
I0313 00:06:49.171536  3083 master.cpp:3705] Authorizing principal 'test-principal' to perform action CREATE_VOLUME on object {"value":"storage/default-role","resource":{"provider_id":{"value":"09cf7286-d072-4e9f-b244-fac5e5f263af"},"name":"disk","type":"SCALAR","scalar":{"value":2048.0},"reservations":[{"type":"DYNAMIC","role":"storage"},{"type":"DYNAMIC","role":"storage/default-role","principal":"test-principal"}],"disk":{"persistence":{"id":"a19b626b-4ba9-4163-8cb8-4af013820fd3","principal":"test-principal"},"volume":{"mode":"RW","container_path":"volume"},"source":{"type":"MOUNT","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"vendor":"org.apache.mesos.csi.test.local","id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1NRe6/2GB-0e93e415-ba68-4b66-bf0d-7bc7611ba6aa","profile":"test"}}}}
I0313 00:06:49.173388  3091 sched.cpp:960] Rescinded offer a330d48b-9410-478c-8b3a-a92f5a5a0d6e-O3
I0313 00:06:49.173463  3091 sched.cpp:971] Scheduler::offerRescinded took 23066ns
I0313 00:06:49.173961  3092 hierarchical.cpp:1576] Recovered ports(allocated: storage/default-role):[31000-32000]; disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1NRe6/2GB-0e93e415-ba68-4b66-bf0d-7bc7611ba6aa,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_u1NRe6/2GB-0e93e415-ba68-4b66-bf0d-7bc7611ba6aa,test)]:2048, offered or allocated: {}) on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 from framework a330d
 48b-9410-478c-8b3a-a92f5a5a0d6e-0000
I0313 00:06:49.174172  3096 master.cpp:11784] Removing offer a330d48b-9410-478c-8b3a-a92f5a5a0d6e-O3
I0313 00:06:49.175734  3092 hierarchical.cpp:1625] Framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 filtered agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 for 5secs
I0313 00:06:49.178416  3085 master.cpp:11649] Sending operation '' (uuid: 17a3a443-f24e-4549-ba5a-31cb147963f5) to agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 at slave(1237)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:49.179114  3087 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version
I0313 00:06:49.182605  3090 provider.cpp:498] Received APPLY_OPERATION event
I0313 00:06:49.182662  3090 provider.cpp:1351] Received CREATE operation '' (uuid: 17a3a443-f24e-4549-ba5a-31cb147963f5)
I0313 00:06:49.185658  3086 master.cpp:5533] Processing REVIVE call for framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 (default) at scheduler-7415ea59-81b7-4f70-a422-878b18b00742@172.17.0.2:43769
I0313 00:06:49.186375  3086 hierarchical.cpp:1721] Unsuppressed offers and cleared filters for roles { storage/default-role } of framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000
I0313 00:06:49.187953  3086 hierarchical.cpp:1853] Performed allocation for 1 agents in 1.307842ms
I0313 00:06:49.188395  3086 hierarchical.cpp:1853] Performed allocation for 1 agents in 209409ns
I0313 00:06:49.188756  3089 master.cpp:9485] Sending offers [ a330d48b-9410-478c-8b3a-a92f5a5a0d6e-O4 ] to framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 (default) at scheduler-7415ea59-81b7-4f70-a422-878b18b00742@172.17.0.2:43769
I0313 00:06:49.189604  3081 sched.cpp:934] Scheduler::resourceOffers took 108479ns
I0313 00:06:49.201472  3096 http.cpp:1405] HTTP POST for /slave(1237)/api/v1/resource_provider from 172.17.0.2:59548
I0313 00:06:49.202409  3092 slave.cpp:8597] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 98d3bdb4-9d59-433b-adac-3668a25ed339) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0313 00:06:49.202567  3092 slave.cpp:9050] Updating the state of operation with no ID (uuid: 98d3bdb4-9d59-433b-adac-3668a25ed339) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0313 00:06:49.202613  3092 slave.cpp:8804] Forwarding status update of operation with no ID (operation_uuid: 98d3bdb4-9d59-433b-adac-3668a25ed339) for an operator API call
I0313 00:06:49.202987  3085 master.cpp:11301] Updating the state of operation '' (uuid: 98d3bdb4-9d59-433b-adac-3668a25ed339) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0313 00:06:49.203852  3093 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version
I0313 00:06:49.289564  3092 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: de013c45-2628-402b-b4e2-b95499d3a5fd) for operation UUID 17a3a443-f24e-4549-ba5a-31cb147963f5 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.289623  3090 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0313 00:06:49.289636  3092 status_update_manager_process.hpp:414] Creating operation status update stream 17a3a443-f24e-4549-ba5a-31cb147963f5 checkpoint=true
I0313 00:06:49.289903  3092 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: de013c45-2628-402b-b4e2-b95499d3a5fd) for operation UUID 17a3a443-f24e-4549-ba5a-31cb147963f5 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.362073  3092 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: de013c45-2628-402b-b4e2-b95499d3a5fd) for operation UUID 17a3a443-f24e-4549-ba5a-31cb147963f5 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.362403  3092 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 8bd91c02-2b7a-4d76-8a5b-4ac211bee585) for stream 98d3bdb4-9d59-433b-adac-3668a25ed339
I0313 00:06:49.362478  3092 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 8bd91c02-2b7a-4d76-8a5b-4ac211bee585) for operation UUID 98d3bdb4-9d59-433b-adac-3668a25ed339 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.363095  3088 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:43769/slave(1237)/api/v1/resource_provider
I0313 00:06:49.364243  3089 process.cpp:3671] Handling HTTP event for process 'slave(1237)' with path: '/slave(1237)/api/v1/resource_provider'
I0313 00:06:49.405709  3083 http.cpp:1405] HTTP POST for /slave(1237)/api/v1/resource_provider from 172.17.0.2:59548
I0313 00:06:49.407053  3084 slave.cpp:8597] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 17a3a443-f24e-4549-ba5a-31cb147963f5) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0313 00:06:49.407313  3084 slave.cpp:9050] Updating the state of operation with no ID (uuid: 17a3a443-f24e-4549-ba5a-31cb147963f5) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0313 00:06:49.407400  3084 slave.cpp:8804] Forwarding status update of operation with no ID (operation_uuid: 17a3a443-f24e-4549-ba5a-31cb147963f5) for an operator API call
I0313 00:06:49.407866  3090 master.cpp:11301] Updating the state of operation '' (uuid: 17a3a443-f24e-4549-ba5a-31cb147963f5) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0313 00:06:49.408469  3088 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version
I0313 00:06:49.410112  3083 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0313 00:06:49.412149  3092 status_update_manager_process.hpp:490] Cleaning up operation status update stream 98d3bdb4-9d59-433b-adac-3668a25ed339
I0313 00:06:49.412338  3092 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: de013c45-2628-402b-b4e2-b95499d3a5fd) for stream 17a3a443-f24e-4549-ba5a-31cb147963f5
I0313 00:06:49.412403  3092 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: de013c45-2628-402b-b4e2-b95499d3a5fd) for operation UUID 17a3a443-f24e-4549-ba5a-31cb147963f5 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.482355  3092 status_update_manager_process.hpp:490] Cleaning up operation status update stream 17a3a443-f24e-4549-ba5a-31cb147963f5
I0313 00:06:49.543581  3093 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0313 00:06:49.546072  3081 http.cpp:1405] HTTP POST for /master/api/v1 from 172.17.0.2:59556
I0313 00:06:49.546350  3081 http.cpp:277] Processing call DESTROY_VOLUMES
I0313 00:06:49.547482  3081 master.cpp:3705] Authorizing principal 'test-principal' to perform action DESTROY_VOLUME on object {"value":"test-principal","resource":{"provider_id":{"value":"09cf7286-d072-4e9f-b244-fac5e5f263af"},"name":"disk","type":"SCALAR","scalar":{"value":2048.0},"reservations":[{"type":"DYNAMIC","role":"storage"},{"type":"DYNAMIC","role":"storage/default-role","principal":"test-principal"}],"disk":{"persistence":{"id":"a19b626b-4ba9-4163-8cb8-4af013820fd3","principal":"test-principal"},"volume":{"mode":"RW","container_path":"volume"},"source":{"type":"MOUNT","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"vendor":"org.apache.mesos.csi.test.local","id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1NRe6/2GB-0e93e415-ba68-4b66-bf0d-7bc7611ba6aa","profile":"test"}}}}
I0313 00:06:49.549583  3083 sched.cpp:960] Rescinded offer a330d48b-9410-478c-8b3a-a92f5a5a0d6e-O4
I0313 00:06:49.549680  3083 sched.cpp:971] Scheduler::offerRescinded took 26200ns
I0313 00:06:49.550285  3092 hierarchical.cpp:1576] Recovered ports(allocated: storage/default-role):[31000-32000]; disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1NRe6/2GB-0e93e415-ba68-4b66-bf0d-7bc7611ba6aa,test),a19b626b-4ba9-4163-8cb8-4af013820fd3: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_u1NRe6/2GB-0e93e415-ba68-4b66-bf0d-7bc7611ba6aa,test),a19b626b-4ba9-4163-8cb8-4af013820fd3:volume]:2048, offered
  or allocated: {}) on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 from framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000
I0313 00:06:49.550417  3082 master.cpp:11784] Removing offer a330d48b-9410-478c-8b3a-a92f5a5a0d6e-O4
I0313 00:06:49.552570  3092 hierarchical.cpp:1625] Framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 filtered agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 for 5secs
I0313 00:06:49.556190  3090 master.cpp:11649] Sending operation '' (uuid: e911cdb4-91d1-40ce-a165-f65a79f0eaa3) to agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 at slave(1237)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:49.556963  3089 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version
I0313 00:06:49.560705  3084 provider.cpp:498] Received APPLY_OPERATION event
I0313 00:06:49.560770  3084 provider.cpp:1351] Received DESTROY operation '' (uuid: e911cdb4-91d1-40ce-a165-f65a79f0eaa3)
I0313 00:06:49.564193  3085 hierarchical.cpp:1853] Performed allocation for 1 agents in 1.229909ms
I0313 00:06:49.564985  3096 master.cpp:9485] Sending offers [ a330d48b-9410-478c-8b3a-a92f5a5a0d6e-O5 ] to framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 (default) at scheduler-7415ea59-81b7-4f70-a422-878b18b00742@172.17.0.2:43769
I0313 00:06:49.565783  3096 sched.cpp:934] Scheduler::resourceOffers took 91443ns
I0313 00:06:49.658778  3093 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 14a09f2f-85d2-44e2-869d-a632a4e76a17) for operation UUID e911cdb4-91d1-40ce-a165-f65a79f0eaa3 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.658870  3093 status_update_manager_process.hpp:414] Creating operation status update stream e911cdb4-91d1-40ce-a165-f65a79f0eaa3 checkpoint=true
I0313 00:06:49.659224  3093 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 14a09f2f-85d2-44e2-869d-a632a4e76a17) for operation UUID e911cdb4-91d1-40ce-a165-f65a79f0eaa3 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.724579  3093 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 14a09f2f-85d2-44e2-869d-a632a4e76a17) for operation UUID e911cdb4-91d1-40ce-a165-f65a79f0eaa3 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.725620  3089 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:43769/slave(1237)/api/v1/resource_provider
I0313 00:06:49.726660  3088 process.cpp:3671] Handling HTTP event for process 'slave(1237)' with path: '/slave(1237)/api/v1/resource_provider'
I0313 00:06:49.730278  3083 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0313 00:06:49.732432  3084 http.cpp:1405] HTTP POST for /master/api/v1 from 172.17.0.2:59558
I0313 00:06:49.732772  3084 http.cpp:277] Processing call UNRESERVE_RESOURCES
I0313 00:06:49.733669  3084 master.cpp:3705] Authorizing principal 'test-principal' to perform action UNRESERVE_RESOURCES on object {"value":"test-principal","resource":{"provider_id":{"value":"09cf7286-d072-4e9f-b244-fac5e5f263af"},"name":"disk","type":"SCALAR","scalar":{"value":2048.0},"reservations":[{"type":"DYNAMIC","role":"storage"},{"type":"DYNAMIC","role":"storage/default-role","principal":"test-principal"}],"disk":{"source":{"type":"MOUNT","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"vendor":"org.apache.mesos.csi.test.local","id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1NRe6/2GB-0e93e415-ba68-4b66-bf0d-7bc7611ba6aa","profile":"test"}}}}
I0313 00:06:49.735277  3086 sched.cpp:960] Rescinded offer a330d48b-9410-478c-8b3a-a92f5a5a0d6e-O5
I0313 00:06:49.735389  3086 sched.cpp:971] Scheduler::offerRescinded took 47122ns
I0313 00:06:49.735859  3088 hierarchical.cpp:1576] Recovered ports(allocated: storage/default-role):[31000-32000]; disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1NRe6/2GB-0e93e415-ba68-4b66-bf0d-7bc7611ba6aa,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_u1NRe6/2GB-0e93e415-ba68-4b66-bf0d-7bc7611ba6aa,test)]:2048, offered or allocated: {}) on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 from framework a330d
 48b-9410-478c-8b3a-a92f5a5a0d6e-0000
I0313 00:06:49.736093  3089 master.cpp:11784] Removing offer a330d48b-9410-478c-8b3a-a92f5a5a0d6e-O5
I0313 00:06:49.737331  3088 hierarchical.cpp:1625] Framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 filtered agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 for 5secs
I0313 00:06:49.739845  3091 master.cpp:11649] Sending operation '' (uuid: 6991cdf0-d7fd-423b-953d-a092daf50005) to agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 at slave(1237)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:49.740465  3091 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version
I0313 00:06:49.743357  3082 provider.cpp:498] Received APPLY_OPERATION event
I0313 00:06:49.743410  3082 provider.cpp:1351] Received UNRESERVE operation '' (uuid: 6991cdf0-d7fd-423b-953d-a092daf50005)
I0313 00:06:49.750916  3092 hierarchical.cpp:1853] Performed allocation for 1 agents in 1.273807ms
I0313 00:06:49.751646  3085 master.cpp:9485] Sending offers [ a330d48b-9410-478c-8b3a-a92f5a5a0d6e-O6 ] to framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 (default) at scheduler-7415ea59-81b7-4f70-a422-878b18b00742@172.17.0.2:43769
I0313 00:06:49.752351  3081 sched.cpp:934] Scheduler::resourceOffers took 83868ns
I0313 00:06:49.769485  3095 http.cpp:1405] HTTP POST for /slave(1237)/api/v1/resource_provider from 172.17.0.2:59548
I0313 00:06:49.770766  3089 slave.cpp:8597] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: e911cdb4-91d1-40ce-a165-f65a79f0eaa3) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0313 00:06:49.770962  3089 slave.cpp:9050] Updating the state of operation with no ID (uuid: e911cdb4-91d1-40ce-a165-f65a79f0eaa3) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0313 00:06:49.771021  3089 slave.cpp:8804] Forwarding status update of operation with no ID (operation_uuid: e911cdb4-91d1-40ce-a165-f65a79f0eaa3) for an operator API call
I0313 00:06:49.771340  3088 master.cpp:11301] Updating the state of operation '' (uuid: e911cdb4-91d1-40ce-a165-f65a79f0eaa3) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0313 00:06:49.771955  3083 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version
I0313 00:06:49.856952  3089 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: f829b941-0f0e-4073-ba33-15ef6ae4e35a) for operation UUID 6991cdf0-d7fd-423b-953d-a092daf50005 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.857033  3082 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0313 00:06:49.857039  3089 status_update_manager_process.hpp:414] Creating operation status update stream 6991cdf0-d7fd-423b-953d-a092daf50005 checkpoint=true
I0313 00:06:49.857437  3089 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: f829b941-0f0e-4073-ba33-15ef6ae4e35a) for operation UUID 6991cdf0-d7fd-423b-953d-a092daf50005 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.907124  3089 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: f829b941-0f0e-4073-ba33-15ef6ae4e35a) for operation UUID 6991cdf0-d7fd-423b-953d-a092daf50005 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.907480  3089 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 14a09f2f-85d2-44e2-869d-a632a4e76a17) for stream e911cdb4-91d1-40ce-a165-f65a79f0eaa3
I0313 00:06:49.907573  3089 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 14a09f2f-85d2-44e2-869d-a632a4e76a17) for operation UUID e911cdb4-91d1-40ce-a165-f65a79f0eaa3 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:49.907946  3087 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:43769/slave(1237)/api/v1/resource_provider
I0313 00:06:49.908864  3081 process.cpp:3671] Handling HTTP event for process 'slave(1237)' with path: '/slave(1237)/api/v1/resource_provider'
I0313 00:06:49.953750  3084 http.cpp:1405] HTTP POST for /slave(1237)/api/v1/resource_provider from 172.17.0.2:59548
I0313 00:06:49.954872  3095 slave.cpp:8597] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 6991cdf0-d7fd-423b-953d-a092daf50005) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0313 00:06:49.955081  3095 slave.cpp:9050] Updating the state of operation with no ID (uuid: 6991cdf0-d7fd-423b-953d-a092daf50005) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0313 00:06:49.955138  3095 slave.cpp:8804] Forwarding status update of operation with no ID (operation_uuid: 6991cdf0-d7fd-423b-953d-a092daf50005) for an operator API call
I0313 00:06:49.955515  3082 master.cpp:11301] Updating the state of operation '' (uuid: 6991cdf0-d7fd-423b-953d-a092daf50005) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0313 00:06:49.956064  3083 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version
I0313 00:06:49.957893  3096 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event
I0313 00:06:49.959666  3089 status_update_manager_process.hpp:490] Cleaning up operation status update stream e911cdb4-91d1-40ce-a165-f65a79f0eaa3
I0313 00:06:49.959944  3089 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: f829b941-0f0e-4073-ba33-15ef6ae4e35a) for stream 6991cdf0-d7fd-423b-953d-a092daf50005
I0313 00:06:49.960019  3089 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: f829b941-0f0e-4073-ba33-15ef6ae4e35a) for operation UUID 6991cdf0-d7fd-423b-953d-a092daf50005 on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:50.025910  3089 status_update_manager_process.hpp:490] Cleaning up operation status update stream 6991cdf0-d7fd-423b-953d-a092daf50005
I0313 00:06:50.077294  3082 master.cpp:1407] Framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 (default) at scheduler-7415ea59-81b7-4f70-a422-878b18b00742@172.17.0.2:43769 disconnected
I0313 00:06:50.077343  3082 master.cpp:3326] Deactivating framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 (default) at scheduler-7415ea59-81b7-4f70-a422-878b18b00742@172.17.0.2:43769
I0313 00:06:50.077639  3083 hierarchical.cpp:813] Deactivated framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000
I0313 00:06:50.078107  3084 slave.cpp:995] Agent terminating
I0313 00:06:50.078188  3085 hierarchical.cpp:1576] Recovered ports(allocated: storage/default-role):[31000-32000]; disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1NRe6/2GB-0e93e415-ba68-4b66-bf0d-7bc7611ba6aa,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_u1NRe6/2GB-0e93e415-ba68-4b66-bf0d-7bc7611ba6aa,test)]:2048, offered or allocated: {}) on agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 from framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000
I0313 00:06:50.078599  3082 master.cpp:11784] Removing offer a330d48b-9410-478c-8b3a-a92f5a5a0d6e-O6
I0313 00:06:50.078693  3082 master.cpp:3310] Disconnecting framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 (default) at scheduler-7415ea59-81b7-4f70-a422-878b18b00742@172.17.0.2:43769
I0313 00:06:50.078871  3082 master.cpp:1422] Giving framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 (default) at scheduler-7415ea59-81b7-4f70-a422-878b18b00742@172.17.0.2:43769 0ns to failover
I0313 00:06:50.079123  3084 manager.cpp:127] Terminating resource provider 09cf7286-d072-4e9f-b244-fac5e5f263af
I0313 00:06:50.079687  3083 master.cpp:1292] Agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 at slave(1237)@172.17.0.2:43769 (b49bdfa63993) disconnected
I0313 00:06:50.079732  3083 master.cpp:3361] Disconnecting agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 at slave(1237)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:50.079896  3083 master.cpp:3380] Deactivating agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 at slave(1237)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:50.080190  3083 master.cpp:9269] Framework failover timeout, removing framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 (default) at scheduler-7415ea59-81b7-4f70-a422-878b18b00742@172.17.0.2:43769
I0313 00:06:50.080229  3083 master.cpp:10285] Removing framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000 (default) at scheduler-7415ea59-81b7-4f70-a422-878b18b00742@172.17.0.2:43769
E0313 00:06:50.080364  3088 http_connection.hpp:449] End-Of-File received
I0313 00:06:50.080647  3085 hierarchical.cpp:1156] Agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0 deactivated
I0313 00:06:50.080693  3085 hierarchical.cpp:1777] Allocation paused
I0313 00:06:50.080982  3088 http_connection.hpp:217] Re-detecting endpoint
I0313 00:06:50.081223  3085 hierarchical.cpp:757] Removed framework a330d48b-9410-478c-8b3a-a92f5a5a0d6e-0000
I0313 00:06:50.081284  3085 hierarchical.cpp:1787] Allocation resumed
I0313 00:06:50.081511  3088 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0313 00:06:50.081591  3094 provider.cpp:488] Disconnected from resource provider manager
I0313 00:06:50.081634  3088 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0313 00:06:50.081748  3083 status_update_manager_process.hpp:379] Pausing operation status update manager
I0313 00:06:50.081820  3088 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:43769/slave(1237)/api/v1/resource_provider
I0313 00:06:50.083210  3084 containerizer.cpp:2619] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0313 00:06:50.083300  3084 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 2.405097088secs
I0313 00:06:50.083842  3084 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:50.085407  3089 hierarchical.cpp:1853] Performed allocation for 1 agents in 177131ns
I0313 00:06:50.085711  3083 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:43769/slave(1237)/api/v1/resource_provider
I0313 00:06:50.086438  3092 provider.cpp:476] Connected to resource provider manager
I0313 00:06:50.087188  3096 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:43769/slave(1237)/api/v1/resource_provider
I0313 00:06:50.088083  3097 process.cpp:2781] Returning '404 Not Found' for '/slave(1237)/api/v1/resource_provider'
E0313 00:06:50.089303  3086 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0313 00:06:50.136198  3082 hierarchical.cpp:1853] Performed allocation for 1 agents in 145076ns
I0313 00:06:50.187722  3088 containerizer.cpp:3155] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0313 00:06:50.187995  3081 hierarchical.cpp:1853] Performed allocation for 1 agents in 141479ns
I0313 00:06:50.189628  3084 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
I0313 00:06:50.192525  3093 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'
I0313 00:06:50.192843  3093 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-GzoK8v/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:50.193126  3093 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:50.195777  3097 process.cpp:2781] Returning '404 Not Found' for '/slave(1237)/api/v1'
I0313 00:06:50.209123  3080 master.cpp:1140] Master terminating
I0313 00:06:50.209882  3083 hierarchical.cpp:1132] Removed all filters for agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
I0313 00:06:50.209906  3083 hierarchical.cpp:1008] Removed agent a330d48b-9410-478c-8b3a-a92f5a5a0d6e-S0
[       OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (2290 ms)
[ RUN      ] CSIVersion/StorageLocalResourceProviderTest.Update/v0
I0313 00:06:50.224995  3080 cluster.cpp:186] Creating default 'local' authorizer
I0313 00:06:50.229724  3081 master.cpp:443] Master adeea4b8-af7f-4cea-b692-0058fd178e86 (b49bdfa63993) started on 172.17.0.2:43769
I0313 00:06:50.229758  3081 master.cpp:446] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/8ETUZe/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_alloca
 table_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.10.0/_inst/share/mesos/webui" --work_dir="/tmp/8ETUZe/master" --zk_session_timeout="10secs"
I0313 00:06:50.230170  3081 master.cpp:495] Master only allowing authenticated frameworks to register
I0313 00:06:50.230183  3081 master.cpp:501] Master only allowing authenticated agents to register
I0313 00:06:50.230191  3081 master.cpp:507] Master only allowing authenticated HTTP frameworks to register
I0313 00:06:50.230201  3081 credentials.hpp:37] Loading credentials for authentication from '/tmp/8ETUZe/credentials'
I0313 00:06:50.230453  3081 master.cpp:551] Using default 'crammd5' authenticator
I0313 00:06:50.230659  3081 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0313 00:06:50.230906  3081 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0313 00:06:50.231096  3081 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0313 00:06:50.231325  3081 master.cpp:632] Authorization enabled
I0313 00:06:50.231747  3082 hierarchical.cpp:567] Initialized hierarchical allocator process
I0313 00:06:50.231791  3096 whitelist_watcher.cpp:77] No whitelist given
I0313 00:06:50.234853  3093 master.cpp:2165] Elected as the leading master!
I0313 00:06:50.234891  3093 master.cpp:1661] Recovering from registrar
I0313 00:06:50.235137  3089 registrar.cpp:339] Recovering registrar
I0313 00:06:50.235991  3089 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0313 00:06:50.236156  3089 registrar.cpp:487] Applied 1 operations in 55345ns; attempting to update the registry
I0313 00:06:50.236879  3089 registrar.cpp:544] Successfully updated the registry in 0ns
I0313 00:06:50.237056  3089 registrar.cpp:416] Successfully recovered registrar
I0313 00:06:50.237607  3082 master.cpp:1814] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I0313 00:06:50.237632  3081 hierarchical.cpp:606] Skipping recovery of hierarchical allocator: nothing to recover
W0313 00:06:50.243394  3080 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:43769
I0313 00:06:50.244820  3080 containerizer.cpp:317] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0313 00:06:50.245390  3080 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0313 00:06:50.245417  3080 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0313 00:06:50.245432  3080 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0313 00:06:50.245463  3080 provisioner.cpp:294] Using default backend 'copy'
I0313 00:06:50.248134  3080 cluster.cpp:533] Creating default 'local' authorizer
I0313 00:06:50.251319  3087 slave.cpp:274] Mesos agent started on (1238)@172.17.0.2:43769
I0313 00:06:50.251353  3087 slave.cpp:275] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/8ETUZe/KKHzXq/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/8ETUZe/KKHzXq/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/8ETUZe/KKHzXq/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/8ETUZe/KKHzXq/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/8ETUZe/KKHzXq/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/8ETUZe/KKHzXq/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posi
 x" --launcher_dir="/tmp/SRC/build/mesos-1.10.0/_build/sub/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/8ETUZe/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_I7Kls8" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/CSIVersion_StorageLoca
 lResourceProviderTest_Update_v0_AHt8WP" --zk_session_timeout="10secs"
I0313 00:06:50.252144  3087 credentials.hpp:86] Loading credential for authentication from '/tmp/8ETUZe/KKHzXq/credential'
I0313 00:06:50.252398  3087 slave.cpp:307] Agent using credential for: test-principal
I0313 00:06:50.252434  3087 credentials.hpp:37] Loading credentials for authentication from '/tmp/8ETUZe/KKHzXq/http_credentials'
I0313 00:06:50.252729  3087 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0313 00:06:50.253211  3087 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0313 00:06:50.255123  3082 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I0313 00:06:50.255162  3087 slave.cpp:622] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0313 00:06:50.255504  3087 slave.cpp:630] Agent attributes: [  ]
I0313 00:06:50.255527  3087 slave.cpp:639] Agent hostname: b49bdfa63993
I0313 00:06:50.255730  3095 status_update_manager_process.hpp:379] Pausing operation status update manager
I0313 00:06:50.255744  3083 task_status_update_manager.cpp:181] Pausing sending task status updates
I0313 00:06:50.258070  3084 state.cpp:68] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_AHt8WP/meta'
I0313 00:06:50.258325  3085 slave.cpp:7606] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_AHt8WP/meta', beginning agent recovery
I0313 00:06:50.259016  3094 task_status_update_manager.cpp:207] Recovering task status update manager
I0313 00:06:50.259546  3089 containerizer.cpp:820] Recovering Mesos containers
I0313 00:06:50.260028  3089 containerizer.cpp:1160] Recovering isolators
I0313 00:06:50.260993  3085 containerizer.cpp:1199] Recovering provisioner
I0313 00:06:50.261613  3081 hierarchical.cpp:1853] Performed allocation for 0 agents in 108259ns
I0313 00:06:50.261890  3094 provisioner.cpp:518] Provisioner recovery complete
I0313 00:06:50.262867  3090 composing.cpp:339] Finished recovering all containerizers
I0313 00:06:50.263231  3096 slave.cpp:8088] Recovering executors
I0313 00:06:50.263361  3096 slave.cpp:8241] Finished recovery
I0313 00:06:50.264322  3082 task_status_update_manager.cpp:181] Pausing sending task status updates
I0313 00:06:50.264382  3094 status_update_manager_process.hpp:379] Pausing operation status update manager
I0313 00:06:50.264453  3088 slave.cpp:1454] New master detected at master@172.17.0.2:43769
I0313 00:06:50.264591  3088 slave.cpp:1519] Detecting new master
I0313 00:06:50.273066  3089 slave.cpp:1546] Authenticating with master master@172.17.0.2:43769
I0313 00:06:50.273205  3089 slave.cpp:1555] Using default CRAM-MD5 authenticatee
I0313 00:06:50.273612  3084 authenticatee.cpp:121] Creating new client SASL connection
I0313 00:06:50.273988  3084 master.cpp:9676] Authenticating slave(1238)@172.17.0.2:43769
I0313 00:06:50.274157  3083 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2099)@172.17.0.2:43769
I0313 00:06:50.274551  3092 authenticator.cpp:98] Creating new server SASL connection
I0313 00:06:50.274828  3090 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0313 00:06:50.274868  3090 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0313 00:06:50.275056  3087 authenticator.cpp:204] Received SASL authentication start
I0313 00:06:50.275143  3087 authenticator.cpp:326] Authentication requires more steps
I0313 00:06:50.275300  3087 authenticatee.cpp:259] Received SASL authentication step
I0313 00:06:50.275490  3087 authenticator.cpp:232] Received SASL authentication step
I0313 00:06:50.275533  3087 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b49bdfa63993' server FQDN: 'b49bdfa63993' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0313 00:06:50.275558  3087 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0313 00:06:50.275619  3087 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0313 00:06:50.275692  3087 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b49bdfa63993' server FQDN: 'b49bdfa63993' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0313 00:06:50.275718  3087 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0313 00:06:50.275737  3087 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0313 00:06:50.275763  3087 authenticator.cpp:318] Authentication success
I0313 00:06:50.275913  3081 authenticatee.cpp:299] Authentication success
I0313 00:06:50.276047  3085 master.cpp:9708] Successfully authenticated principal 'test-principal' at slave(1238)@172.17.0.2:43769
I0313 00:06:50.276139  3087 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2099)@172.17.0.2:43769
I0313 00:06:50.276546  3091 slave.cpp:1646] Successfully authenticated with master master@172.17.0.2:43769
I0313 00:06:50.277004  3091 slave.cpp:2096] Will retry registration in 15.751324ms if necessary
I0313 00:06:50.277278  3095 master.cpp:6174] Received register agent message from slave(1238)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:50.277734  3095 master.cpp:3705] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I0313 00:06:50.278419  3096 master.cpp:6241] Authorized registration of agent at slave(1238)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:50.278527  3096 master.cpp:6353] Registering agent at slave(1238)@172.17.0.2:43769 (b49bdfa63993) with id adeea4b8-af7f-4cea-b692-0058fd178e86-S0
I0313 00:06:50.279291  3082 registrar.cpp:487] Applied 1 operations in 254758ns; attempting to update the registry
I0313 00:06:50.280097  3082 registrar.cpp:544] Successfully updated the registry in 732672ns
I0313 00:06:50.280303  3081 master.cpp:6401] Admitted agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0 at slave(1238)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:50.281188  3081 master.cpp:6446] Registered agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0 at slave(1238)@172.17.0.2:43769 (b49bdfa63993) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0313 00:06:50.281283  3087 slave.cpp:1679] Registered with master master@172.17.0.2:43769; given agent ID adeea4b8-af7f-4cea-b692-0058fd178e86-S0
I0313 00:06:50.281407  3089 hierarchical.cpp:959] Added agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0 (b49bdfa63993) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I0313 00:06:50.281483  3095 task_status_update_manager.cpp:188] Resuming sending task status updates
I0313 00:06:50.281819  3089 hierarchical.cpp:1853] Performed allocation for 1 agents in 157465ns
I0313 00:06:50.281824  3087 slave.cpp:1714] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_AHt8WP/meta/slaves/adeea4b8-af7f-4cea-b692-0058fd178e86-S0/slave.info'
I0313 00:06:50.281914  3084 status_update_manager_process.hpp:385] Resuming operation status update manager
I0313 00:06:50.283354  3087 slave.cpp:1766] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"uHfoHY/nRpiVGolfEA9+sw=="},"slave_id":{"value":"adeea4b8-af7f-4cea-b692-0058fd178e86-S0"},"update_oversubscribed_resources":false}
I0313 00:06:50.284221  3085 master.cpp:7584] Ignoring update on agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0 at slave(1238)@172.17.0.2:43769 (b49bdfa63993) as it reports no changes
I0313 00:06:50.288925  3092 process.cpp:3671] Handling HTTP event for process 'slave(1238)' with path: '/slave(1238)/api/v1'
I0313 00:06:50.290448  3085 http.cpp:1405] HTTP POST for /slave(1238)/api/v1 from 172.17.0.2:59566
I0313 00:06:50.291030  3085 http.cpp:2828] Processing GET_CONTAINERS call
I0313 00:06:50.311097  3085 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:50.313151  3095 hierarchical.cpp:1853] Performed allocation for 1 agents in 152987ns
I0313 00:06:50.314424  3083 process.cpp:3671] Handling HTTP event for process 'slave(1238)' with path: '/slave(1238)/api/v1'
I0313 00:06:50.315706  3092 http.cpp:1405] HTTP POST for /slave(1238)/api/v1 from 172.17.0.2:59568
I0313 00:06:50.316541  3092 http.cpp:3288] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:50.317643  3082 http.cpp:3392] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_AHt8WP/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:50.318547  3095 containerizer.cpp:1395] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:50.319124  3095 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from STARTING to PROVISIONING after 233216ns
I0313 00:06:50.364684  3091 hierarchical.cpp:1853] Performed allocation for 1 agents in 180402ns
I0313 00:06:50.369781  3095 containerizer.cpp:1573] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_I7Kls8/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0313 00:06:50.369832  3095 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PROVISIONING to PREPARING after 50.710784ms
I0313 00:06:50.373160  3096 containerizer.cpp:2099] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_OebWrx","--available_capacity=0B","--volumes=","--forward=unix:///tmp/8ETUZe/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_AHt8WP/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-qvlCvD/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_AHt8WP/containers/o
 rg-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="109" --pipe_write="110" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_I7Kls8/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I0313 00:06:50.384306  3096 launcher.cpp:145] Forked child with pid '14650' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:50.385174  3096 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PREPARING to ISOLATING after 15.336192ms
I0313 00:06:50.386718  3096 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from ISOLATING to FETCHING after 1.539072ms
I0313 00:06:50.387037  3094 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_AHt8WP/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:50.388327  3093 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from FETCHING to RUNNING after 1.551872ms
I0313 00:06:50.391561  3091 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'
I0313 00:06:50.391927  3085 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-qvlCvD/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:50.415550  3094 hierarchical.cpp:1853] Performed allocation for 1 agents in 195933ns
I0313 00:06:50.467123  3082 hierarchical.cpp:1853] Performed allocation for 1 agents in 199599ns
I0313 00:06:50.518622  3086 hierarchical.cpp:1853] Performed allocation for 1 agents in 191044ns
I0313 00:06:50.569546  3082 hierarchical.cpp:1853] Performed allocation for 1 agents in 159509ns
I0313 00:06:50.620983  3095 hierarchical.cpp:1853] Performed allocation for 1 agents in 145319ns
I0313 00:06:50.672248  3092 hierarchical.cpp:1853] Performed allocation for 1 agents in 145992ns
I0313 00:06:50.713711  3090 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-qvlCvD/endpoint.sock' with CSI v1
I0313 00:06:50.716477  3095 service_manager.cpp:532] Probing endpoint 'unix:///tmp/mesos-csi-qvlCvD/endpoint.sock' with CSI v0
I0313 00:06:50.717669 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/Probe call
I0313 00:06:50.720767  3094 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:50.723134  3087 hierarchical.cpp:1853] Performed allocation for 1 agents in 149579ns
I0313 00:06:50.724088 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginCapabilities call
I0313 00:06:50.724623  3090 process.cpp:3671] Handling HTTP event for process 'slave(1238)' with path: '/slave(1238)/api/v1'
I0313 00:06:50.725947  3093 http.cpp:1405] HTTP POST for /slave(1238)/api/v1 from 172.17.0.2:59570
I0313 00:06:50.726516  3093 http.cpp:3506] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:50.728479 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginInfo call
I0313 00:06:50.728850 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginInfo call
I0313 00:06:50.730635  3095 v0_volume_manager.cpp:628] NODE_SERVICE loaded: {}
I0313 00:06:50.731212  3095 v0_volume_manager.cpp:628] CONTROLLER_SERVICE loaded: {}
I0313 00:06:50.733870 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ControllerGetCapabilities call
I0313 00:06:50.737839 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Node/NodeGetCapabilities call
I0313 00:06:50.741509 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Node/NodeGetId call
I0313 00:06:50.744079  3094 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0313 00:06:50.744243  3092 status_update_manager_process.hpp:379] Pausing operation status update manager
I0313 00:06:50.744632  3093 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:43769/slave(1238)/api/v1/resource_provider
I0313 00:06:50.747879  3091 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:43769/slave(1238)/api/v1/resource_provider
I0313 00:06:50.748572  3095 provider.cpp:476] Connected to resource provider manager
I0313 00:06:50.749301  3088 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:43769/slave(1238)/api/v1/resource_provider
I0313 00:06:50.750540  3093 process.cpp:3671] Handling HTTP event for process 'slave(1238)' with path: '/slave(1238)/api/v1/resource_provider'
I0313 00:06:50.752460  3082 http.cpp:1405] HTTP POST for /slave(1238)/api/v1/resource_provider from 172.17.0.2:59574
I0313 00:06:50.753214  3082 manager.cpp:779] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_OebWrx","--available_capacity=0B","--volumes=","--forward=unix:///tmp/8ETUZe/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}
I0313 00:06:50.774268  3094 hierarchical.cpp:1853] Performed allocation for 1 agents in 188217ns
I0313 00:06:50.795527  3081 slave.cpp:8597] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"3b27feda-a4de-4aef-9f36-693b863044c7"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_OebWrx","--available_capacity=0B","--volumes=","--forward=unix:///tmp/8ETUZe/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}'
I0313 00:06:50.797250  3086 provider.cpp:498] Received SUBSCRIBED event
I0313 00:06:50.797304  3086 provider.cpp:1309] Subscribed with ID 3b27feda-a4de-4aef-9f36-693b863044c7
I0313 00:06:50.798126  3095 status_update_manager_process.hpp:314] Recovering operation status update manager
I0313 00:06:50.825328  3089 hierarchical.cpp:1853] Performed allocation for 1 agents in 143866ns
I0313 00:06:50.853859  3094 provider.cpp:790] Reconciling storage pools and volumes
I0313 00:06:50.856174 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I0313 00:06:50.859138  3092 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0
I0313 00:06:50.859421  3094 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.2:43769/slave(1238)/api/v1/resource_provider
I0313 00:06:50.859560  3092 provider.cpp:748] Resource provider 3b27feda-a4de-4aef-9f36-693b863044c7 is in READY state
I0313 00:06:50.859620  3093 status_update_manager_process.hpp:385] Resuming operation status update manager
I0313 00:06:50.860523  3082 provider.cpp:1235] Updating profiles { test } for resource provider 3b27feda-a4de-4aef-9f36-693b863044c7
I0313 00:06:50.860827  3085 process.cpp:3671] Handling HTTP event for process 'slave(1238)' with path: '/slave(1238)/api/v1/resource_provider'
I0313 00:06:50.861853  3094 provider.cpp:790] Reconciling storage pools and volumes
I0313 00:06:50.862596  3082 http.cpp:1405] HTTP POST for /slave(1238)/api/v1/resource_provider from 172.17.0.2:59572
I0313 00:06:50.863242  3083 manager.cpp:1011] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 3b27feda-a4de-4aef-9f36-693b863044c7
I0313 00:06:50.863489  3095 slave.cpp:8597] Handling resource provider message 'UPDATE_STATE: 3b27feda-a4de-4aef-9f36-693b863044c7 {}'
I0313 00:06:50.863608  3095 slave.cpp:8717] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0313 00:06:50.864223 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I0313 00:06:50.864708 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/GetCapacity call
I0313 00:06:50.866019  3093 hierarchical.cpp:1110] Grew agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0 by {} (total), {  } (used)
I0313 00:06:50.866449  3093 hierarchical.cpp:1067] Agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0 (b49bdfa63993) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0313 00:06:50.871342  3084 hierarchical.cpp:1853] Performed allocation for 1 agents in 149263ns
I0313 00:06:50.871712  3092 provider.cpp:790] Reconciling storage pools and volumes
I0313 00:06:50.874101 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call
I0313 00:06:50.874667 14654 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/GetCapacity call
I0313 00:06:50.885581  3080 slave.cpp:995] Agent terminating
I0313 00:06:50.886495  3080 manager.cpp:127] Terminating resource provider 3b27feda-a4de-4aef-9f36-693b863044c7
I0313 00:06:50.887035  3090 master.cpp:1292] Agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0 at slave(1238)@172.17.0.2:43769 (b49bdfa63993) disconnected
I0313 00:06:50.887079  3090 master.cpp:3361] Disconnecting agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0 at slave(1238)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:50.887164  3090 master.cpp:3380] Deactivating agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0 at slave(1238)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:50.887311  3087 hierarchical.cpp:1156] Agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0 deactivated
E0313 00:06:50.887639  3086 http_connection.hpp:449] End-Of-File received
I0313 00:06:50.888146  3086 http_connection.hpp:217] Re-detecting endpoint
I0313 00:06:50.888624  3086 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0313 00:06:50.888713  3086 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0313 00:06:50.888744  3083 provider.cpp:488] Disconnected from resource provider manager
I0313 00:06:50.888808  3086 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:43769/slave(1238)/api/v1/resource_provider
I0313 00:06:50.888978  3083 status_update_manager_process.hpp:379] Pausing operation status update manager
I0313 00:06:50.890609  3091 containerizer.cpp:2619] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0313 00:06:50.890678  3091 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 15.502409984secs
I0313 00:06:50.891132  3091 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:50.892364  3083 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:43769/slave(1238)/api/v1/resource_provider
I0313 00:06:50.893105  3086 provider.cpp:476] Connected to resource provider manager
I0313 00:06:50.893710  3081 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:43769/slave(1238)/api/v1/resource_provider
I0313 00:06:50.894690  3097 process.cpp:2781] Returning '404 Not Found' for '/slave(1238)/api/v1/resource_provider'
E0313 00:06:50.896138  3085 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0313 00:06:50.918251  3095 hierarchical.cpp:1853] Performed allocation for 1 agents in 163104ns
I0313 00:06:50.967586  3090 containerizer.cpp:3155] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0313 00:06:50.969472  3090 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
I0313 00:06:50.970026  3085 hierarchical.cpp:1853] Performed allocation for 1 agents in 171899ns
I0313 00:06:50.972889  3086 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'
I0313 00:06:50.973121  3086 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-qvlCvD/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:50.973366  3096 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:50.976614  3097 process.cpp:2781] Returning '404 Not Found' for '/slave(1238)/api/v1'
I0313 00:06:50.988596  3080 master.cpp:1140] Master terminating
I0313 00:06:50.989029  3092 hierarchical.cpp:1132] Removed all filters for agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0
I0313 00:06:50.989056  3092 hierarchical.cpp:1008] Removed agent adeea4b8-af7f-4cea-b692-0058fd178e86-S0
[       OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v0 (777 ms)
[ RUN      ] CSIVersion/StorageLocalResourceProviderTest.Update/v1
I0313 00:06:51.005738  3080 cluster.cpp:186] Creating default 'local' authorizer
I0313 00:06:51.010594  3090 master.cpp:443] Master d52c6d46-1166-42cc-a4ba-6fa17843d194 (b49bdfa63993) started on 172.17.0.2:43769
I0313 00:06:51.010622  3090 master.cpp:446] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/zD2t7u/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_alloca
 table_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.10.0/_inst/share/mesos/webui" --work_dir="/tmp/zD2t7u/master" --zk_session_timeout="10secs"
I0313 00:06:51.010921  3090 master.cpp:495] Master only allowing authenticated frameworks to register
I0313 00:06:51.010936  3090 master.cpp:501] Master only allowing authenticated agents to register
I0313 00:06:51.010943  3090 master.cpp:507] Master only allowing authenticated HTTP frameworks to register
I0313 00:06:51.010952  3090 credentials.hpp:37] Loading credentials for authentication from '/tmp/zD2t7u/credentials'
I0313 00:06:51.011183  3090 master.cpp:551] Using default 'crammd5' authenticator
I0313 00:06:51.011390  3090 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0313 00:06:51.011636  3090 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0313 00:06:51.011837  3090 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0313 00:06:51.012030  3090 master.cpp:632] Authorization enabled
I0313 00:06:51.012434  3084 whitelist_watcher.cpp:77] No whitelist given
I0313 00:06:51.012562  3081 hierarchical.cpp:567] Initialized hierarchical allocator process
I0313 00:06:51.015385  3087 master.cpp:2165] Elected as the leading master!
I0313 00:06:51.015421  3087 master.cpp:1661] Recovering from registrar
I0313 00:06:51.015627  3083 registrar.cpp:339] Recovering registrar
I0313 00:06:51.016541  3083 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0313 00:06:51.016717  3083 registrar.cpp:487] Applied 1 operations in 57925ns; attempting to update the registry
I0313 00:06:51.017467  3083 registrar.cpp:544] Successfully updated the registry in 0ns
I0313 00:06:51.017652  3083 registrar.cpp:416] Successfully recovered registrar
I0313 00:06:51.018165  3084 master.cpp:1814] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister
I0313 00:06:51.018208  3081 hierarchical.cpp:606] Skipping recovery of hierarchical allocator: nothing to recover
W0313 00:06:51.023938  3080 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:43769
I0313 00:06:51.025317  3080 containerizer.cpp:317] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0313 00:06:51.025899  3080 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0313 00:06:51.025925  3080 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0313 00:06:51.025941  3080 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0313 00:06:51.025971  3080 provisioner.cpp:294] Using default backend 'copy'
I0313 00:06:51.028748  3080 cluster.cpp:533] Creating default 'local' authorizer
I0313 00:06:51.031178  3091 slave.cpp:274] Mesos agent started on (1239)@172.17.0.2:43769
I0313 00:06:51.031211  3091 slave.cpp:275] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/zD2t7u/zGPcgP/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/zD2t7u/zGPcgP/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/zD2t7u/zGPcgP/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/zD2t7u/zGPcgP/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/zD2t7u/zGPcgP/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/zD2t7u/zGPcgP/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posi
 x" --launcher_dir="/tmp/SRC/build/mesos-1.10.0/_build/sub/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/zD2t7u/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_BrMcIu" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/CSIVersion_StorageLoca
 lResourceProviderTest_Update_v1_TGldaa" --zk_session_timeout="10secs"
I0313 00:06:51.031796  3091 credentials.hpp:86] Loading credential for authentication from '/tmp/zD2t7u/zGPcgP/credential'
I0313 00:06:51.032044  3091 slave.cpp:307] Agent using credential for: test-principal
I0313 00:06:51.032085  3091 credentials.hpp:37] Loading credentials for authentication from '/tmp/zD2t7u/zGPcgP/http_credentials'
I0313 00:06:51.032380  3091 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0313 00:06:51.032902  3091 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0313 00:06:51.034477  3090 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I0313 00:06:51.034837  3091 slave.cpp:622] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0313 00:06:51.035131  3091 slave.cpp:630] Agent attributes: [  ]
I0313 00:06:51.035151  3091 slave.cpp:639] Agent hostname: b49bdfa63993
I0313 00:06:51.035377  3086 status_update_manager_process.hpp:379] Pausing operation status update manager
I0313 00:06:51.035392  3089 task_status_update_manager.cpp:181] Pausing sending task status updates
I0313 00:06:51.037262  3093 state.cpp:68] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TGldaa/meta'
I0313 00:06:51.037619  3094 slave.cpp:7606] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TGldaa/meta', beginning agent recovery
I0313 00:06:51.038286  3085 task_status_update_manager.cpp:207] Recovering task status update manager
I0313 00:06:51.038892  3082 containerizer.cpp:820] Recovering Mesos containers
I0313 00:06:51.039295  3082 containerizer.cpp:1160] Recovering isolators
I0313 00:06:51.040577  3095 containerizer.cpp:1199] Recovering provisioner
I0313 00:06:51.041442  3085 provisioner.cpp:518] Provisioner recovery complete
I0313 00:06:51.042431  3090 hierarchical.cpp:1853] Performed allocation for 0 agents in 130332ns
I0313 00:06:51.042513  3082 composing.cpp:339] Finished recovering all containerizers
I0313 00:06:51.042907  3087 slave.cpp:8088] Recovering executors
I0313 00:06:51.043045  3087 slave.cpp:8241] Finished recovery
I0313 00:06:51.044023  3084 task_status_update_manager.cpp:181] Pausing sending task status updates
I0313 00:06:51.044049  3094 slave.cpp:1454] New master detected at master@172.17.0.2:43769
I0313 00:06:51.044065  3085 status_update_manager_process.hpp:379] Pausing operation status update manager
I0313 00:06:51.044179  3094 slave.cpp:1519] Detecting new master
I0313 00:06:51.045554  3083 slave.cpp:1546] Authenticating with master master@172.17.0.2:43769
I0313 00:06:51.045706  3083 slave.cpp:1555] Using default CRAM-MD5 authenticatee
I0313 00:06:51.046064  3091 authenticatee.cpp:121] Creating new client SASL connection
I0313 00:06:51.046432  3092 master.cpp:9676] Authenticating slave(1239)@172.17.0.2:43769
I0313 00:06:51.046634  3086 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2100)@172.17.0.2:43769
I0313 00:06:51.047029  3090 authenticator.cpp:98] Creating new server SASL connection
I0313 00:06:51.047298  3082 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0313 00:06:51.047338  3082 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0313 00:06:51.047479  3082 authenticator.cpp:204] Received SASL authentication start
I0313 00:06:51.047564  3082 authenticator.cpp:326] Authentication requires more steps
I0313 00:06:51.047706  3082 authenticatee.cpp:259] Received SASL authentication step
I0313 00:06:51.047890  3096 authenticator.cpp:232] Received SASL authentication step
I0313 00:06:51.047945  3096 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b49bdfa63993' server FQDN: 'b49bdfa63993' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0313 00:06:51.047974  3096 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0313 00:06:51.048041  3096 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0313 00:06:51.048105  3096 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b49bdfa63993' server FQDN: 'b49bdfa63993' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0313 00:06:51.048130  3096 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0313 00:06:51.048149  3096 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0313 00:06:51.048179  3096 authenticator.cpp:318] Authentication success
I0313 00:06:51.048293  3095 authenticatee.cpp:299] Authentication success
I0313 00:06:51.048430  3093 master.cpp:9708] Successfully authenticated principal 'test-principal' at slave(1239)@172.17.0.2:43769
I0313 00:06:51.048521  3084 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2100)@172.17.0.2:43769
I0313 00:06:51.048753  3085 slave.cpp:1646] Successfully authenticated with master master@172.17.0.2:43769
I0313 00:06:51.049221  3085 slave.cpp:2096] Will retry registration in 10.657038ms if necessary
I0313 00:06:51.049418  3091 master.cpp:6174] Received register agent message from slave(1239)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:51.049800  3091 master.cpp:3705] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object
I0313 00:06:51.050429  3090 master.cpp:6241] Authorized registration of agent at slave(1239)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:51.050561  3090 master.cpp:6353] Registering agent at slave(1239)@172.17.0.2:43769 (b49bdfa63993) with id d52c6d46-1166-42cc-a4ba-6fa17843d194-S0
I0313 00:06:51.051299  3087 registrar.cpp:487] Applied 1 operations in 267806ns; attempting to update the registry
I0313 00:06:51.052079  3087 registrar.cpp:544] Successfully updated the registry in 712960ns
I0313 00:06:51.052310  3089 master.cpp:6401] Admitted agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0 at slave(1239)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:51.053158  3089 master.cpp:6446] Registered agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0 at slave(1239)@172.17.0.2:43769 (b49bdfa63993) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0313 00:06:51.053328  3083 slave.cpp:1679] Registered with master master@172.17.0.2:43769; given agent ID d52c6d46-1166-42cc-a4ba-6fa17843d194-S0
I0313 00:06:51.053402  3095 hierarchical.cpp:959] Added agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0 (b49bdfa63993) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {})
I0313 00:06:51.053490  3085 task_status_update_manager.cpp:188] Resuming sending task status updates
I0313 00:06:51.053848  3095 hierarchical.cpp:1853] Performed allocation for 1 agents in 146206ns
I0313 00:06:51.053869  3083 slave.cpp:1714] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TGldaa/meta/slaves/d52c6d46-1166-42cc-a4ba-6fa17843d194-S0/slave.info'
I0313 00:06:51.053972  3092 status_update_manager_process.hpp:385] Resuming operation status update manager
I0313 00:06:51.055297  3083 slave.cpp:1766] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"NX+Mb6dpTOKW4zaP23KegQ=="},"slave_id":{"value":"d52c6d46-1166-42cc-a4ba-6fa17843d194-S0"},"update_oversubscribed_resources":false}
I0313 00:06:51.056265  3088 master.cpp:7584] Ignoring update on agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0 at slave(1239)@172.17.0.2:43769 (b49bdfa63993) as it reports no changes
I0313 00:06:51.060537  3092 process.cpp:3671] Handling HTTP event for process 'slave(1239)' with path: '/slave(1239)/api/v1'
I0313 00:06:51.061921  3088 http.cpp:1405] HTTP POST for /slave(1239)/api/v1 from 172.17.0.2:59582
I0313 00:06:51.062461  3088 http.cpp:2828] Processing GET_CONTAINERS call
I0313 00:06:51.089306  3088 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:51.092301  3085 process.cpp:3671] Handling HTTP event for process 'slave(1239)' with path: '/slave(1239)/api/v1'
I0313 00:06:51.093497  3096 http.cpp:1405] HTTP POST for /slave(1239)/api/v1 from 172.17.0.2:59584
I0313 00:06:51.094290  3096 http.cpp:3288] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:51.094358  3081 hierarchical.cpp:1853] Performed allocation for 1 agents in 182964ns
I0313 00:06:51.095494  3083 http.cpp:3392] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TGldaa/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:51.096284  3088 containerizer.cpp:1395] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:51.096979  3088 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from STARTING to PROVISIONING after 273920ns
I0313 00:06:51.114364  3088 containerizer.cpp:1573] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_BrMcIu/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0313 00:06:51.114440  3088 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PROVISIONING to PREPARING after 17.4592ms
I0313 00:06:51.117753  3086 containerizer.cpp:2099] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_V3SeCP","--available_capacity=0B","--volumes=","--forward=unix:///tmp/zD2t7u/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TGldaa/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-LvA5W9/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TGldaa/containers/o
 rg-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="109" --pipe_write="110" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_BrMcIu/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I0313 00:06:51.128803  3086 launcher.cpp:145] Forked child with pid '14663' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:51.129703  3086 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PREPARING to ISOLATING after 15.256832ms
I0313 00:06:51.131217  3086 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from ISOLATING to FETCHING after 1.511936ms
I0313 00:06:51.131451  3086 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_TGldaa/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:51.132537  3093 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from FETCHING to RUNNING after 1.231104ms
I0313 00:06:51.135741  3081 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'
I0313 00:06:51.136135  3095 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-LvA5W9/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:51.145854  3082 hierarchical.cpp:1853] Performed allocation for 1 agents in 182775ns
I0313 00:06:51.197022  3085 hierarchical.cpp:1853] Performed allocation for 1 agents in 205521ns
I0313 00:06:51.248306  3082 hierarchical.cpp:1853] Performed allocation for 1 agents in 162526ns
I0313 00:06:51.299660  3085 hierarchical.cpp:1853] Performed allocation for 1 agents in 131150ns
I0313 00:06:51.351009  3081 hierarchical.cpp:1853] Performed allocation for 1 agents in 212431ns
I0313 00:06:51.402806  3086 hierarchical.cpp:1853] Performed allocation for 1 agents in 153647ns
I0313 00:06:51.454041  3087 hierarchical.cpp:1853] Performed allocation for 1 agents in 164424ns
I0313 00:06:51.456374  3083 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-LvA5W9/endpoint.sock' with CSI v1
I0313 00:06:51.458331 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/Probe call
I0313 00:06:51.461280  3082 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:51.464092 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginCapabilities call
I0313 00:06:51.464890  3089 process.cpp:3671] Handling HTTP event for process 'slave(1239)' with path: '/slave(1239)/api/v1'
I0313 00:06:51.466372  3090 http.cpp:1405] HTTP POST for /slave(1239)/api/v1 from 172.17.0.2:59586
I0313 00:06:51.466907  3090 http.cpp:3506] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:51.468448 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call
I0313 00:06:51.468822 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call
I0313 00:06:51.470569  3083 v1_volume_manager.cpp:649] NODE_SERVICE loaded: {}
I0313 00:06:51.471101  3083 v1_volume_manager.cpp:649] CONTROLLER_SERVICE loaded: {}
I0313 00:06:51.473330 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ControllerGetCapabilities call
I0313 00:06:51.477227 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetCapabilities call
I0313 00:06:51.480979 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetInfo call
I0313 00:06:51.483582  3086 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0313 00:06:51.483762  3092 status_update_manager_process.hpp:379] Pausing operation status update manager
I0313 00:06:51.484185  3086 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:43769/slave(1239)/api/v1/resource_provider
I0313 00:06:51.487736  3096 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:43769/slave(1239)/api/v1/resource_provider
I0313 00:06:51.488548  3083 provider.cpp:476] Connected to resource provider manager
I0313 00:06:51.489281  3092 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:43769/slave(1239)/api/v1/resource_provider
I0313 00:06:51.490514  3086 process.cpp:3671] Handling HTTP event for process 'slave(1239)' with path: '/slave(1239)/api/v1/resource_provider'
I0313 00:06:51.492341  3085 http.cpp:1405] HTTP POST for /slave(1239)/api/v1/resource_provider from 172.17.0.2:59590
I0313 00:06:51.493089  3085 manager.cpp:779] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_V3SeCP","--available_capacity=0B","--volumes=","--forward=unix:///tmp/zD2t7u/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}
I0313 00:06:51.505096  3090 hierarchical.cpp:1853] Performed allocation for 1 agents in 191749ns
I0313 00:06:51.522521  3086 slave.cpp:8597] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"44fd3d2b-5f85-48c3-ad0f-221e3e7a4746"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_V3SeCP","--available_capacity=0B","--volumes=","--forward=unix:///tmp/zD2t7u/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}'
I0313 00:06:51.524333  3095 provider.cpp:498] Received SUBSCRIBED event
I0313 00:06:51.524384  3095 provider.cpp:1309] Subscribed with ID 44fd3d2b-5f85-48c3-ad0f-221e3e7a4746
I0313 00:06:51.525207  3092 status_update_manager_process.hpp:314] Recovering operation status update manager
I0313 00:06:51.556222  3090 hierarchical.cpp:1853] Performed allocation for 1 agents in 134069ns
I0313 00:06:51.564035  3083 provider.cpp:790] Reconciling storage pools and volumes
I0313 00:06:51.566395 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I0313 00:06:51.569602  3091 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0
I0313 00:06:51.569973  3091 provider.cpp:748] Resource provider 44fd3d2b-5f85-48c3-ad0f-221e3e7a4746 is in READY state
I0313 00:06:51.569957  3081 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.2:43769/slave(1239)/api/v1/resource_provider
I0313 00:06:51.570129  3088 status_update_manager_process.hpp:385] Resuming operation status update manager
I0313 00:06:51.570684  3089 provider.cpp:1235] Updating profiles { test } for resource provider 44fd3d2b-5f85-48c3-ad0f-221e3e7a4746
I0313 00:06:51.571244  3092 process.cpp:3671] Handling HTTP event for process 'slave(1239)' with path: '/slave(1239)/api/v1/resource_provider'
I0313 00:06:51.571893  3094 provider.cpp:790] Reconciling storage pools and volumes
I0313 00:06:51.572963  3085 http.cpp:1405] HTTP POST for /slave(1239)/api/v1/resource_provider from 172.17.0.2:59588
I0313 00:06:51.573604  3085 manager.cpp:1011] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 44fd3d2b-5f85-48c3-ad0f-221e3e7a4746
I0313 00:06:51.573894  3081 slave.cpp:8597] Handling resource provider message 'UPDATE_STATE: 44fd3d2b-5f85-48c3-ad0f-221e3e7a4746 {}'
I0313 00:06:51.573995  3081 slave.cpp:8717] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0313 00:06:51.574154 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I0313 00:06:51.574923 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call
I0313 00:06:51.576081  3082 hierarchical.cpp:1110] Grew agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0 by {} (total), {  } (used)
I0313 00:06:51.576524  3082 hierarchical.cpp:1067] Agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0 (b49bdfa63993) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0313 00:06:51.580598  3094 hierarchical.cpp:1853] Performed allocation for 1 agents in 196939ns
I0313 00:06:51.581014  3086 provider.cpp:790] Reconciling storage pools and volumes
I0313 00:06:51.583153 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call
I0313 00:06:51.583545 14667 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call
I0313 00:06:51.594265  3080 slave.cpp:995] Agent terminating
I0313 00:06:51.595202  3080 manager.cpp:127] Terminating resource provider 44fd3d2b-5f85-48c3-ad0f-221e3e7a4746
I0313 00:06:51.595733  3083 master.cpp:1292] Agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0 at slave(1239)@172.17.0.2:43769 (b49bdfa63993) disconnected
I0313 00:06:51.595772  3083 master.cpp:3361] Disconnecting agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0 at slave(1239)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:51.595877  3083 master.cpp:3380] Deactivating agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0 at slave(1239)@172.17.0.2:43769 (b49bdfa63993)
I0313 00:06:51.596040  3091 hierarchical.cpp:1156] Agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0 deactivated
E0313 00:06:51.596244  3087 http_connection.hpp:449] End-Of-File received
I0313 00:06:51.596760  3087 http_connection.hpp:217] Re-detecting endpoint
I0313 00:06:51.597347  3087 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0313 00:06:51.597424  3087 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0313 00:06:51.597513  3087 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:43769/slave(1239)/api/v1/resource_provider
I0313 00:06:51.597538  3096 provider.cpp:488] Disconnected from resource provider manager
I0313 00:06:51.597730  3096 status_update_manager_process.hpp:379] Pausing operation status update manager
I0313 00:06:51.599243  3095 containerizer.cpp:2619] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0313 00:06:51.599313  3095 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 15.466877952secs
I0313 00:06:51.599786  3095 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:51.600850  3085 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:43769/slave(1239)/api/v1/resource_provider
I0313 00:06:51.601521  3083 provider.cpp:476] Connected to resource provider manager
I0313 00:06:51.602208  3087 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:43769/slave(1239)/api/v1/resource_provider
I0313 00:06:51.603111  3097 process.cpp:2781] Returning '404 Not Found' for '/slave(1239)/api/v1/resource_provider'
E0313 00:06:51.604403  3090 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0313 00:06:51.627919  3093 hierarchical.cpp:1853] Performed allocation for 1 agents in 227784ns
I0313 00:06:51.678125  3092 containerizer.cpp:3155] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0313 00:06:51.679492  3088 hierarchical.cpp:1853] Performed allocation for 1 agents in 119289ns
I0313 00:06:51.680012  3086 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
I0313 00:06:51.683215  3083 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'
I0313 00:06:51.683456  3090 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-LvA5W9/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0313 00:06:51.683753  3088 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0313 00:06:51.687024  3097 process.cpp:2781] Returning '404 Not Found' for '/slave(1239)/api/v1'
I0313 00:06:51.699250  3080 master.cpp:1140] Master terminating
I0313 00:06:51.699623  3093 hierarchical.cpp:1132] Removed all filters for agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0
I0313 00:06:51.699652  3093 hierarchical.cpp:1008] Removed agent d52c6d46-1166-42cc-a4ba-6fa17843d194-S0
[       OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v1 (708 ms)
[----------] 54 tests from CSIVersion/StorageLocalResourceProviderTest (107754 ms total)

[----------] Global test environment tear-down
[==========] 2312 tests from 223 test cases ran. (1101400 ms total)
[  PASSED  ] 2311 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] CSIVersion/StorageLocalResourceProviderTest.CreateDestroyPreprovisionedVolume/v0, where GetParam() = "v0"

 1 FAILED TEST
  YOU HAVE 34 DISABLED TESTS

I0313 00:06:51.786792  3097 process.cpp:935] Stopped the socket accept loop
Makefile:15957: recipe for target 'check-local' failed
make[4]: *** [check-local] Error 1
make[4]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub/src'
Makefile:15073: recipe for target 'check-am' failed
make[3]: *** [check-am] Error 2
make[3]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub/src'
Makefile:15077: recipe for target 'check' failed
make[2]: *** [check] Error 2
make[2]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub/src'
Makefile:785: recipe for target 'check-recursive' failed
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub'
Makefile:991: recipe for target 'distcheck' failed
make: *** [distcheck] Error 1
Untagged: mesos/mesos-build:ubuntu-16.04
Untagged: mesos/mesos-build@sha256:fa967cbcfb44f55708a3cbc87f245c6d29dd891464db558af56a03ee321526bb
Deleted: sha256:e895c0531b9a9a288fabe479a49f7059aed83645351ac99ec2ea2616822c9f97
Deleted: sha256:09119b0b314a69ba6ec6251f2e89f4199fe1e874c84f9abf07dcbd23dbc3f1c1
Deleted: sha256:562fe6af5a3883058be9c784a839392215ed4185a21d21f1d99df0d17f3ae6e7
Deleted: sha256:0dcdfbe322a4f332f73ac70905d557300ec6dae3bd19586758772c750c7b4a19
Deleted: sha256:c66652d605f01094e2db53d62505dbd524e076d5aa69b89d5e620003803eb149
Deleted: sha256:a2cf79bfb9593c05fd7142ddb49afef77ea4ad5d2464e841f09fe62ffee396e0
Deleted: sha256:f7a904214b390f39d98573882f631dc908df8b2b540cf04e1062f8182c1efffd
Deleted: sha256:ce1f6fcaa83dfce189d76e08f184085732eab4eeb2562d2399953958405c5bec
Deleted: sha256:cce92fda689ab9033f0b8db214bc63edd1ae3e05831a0f3a9418976d7dc7ccdd
Deleted: sha256:d22094bbd65447c59a42c580eaa3a44cee9cd855f00905f59409be21bcefc745
Deleted: sha256:b8976847450013f3eb5e9a81a5778f73ed7bef67e6393049712ef17102b4b7b7
Deleted: sha256:b8c891f0ffec910a12757d733b178e3f62d81dbbde2b31d3b754071c416108ed

Full log: https://builds.apache.org/job/Mesos-Reviewbot-Linux/7976/console

- Mesos Reviewbot


On March 12, 2020, 10 p.m., Benjamin Mahler wrote:
> 
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/72233/
> -----------------------------------------------------------
> 
> (Updated March 12, 2020, 10 p.m.)
> 
> 
> Review request for mesos and Andrei Sekretenko.
> 
> 
> Bugs: MESOS-10103
>     https://issues.apache.org/jira/browse/MESOS-10103
> 
> 
> Repository: mesos
> 
> 
> Description
> -------
> 
> Found by Andrei Sekretenko using -fsanitize=address, the following
> expression has an intermediate temporary!
> 
>   const RepeatedPtrField<Resource::ReservationInfo>&
>     ancestorReservations =
>     RepeatedPtrField<Resource>(ancestor).begin()->reservations();
> 
> Therefore, the intermediate temporary will not have its lifetime
> extended and this is undefined behavior which leads to a crash
> in the windows CI.
> 
> 
> Diffs
> -----
> 
>   src/master/authorization.cpp 6dfa59ad621d9aa0fd1dbbdbe4fa8965e413774f 
> 
> 
> Diff: https://reviews.apache.org/r/72233/diff/1/
> 
> 
> Testing
> -------
> 
> Ran through windows CI.
> 
> 
> Thanks,
> 
> Benjamin Mahler
> 
>


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