You are viewing a plain text version of this content. The canonical link for it is here.
Posted to reviews@mesos.apache.org by Meng Zhu <mz...@mesosphere.io> on 2019/07/07 22:12:33 UTC
Review Request 71022: Added tests for `UPDATE_QUOTA`.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71022/
-----------------------------------------------------------
Review request for mesos and Benjamin Mahler.
Bugs: MESOS-8968
https://issues.apache.org/jira/browse/MESOS-8968
Repository: mesos
Description
-------
These tests reuse the existing tests for `SET_QUOTA` and
`REMOVE_QUOTA` calls. In general, `UPDATE_QUOTA` request
should fail where `SET_QUOTA` fails. When the existing
test expects `SET_QUOTA` call succeeds, we test the
`UPDATE_QUOTA` call by first remove the set quota and then
send the `UPDATE_QUOTA` request.
Diffs
-----
src/tests/master_quota_tests.cpp 34a652029e31827f8d94bb66d408fbe3d121fd8f
Diff: https://reviews.apache.org/r/71022/diff/1/
Testing
-------
make check
Thanks,
Meng Zhu
Re: Review Request 71022: Added tests for `UPDATE_QUOTA`.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71022/#review216437
-----------------------------------------------------------
Bad patch!
Reviews applied: [71019, 71020, 71021, 71022]
Failed command: ['bash', '-c', "set -o pipefail; export OS='ubuntu:14.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/docker-build.sh 2>&1 | tee build_71022"]
Error:
...<truncated>...
4073b43 on agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0
I0709 03:35:01.168401 18254 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: a96cd6c2-c340-4b72-ad92-80df0992c953) for operation UUID b955f716-c2c3-4506-a00d-0e19f4073b43 on agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0
I0709 03:35:01.169265 18277 http_connection.hpp:131] Sending 2 call to http://172.17.0.3:42622/slave(1196)/api/v1/resource_provider
I0709 03:35:01.170203 18255 process.cpp:3671] Handling HTTP event for process 'slave(1196)' with path: '/slave(1196)/api/v1/resource_provider'
I0709 03:35:01.173105 18275 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0709 03:35:01.174614 18276 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.3:60644
I0709 03:35:01.174844 18276 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0709 03:35:01.175524 18276 master.cpp:3785] Authorizing principal 'test-principal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_CidaWX/2GB-7f5f815d-7d9f-4de7-86e5-80d2a26ce62b","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"6c76a1b0-a9eb-4a97-b9db-4ba08b6011e3"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0709 03:35:01.177569 18271 master.cpp:12470] Removing offer 4dac6b5f-2b59-45cf-9202-06d12f77be62-O5
I0709 03:35:01.177723 18261 sched.cpp:960] Rescinded offer 4dac6b5f-2b59-45cf-9202-06d12f77be62-O5
I0709 03:35:01.177804 18261 sched.cpp:971] Scheduler::offerRescinded took 21895ns
I0709 03:35:01.178423 18268 hierarchical.cpp:1218] Recovered 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_v0_CidaWX/2GB-7f5f815d-7d9f-4de7-86e5-80d2a26ce62b,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (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_v0_CidaWX/2GB-7f5f815d-7d9f-4de7-86e5-80d2a26ce62b,test)]:2048, allocated: {}) on agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0 from framework 4dac6b5f-2b59-45
cf-9202-06d12f77be62-0000
I0709 03:35:01.178540 18268 hierarchical.cpp:1264] Framework 4dac6b5f-2b59-45cf-9202-06d12f77be62-0000 filtered agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0 for 5secs
I0709 03:35:01.180860 18263 master.cpp:12361] Sending operation '' (uuid: db54fe76-3dda-41ef-9384-44f211cf8517) to agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0 at slave(1196)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:01.181380 18277 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:01.183845 18260 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.163109ms
I0709 03:35:01.184108 18273 provider.cpp:481] Received APPLY_OPERATION event
I0709 03:35:01.184156 18273 provider.cpp:1295] Received UNRESERVE operation '' (uuid: db54fe76-3dda-41ef-9384-44f211cf8517)
I0709 03:35:01.184527 18266 master.cpp:10195] Sending offers [ 4dac6b5f-2b59-45cf-9202-06d12f77be62-O6 ] to framework 4dac6b5f-2b59-45cf-9202-06d12f77be62-0000 (default) at scheduler-68435923-60d8-4dc3-a43a-03309815a5d5@172.17.0.3:42622
I0709 03:35:01.185142 18276 sched.cpp:934] Scheduler::resourceOffers took 69570ns
I0709 03:35:01.209959 18265 http.cpp:1115] HTTP POST for /slave(1196)/api/v1/resource_provider from 172.17.0.3:60590
I0709 03:35:01.210876 18256 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: b955f716-c2c3-4506-a00d-0e19f4073b43) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 03:35:01.211057 18256 slave.cpp:8670] Updating the state of operation with no ID (uuid: b955f716-c2c3-4506-a00d-0e19f4073b43) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 03:35:01.211120 18256 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: b955f716-c2c3-4506-a00d-0e19f4073b43) for an operator API call
I0709 03:35:01.211552 18256 master.cpp:12017] Updating the state of operation '' (uuid: b955f716-c2c3-4506-a00d-0e19f4073b43) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 03:35:01.212054 18262 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:01.286237 18276 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 464f8521-6c05-46e5-9ca7-df635a3914a7) for operation UUID db54fe76-3dda-41ef-9384-44f211cf8517 on agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0
I0709 03:35:01.286309 18276 status_update_manager_process.hpp:414] Creating operation status update stream db54fe76-3dda-41ef-9384-44f211cf8517 checkpoint=true
I0709 03:35:01.286334 18273 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 03:35:01.286868 18276 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 464f8521-6c05-46e5-9ca7-df635a3914a7) for operation UUID db54fe76-3dda-41ef-9384-44f211cf8517 on agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0
I0709 03:35:01.336398 18276 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 464f8521-6c05-46e5-9ca7-df635a3914a7) for operation UUID db54fe76-3dda-41ef-9384-44f211cf8517 on agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0
I0709 03:35:01.336838 18276 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: a96cd6c2-c340-4b72-ad92-80df0992c953) for stream b955f716-c2c3-4506-a00d-0e19f4073b43
I0709 03:35:01.336923 18276 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: a96cd6c2-c340-4b72-ad92-80df0992c953) for operation UUID b955f716-c2c3-4506-a00d-0e19f4073b43 on agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0
I0709 03:35:01.337303 18264 http_connection.hpp:131] Sending 2 call to http://172.17.0.3:42622/slave(1196)/api/v1/resource_provider
I0709 03:35:01.338176 18268 process.cpp:3671] Handling HTTP event for process 'slave(1196)' with path: '/slave(1196)/api/v1/resource_provider'
I0709 03:35:01.378027 18255 http.cpp:1115] HTTP POST for /slave(1196)/api/v1/resource_provider from 172.17.0.3:60590
I0709 03:35:01.378875 18262 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: db54fe76-3dda-41ef-9384-44f211cf8517) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 03:35:01.379065 18262 slave.cpp:8670] Updating the state of operation with no ID (uuid: db54fe76-3dda-41ef-9384-44f211cf8517) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 03:35:01.379125 18262 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: db54fe76-3dda-41ef-9384-44f211cf8517) for an operator API call
I0709 03:35:01.379505 18275 master.cpp:12017] Updating the state of operation '' (uuid: db54fe76-3dda-41ef-9384-44f211cf8517) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 03:35:01.380045 18257 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:01.381423 18261 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 03:35:01.420053 18276 status_update_manager_process.hpp:490] Cleaning up operation status update stream b955f716-c2c3-4506-a00d-0e19f4073b43
I0709 03:35:01.420296 18276 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 464f8521-6c05-46e5-9ca7-df635a3914a7) for stream db54fe76-3dda-41ef-9384-44f211cf8517
I0709 03:35:01.420369 18276 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 464f8521-6c05-46e5-9ca7-df635a3914a7) for operation UUID db54fe76-3dda-41ef-9384-44f211cf8517 on agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0
I0709 03:35:01.503763 18276 status_update_manager_process.hpp:490] Cleaning up operation status update stream db54fe76-3dda-41ef-9384-44f211cf8517
I0709 03:35:01.572214 18254 master.cpp:1410] Framework 4dac6b5f-2b59-45cf-9202-06d12f77be62-0000 (default) at scheduler-68435923-60d8-4dc3-a43a-03309815a5d5@172.17.0.3:42622 disconnected
I0709 03:35:01.572260 18254 master.cpp:3342] Deactivating framework 4dac6b5f-2b59-45cf-9202-06d12f77be62-0000 (default) at scheduler-68435923-60d8-4dc3-a43a-03309815a5d5@172.17.0.3:42622
I0709 03:35:01.572672 18256 hierarchical.cpp:475] Deactivated framework 4dac6b5f-2b59-45cf-9202-06d12f77be62-0000
I0709 03:35:01.573196 18257 slave.cpp:912] Agent terminating
I0709 03:35:01.573462 18254 master.cpp:12470] Removing offer 4dac6b5f-2b59-45cf-9202-06d12f77be62-O6
I0709 03:35:01.573549 18254 master.cpp:3319] Disconnecting framework 4dac6b5f-2b59-45cf-9202-06d12f77be62-0000 (default) at scheduler-68435923-60d8-4dc3-a43a-03309815a5d5@172.17.0.3:42622
I0709 03:35:01.573606 18254 master.cpp:1425] Giving framework 4dac6b5f-2b59-45cf-9202-06d12f77be62-0000 (default) at scheduler-68435923-60d8-4dc3-a43a-03309815a5d5@172.17.0.3:42622 0ns to failover
I0709 03:35:01.574156 18257 manager.cpp:163] Terminating resource provider 6c76a1b0-a9eb-4a97-b9db-4ba08b6011e3
I0709 03:35:01.574328 18256 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_CidaWX/2GB-7f5f815d-7d9f-4de7-86e5-80d2a26ce62b,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (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_v0_CidaWX/2GB-7f5f815d-7d9f-4de7-86e5-80d2a26ce62b,test)]:2048, allocated: {}) on agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0 from framework 4dac6b5f-2b59-45cf-9202-06d12f77be62-0000
I0709 03:35:01.574569 18265 master.cpp:1295] Agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0 at slave(1196)@172.17.0.3:42622 (fc165f183aad) disconnected
I0709 03:35:01.574611 18265 master.cpp:3379] Disconnecting agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0 at slave(1196)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:01.574697 18265 master.cpp:3398] Deactivating agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0 at slave(1196)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:01.574841 18262 hierarchical.cpp:799] Agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0 deactivated
I0709 03:35:01.574905 18265 master.cpp:9987] Framework failover timeout, removing framework 4dac6b5f-2b59-45cf-9202-06d12f77be62-0000 (default) at scheduler-68435923-60d8-4dc3-a43a-03309815a5d5@172.17.0.3:42622
I0709 03:35:01.574947 18265 master.cpp:10979] Removing framework 4dac6b5f-2b59-45cf-9202-06d12f77be62-0000 (default) at scheduler-68435923-60d8-4dc3-a43a-03309815a5d5@172.17.0.3:42622
E0709 03:35:01.575289 18270 http_connection.hpp:452] End-Of-File received
I0709 03:35:01.575381 18267 hierarchical.cpp:1432] Allocation paused
I0709 03:35:01.575757 18267 hierarchical.cpp:417] Removed framework 4dac6b5f-2b59-45cf-9202-06d12f77be62-0000
I0709 03:35:01.575810 18270 http_connection.hpp:217] Re-detecting endpoint
I0709 03:35:01.575816 18267 hierarchical.cpp:1442] Allocation resumed
I0709 03:35:01.576241 18270 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0709 03:35:01.576328 18273 provider.cpp:471] Disconnected from resource provider manager
I0709 03:35:01.576355 18270 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0709 03:35:01.576544 18270 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:42622/slave(1196)/api/v1/resource_provider
I0709 03:35:01.576581 18271 status_update_manager_process.hpp:379] Pausing operation status update manager
I0709 03:35:01.578037 18261 containerizer.cpp:2575] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0709 03:35:01.578076 18261 containerizer.cpp:3277] 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
I0709 03:35:01.578497 18261 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 03:35:01.579535 18274 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.3:42622/slave(1196)/api/v1/resource_provider
I0709 03:35:01.580113 18259 provider.cpp:459] Connected to resource provider manager
I0709 03:35:01.580519 18271 hierarchical.cpp:1508] Performed allocation for 1 agents in 159751ns
I0709 03:35:01.580773 18273 http_connection.hpp:131] Sending 1 call to http://172.17.0.3:42622/slave(1196)/api/v1/resource_provider
E0709 03:35:01.581297 18273 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Cannot process 'SUBSCRIBE' call as the driver is in state SUBSCRIBING
I0709 03:35:01.581553 18278 process.cpp:2781] Returning '404 Not Found' for '/slave(1196)/api/v1/resource_provider'
E0709 03:35:01.582731 18262 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0709 03:35:01.631553 18277 hierarchical.cpp:1508] Performed allocation for 1 agents in 114337ns
I0709 03:35:01.681787 18255 containerizer.cpp:3116] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0709 03:35:01.682250 18258 hierarchical.cpp:1508] Performed allocation for 1 agents in 110585ns
I0709 03:35:01.683394 18268 provisioner.cpp:609] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 03:35:01.685979 18263 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'
I0709 03:35:01.686213 18277 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-bWNHNQ/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 03:35:01.686518 18260 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 03:35:01.689430 18278 process.cpp:2781] Returning '404 Not Found' for '/slave(1196)/api/v1'
I0709 03:35:01.701262 18253 master.cpp:1135] Master terminating
I0709 03:35:01.701932 18276 hierarchical.cpp:775] Removed all filters for agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0
I0709 03:35:01.701962 18276 hierarchical.cpp:650] Removed agent 4dac6b5f-2b59-45cf-9202-06d12f77be62-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v0 (2524 ms)
[ RUN ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1
I0709 03:35:01.718430 18253 cluster.cpp:176] Creating default 'local' authorizer
I0709 03:35:01.723111 18277 master.cpp:440] Master 7668db62-5096-4685-ad2c-f6ce543fc060 (fc165f183aad) started on 172.17.0.3:42622
I0709 03:35:01.723139 18277 master.cpp:443] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/mV4hrc/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_alloca
table_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/mesos/mesos-1.9.0/_inst/share/mesos/webui" --work_dir="/tmp/mV4hrc/master" --zk_session_timeout="10secs"
I0709 03:35:01.723667 18277 master.cpp:492] Master only allowing authenticated frameworks to register
I0709 03:35:01.723685 18277 master.cpp:498] Master only allowing authenticated agents to register
I0709 03:35:01.723698 18277 master.cpp:504] Master only allowing authenticated HTTP frameworks to register
I0709 03:35:01.723717 18277 credentials.hpp:37] Loading credentials for authentication from '/tmp/mV4hrc/credentials'
I0709 03:35:01.724094 18277 master.cpp:548] Using default 'crammd5' authenticator
I0709 03:35:01.724316 18277 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0709 03:35:01.724619 18277 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0709 03:35:01.724849 18277 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0709 03:35:01.725071 18277 master.cpp:629] Authorization enabled
I0709 03:35:01.725517 18274 whitelist_watcher.cpp:77] No whitelist given
I0709 03:35:01.725528 18268 hierarchical.cpp:241] Initialized hierarchical allocator process
I0709 03:35:01.729434 18276 master.cpp:2150] Elected as the leading master!
I0709 03:35:01.729472 18276 master.cpp:1664] Recovering from registrar
I0709 03:35:01.729722 18267 registrar.cpp:339] Recovering registrar
I0709 03:35:01.730643 18267 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0709 03:35:01.730804 18267 registrar.cpp:487] Applied 1 operations in 55560ns; attempting to update the registry
I0709 03:35:01.731570 18267 registrar.cpp:544] Successfully updated the registry in 0ns
I0709 03:35:01.731719 18267 registrar.cpp:416] Successfully recovered registrar
I0709 03:35:01.732201 18255 master.cpp:1799] Recovered 0 agents from the registry (143B); allowing 10mins for agents to reregister
I0709 03:35:01.732234 18275 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover
W0709 03:35:01.738742 18253 process.cpp:2877] Attempted to spawn already running process files@172.17.0.3:42622
I0709 03:35:01.740087 18253 containerizer.cpp:314] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0709 03:35:01.740703 18253 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0709 03:35:01.740878 18253 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0709 03:35:01.740927 18253 provisioner.cpp:298] Using default backend 'copy'
I0709 03:35:01.743568 18253 cluster.cpp:510] Creating default 'local' authorizer
I0709 03:35:01.745999 18264 slave.cpp:265] Mesos agent started on (1197)@172.17.0.3:42622
I0709 03:35:01.746024 18264 slave.cpp:266] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mV4hrc/QMpNPV/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/mV4hrc/QMpNPV/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/mV4hrc/QMpNPV/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mV4hrc/QMpNPV/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/mV4hrc/QMpNPV/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/mV4hrc/QMpNPV/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.9.0/_build/src" --logbufsecs="0" --
logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/mV4hrc/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_OperatorOperationsWithResourceProviderResources_v1_KjpqYZ" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsW
ithResourceProviderResources_v1_eDh463" --zk_session_timeout="10secs"
I0709 03:35:01.746505 18264 credentials.hpp:86] Loading credential for authentication from '/tmp/mV4hrc/QMpNPV/credential'
I0709 03:35:01.746716 18264 slave.cpp:298] Agent using credential for: test-principal
I0709 03:35:01.746747 18264 credentials.hpp:37] Loading credentials for authentication from '/tmp/mV4hrc/QMpNPV/http_credentials'
I0709 03:35:01.747015 18264 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0709 03:35:01.747445 18264 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0709 03:35:01.749270 18264 slave.cpp:613] 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"}]
I0709 03:35:01.749490 18264 slave.cpp:621] Agent attributes: [ ]
I0709 03:35:01.749509 18264 slave.cpp:630] Agent hostname: fc165f183aad
I0709 03:35:01.749683 18268 status_update_manager_process.hpp:379] Pausing operation status update manager
I0709 03:35:01.749713 18277 task_status_update_manager.cpp:181] Pausing sending task status updates
I0709 03:35:01.750857 18262 process.cpp:3671] Handling HTTP event for process 'test-disk-profile-server' with path: '/test-disk-profile-server/profiles'
I0709 03:35:01.751513 18265 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_eDh463/meta'
I0709 03:35:01.751747 18273 slave.cpp:7246] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_eDh463/meta', beginning agent recovery
I0709 03:35:01.752458 18255 task_status_update_manager.cpp:207] Recovering task status update manager
I0709 03:35:01.752985 18271 containerizer.cpp:796] Recovering Mesos containers
I0709 03:35:01.753356 18271 containerizer.cpp:1122] Recovering isolators
I0709 03:35:01.754137 18258 containerizer.cpp:1161] Recovering provisioner
I0709 03:35:01.754863 18267 provisioner.cpp:498] Provisioner recovery complete
I0709 03:35:01.755218 18264 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I0709 03:35:01.755615 18276 composing.cpp:339] Finished recovering all containerizers
I0709 03:35:01.755892 18277 slave.cpp:7708] Recovering executors
I0709 03:35:01.756011 18277 slave.cpp:7861] Finished recovery
I0709 03:35:01.756927 18260 task_status_update_manager.cpp:181] Pausing sending task status updates
I0709 03:35:01.756952 18271 status_update_manager_process.hpp:379] Pausing operation status update manager
I0709 03:35:01.756994 18269 slave.cpp:1258] New master detected at master@172.17.0.3:42622
I0709 03:35:01.757166 18269 slave.cpp:1323] Detecting new master
I0709 03:35:01.758430 18268 slave.cpp:1350] Authenticating with master master@172.17.0.3:42622
I0709 03:35:01.758548 18268 slave.cpp:1359] Using default CRAM-MD5 authenticatee
I0709 03:35:01.758894 18259 authenticatee.cpp:121] Creating new client SASL connection
I0709 03:35:01.759250 18258 master.cpp:10380] Authenticating slave(1197)@172.17.0.3:42622
I0709 03:35:01.759444 18266 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2043)@172.17.0.3:42622
I0709 03:35:01.759742 18273 authenticator.cpp:98] Creating new server SASL connection
I0709 03:35:01.759989 18267 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0709 03:35:01.760020 18267 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0709 03:35:01.760154 18257 authenticator.cpp:204] Received SASL authentication start
I0709 03:35:01.760228 18257 authenticator.cpp:326] Authentication requires more steps
I0709 03:35:01.760358 18264 authenticatee.cpp:259] Received SASL authentication step
I0709 03:35:01.760556 18275 authenticator.cpp:232] Received SASL authentication step
I0709 03:35:01.760607 18275 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'fc165f183aad' server FQDN: 'fc165f183aad' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0709 03:35:01.760627 18275 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0709 03:35:01.760679 18275 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0709 03:35:01.760716 18275 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'fc165f183aad' server FQDN: 'fc165f183aad' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0709 03:35:01.760740 18275 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0709 03:35:01.760758 18275 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0709 03:35:01.760778 18275 authenticator.cpp:318] Authentication success
I0709 03:35:01.760905 18274 authenticatee.cpp:299] Authentication success
I0709 03:35:01.761030 18255 master.cpp:10412] Successfully authenticated principal 'test-principal' at slave(1197)@172.17.0.3:42622
I0709 03:35:01.761195 18272 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2043)@172.17.0.3:42622
I0709 03:35:01.761458 18254 slave.cpp:1450] Successfully authenticated with master master@172.17.0.3:42622
I0709 03:35:01.761880 18254 slave.cpp:1900] Will retry registration in 6.049526ms if necessary
I0709 03:35:01.762106 18261 master.cpp:6900] Received register agent message from slave(1197)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:01.762542 18261 master.cpp:4099] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I0709 03:35:01.763321 18271 master.cpp:6967] Authorized registration of agent at slave(1197)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:01.763419 18271 master.cpp:7082] Registering agent at slave(1197)@172.17.0.3:42622 (fc165f183aad) with id 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:01.764120 18265 registrar.cpp:487] Applied 1 operations in 192034ns; attempting to update the registry
I0709 03:35:01.764921 18265 registrar.cpp:544] Successfully updated the registry in 0ns
I0709 03:35:01.765125 18266 master.cpp:7130] Admitted agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:01.765933 18266 master.cpp:7175] Registered agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0709 03:35:01.766062 18267 slave.cpp:1483] Registered with master master@172.17.0.3:42622; given agent ID 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:01.766058 18257 hierarchical.cpp:617] Added agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 (fc165f183aad) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I0709 03:35:01.766194 18276 task_status_update_manager.cpp:188] Resuming sending task status updates
I0709 03:35:01.766484 18257 hierarchical.cpp:1508] Performed allocation for 1 agents in 168386ns
I0709 03:35:01.766716 18267 slave.cpp:1518] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_eDh463/meta/slaves/7668db62-5096-4685-ad2c-f6ce543fc060-S0/slave.info'
I0709 03:35:01.766762 18255 status_update_manager_process.hpp:385] Resuming operation status update manager
I0709 03:35:01.768013 18267 slave.cpp:1570] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"sDo0N/LLTjOhrU/sEpOERw=="},"slave_id":{"value":"7668db62-5096-4685-ad2c-f6ce543fc060-S0"},"update_oversubscribed_resources":false}
I0709 03:35:01.768810 18254 master.cpp:8261] Ignoring update on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad) as it reports no changes
I0709 03:35:01.773327 18265 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1'
I0709 03:35:01.774566 18263 http.cpp:1115] HTTP POST for /slave(1197)/api/v1 from 172.17.0.3:60678
I0709 03:35:01.775084 18263 http.cpp:2120] Processing GET_CONTAINERS call
I0709 03:35:01.780755 18259 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 03:35:01.783051 18265 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1'
I0709 03:35:01.783958 18274 http.cpp:1115] HTTP POST for /slave(1197)/api/v1 from 172.17.0.3:60680
I0709 03:35:01.784759 18274 http.cpp:2486] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 03:35:01.785606 18267 http.cpp:2590] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_eDh463/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 03:35:01.786299 18272 containerizer.cpp:1357] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 03:35:01.787492 18272 containerizer.cpp:1529] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_KjpqYZ/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0709 03:35:01.787535 18272 containerizer.cpp:3277] 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
I0709 03:35:01.790611 18271 containerizer.cpp:2055] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/mesos/mesos-1.9.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8","--available_capacity=2GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.9.0/_build/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_eDh463/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-i5t9AF/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperat
ionsWithResourceProviderResources_v1_eDh463/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="89" --pipe_write="90" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_KjpqYZ/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I0709 03:35:01.799921 18271 launcher.cpp:145] Forked child with pid '32026' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 03:35:01.800730 18271 containerizer.cpp:3277] 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
I0709 03:35:01.802206 18271 containerizer.cpp:3277] 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
I0709 03:35:01.802630 18265 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_OperatorOperationsWithResourceProviderResources_v1_eDh463/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 03:35:01.803822 18257 containerizer.cpp:3277] 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
I0709 03:35:01.807236 18254 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'
I0709 03:35:01.807513 18256 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-i5t9AF/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 03:35:01.943315 18259 hierarchical.cpp:1508] Performed allocation for 1 agents in 219340ns
I0709 03:35:01.994318 18277 hierarchical.cpp:1508] Performed allocation for 1 agents in 135787ns
I0709 03:35:02.045835 18267 hierarchical.cpp:1508] Performed allocation for 1 agents in 114524ns
I0709 03:35:02.097489 18268 hierarchical.cpp:1508] Performed allocation for 1 agents in 154461ns
I0709 03:35:02.148504 18276 hierarchical.cpp:1508] Performed allocation for 1 agents in 175499ns
I0709 03:35:02.185317 18257 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-i5t9AF/endpoint.sock' with CSI v1
I0709 03:35:02.199712 18275 hierarchical.cpp:1508] Performed allocation for 1 agents in 116409ns
I0709 03:35:02.204371 32030 test_csi_plugin.cpp:909] ProbeRequest '{}'
I0709 03:35:02.206331 18267 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 03:35:02.208839 32031 test_csi_plugin.cpp:895] GetPluginCapabilitiesRequest '{}'
I0709 03:35:02.209561 18259 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1'
I0709 03:35:02.210737 18263 http.cpp:1115] HTTP POST for /slave(1197)/api/v1 from 172.17.0.3:60694
I0709 03:35:02.211261 18263 http.cpp:2704] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 03:35:02.212224 32031 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0709 03:35:02.212572 32030 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0709 03:35:02.213835 18256 v1_volume_manager.cpp:648] NODE_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"}
I0709 03:35:02.214293 18256 v1_volume_manager.cpp:648] CONTROLLER_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"}
I0709 03:35:02.216272 32032 test_csi_plugin.cpp:1105] ControllerGetCapabilitiesRequest '{}'
I0709 03:35:02.219131 32032 test_csi_plugin.cpp:1241] NodeGetCapabilitiesRequest '{}'
I0709 03:35:02.221966 32031 test_csi_plugin.cpp:1255] NodeGetInfoRequest '{}'
I0709 03:35:02.223773 18274 provider.cpp:659] Finished recovery for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0709 03:35:02.223923 18255 status_update_manager_process.hpp:379] Pausing operation status update manager
I0709 03:35:02.224298 18269 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:02.227174 18268 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:02.227774 18266 provider.cpp:459] Connected to resource provider manager
I0709 03:35:02.228384 18277 http_connection.hpp:131] Sending 1 call to http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:02.229353 18263 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 03:35:02.230917 18274 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.3:60698
I0709 03:35:02.231549 18267 manager.cpp:807] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.9.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8","--available_capacity=2GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.9.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"}},"type":"org.apache.mesos.rp.local.storage"}
I0709 03:35:02.251355 18276 hierarchical.cpp:1508] Performed allocation for 1 agents in 184236ns
I0709 03:35:02.266371 18271 slave.cpp:8217] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"56d43a24-f3f5-47af-adb1-10a2ba1f796f"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.9.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8","--available_capacity=2GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.9.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"}},"type":"org.apache.mesos.rp.local.storage"}'
I0709 03:35:02.267750 18254 provider.cpp:481] Received SUBSCRIBED event
I0709 03:35:02.267784 18254 provider.cpp:1255] Subscribed with ID 56d43a24-f3f5-47af-adb1-10a2ba1f796f
I0709 03:35:02.268637 18274 status_update_manager_process.hpp:314] Recovering operation status update manager
I0709 03:35:02.302794 18269 hierarchical.cpp:1508] Performed allocation for 1 agents in 111965ns
I0709 03:35:02.318588 32032 test_csi_plugin.cpp:1050] ListVolumesRequest '{}'
I0709 03:35:02.320734 18266 provider.cpp:2145] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:02.320935 18266 provider.cpp:745] Resource provider 56d43a24-f3f5-47af-adb1-10a2ba1f796f is in READY state
I0709 03:35:02.320996 18277 status_update_manager_process.hpp:385] Resuming operation status update manager
I0709 03:35:02.320996 18258 http_connection.hpp:131] Sending 3 call to http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:02.321601 18257 provider.cpp:1181] Updating profiles { test } for resource provider 56d43a24-f3f5-47af-adb1-10a2ba1f796f
I0709 03:35:02.322021 18265 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 03:35:02.323540 18271 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.3:60696
I0709 03:35:02.323999 18277 manager.cpp:1039] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 56d43a24-f3f5-47af-adb1-10a2ba1f796f
I0709 03:35:02.324221 18266 slave.cpp:8217] Handling resource provider message 'UPDATE_STATE: 56d43a24-f3f5-47af-adb1-10a2ba1f796f {}'
I0709 03:35:02.324327 18266 slave.cpp:8337] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0709 03:35:02.325033 32032 test_csi_plugin.cpp:1078] GetCapacityRequest '{"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0709 03:35:02.326323 18255 hierarchical.cpp:753] Grew agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 by {} (total), { } (used)
I0709 03:35:02.326772 18255 hierarchical.cpp:710] Agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 (fc165f183aad) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
W0709 03:35:02.327566 18253 process.cpp:2877] Attempted to spawn already running process version@172.17.0.3:42622
I0709 03:35:02.328853 18253 sched.cpp:239] Version: 1.9.0
I0709 03:35:02.329704 18271 sched.cpp:343] New master detected at master@172.17.0.3:42622
I0709 03:35:02.329753 18276 provider.cpp:933] Removing '{}' and adding 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' to the total resources
I0709 03:35:02.329839 18271 sched.cpp:408] Authenticating with master master@172.17.0.3:42622
I0709 03:35:02.329865 18271 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0709 03:35:02.330278 18273 authenticatee.cpp:121] Creating new client SASL connection
I0709 03:35:02.330691 18263 master.cpp:10380] Authenticating scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:02.330785 18260 hierarchical.cpp:1508] Performed allocation for 1 agents in 195186ns
I0709 03:35:02.330911 18270 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2044)@172.17.0.3:42622
I0709 03:35:02.331295 18254 authenticator.cpp:98] Creating new server SASL connection
I0709 03:35:02.331568 18275 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0709 03:35:02.331600 18275 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0709 03:35:02.331743 18269 authenticator.cpp:204] Received SASL authentication start
I0709 03:35:02.331820 18269 authenticator.cpp:326] Authentication requires more steps
I0709 03:35:02.331954 18266 authenticatee.cpp:259] Received SASL authentication step
I0709 03:35:02.332116 18257 authenticator.cpp:232] Received SASL authentication step
I0709 03:35:02.332166 18257 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'fc165f183aad' server FQDN: 'fc165f183aad' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0709 03:35:02.332195 18257 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0709 03:35:02.332262 18257 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0709 03:35:02.332299 18257 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'fc165f183aad' server FQDN: 'fc165f183aad' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0709 03:35:02.332319 18257 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0709 03:35:02.332336 18257 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0709 03:35:02.332363 18257 authenticator.cpp:318] Authentication success
I0709 03:35:02.332569 18255 authenticatee.cpp:299] Authentication success
I0709 03:35:02.332635 18261 master.cpp:10412] Successfully authenticated principal 'test-principal' at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:02.332653 18256 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2044)@172.17.0.3:42622
I0709 03:35:02.333056 18267 sched.cpp:520] Successfully authenticated with master master@172.17.0.3:42622
I0709 03:35:02.333086 18267 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.3:42622
I0709 03:35:02.333253 18267 sched.cpp:870] Will retry registration in 907.661037ms if necessary
I0709 03:35:02.333468 18268 master.cpp:2890] Received SUBSCRIBE call for framework 'default' at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:02.333511 18268 master.cpp:2222] Authorizing framework principal 'test-principal' to receive offers for roles '{ storage/default-role }'
I0709 03:35:02.334172 18258 master.cpp:2977] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0709 03:35:02.336764 18258 master.cpp:10610] Adding framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622 with roles { } suppressed
I0709 03:35:02.337347 18273 sched.cpp:751] Framework registered with 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.337414 18273 sched.cpp:770] Scheduler::registered took 27773ns
I0709 03:35:02.337901 18271 hierarchical.cpp:368] Added framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.339146 18271 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.084989ms
I0709 03:35:02.339665 18260 master.cpp:10195] Sending offers [ 7668db62-5096-4685-ad2c-f6ce543fc060-O0 ] to framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:02.340229 18270 sched.cpp:934] Scheduler::resourceOffers took 118676ns
I0709 03:35:02.340595 18254 master.cpp:6119] Processing DECLINE call for offers: [ 7668db62-5096-4685-ad2c-f6ce543fc060-O0 ] for framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622 with 5 seconds filter
I0709 03:35:02.341181 18254 master.cpp:12470] Removing offer 7668db62-5096-4685-ad2c-f6ce543fc060-O0
I0709 03:35:02.341791 18275 hierarchical.cpp:1218] Recovered cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 from framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.341866 18275 hierarchical.cpp:1264] Framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 filtered agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 for 5secs
I0709 03:35:02.391798 18276 provider.cpp:2145] Sending UPDATE_STATE call with resources 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' and 0 operations to agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:02.392302 18269 http_connection.hpp:131] Sending 3 call to http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:02.393465 18261 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 03:35:02.434629 18267 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.3:60696
I0709 03:35:02.435189 18268 manager.cpp:1039] Received UPDATE_STATE call with resources '[{"disk":{"source":{"profile":"test","type":"RAW","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"56d43a24-f3f5-47af-adb1-10a2ba1f796f"},"reservations":[{"role":"storage","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]' and 0 operations from resource provider 56d43a24-f3f5-47af-adb1-10a2ba1f796f
I0709 03:35:02.435668 18264 slave.cpp:8217] Handling resource provider message 'UPDATE_STATE: 56d43a24-f3f5-47af-adb1-10a2ba1f796f disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048'
I0709 03:35:02.435824 18264 slave.cpp:8337] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048
I0709 03:35:02.438071 18263 hierarchical.cpp:710] Agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 (fc165f183aad) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048
I0709 03:35:02.439348 18263 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.078818ms
I0709 03:35:02.439956 18271 master.cpp:10195] Sending offers [ 7668db62-5096-4685-ad2c-f6ce543fc060-O1 ] to framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:02.440619 18260 sched.cpp:934] Scheduler::resourceOffers took 128604ns
I0709 03:35:02.446301 18275 master.cpp:12470] Removing offer 7668db62-5096-4685-ad2c-f6ce543fc060-O1
I0709 03:35:02.446612 18276 hierarchical.cpp:1508] Performed allocation for 1 agents in 248248ns
I0709 03:35:02.446684 18275 master.cpp:4636] Processing ACCEPT call for offers: [ 7668db62-5096-4685-ad2c-f6ce543fc060-O1 ] on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad) for framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:02.446795 18275 master.cpp:4009] Authorizing principal 'test-principal' to create a MOUNT disk from 'disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048'
I0709 03:35:02.447726 18261 master.cpp:5911] Processing CREATE_DISK operation with source disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048 from framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622 to agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:02.448264 18261 master.cpp:12361] Sending operation '' (uuid: aab38a95-cc4c-414a-a090-94d922461dd2) to agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:02.448565 18256 hierarchical.cpp:1432] Allocation paused
I0709 03:35:02.448825 18259 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:02.449775 18256 hierarchical.cpp:1218] Recovered ports(allocated: storage/default-role):[31000-32000]; 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)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048, allocated: disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048) on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 from framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.449869 18256 hierarchical.cpp:1264] Framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 filtered agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 for 5secs
I0709 03:35:02.450067 18256 hierarchical.cpp:1442] Allocation resumed
I0709 03:35:02.450948 18277 provider.cpp:481] Received APPLY_OPERATION event
I0709 03:35:02.450992 18277 provider.cpp:1295] Received CREATE_DISK operation '' (uuid: aab38a95-cc4c-414a-a090-94d922461dd2)
I0709 03:35:02.498060 18271 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 for role storage/default-role of framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.498172 18271 hierarchical.cpp:1508] Performed allocation for 1 agents in 462549ns
I0709 03:35:02.517791 18260 v1_volume_manager.cpp:292] Creating volume with name 'aab38a95-cc4c-414a-a090-94d922461dd2'
I0709 03:35:02.520519 32031 test_csi_plugin.cpp:922] CreateVolumeRequest '{"name":"aab38a95-cc4c-414a-a090-94d922461dd2","capacityRange":{"requiredBytes":"2147483648","limitBytes":"2147483648"},"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0709 03:35:02.550148 18265 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 for role storage/default-role of framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.550331 18265 hierarchical.cpp:1508] Performed allocation for 1 agents in 715860ns
I0709 03:35:02.601296 18272 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 for role storage/default-role of framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.601404 18272 hierarchical.cpp:1508] Performed allocation for 1 agents in 433443ns
I0709 03:35:02.610520 18261 provider.cpp:1597] Applying conversion from 'disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' to 'disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048' for operation (uuid: aab38a95-cc4c-414a-a090-94d922461dd2)
I0709 03:35:02.653125 18255 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 for role storage/default-role of framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.653241 18255 hierarchical.cpp:1508] Performed allocation for 1 agents in 431072ns
I0709 03:35:02.660621 18262 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 8dfa5136-032a-46ac-842f-15591ad01491) for operation UUID aab38a95-cc4c-414a-a090-94d922461dd2 of framework '7668db62-5096-4685-ad2c-f6ce543fc060-0000' on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:02.660723 18262 status_update_manager_process.hpp:414] Creating operation status update stream aab38a95-cc4c-414a-a090-94d922461dd2 checkpoint=true
I0709 03:35:02.661402 18262 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 8dfa5136-032a-46ac-842f-15591ad01491) for operation UUID aab38a95-cc4c-414a-a090-94d922461dd2 of framework '7668db62-5096-4685-ad2c-f6ce543fc060-0000' on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:02.704556 18267 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 for role storage/default-role of framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.704706 18267 hierarchical.cpp:1508] Performed allocation for 1 agents in 582804ns
I0709 03:35:02.710810 18262 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 8dfa5136-032a-46ac-842f-15591ad01491) for operation UUID aab38a95-cc4c-414a-a090-94d922461dd2 of framework '7668db62-5096-4685-ad2c-f6ce543fc060-0000' on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:02.711858 18268 http_connection.hpp:131] Sending 2 call to http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:02.713163 18258 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 03:35:02.750984 18260 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.3:60696
I0709 03:35:02.752228 18257 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: aab38a95-cc4c-414a-a090-94d922461dd2) for framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 03:35:02.752549 18257 slave.cpp:8670] Updating the state of operation with no ID (uuid: aab38a95-cc4c-414a-a090-94d922461dd2) for framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 03:35:02.753181 18257 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: aab38a95-cc4c-414a-a090-94d922461dd2) for framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.753808 18265 master.cpp:12017] Updating the state of operation '' (uuid: aab38a95-cc4c-414a-a090-94d922461dd2) for framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 03:35:02.755714 18259 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:02.756917 18276 hierarchical.cpp:956] Updated allocation of framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 from disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048 to disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048
I0709 03:35:02.757848 18258 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 03:35:02.757809 18276 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048 (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_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048, allocated: {}) on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 from framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.758072 18263 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 8dfa5136-032a-46ac-842f-15591ad01491) for stream aab38a95-cc4c-414a-a090-94d922461dd2
I0709 03:35:02.758198 18263 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 8dfa5136-032a-46ac-842f-15591ad01491) for operation UUID aab38a95-cc4c-414a-a090-94d922461dd2 of framework '7668db62-5096-4685-ad2c-f6ce543fc060-0000' on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:02.759656 18276 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.488206ms
I0709 03:35:02.760607 18271 master.cpp:10195] Sending offers [ 7668db62-5096-4685-ad2c-f6ce543fc060-O2 ] to framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:02.761555 18277 sched.cpp:934] Scheduler::resourceOffers took 180325ns
I0709 03:35:02.766347 18266 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0709 03:35:02.768589 18268 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.3:60716
I0709 03:35:02.768896 18268 http.cpp:263] Processing call RESERVE_RESOURCES
I0709 03:35:02.769874 18268 master.cpp:3721] Authorizing principal 'test-principal' to reserve resources 'disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048'
I0709 03:35:02.772048 18273 master.cpp:12470] Removing offer 7668db62-5096-4685-ad2c-f6ce543fc060-O2
I0709 03:35:02.772199 18271 sched.cpp:960] Rescinded offer 7668db62-5096-4685-ad2c-f6ce543fc060-O2
I0709 03:35:02.772543 18271 sched.cpp:971] Scheduler::offerRescinded took 35693ns
I0709 03:35:02.773059 18276 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (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_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048, allocated: {}) on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 from framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:02.773186 18276 hierarchical.cpp:1264] Framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 filtered agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 for 5secs
I0709 03:35:02.775951 18277 master.cpp:12361] Sending operation '' (uuid: 2dabd024-5305-4e64-a3a3-c6e37314081a) to agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:02.776650 18269 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:02.779479 18267 provider.cpp:481] Received APPLY_OPERATION event
I0709 03:35:02.779528 18267 provider.cpp:1295] Received RESERVE operation '' (uuid: 2dabd024-5305-4e64-a3a3-c6e37314081a)
I0709 03:35:02.819212 18263 status_update_manager_process.hpp:490] Cleaning up operation status update stream aab38a95-cc4c-414a-a090-94d922461dd2
I0709 03:35:02.911999 18264 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 07cb2461-27a0-4bfb-8d03-43be0be8051a) for operation UUID 2dabd024-5305-4e64-a3a3-c6e37314081a on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:02.912062 18264 status_update_manager_process.hpp:414] Creating operation status update stream 2dabd024-5305-4e64-a3a3-c6e37314081a checkpoint=true
I0709 03:35:02.912585 18264 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 07cb2461-27a0-4bfb-8d03-43be0be8051a) for operation UUID 2dabd024-5305-4e64-a3a3-c6e37314081a on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:02.995733 18264 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 07cb2461-27a0-4bfb-8d03-43be0be8051a) for operation UUID 2dabd024-5305-4e64-a3a3-c6e37314081a on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.013598 18268 http_connection.hpp:131] Sending 2 call to http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:03.014523 18274 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 03:35:03.017644 18273 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.254287ms
I0709 03:35:03.018301 18276 master.cpp:10195] Sending offers [ 7668db62-5096-4685-ad2c-f6ce543fc060-O3 ] to framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:03.018939 18270 sched.cpp:934] Scheduler::resourceOffers took 75383ns
I0709 03:35:03.021876 18254 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0709 03:35:03.023515 18255 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.3:60726
I0709 03:35:03.023748 18255 http.cpp:263] Processing call CREATE_VOLUMES
I0709 03:35:03.024544 18255 master.cpp:3848] Authorizing principal 'test-principal' to create volumes '[{"disk":{"persistence":{"id":"74485d12-66ef-4558-88aa-073150a3389a","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"},"volume":{"container_path":"volume","mode":"RW"}},"name":"disk","provider_id":{"value":"56d43a24-f3f5-47af-adb1-10a2ba1f796f"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0709 03:35:03.026446 18262 master.cpp:12470] Removing offer 7668db62-5096-4685-ad2c-f6ce543fc060-O3
I0709 03:35:03.026578 18264 sched.cpp:960] Rescinded offer 7668db62-5096-4685-ad2c-f6ce543fc060-O3
I0709 03:35:03.026660 18264 sched.cpp:971] Scheduler::offerRescinded took 22546ns
I0709 03:35:03.027236 18263 hierarchical.cpp:1218] Recovered 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_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (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_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048, allocated: {}) on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 from framework 7668db62-5096-46
85-ad2c-f6ce543fc060-0000
I0709 03:35:03.027349 18263 hierarchical.cpp:1264] Framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 filtered agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 for 5secs
I0709 03:35:03.029695 18267 master.cpp:12361] Sending operation '' (uuid: 12c8ee01-e76e-405a-9471-eac0f21bf1d0) to agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:03.030195 18268 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:03.030376 18270 master.cpp:6233] Processing REVIVE call for framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:03.030776 18277 hierarchical.cpp:1365] Unsuppressed offers for roles { storage/default-role } of framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:03.030803 18277 hierarchical.cpp:1387] Revived roles { storage/default-role } of framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:03.032207 18277 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.250888ms
I0709 03:35:03.032708 18277 hierarchical.cpp:1508] Performed allocation for 1 agents in 250401ns
I0709 03:35:03.032862 18275 master.cpp:10195] Sending offers [ 7668db62-5096-4685-ad2c-f6ce543fc060-O4 ] to framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:03.033262 18256 provider.cpp:481] Received APPLY_OPERATION event
I0709 03:35:03.033301 18256 provider.cpp:1295] Received CREATE operation '' (uuid: 12c8ee01-e76e-405a-9471-eac0f21bf1d0)
I0709 03:35:03.033460 18259 sched.cpp:934] Scheduler::resourceOffers took 72464ns
I0709 03:35:03.053928 18276 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.3:60696
I0709 03:35:03.054857 18273 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 2dabd024-5305-4e64-a3a3-c6e37314081a) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 03:35:03.055095 18273 slave.cpp:8670] Updating the state of operation with no ID (uuid: 2dabd024-5305-4e64-a3a3-c6e37314081a) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 03:35:03.055166 18273 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 2dabd024-5305-4e64-a3a3-c6e37314081a) for an operator API call
I0709 03:35:03.055546 18268 master.cpp:12017] Updating the state of operation '' (uuid: 2dabd024-5305-4e64-a3a3-c6e37314081a) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 03:35:03.056044 18254 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:03.147110 18259 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 1faf6b80-53f6-4506-b69b-7c33c1261234) for operation UUID 12c8ee01-e76e-405a-9471-eac0f21bf1d0 on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.147174 18259 status_update_manager_process.hpp:414] Creating operation status update stream 12c8ee01-e76e-405a-9471-eac0f21bf1d0 checkpoint=true
I0709 03:35:03.147217 18256 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 03:35:03.147698 18259 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 1faf6b80-53f6-4506-b69b-7c33c1261234) for operation UUID 12c8ee01-e76e-405a-9471-eac0f21bf1d0 on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.214020 18259 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 1faf6b80-53f6-4506-b69b-7c33c1261234) for operation UUID 12c8ee01-e76e-405a-9471-eac0f21bf1d0 on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.214409 18259 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 07cb2461-27a0-4bfb-8d03-43be0be8051a) for stream 2dabd024-5305-4e64-a3a3-c6e37314081a
I0709 03:35:03.214484 18259 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 07cb2461-27a0-4bfb-8d03-43be0be8051a) for operation UUID 2dabd024-5305-4e64-a3a3-c6e37314081a on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.214887 18263 http_connection.hpp:131] Sending 2 call to http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:03.215802 18258 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 03:35:03.253917 18260 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.3:60696
I0709 03:35:03.254940 18257 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 12c8ee01-e76e-405a-9471-eac0f21bf1d0) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 03:35:03.255144 18257 slave.cpp:8670] Updating the state of operation with no ID (uuid: 12c8ee01-e76e-405a-9471-eac0f21bf1d0) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 03:35:03.255208 18257 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 12c8ee01-e76e-405a-9471-eac0f21bf1d0) for an operator API call
I0709 03:35:03.255556 18269 master.cpp:12017] Updating the state of operation '' (uuid: 12c8ee01-e76e-405a-9471-eac0f21bf1d0) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 03:35:03.256367 18257 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:03.257668 18267 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 03:35:03.297466 18259 status_update_manager_process.hpp:490] Cleaning up operation status update stream 2dabd024-5305-4e64-a3a3-c6e37314081a
I0709 03:35:03.297732 18259 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 1faf6b80-53f6-4506-b69b-7c33c1261234) for stream 12c8ee01-e76e-405a-9471-eac0f21bf1d0
I0709 03:35:03.297821 18259 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 1faf6b80-53f6-4506-b69b-7c33c1261234) for operation UUID 12c8ee01-e76e-405a-9471-eac0f21bf1d0 on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.389602 18259 status_update_manager_process.hpp:490] Cleaning up operation status update stream 12c8ee01-e76e-405a-9471-eac0f21bf1d0
I0709 03:35:03.452057 18273 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0709 03:35:03.453657 18269 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.3:60736
I0709 03:35:03.453905 18269 http.cpp:263] Processing call DESTROY_VOLUMES
I0709 03:35:03.454710 18269 master.cpp:3893] Authorizing principal 'test-principal' to destroy volumes '[{"disk":{"persistence":{"id":"74485d12-66ef-4558-88aa-073150a3389a","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"},"volume":{"container_path":"volume","mode":"RW"}},"name":"disk","provider_id":{"value":"56d43a24-f3f5-47af-adb1-10a2ba1f796f"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0709 03:35:03.456913 18257 master.cpp:12470] Removing offer 7668db62-5096-4685-ad2c-f6ce543fc060-O4
I0709 03:35:03.457080 18255 sched.cpp:960] Rescinded offer 7668db62-5096-4685-ad2c-f6ce543fc060-O4
I0709 03:35:03.457177 18255 sched.cpp:971] Scheduler::offerRescinded took 29431ns
I0709 03:35:03.458065 18266 hierarchical.cpp:1218] Recovered 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_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test),74485d12-66ef-4558-88aa-073150a3389a:volume]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (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_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test),74485d12-66ef-4558-88aa-073150a3389a:volume]:2048, allocat
ed: {}) on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 from framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:03.458189 18266 hierarchical.cpp:1264] Framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 filtered agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 for 5secs
I0709 03:35:03.461096 18265 master.cpp:12361] Sending operation '' (uuid: d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff) to agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:03.461663 18274 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:03.464898 18260 provider.cpp:481] Received APPLY_OPERATION event
I0709 03:35:03.464942 18260 provider.cpp:1295] Received DESTROY operation '' (uuid: d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff)
I0709 03:35:03.473014 18272 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.220913ms
I0709 03:35:03.473645 18275 master.cpp:10195] Sending offers [ 7668db62-5096-4685-ad2c-f6ce543fc060-O5 ] to framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:03.474297 18269 sched.cpp:934] Scheduler::resourceOffers took 71337ns
I0709 03:35:03.575335 18277 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: e76c918e-566b-4a89-942e-66cdc0d8061a) for operation UUID d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.575402 18277 status_update_manager_process.hpp:414] Creating operation status update stream d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff checkpoint=true
I0709 03:35:03.575887 18277 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: e76c918e-566b-4a89-942e-66cdc0d8061a) for operation UUID d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.642207 18277 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: e76c918e-566b-4a89-942e-66cdc0d8061a) for operation UUID d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.642998 18255 http_connection.hpp:131] Sending 2 call to http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:03.643954 18266 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 03:35:03.647053 18262 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0709 03:35:03.648752 18273 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.3:60740
I0709 03:35:03.648986 18273 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0709 03:35:03.649634 18273 master.cpp:3785] Authorizing principal 'test-principal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"56d43a24-f3f5-47af-adb1-10a2ba1f796f"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0709 03:35:03.651564 18268 master.cpp:12470] Removing offer 7668db62-5096-4685-ad2c-f6ce543fc060-O5
I0709 03:35:03.651706 18275 sched.cpp:960] Rescinded offer 7668db62-5096-4685-ad2c-f6ce543fc060-O5
I0709 03:35:03.651783 18275 sched.cpp:971] Scheduler::offerRescinded took 20545ns
I0709 03:35:03.652388 18272 hierarchical.cpp:1218] Recovered 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_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (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_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048, allocated: {}) on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 from framework 7668db62-5096-46
85-ad2c-f6ce543fc060-0000
I0709 03:35:03.652506 18272 hierarchical.cpp:1264] Framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 filtered agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 for 5secs
I0709 03:35:03.654904 18269 master.cpp:12361] Sending operation '' (uuid: 7382e1e7-a04a-41f8-a7fb-0c5858573993) to agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:03.655460 18255 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:03.657917 18263 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.165011ms
I0709 03:35:03.658053 18270 provider.cpp:481] Received APPLY_OPERATION event
I0709 03:35:03.658100 18270 provider.cpp:1295] Received UNRESERVE operation '' (uuid: 7382e1e7-a04a-41f8-a7fb-0c5858573993)
I0709 03:35:03.658499 18262 master.cpp:10195] Sending offers [ 7668db62-5096-4685-ad2c-f6ce543fc060-O6 ] to framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:03.659104 18276 sched.cpp:934] Scheduler::resourceOffers took 72061ns
I0709 03:35:03.682010 18261 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.3:60696
I0709 03:35:03.682900 18277 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 03:35:03.683096 18277 slave.cpp:8670] Updating the state of operation with no ID (uuid: d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 03:35:03.683146 18277 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff) for an operator API call
I0709 03:35:03.683496 18256 master.cpp:12017] Updating the state of operation '' (uuid: d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 03:35:03.683993 18265 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:03.776698 18276 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: c20f0b7b-9535-42d6-acf8-b93ee0a0ab13) for operation UUID 7382e1e7-a04a-41f8-a7fb-0c5858573993 on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.776763 18276 status_update_manager_process.hpp:414] Creating operation status update stream 7382e1e7-a04a-41f8-a7fb-0c5858573993 checkpoint=true
I0709 03:35:03.776813 18270 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 03:35:03.777284 18276 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: c20f0b7b-9535-42d6-acf8-b93ee0a0ab13) for operation UUID 7382e1e7-a04a-41f8-a7fb-0c5858573993 on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.860183 18276 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: c20f0b7b-9535-42d6-acf8-b93ee0a0ab13) for operation UUID 7382e1e7-a04a-41f8-a7fb-0c5858573993 on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.860550 18276 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: e76c918e-566b-4a89-942e-66cdc0d8061a) for stream d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff
I0709 03:35:03.860635 18276 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: e76c918e-566b-4a89-942e-66cdc0d8061a) for operation UUID d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:03.861050 18275 http_connection.hpp:131] Sending 2 call to http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:03.861984 18260 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 03:35:03.901974 18266 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.3:60696
I0709 03:35:03.902812 18264 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 7382e1e7-a04a-41f8-a7fb-0c5858573993) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 03:35:03.902988 18264 slave.cpp:8670] Updating the state of operation with no ID (uuid: 7382e1e7-a04a-41f8-a7fb-0c5858573993) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 03:35:03.903038 18264 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 7382e1e7-a04a-41f8-a7fb-0c5858573993) for an operator API call
I0709 03:35:03.903393 18264 master.cpp:12017] Updating the state of operation '' (uuid: 7382e1e7-a04a-41f8-a7fb-0c5858573993) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 03:35:03.903856 18267 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 03:35:03.905220 18268 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 03:35:03.926975 18276 status_update_manager_process.hpp:490] Cleaning up operation status update stream d6a9d4cd-b4a5-418d-98ff-e6f70d6830ff
I0709 03:35:03.927268 18276 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: c20f0b7b-9535-42d6-acf8-b93ee0a0ab13) for stream 7382e1e7-a04a-41f8-a7fb-0c5858573993
I0709 03:35:03.927397 18276 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: c20f0b7b-9535-42d6-acf8-b93ee0a0ab13) for operation UUID 7382e1e7-a04a-41f8-a7fb-0c5858573993 on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:04.019079 18276 status_update_manager_process.hpp:490] Cleaning up operation status update stream 7382e1e7-a04a-41f8-a7fb-0c5858573993
I0709 03:35:04.087477 18257 master.cpp:1410] Framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622 disconnected
I0709 03:35:04.087520 18257 master.cpp:3342] Deactivating framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:04.087868 18266 hierarchical.cpp:475] Deactivated framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:04.088474 18271 slave.cpp:912] Agent terminating
I0709 03:35:04.088483 18257 master.cpp:12470] Removing offer 7668db62-5096-4685-ad2c-f6ce543fc060-O6
I0709 03:35:04.088590 18257 master.cpp:3319] Disconnecting framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:04.088661 18257 master.cpp:1425] Giving framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622 0ns to failover
I0709 03:35:04.089352 18266 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (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_OtmJf8/2GB-aab38a95-cc4c-414a-a090-94d922461dd2,test)]:2048, allocated: {}) on agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 from framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:04.089431 18271 manager.cpp:163] Terminating resource provider 56d43a24-f3f5-47af-adb1-10a2ba1f796f
I0709 03:35:04.089848 18261 master.cpp:9987] Framework failover timeout, removing framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:04.089885 18261 master.cpp:10979] Removing framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000 (default) at scheduler-8a0cd8cd-82cd-47a8-b3e5-5a51c5942c8a@172.17.0.3:42622
I0709 03:35:04.090333 18264 hierarchical.cpp:1432] Allocation paused
E0709 03:35:04.090414 18255 http_connection.hpp:452] End-Of-File received
I0709 03:35:04.090463 18261 master.cpp:1295] Agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad) disconnected
I0709 03:35:04.090504 18261 master.cpp:3379] Disconnecting agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:04.090629 18261 master.cpp:3398] Deactivating agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 at slave(1197)@172.17.0.3:42622 (fc165f183aad)
I0709 03:35:04.090767 18264 hierarchical.cpp:417] Removed framework 7668db62-5096-4685-ad2c-f6ce543fc060-0000
I0709 03:35:04.090855 18264 hierarchical.cpp:1442] Allocation resumed
I0709 03:35:04.090906 18264 hierarchical.cpp:799] Agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0 deactivated
I0709 03:35:04.091177 18255 http_connection.hpp:217] Re-detecting endpoint
I0709 03:35:04.091639 18255 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0709 03:35:04.091719 18275 provider.cpp:471] Disconnected from resource provider manager
I0709 03:35:04.091737 18255 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0709 03:35:04.091822 18255 http_connection.hpp:227] New endpoint detected at http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:04.091934 18259 status_update_manager_process.hpp:379] Pausing operation status update manager
I0709 03:35:04.093350 18268 containerizer.cpp:2575] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0709 03:35:04.093396 18268 containerizer.cpp:3277] 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
I0709 03:35:04.093842 18268 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 03:35:04.095310 18258 hierarchical.cpp:1508] Performed allocation for 1 agents in 161280ns
I0709 03:35:04.095598 18274 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:04.096140 18254 provider.cpp:459] Connected to resource provider manager
I0709 03:35:04.096843 18270 http_connection.hpp:131] Sending 1 call to http://172.17.0.3:42622/slave(1197)/api/v1/resource_provider
I0709 03:35:04.097590 18278 process.cpp:2781] Returning '404 Not Found' for '/slave(1197)/api/v1/resource_provider'
E0709 03:35:04.098779 18277 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0709 03:35:04.146601 18256 hierarchical.cpp:1508] Performed allocation for 1 agents in 147313ns
I0709 03:35:04.196468 18265 containerizer.cpp:3116] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0709 03:35:04.197917 18257 provisioner.cpp:609] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 03:35:04.197962 18273 hierarchical.cpp:1508] Performed allocation for 1 agents in 110208ns
I0709 03:35:04.200230 18272 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'
I0709 03:35:04.200392 18271 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-i5t9AF/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 03:35:04.200711 18269 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 03:35:04.202913 18278 process.cpp:2781] Returning '404 Not Found' for '/slave(1197)/api/v1'
I0709 03:35:04.214373 18253 master.cpp:1135] Master terminating
I0709 03:35:04.215008 18258 hierarchical.cpp:775] Removed all filters for agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
I0709 03:35:04.215037 18258 hierarchical.cpp:650] Removed agent 7668db62-5096-4685-ad2c-f6ce543fc060-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (2512 ms)
[----------] 50 tests from CSIVersion/StorageLocalResourceProviderTest (95508 ms total)
[----------] Global test environment tear-down
[==========] 2264 tests from 216 test cases ran. (1126573 ms total)
[ PASSED ] 2262 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] MasterQuotaTest.InsufficientResourcesSingleAgent
[ FAILED ] MasterQuotaTest.InsufficientResourcesMultipleAgents
2 FAILED TESTS
YOU HAVE 31 DISABLED TESTS
I0709 03:35:04.323735 18278 process.cpp:935] Stopped the socket accept loop
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-1.9.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.9.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.9.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.9.0/_build'
make: *** [distcheck] Error 1
+ docker rmi --force mesos-1562637211-17598
Untagged: mesos-1562637211-17598:latest
Deleted: sha256:6837e0c084cdd1a1ed12775179d991fdf1ac167d033286802f708c2219bcfe8a
Deleted: sha256:0fbe61f5dfc23837d242ffce6b36462cae039b2a4f0a6a8a2dfbf6da1d7fd49d
Deleted: sha256:ad2008ac2815abf7921ef1e41bdeb0a6b7afe4420249e4f26ab2e292a41e506d
Deleted: sha256:ca52ecb2c0003042d2d04b51a29313a9ba5b93e12f0a83d6a13e3c4d8fad4d5a
Deleted: sha256:52c2b7f845416316a637aa289280cca55e746a5769d660a04b4e9d24768f5974
Deleted: sha256:70f574e15c619961f0ee5ffc6d204ffc3adaf92a01e7a437534e674d15431f2c
Deleted: sha256:0685e9e921c425e4b4bee29e274ac5c0bad546206105678c02e8bdb9679b741a
Deleted: sha256:8f76f32651e65c270cfbd90dffc5108a0d4bb7492f9b7071286934f4787cec64
Deleted: sha256:ce8618f3aab3d07858a76751c3810c7df47a528b3a93cdda56c27666f1d884b0
Deleted: sha256:43654fdc8d8593f5df832ff828b1acad2e335af2b82ee26c25c4df68359dc904
Deleted: sha256:4d69b7ae49bcbb4d3a71752ba66720a80cda95940bbc8992f4796a8a85b78a54
Deleted: sha256:8d2fe2331947306b95a098eec93ff3b62ea0ed3a0743de21dd3b3335318e5a7e
Deleted: sha256:2fe0901a0814888594688c367a307f92855c5fe5bacb5f9967290bce1e5d8eb8
Deleted: sha256:37b0b42ac310395117b3fd7c50bcdbaa647d4eaa16060133cfbd30b2fa9ebe2d
Deleted: sha256:9e16a0a0fff7c50f5b5e7ceed938234411f5f230a44fcbfb4773a878e32aba38
Deleted: sha256:90d489498f724c870997961cd9ae11d00faf3f342ae4cb5bc4db00cc886499dc
Deleted: sha256:65d7cca02c0d187a56fbc951ba3587b5ba12c262fbd38b2682b8c56917ba6ebf
Deleted: sha256:f9c5bd0c39d65a7039c2a120d165937f375f64608dbae0869f0fc8ee611301f8
Deleted: sha256:00258107dcc93519e58b4c46359c9156b804ee955a00810524d36928a7bdce8a
Deleted: sha256:e8ce442b2073704b31e1e4bd4d53105d922f0068290aa664790fea450dab62f2
Deleted: sha256:acfa8791e6fce8288beb96aa30ffc1b44dc0433d6f545ebc2a915fb5dee7720e
Deleted: sha256:c3f2301e189be80f75d312ac546dfb90e327a38f539e84bd920a5408376d6cc4
Deleted: sha256:4b89ebb227fcc076c7ff159c02047b5599aae53d20b8abff8154c3e1b0bc8253
Deleted: sha256:3a060e2ad7f5e7062a2d7f5829601947c6c8db9ef46543f52f7436ec7c17ec4e
Deleted: sha256:ab81de065a8a510ac37bbaf95a50ae8518f449354836d18188e296367627da69
Deleted: sha256:2b47aeb0fcb1a8d9dc4733eab77bff1aa87e41338eb774963a406e0fcd6626dd
Deleted: sha256:bbe9b7b645589065fcb7e6a8e22a586e40415c38d0a087d56427d291c0bfd27b
Deleted: sha256:a6798d7576fad482f88cb25445305bb796b5a29b42b9daad9a3a8a494e20947d
Deleted: sha256:fbbb0b97dbc7d4766a7db442911988e8dfb392a8ec981ed3ac0c6c549e164bdd
Deleted: sha256:f5feb2b5dc83264d24b5cc0084619f162b4318a22b354066cbe27bf401b9e9af
Full log: https://builds.apache.org/job/Mesos-Reviewbot-Linux/2455/console
- Mesos Reviewbot
On July 7, 2019, 10:12 p.m., Meng Zhu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71022/
> -----------------------------------------------------------
>
> (Updated July 7, 2019, 10:12 p.m.)
>
>
> Review request for mesos and Benjamin Mahler.
>
>
> Bugs: MESOS-8968
> https://issues.apache.org/jira/browse/MESOS-8968
>
>
> Repository: mesos
>
>
> Description
> -------
>
> These tests reuse the existing tests for `SET_QUOTA` and
> `REMOVE_QUOTA` calls. In general, `UPDATE_QUOTA` request
> should fail where `SET_QUOTA` fails. When the existing
> test expects `SET_QUOTA` call succeeds, we test the
> `UPDATE_QUOTA` call by first remove the set quota and then
> send the `UPDATE_QUOTA` request.
>
>
> Diffs
> -----
>
> src/tests/master_quota_tests.cpp 34a652029e31827f8d94bb66d408fbe3d121fd8f
>
>
> Diff: https://reviews.apache.org/r/71022/diff/1/
>
>
> Testing
> -------
>
> make check
>
>
> Thanks,
>
> Meng Zhu
>
>
Re: Review Request 71022: Added tests for `UPDATE_QUOTA`.
Posted by Benjamin Mahler <bm...@apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71022/#review216412
-----------------------------------------------------------
Fix it, then Ship it!
src/tests/master_quota_tests.cpp
Lines 153-187 (patched)
<https://reviews.apache.org/r/71022/#comment303638>
Can you make these free standing rather than part of the fixture?
IMHO this fixture already makes the tests less readable (e.g. need to know about `defaultAgentResources`, need to know whether these other functions do anything special since they're non static members, etc). So it would be nice to prune it down to just a named fixture eventually.
src/tests/master_quota_tests.cpp
Lines 975 (patched)
<https://reviews.apache.org/r/71022/#comment303639>
Hm.. was this needed? It looks like the additional EXPECT below will work without it?
Ditto for the others below
src/tests/master_quota_tests.cpp
Lines 1307-1308 (patched)
<https://reviews.apache.org/r/71022/#comment303641>
On all of these, it looks more natural to have the headers declared after the EXPECT, since the headers are related to the http::post
- Benjamin Mahler
On July 7, 2019, 10:12 p.m., Meng Zhu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71022/
> -----------------------------------------------------------
>
> (Updated July 7, 2019, 10:12 p.m.)
>
>
> Review request for mesos and Benjamin Mahler.
>
>
> Bugs: MESOS-8968
> https://issues.apache.org/jira/browse/MESOS-8968
>
>
> Repository: mesos
>
>
> Description
> -------
>
> These tests reuse the existing tests for `SET_QUOTA` and
> `REMOVE_QUOTA` calls. In general, `UPDATE_QUOTA` request
> should fail where `SET_QUOTA` fails. When the existing
> test expects `SET_QUOTA` call succeeds, we test the
> `UPDATE_QUOTA` call by first remove the set quota and then
> send the `UPDATE_QUOTA` request.
>
>
> Diffs
> -----
>
> src/tests/master_quota_tests.cpp 34a652029e31827f8d94bb66d408fbe3d121fd8f
>
>
> Diff: https://reviews.apache.org/r/71022/diff/1/
>
>
> Testing
> -------
>
> make check
>
>
> Thanks,
>
> Meng Zhu
>
>
Re: Review Request 71022: Added tests for `UPDATE_QUOTA`.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71022/#review216414
-----------------------------------------------------------
Patch looks great!
Reviews applied: [71019, 71020, 71021, 71022]
Passed command: export OS='ubuntu:14.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/docker-build.sh
- Mesos Reviewbot
On July 7, 2019, 10:12 p.m., Meng Zhu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71022/
> -----------------------------------------------------------
>
> (Updated July 7, 2019, 10:12 p.m.)
>
>
> Review request for mesos and Benjamin Mahler.
>
>
> Bugs: MESOS-8968
> https://issues.apache.org/jira/browse/MESOS-8968
>
>
> Repository: mesos
>
>
> Description
> -------
>
> These tests reuse the existing tests for `SET_QUOTA` and
> `REMOVE_QUOTA` calls. In general, `UPDATE_QUOTA` request
> should fail where `SET_QUOTA` fails. When the existing
> test expects `SET_QUOTA` call succeeds, we test the
> `UPDATE_QUOTA` call by first remove the set quota and then
> send the `UPDATE_QUOTA` request.
>
>
> Diffs
> -----
>
> src/tests/master_quota_tests.cpp 34a652029e31827f8d94bb66d408fbe3d121fd8f
>
>
> Diff: https://reviews.apache.org/r/71022/diff/1/
>
>
> Testing
> -------
>
> make check
>
>
> Thanks,
>
> Meng Zhu
>
>