mesos-reviews mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Mesos Reviewbot <revi...@mesos.apache.org>
Subject Re: Review Request 71069: Added end-to-end test for agent draining.
Date Sat, 13 Jul 2019 08:55:24 GMT

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



Bad patch!

Reviews applied: [70822, 70910, 70911, 70923, 70956, 70957, 70924, 70996, 71008, 71041, 71055, 71069]

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_71069"]

Error:
...<truncated>...
esource_provider'
I0713 08:55:13.487813 18565 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0713 08:55:13.489799 18581 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:54904
I0713 08:55:13.490156 18581 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0713 08:55:13.491053 18581 master.cpp:3815] Authorizing principal 'test-principal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_L1rK3D/2GB-d903f010-6f01-4e85-8a59-ba7a9feed40e","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":"66648da0-4f93-4804-99b7-be6470d606dc"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0713 08:55:13.493032 18572 master.cpp:12575] Removing offer ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-O5
I0713 08:55:13.493144 18564 sched.cpp:960] Rescinded offer ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-O5
I0713 08:55:13.493207 18564 sched.cpp:971] Scheduler::offerRescinded took 19479ns
I0713 08:55:13.493891 18576 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_L1rK3D/2GB-d903f010-6f01-4e85-8a59-ba7a9feed40e,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_L1rK3D/2GB-d903f010-6f01-4e85-8a59-ba7a9feed40e,test)]:2048, allocated: {}) on agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0 from framework ed8024b8-f9e0-4b
 f4-b615-4b68e9f6e706-0000
I0713 08:55:13.494094 18576 hierarchical.cpp:1264] Framework ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-0000 filtered agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0 for 5secs
I0713 08:55:13.497511 18570 master.cpp:12466] Sending operation '' (uuid: eefcd174-50ac-43a9-bb18-cbeabe9e4318) to agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0 at slave(1201)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:13.498057 18563 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:13.501103 18580 provider.cpp:481] Received APPLY_OPERATION event
I0713 08:55:13.501142 18580 provider.cpp:1295] Received UNRESERVE operation '' (uuid: eefcd174-50ac-43a9-bb18-cbeabe9e4318)
I0713 08:55:13.508707 18573 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.518281ms
I0713 08:55:13.509881 18581 master.cpp:10290] Sending offers [ ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-O6 ] to framework ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-0000 (default) at scheduler-f18f1bb6-5fcc-48ba-9814-8c6dcb812d97@172.17.0.2:46625
I0713 08:55:13.510653 18584 sched.cpp:934] Scheduler::resourceOffers took 73913ns
I0713 08:55:13.526018 18577 http.cpp:1115] HTTP POST for /slave(1201)/api/v1/resource_provider from 172.17.0.2:54894
I0713 08:55:13.527305 18568 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 04dbc6dd-7aff-4445-9abd-b4ede95c2c34) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0713 08:55:13.527659 18568 slave.cpp:8670] Updating the state of operation with no ID (uuid: 04dbc6dd-7aff-4445-9abd-b4ede95c2c34) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0713 08:55:13.527715 18568 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 04dbc6dd-7aff-4445-9abd-b4ede95c2c34) for an operator API call
I0713 08:55:13.528359 18563 master.cpp:12122] Updating the state of operation '' (uuid: 04dbc6dd-7aff-4445-9abd-b4ede95c2c34) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0713 08:55:13.529100 18567 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:13.600663 18584 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 0e2764e5-b2f1-46ff-a8d7-de7db38f2ef2) for operation UUID eefcd174-50ac-43a9-bb18-cbeabe9e4318 on agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0
I0713 08:55:13.600728 18584 status_update_manager_process.hpp:414] Creating operation status update stream eefcd174-50ac-43a9-bb18-cbeabe9e4318 checkpoint=true
I0713 08:55:13.600782 18580 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0713 08:55:13.601011 18584 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 0e2764e5-b2f1-46ff-a8d7-de7db38f2ef2) for operation UUID eefcd174-50ac-43a9-bb18-cbeabe9e4318 on agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0
I0713 08:55:13.667456 18584 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 0e2764e5-b2f1-46ff-a8d7-de7db38f2ef2) for operation UUID eefcd174-50ac-43a9-bb18-cbeabe9e4318 on agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0
I0713 08:55:13.667758 18584 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: a71a1e11-90c0-41dd-8a91-9f095aeeba03) for stream 04dbc6dd-7aff-4445-9abd-b4ede95c2c34
I0713 08:55:13.667832 18584 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: a71a1e11-90c0-41dd-8a91-9f095aeeba03) for operation UUID 04dbc6dd-7aff-4445-9abd-b4ede95c2c34 on agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0
I0713 08:55:13.668220 18564 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:46625/slave(1201)/api/v1/resource_provider
I0713 08:55:13.669095 18570 process.cpp:3671] Handling HTTP event for process 'slave(1201)' with path: '/slave(1201)/api/v1/resource_provider'
I0713 08:55:13.709456 18583 http.cpp:1115] HTTP POST for /slave(1201)/api/v1/resource_provider from 172.17.0.2:54894
I0713 08:55:13.710312 18567 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: eefcd174-50ac-43a9-bb18-cbeabe9e4318) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0713 08:55:13.710489 18567 slave.cpp:8670] Updating the state of operation with no ID (uuid: eefcd174-50ac-43a9-bb18-cbeabe9e4318) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0713 08:55:13.710551 18567 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: eefcd174-50ac-43a9-bb18-cbeabe9e4318) for an operator API call
I0713 08:55:13.710929 18571 master.cpp:12122] Updating the state of operation '' (uuid: eefcd174-50ac-43a9-bb18-cbeabe9e4318) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0713 08:55:13.711407 18579 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:13.713506 18572 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0713 08:55:13.734398 18584 status_update_manager_process.hpp:490] Cleaning up operation status update stream 04dbc6dd-7aff-4445-9abd-b4ede95c2c34
I0713 08:55:13.734612 18584 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 0e2764e5-b2f1-46ff-a8d7-de7db38f2ef2) for stream eefcd174-50ac-43a9-bb18-cbeabe9e4318
I0713 08:55:13.734699 18584 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 0e2764e5-b2f1-46ff-a8d7-de7db38f2ef2) for operation UUID eefcd174-50ac-43a9-bb18-cbeabe9e4318 on agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0
I0713 08:55:13.826459 18584 status_update_manager_process.hpp:490] Cleaning up operation status update stream eefcd174-50ac-43a9-bb18-cbeabe9e4318
I0713 08:55:13.894666 18569 master.cpp:1410] Framework ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-0000 (default) at scheduler-f18f1bb6-5fcc-48ba-9814-8c6dcb812d97@172.17.0.2:46625 disconnected
I0713 08:55:13.894711 18569 master.cpp:3360] Deactivating framework ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-0000 (default) at scheduler-f18f1bb6-5fcc-48ba-9814-8c6dcb812d97@172.17.0.2:46625
I0713 08:55:13.895067 18583 hierarchical.cpp:475] Deactivated framework ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-0000
I0713 08:55:13.895750 18566 slave.cpp:912] Agent terminating
I0713 08:55:13.895768 18569 master.cpp:12575] Removing offer ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-O6
I0713 08:55:13.895854 18569 master.cpp:3337] Disconnecting framework ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-0000 (default) at scheduler-f18f1bb6-5fcc-48ba-9814-8c6dcb812d97@172.17.0.2:46625
I0713 08:55:13.895925 18569 master.cpp:1425] Giving framework ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-0000 (default) at scheduler-f18f1bb6-5fcc-48ba-9814-8c6dcb812d97@172.17.0.2:46625 0ns to failover
I0713 08:55:13.896577 18583 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_L1rK3D/2GB-d903f010-6f01-4e85-8a59-ba7a9feed40e,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_L1rK3D/2GB-d903f010-6f01-4e85-8a59-ba7a9feed40e,test)]:2048, allocated: {}) on agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0 from framework ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-0000
I0713 08:55:13.896970 18566 manager.cpp:163] Terminating resource provider 66648da0-4f93-4804-99b7-be6470d606dc
I0713 08:55:13.897462 18584 master.cpp:10082] Framework failover timeout, removing framework ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-0000 (default) at scheduler-f18f1bb6-5fcc-48ba-9814-8c6dcb812d97@172.17.0.2:46625
I0713 08:55:13.897500 18584 master.cpp:11074] Removing framework ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-0000 (default) at scheduler-f18f1bb6-5fcc-48ba-9814-8c6dcb812d97@172.17.0.2:46625
I0713 08:55:13.897928 18568 hierarchical.cpp:1432] Allocation paused
I0713 08:55:13.897960 18584 master.cpp:1295] Agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0 at slave(1201)@172.17.0.2:46625 (854f964fcdc1) disconnected
I0713 08:55:13.897985 18584 master.cpp:3397] Disconnecting agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0 at slave(1201)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:13.898058 18584 master.cpp:3416] Deactivating agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0 at slave(1201)@172.17.0.2:46625 (854f964fcdc1)
E0713 08:55:13.898475 18578 http_connection.hpp:452] End-Of-File received
I0713 08:55:13.898495 18568 hierarchical.cpp:417] Removed framework ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-0000
I0713 08:55:13.898562 18568 hierarchical.cpp:1442] Allocation resumed
I0713 08:55:13.898622 18568 hierarchical.cpp:799] Agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0 deactivated
I0713 08:55:13.899008 18578 http_connection.hpp:217] Re-detecting endpoint
I0713 08:55:13.899390 18578 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0713 08:55:13.899452 18578 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0713 08:55:13.899493 18580 provider.cpp:471] Disconnected from resource provider manager
I0713 08:55:13.899513 18578 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:46625/slave(1201)/api/v1/resource_provider
I0713 08:55:13.899632 18576 status_update_manager_process.hpp:379] Pausing operation status update manager
I0713 08:55:13.900969 18562 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
I0713 08:55:13.901006 18562 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
I0713 08:55:13.901374 18562 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0713 08:55:13.902215 18575 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:46625/slave(1201)/api/v1/resource_provider
I0713 08:55:13.902745 18580 provider.cpp:459] Connected to resource provider manager
I0713 08:55:13.903250 18564 hierarchical.cpp:1508] Performed allocation for 1 agents in 148481ns
I0713 08:55:13.903380 18566 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:46625/slave(1201)/api/v1/resource_provider
E0713 08:55:13.904420 18566 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
I0713 08:55:13.904556 18586 process.cpp:2781] Returning '404 Not Found' for '/slave(1201)/api/v1/resource_provider'
E0713 08:55:13.905870 18578 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0713 08:55:13.954954 18570 hierarchical.cpp:1508] Performed allocation for 1 agents in 205608ns
I0713 08:55:14.005344 18582 containerizer.cpp:3116] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0713 08:55:14.006827 18579 hierarchical.cpp:1508] Performed allocation for 1 agents in 216175ns
I0713 08:55:14.007354 18581 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
I0713 08:55:14.010104 18576 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'
I0713 08:55:14.010408 18570 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-MvsDXp/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0713 08:55:14.010665 18585 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0713 08:55:14.013193 18586 process.cpp:2781] Returning '404 Not Found' for '/slave(1201)/api/v1'
I0713 08:55:14.027447 18561 master.cpp:1135] Master terminating
I0713 08:55:14.028370 18582 hierarchical.cpp:775] Removed all filters for agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0
I0713 08:55:14.028399 18582 hierarchical.cpp:650] Removed agent ed8024b8-f9e0-4bf4-b615-4b68e9f6e706-S0
[       OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v0 (2441 ms)
[ RUN      ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1
I0713 08:55:14.045862 18561 cluster.cpp:176] Creating default 'local' authorizer
I0713 08:55:14.051699 18571 master.cpp:440] Master 74b802e1-68aa-4ffd-9ec0-393cae375ffd (854f964fcdc1) started on 172.17.0.2:46625
I0713 08:55:14.051728 18571 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/7w20G9/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/7w20G9/master" --zk_session_timeout="10secs"
I0713 08:55:14.052439 18571 master.cpp:492] Master only allowing authenticated frameworks to register
I0713 08:55:14.052459 18571 master.cpp:498] Master only allowing authenticated agents to register
I0713 08:55:14.052469 18571 master.cpp:504] Master only allowing authenticated HTTP frameworks to register
I0713 08:55:14.052477 18571 credentials.hpp:37] Loading credentials for authentication from '/tmp/7w20G9/credentials'
I0713 08:55:14.052930 18571 master.cpp:548] Using default 'crammd5' authenticator
I0713 08:55:14.053166 18571 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0713 08:55:14.053566 18571 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0713 08:55:14.053833 18571 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0713 08:55:14.054078 18571 master.cpp:629] Authorization enabled
I0713 08:55:14.054620 18578 hierarchical.cpp:241] Initialized hierarchical allocator process
I0713 08:55:14.054632 18580 whitelist_watcher.cpp:77] No whitelist given
I0713 08:55:14.058068 18582 master.cpp:2168] Elected as the leading master!
I0713 08:55:14.058122 18582 master.cpp:1664] Recovering from registrar
I0713 08:55:14.058383 18583 registrar.cpp:339] Recovering registrar
I0713 08:55:14.059391 18583 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0713 08:55:14.059540 18583 registrar.cpp:487] Applied 1 operations in 41170ns; attempting to update the registry
I0713 08:55:14.060415 18583 registrar.cpp:544] Successfully updated the registry in 0ns
I0713 08:55:14.060557 18583 registrar.cpp:416] Successfully recovered registrar
I0713 08:55:14.061060 18568 master.cpp:1817] Recovered 0 agents from the registry (143B); allowing 10mins for agents to reregister
I0713 08:55:14.061127 18570 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover
W0713 08:55:14.068044 18561 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:46625
I0713 08:55:14.069576 18561 containerizer.cpp:314] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0713 08:55:14.070222 18561 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0713 08:55:14.070253 18561 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0713 08:55:14.070394 18561 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0713 08:55:14.070459 18561 provisioner.cpp:298] Using default backend 'copy'
I0713 08:55:14.073397 18561 cluster.cpp:510] Creating default 'local' authorizer
I0713 08:55:14.075917 18575 slave.cpp:265] Mesos agent started on (1202)@172.17.0.2:46625
I0713 08:55:14.075948 18575 slave.cpp:266] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/7w20G9/5yzQVf/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/7w20G9/5yzQVf/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/7w20G9/5yzQVf/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/7w20G9/5yzQVf/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/7w20G9/5yzQVf/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/7w20G9/5yzQVf/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/7w20G9/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_m2LgRt" --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_1dQHMH" --zk_session_timeout="10secs"
I0713 08:55:14.076407 18575 credentials.hpp:86] Loading credential for authentication from '/tmp/7w20G9/5yzQVf/credential'
I0713 08:55:14.076586 18575 slave.cpp:298] Agent using credential for: test-principal
I0713 08:55:14.076628 18575 credentials.hpp:37] Loading credentials for authentication from '/tmp/7w20G9/5yzQVf/http_credentials'
I0713 08:55:14.076848 18575 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0713 08:55:14.077278 18575 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0713 08:55:14.079169 18575 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"}]
I0713 08:55:14.079399 18575 slave.cpp:621] Agent attributes: [  ]
I0713 08:55:14.079422 18575 slave.cpp:630] Agent hostname: 854f964fcdc1
I0713 08:55:14.079617 18576 task_status_update_manager.cpp:181] Pausing sending task status updates
I0713 08:55:14.079687 18571 status_update_manager_process.hpp:379] Pausing operation status update manager
I0713 08:55:14.080548 18562 process.cpp:3671] Handling HTTP event for process 'test-disk-profile-server' with path: '/test-disk-profile-server/profiles'
I0713 08:55:14.081295 18566 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_1dQHMH/meta'
I0713 08:55:14.081614 18577 slave.cpp:7246] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_1dQHMH/meta', beginning agent recovery
I0713 08:55:14.082435 18584 task_status_update_manager.cpp:207] Recovering task status update manager
I0713 08:55:14.083137 18585 containerizer.cpp:796] Recovering Mesos containers
I0713 08:55:14.083519 18585 containerizer.cpp:1122] Recovering isolators
I0713 08:55:14.084331 18562 containerizer.cpp:1161] Recovering provisioner
I0713 08:55:14.085115 18572 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I0713 08:55:14.085170 18577 provisioner.cpp:498] Provisioner recovery complete
I0713 08:55:14.086139 18576 composing.cpp:339] Finished recovering all containerizers
I0713 08:55:14.086470 18578 slave.cpp:7708] Recovering executors
I0713 08:55:14.086597 18578 slave.cpp:7861] Finished recovery
I0713 08:55:14.087705 18575 task_status_update_manager.cpp:181] Pausing sending task status updates
I0713 08:55:14.087733 18585 status_update_manager_process.hpp:379] Pausing operation status update manager
I0713 08:55:14.087743 18574 slave.cpp:1258] New master detected at master@172.17.0.2:46625
I0713 08:55:14.087961 18574 slave.cpp:1323] Detecting new master
I0713 08:55:14.089300 18566 slave.cpp:1350] Authenticating with master master@172.17.0.2:46625
I0713 08:55:14.089401 18566 slave.cpp:1359] Using default CRAM-MD5 authenticatee
I0713 08:55:14.089773 18567 authenticatee.cpp:121] Creating new client SASL connection
I0713 08:55:14.090186 18581 master.cpp:10475] Authenticating slave(1202)@172.17.0.2:46625
I0713 08:55:14.090368 18569 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2052)@172.17.0.2:46625
I0713 08:55:14.090745 18572 authenticator.cpp:98] Creating new server SASL connection
I0713 08:55:14.091048 18565 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0713 08:55:14.091089 18565 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0713 08:55:14.091238 18577 authenticator.cpp:204] Received SASL authentication start
I0713 08:55:14.091325 18577 authenticator.cpp:326] Authentication requires more steps
I0713 08:55:14.091543 18563 authenticatee.cpp:259] Received SASL authentication step
I0713 08:55:14.091778 18573 authenticator.cpp:232] Received SASL authentication step
I0713 08:55:14.091820 18573 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '854f964fcdc1' server FQDN: '854f964fcdc1' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0713 08:55:14.091835 18573 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0713 08:55:14.091892 18573 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0713 08:55:14.091944 18573 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '854f964fcdc1' server FQDN: '854f964fcdc1' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0713 08:55:14.091974 18573 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0713 08:55:14.091990 18573 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0713 08:55:14.092010 18573 authenticator.cpp:318] Authentication success
I0713 08:55:14.092180 18570 authenticatee.cpp:299] Authentication success
I0713 08:55:14.092334 18584 master.cpp:10507] Successfully authenticated principal 'test-principal' at slave(1202)@172.17.0.2:46625
I0713 08:55:14.092562 18583 slave.cpp:1450] Successfully authenticated with master master@172.17.0.2:46625
I0713 08:55:14.092579 18578 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2052)@172.17.0.2:46625
I0713 08:55:14.092938 18583 slave.cpp:1900] Will retry registration in 2.001756ms if necessary
I0713 08:55:14.093137 18575 master.cpp:6983] Received register agent message from slave(1202)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:14.093411 18575 master.cpp:4129] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I0713 08:55:14.094147 18562 master.cpp:7050] Authorized registration of agent at slave(1202)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:14.094254 18562 master.cpp:7162] Registering agent at slave(1202)@172.17.0.2:46625 (854f964fcdc1) with id 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:14.094962 18567 registrar.cpp:487] Applied 1 operations in 233643ns; attempting to update the registry
I0713 08:55:14.095729 18567 registrar.cpp:544] Successfully updated the registry in 0ns
I0713 08:55:14.095921 18577 master.cpp:7210] Admitted agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:14.096853 18577 master.cpp:7255] Registered agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0713 08:55:14.096987 18576 slave.cpp:1483] Registered with master master@172.17.0.2:46625; given agent ID 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:14.097008 18568 hierarchical.cpp:617] Added agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 (854f964fcdc1) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I0713 08:55:14.097106 18570 task_status_update_manager.cpp:188] Resuming sending task status updates
I0713 08:55:14.097360 18568 hierarchical.cpp:1508] Performed allocation for 1 agents in 150859ns
I0713 08:55:14.097470 18576 slave.cpp:1518] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_1dQHMH/meta/slaves/74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0/slave.info'
I0713 08:55:14.097533 18584 status_update_manager_process.hpp:385] Resuming operation status update manager
I0713 08:55:14.098706 18576 slave.cpp:1570] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"hIcVzNKVRBS76mDBp75FTA=="},"slave_id":{"value":"74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0"},"update_oversubscribed_resources":false}
I0713 08:55:14.099516 18574 master.cpp:8354] Ignoring update on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1) as it reports no changes
I0713 08:55:14.103832 18567 process.cpp:3671] Handling HTTP event for process 'slave(1202)' with path: '/slave(1202)/api/v1'
I0713 08:55:14.105089 18584 http.cpp:1115] HTTP POST for /slave(1202)/api/v1 from 172.17.0.2:54914
I0713 08:55:14.105639 18584 http.cpp:2120] Processing GET_CONTAINERS call
I0713 08:55:14.111207 18572 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0713 08:55:14.113590 18579 process.cpp:3671] Handling HTTP event for process 'slave(1202)' with path: '/slave(1202)/api/v1'
I0713 08:55:14.114625 18576 http.cpp:1115] HTTP POST for /slave(1202)/api/v1 from 172.17.0.2:54916
I0713 08:55:14.115407 18576 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'
I0713 08:55:14.116292 18564 http.cpp:2590] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_1dQHMH/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0713 08:55:14.117070 18583 containerizer.cpp:1357] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0713 08:55:14.118314 18583 containerizer.cpp:1529] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_m2LgRt/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0713 08:55:14.118358 18583 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
I0713 08:55:14.121337 18566 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_YIV9HV","--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_1dQHMH/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-7qnPzm/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperat
 ionsWithResourceProviderResources_v1_1dQHMH/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_m2LgRt/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I0713 08:55:14.129879 18566 launcher.cpp:145] Forked child with pid '32426' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0713 08:55:14.130606 18566 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
I0713 08:55:14.131987 18566 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
I0713 08:55:14.132438 18568 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_1dQHMH/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0713 08:55:14.133918 18579 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
I0713 08:55:14.137514 18574 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'
I0713 08:55:14.137784 18564 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-7qnPzm/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0713 08:55:14.258327 18563 hierarchical.cpp:1508] Performed allocation for 1 agents in 200631ns
I0713 08:55:14.309881 18568 hierarchical.cpp:1508] Performed allocation for 1 agents in 209623ns
I0713 08:55:14.361909 18576 hierarchical.cpp:1508] Performed allocation for 1 agents in 308627ns
I0713 08:55:14.413122 18583 hierarchical.cpp:1508] Performed allocation for 1 agents in 204600ns
I0713 08:55:14.464638 18567 hierarchical.cpp:1508] Performed allocation for 1 agents in 205463ns
I0713 08:55:14.513029 18584 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-7qnPzm/endpoint.sock' with CSI v1
I0713 08:55:14.516554 18578 hierarchical.cpp:1508] Performed allocation for 1 agents in 335308ns
I0713 08:55:14.535851 32430 test_csi_plugin.cpp:909] ProbeRequest '{}'
I0713 08:55:14.538028 18574 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0713 08:55:14.541144 32430 test_csi_plugin.cpp:895] GetPluginCapabilitiesRequest '{}'
I0713 08:55:14.542287 18563 process.cpp:3671] Handling HTTP event for process 'slave(1202)' with path: '/slave(1202)/api/v1'
I0713 08:55:14.543715 18582 http.cpp:1115] HTTP POST for /slave(1202)/api/v1 from 172.17.0.2:54918
I0713 08:55:14.544368 18582 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'
I0713 08:55:14.545161 32431 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0713 08:55:14.545485 32430 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0713 08:55:14.546942 18564 v1_volume_manager.cpp:648] NODE_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"}
I0713 08:55:14.547534 18564 v1_volume_manager.cpp:648] CONTROLLER_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"}
I0713 08:55:14.550046 32430 test_csi_plugin.cpp:1105] ControllerGetCapabilitiesRequest '{}'
I0713 08:55:14.553473 32430 test_csi_plugin.cpp:1241] NodeGetCapabilitiesRequest '{}'
I0713 08:55:14.556517 32430 test_csi_plugin.cpp:1255] NodeGetInfoRequest '{}'
I0713 08:55:14.558593 18574 provider.cpp:659] Finished recovery for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0713 08:55:14.558748 18584 status_update_manager_process.hpp:379] Pausing operation status update manager
I0713 08:55:14.559088 18581 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:14.562685 18572 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:14.563441 18566 provider.cpp:459] Connected to resource provider manager
I0713 08:55:14.564249 18579 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:14.565549 18582 process.cpp:3671] Handling HTTP event for process 'slave(1202)' with path: '/slave(1202)/api/v1/resource_provider'
I0713 08:55:14.567078 18585 http.cpp:1115] HTTP POST for /slave(1202)/api/v1/resource_provider from 172.17.0.2:54922
I0713 08:55:14.567370 18574 hierarchical.cpp:1508] Performed allocation for 1 agents in 153616ns
I0713 08:55:14.567714 18571 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_YIV9HV","--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"}
I0713 08:55:14.618321 18563 hierarchical.cpp:1508] Performed allocation for 1 agents in 187187ns
I0713 08:55:14.622625 18577 slave.cpp:8217] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"f5f2a3f8-ec9b-449e-a6be-14dd6e01506c"},"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_YIV9HV","--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"}'
I0713 08:55:14.624636 18575 provider.cpp:481] Received SUBSCRIBED event
I0713 08:55:14.624749 18575 provider.cpp:1255] Subscribed with ID f5f2a3f8-ec9b-449e-a6be-14dd6e01506c
I0713 08:55:14.625511 18585 status_update_manager_process.hpp:314] Recovering operation status update manager
I0713 08:55:14.669876 18581 hierarchical.cpp:1508] Performed allocation for 1 agents in 161755ns
I0713 08:55:14.720765 18583 hierarchical.cpp:1508] Performed allocation for 1 agents in 103927ns
I0713 08:55:14.725420 32430 test_csi_plugin.cpp:1050] ListVolumesRequest '{}'
I0713 08:55:14.728945 18579 provider.cpp:2145] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:14.729239 18579 provider.cpp:745] Resource provider f5f2a3f8-ec9b-449e-a6be-14dd6e01506c is in READY state
I0713 08:55:14.729357 18573 http_connection.hpp:131] Sending 3 call to http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:14.729377 18582 status_update_manager_process.hpp:385] Resuming operation status update manager
I0713 08:55:14.730309 18578 provider.cpp:1181] Updating profiles { test } for resource provider f5f2a3f8-ec9b-449e-a6be-14dd6e01506c
I0713 08:55:14.730760 18584 process.cpp:3671] Handling HTTP event for process 'slave(1202)' with path: '/slave(1202)/api/v1/resource_provider'
I0713 08:55:14.733469 18582 http.cpp:1115] HTTP POST for /slave(1202)/api/v1/resource_provider from 172.17.0.2:54920
I0713 08:55:14.734144 18576 manager.cpp:1039] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider f5f2a3f8-ec9b-449e-a6be-14dd6e01506c
I0713 08:55:14.734454 18578 slave.cpp:8217] Handling resource provider message 'UPDATE_STATE: f5f2a3f8-ec9b-449e-a6be-14dd6e01506c {}'
I0713 08:55:14.734550 18578 slave.cpp:8337] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0713 08:55:14.735388 32432 test_csi_plugin.cpp:1078] GetCapacityRequest '{"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0713 08:55:14.736455 18580 hierarchical.cpp:753] Grew agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 by {} (total), {  } (used)
I0713 08:55:14.737131 18580 hierarchical.cpp:710] Agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 (854f964fcdc1) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
W0713 08:55:14.738448 18561 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:46625
I0713 08:55:14.740602 18561 sched.cpp:239] Version: 1.9.0
I0713 08:55:14.741526 18572 provider.cpp:933] Removing '{}' and adding 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' to the total resources
I0713 08:55:14.741739 18566 sched.cpp:343] New master detected at master@172.17.0.2:46625
I0713 08:55:14.741917 18566 sched.cpp:408] Authenticating with master master@172.17.0.2:46625
I0713 08:55:14.741961 18566 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0713 08:55:14.742379 18576 authenticatee.cpp:121] Creating new client SASL connection
I0713 08:55:14.742689 18578 hierarchical.cpp:1508] Performed allocation for 1 agents in 228809ns
I0713 08:55:14.742857 18575 master.cpp:10475] Authenticating scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:14.743041 18578 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2053)@172.17.0.2:46625
I0713 08:55:14.743573 18567 authenticator.cpp:98] Creating new server SASL connection
I0713 08:55:14.744000 18583 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0713 08:55:14.744048 18583 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0713 08:55:14.744287 18562 authenticator.cpp:204] Received SASL authentication start
I0713 08:55:14.744431 18562 authenticator.cpp:326] Authentication requires more steps
I0713 08:55:14.744601 18581 authenticatee.cpp:259] Received SASL authentication step
I0713 08:55:14.744796 18569 authenticator.cpp:232] Received SASL authentication step
I0713 08:55:14.744838 18569 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '854f964fcdc1' server FQDN: '854f964fcdc1' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0713 08:55:14.744853 18569 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0713 08:55:14.744913 18569 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0713 08:55:14.744937 18569 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '854f964fcdc1' server FQDN: '854f964fcdc1' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0713 08:55:14.744951 18569 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0713 08:55:14.744961 18569 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0713 08:55:14.744994 18569 authenticator.cpp:318] Authentication success
I0713 08:55:14.745126 18580 authenticatee.cpp:299] Authentication success
I0713 08:55:14.745308 18574 master.cpp:10507] Successfully authenticated principal 'test-principal' at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:14.745398 18570 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2053)@172.17.0.2:46625
I0713 08:55:14.745656 18565 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:46625
I0713 08:55:14.745703 18565 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:46625
I0713 08:55:14.745921 18565 sched.cpp:870] Will retry registration in 678.827424ms if necessary
I0713 08:55:14.746157 18564 master.cpp:2908] Received SUBSCRIBE call for framework 'default' at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:14.746196 18564 master.cpp:2240] Authorizing framework principal 'test-principal' to receive offers for roles '{ storage/default-role }'
I0713 08:55:14.746886 18585 master.cpp:2995] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0713 08:55:14.750010 18585 master.cpp:10705] Adding framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625 with roles {  } suppressed
I0713 08:55:14.750722 18573 sched.cpp:751] Framework registered with 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:14.750829 18573 sched.cpp:770] Scheduler::registered took 56500ns
I0713 08:55:14.751215 18576 hierarchical.cpp:368] Added framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:14.752723 18576 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.295086ms
I0713 08:55:14.753470 18571 master.cpp:10290] Sending offers [ 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O0 ] to framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:14.754240 18575 sched.cpp:934] Scheduler::resourceOffers took 152383ns
I0713 08:55:14.754762 18575 master.cpp:6149] Processing DECLINE call for offers: [ 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O0 ] for framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625 with 5 seconds filter
I0713 08:55:14.755441 18575 master.cpp:12575] Removing offer 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O0
I0713 08:55:14.756286 18567 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 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 from framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:14.756371 18567 hierarchical.cpp:1264] Framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 filtered agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 for 5secs
I0713 08:55:14.797260 18572 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 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:14.797792 18583 http_connection.hpp:131] Sending 3 call to http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:14.798964 18577 process.cpp:3671] Handling HTTP event for process 'slave(1202)' with path: '/slave(1202)/api/v1/resource_provider'
I0713 08:55:14.838995 18582 http.cpp:1115] HTTP POST for /slave(1202)/api/v1/resource_provider from 172.17.0.2:54920
I0713 08:55:14.839958 18570 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":"f5f2a3f8-ec9b-449e-a6be-14dd6e01506c"},"reservations":[{"role":"storage","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]' and 0 operations from resource provider f5f2a3f8-ec9b-449e-a6be-14dd6e01506c
I0713 08:55:14.840775 18565 slave.cpp:8217] Handling resource provider message 'UPDATE_STATE: f5f2a3f8-ec9b-449e-a6be-14dd6e01506c disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048'
I0713 08:55:14.840968 18565 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
I0713 08:55:14.844458 18566 hierarchical.cpp:710] Agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 (854f964fcdc1) 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
I0713 08:55:14.846571 18566 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.782213ms
I0713 08:55:14.847507 18576 master.cpp:10290] Sending offers [ 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O1 ] to framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:14.848414 18571 sched.cpp:934] Scheduler::resourceOffers took 89880ns
I0713 08:55:14.851538 18575 master.cpp:12575] Removing offer 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O1
I0713 08:55:14.851958 18575 master.cpp:4666] Processing ACCEPT call for offers: [ 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O1 ] on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1) for framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:14.852067 18575 master.cpp:4039] 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'
I0713 08:55:14.852505 18583 hierarchical.cpp:1508] Performed allocation for 1 agents in 400708ns
I0713 08:55:14.853529 18584 master.cpp:5941] 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 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625 to agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:14.854290 18584 master.cpp:12466] Sending operation '' (uuid: dccae354-5fb1-41be-93cc-dbe6f6e02b9d) to agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:14.854744 18563 hierarchical.cpp:1432] Allocation paused
I0713 08:55:14.854984 18580 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:14.856207 18563 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 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 from framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:14.856343 18563 hierarchical.cpp:1264] Framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 filtered agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 for 5secs
I0713 08:55:14.856621 18563 hierarchical.cpp:1442] Allocation resumed
I0713 08:55:14.858162 18566 provider.cpp:481] Received APPLY_OPERATION event
I0713 08:55:14.858225 18566 provider.cpp:1295] Received CREATE_DISK operation '' (uuid: dccae354-5fb1-41be-93cc-dbe6f6e02b9d)
I0713 08:55:14.898125 18571 v1_volume_manager.cpp:292] Creating volume with name 'dccae354-5fb1-41be-93cc-dbe6f6e02b9d'
I0713 08:55:14.901037 32432 test_csi_plugin.cpp:922] CreateVolumeRequest '{"name":"dccae354-5fb1-41be-93cc-dbe6f6e02b9d","capacityRange":{"requiredBytes":"2147483648","limitBytes":"2147483648"},"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0713 08:55:14.904702 18562 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 for role storage/default-role of framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:14.904892 18562 hierarchical.cpp:1508] Performed allocation for 1 agents in 934399ns
I0713 08:55:14.956358 18569 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 for role storage/default-role of framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:14.956534 18569 hierarchical.cpp:1508] Performed allocation for 1 agents in 771138ns
I0713 08:55:14.983464 18584 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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,test)]:2048' for operation (uuid: dccae354-5fb1-41be-93cc-dbe6f6e02b9d)
I0713 08:55:15.008114 18580 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 for role storage/default-role of framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:15.008344 18580 hierarchical.cpp:1508] Performed allocation for 1 agents in 743807ns
I0713 08:55:15.024776 18568 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: b45e56c8-0d8a-4ea8-813b-444154321dbc) for operation UUID dccae354-5fb1-41be-93cc-dbe6f6e02b9d of framework '74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000' on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.024889 18568 status_update_manager_process.hpp:414] Creating operation status update stream dccae354-5fb1-41be-93cc-dbe6f6e02b9d checkpoint=true
I0713 08:55:15.025503 18568 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: b45e56c8-0d8a-4ea8-813b-444154321dbc) for operation UUID dccae354-5fb1-41be-93cc-dbe6f6e02b9d of framework '74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000' on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.060091 18582 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 for role storage/default-role of framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:15.060402 18582 hierarchical.cpp:1508] Performed allocation for 1 agents in 996033ns
I0713 08:55:15.099930 18568 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: b45e56c8-0d8a-4ea8-813b-444154321dbc) for operation UUID dccae354-5fb1-41be-93cc-dbe6f6e02b9d of framework '74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000' on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.101471 18565 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:15.103183 18564 process.cpp:3671] Handling HTTP event for process 'slave(1202)' with path: '/slave(1202)/api/v1/resource_provider'
I0713 08:55:15.112670 18579 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 for role storage/default-role of framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:15.112872 18579 hierarchical.cpp:1508] Performed allocation for 1 agents in 794942ns
I0713 08:55:15.142639 18572 http.cpp:1115] HTTP POST for /slave(1202)/api/v1/resource_provider from 172.17.0.2:54920
I0713 08:55:15.144260 18575 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: dccae354-5fb1-41be-93cc-dbe6f6e02b9d) for framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0713 08:55:15.144618 18575 slave.cpp:8670] Updating the state of operation with no ID (uuid: dccae354-5fb1-41be-93cc-dbe6f6e02b9d) for framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0713 08:55:15.145200 18575 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: dccae354-5fb1-41be-93cc-dbe6f6e02b9d) for framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:15.145854 18562 master.cpp:12122] Updating the state of operation '' (uuid: dccae354-5fb1-41be-93cc-dbe6f6e02b9d) for framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0713 08:55:15.147657 18580 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:15.149335 18569 hierarchical.cpp:956] Updated allocation of framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,test)]:2048
I0713 08:55:15.150295 18564 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0713 08:55:15.150581 18579 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: b45e56c8-0d8a-4ea8-813b-444154321dbc) for stream dccae354-5fb1-41be-93cc-dbe6f6e02b9d
I0713 08:55:15.150601 18569 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,test)]:2048, allocated: {}) on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 from framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:15.150774 18579 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: b45e56c8-0d8a-4ea8-813b-444154321dbc) for operation UUID dccae354-5fb1-41be-93cc-dbe6f6e02b9d of framework '74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000' on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.165792 18578 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.725936ms
I0713 08:55:15.166860 18571 master.cpp:10290] Sending offers [ 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O2 ] to framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:15.168058 18567 sched.cpp:934] Scheduler::resourceOffers took 187734ns
I0713 08:55:15.173892 18584 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0713 08:55:15.176360 18573 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:54924
I0713 08:55:15.176703 18573 http.cpp:263] Processing call RESERVE_RESOURCES
I0713 08:55:15.177760 18573 master.cpp:3751] 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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,test)]:2048'
I0713 08:55:15.180433 18569 master.cpp:12575] Removing offer 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O2
I0713 08:55:15.180639 18571 sched.cpp:960] Rescinded offer 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O2
I0713 08:55:15.180752 18571 sched.cpp:971] Scheduler::offerRescinded took 32758ns
I0713 08:55:15.181439 18578 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,test)]:2048, allocated: {}) on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 from framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:15.181586 18578 hierarchical.cpp:1264] Framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 filtered agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 for 5secs
I0713 08:55:15.184700 18581 master.cpp:12466] Sending operation '' (uuid: e507e065-dd89-4ea8-9f69-67008d10dec5) to agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:15.185269 18567 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:15.188978 18563 provider.cpp:481] Received APPLY_OPERATION event
I0713 08:55:15.189030 18563 provider.cpp:1295] Received RESERVE operation '' (uuid: e507e065-dd89-4ea8-9f69-67008d10dec5)
I0713 08:55:15.241673 18579 status_update_manager_process.hpp:490] Cleaning up operation status update stream dccae354-5fb1-41be-93cc-dbe6f6e02b9d
I0713 08:55:15.309904 18564 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: f791f465-d1c7-4442-9df7-ae1c4aaa9a12) for operation UUID e507e065-dd89-4ea8-9f69-67008d10dec5 on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.310014 18564 status_update_manager_process.hpp:414] Creating operation status update stream e507e065-dd89-4ea8-9f69-67008d10dec5 checkpoint=true
I0713 08:55:15.310415 18564 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: f791f465-d1c7-4442-9df7-ae1c4aaa9a12) for operation UUID e507e065-dd89-4ea8-9f69-67008d10dec5 on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.403254 18564 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: f791f465-d1c7-4442-9df7-ae1c4aaa9a12) for operation UUID e507e065-dd89-4ea8-9f69-67008d10dec5 on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.421237 18573 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:15.422627 18571 process.cpp:3671] Handling HTTP event for process 'slave(1202)' with path: '/slave(1202)/api/v1/resource_provider'
I0713 08:55:15.426106 18569 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.337557ms
I0713 08:55:15.426880 18578 master.cpp:10290] Sending offers [ 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O3 ] to framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:15.427618 18583 sched.cpp:934] Scheduler::resourceOffers took 92920ns
I0713 08:55:15.432545 18577 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0713 08:55:15.434576 18568 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:54928
I0713 08:55:15.434852 18568 http.cpp:263] Processing call CREATE_VOLUMES
I0713 08:55:15.435770 18568 master.cpp:3878] Authorizing principal 'test-principal' to create volumes '[{"disk":{"persistence":{"id":"b75b2cf6-01c0-4a2d-a816-ca65c191522c","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d","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":"f5f2a3f8-ec9b-449e-a6be-14dd6e01506c"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0713 08:55:15.438880 18565 master.cpp:12575] Removing offer 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O3
I0713 08:55:15.439095 18564 sched.cpp:960] Rescinded offer 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O3
I0713 08:55:15.439185 18564 sched.cpp:971] Scheduler::offerRescinded took 24357ns
I0713 08:55:15.440062 18579 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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,test)]:2048, allocated: {}) on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 from framework 74b802e1-68aa-4f
 fd-9ec0-393cae375ffd-0000
I0713 08:55:15.440263 18579 hierarchical.cpp:1264] Framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 filtered agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 for 5secs
I0713 08:55:15.443455 18563 master.cpp:12466] Sending operation '' (uuid: 880697f0-cc6d-4839-b717-b4f4e0f98ebb) to agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:15.444195 18585 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:15.448160 18584 provider.cpp:481] Received APPLY_OPERATION event
I0713 08:55:15.448247 18584 provider.cpp:1295] Received CREATE operation '' (uuid: 880697f0-cc6d-4839-b717-b4f4e0f98ebb)
I0713 08:55:15.449921 18577 master.cpp:6312] Processing REVIVE call for framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:15.450423 18577 hierarchical.cpp:1365] Unsuppressed offers for roles { storage/default-role } of framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:15.450456 18577 hierarchical.cpp:1387] Revived roles { storage/default-role } of framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:15.452031 18577 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.408894ms
I0713 08:55:15.452558 18577 hierarchical.cpp:1508] Performed allocation for 1 agents in 257913ns
I0713 08:55:15.453074 18576 master.cpp:10290] Sending offers [ 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O4 ] to framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:15.454138 18564 sched.cpp:934] Scheduler::resourceOffers took 143621ns
I0713 08:55:15.462534 18566 http.cpp:1115] HTTP POST for /slave(1202)/api/v1/resource_provider from 172.17.0.2:54920
I0713 08:55:15.463949 18585 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: e507e065-dd89-4ea8-9f69-67008d10dec5) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0713 08:55:15.464244 18585 slave.cpp:8670] Updating the state of operation with no ID (uuid: e507e065-dd89-4ea8-9f69-67008d10dec5) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0713 08:55:15.464320 18585 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: e507e065-dd89-4ea8-9f69-67008d10dec5) for an operator API call
I0713 08:55:15.464752 18583 master.cpp:12122] Updating the state of operation '' (uuid: e507e065-dd89-4ea8-9f69-67008d10dec5) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0713 08:55:15.465615 18572 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:15.546432 18564 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 28ee657e-4572-4b3e-81e1-11ad21cd709b) for operation UUID 880697f0-cc6d-4839-b717-b4f4e0f98ebb on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.546502 18564 status_update_manager_process.hpp:414] Creating operation status update stream 880697f0-cc6d-4839-b717-b4f4e0f98ebb checkpoint=true
I0713 08:55:15.546631 18584 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0713 08:55:15.546897 18564 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 28ee657e-4572-4b3e-81e1-11ad21cd709b) for operation UUID 880697f0-cc6d-4839-b717-b4f4e0f98ebb on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.596432 18564 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 28ee657e-4572-4b3e-81e1-11ad21cd709b) for operation UUID 880697f0-cc6d-4839-b717-b4f4e0f98ebb on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.596773 18564 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: f791f465-d1c7-4442-9df7-ae1c4aaa9a12) for stream e507e065-dd89-4ea8-9f69-67008d10dec5
I0713 08:55:15.596843 18564 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: f791f465-d1c7-4442-9df7-ae1c4aaa9a12) for operation UUID e507e065-dd89-4ea8-9f69-67008d10dec5 on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.597277 18579 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:15.598179 18563 process.cpp:3671] Handling HTTP event for process 'slave(1202)' with path: '/slave(1202)/api/v1/resource_provider'
I0713 08:55:15.637524 18570 http.cpp:1115] HTTP POST for /slave(1202)/api/v1/resource_provider from 172.17.0.2:54920
I0713 08:55:15.638708 18572 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 880697f0-cc6d-4839-b717-b4f4e0f98ebb) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0713 08:55:15.639202 18572 slave.cpp:8670] Updating the state of operation with no ID (uuid: 880697f0-cc6d-4839-b717-b4f4e0f98ebb) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0713 08:55:15.639286 18572 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 880697f0-cc6d-4839-b717-b4f4e0f98ebb) for an operator API call
I0713 08:55:15.640023 18581 master.cpp:12122] Updating the state of operation '' (uuid: 880697f0-cc6d-4839-b717-b4f4e0f98ebb) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0713 08:55:15.640774 18567 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:15.642612 18573 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0713 08:55:15.671711 18564 status_update_manager_process.hpp:490] Cleaning up operation status update stream e507e065-dd89-4ea8-9f69-67008d10dec5
I0713 08:55:15.671923 18564 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 28ee657e-4572-4b3e-81e1-11ad21cd709b) for stream 880697f0-cc6d-4839-b717-b4f4e0f98ebb
I0713 08:55:15.671993 18564 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 28ee657e-4572-4b3e-81e1-11ad21cd709b) for operation UUID 880697f0-cc6d-4839-b717-b4f4e0f98ebb on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.747108 18564 status_update_manager_process.hpp:490] Cleaning up operation status update stream 880697f0-cc6d-4839-b717-b4f4e0f98ebb
I0713 08:55:15.810992 18578 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0713 08:55:15.813040 18581 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:54932
I0713 08:55:15.813396 18581 http.cpp:263] Processing call DESTROY_VOLUMES
I0713 08:55:15.814733 18581 master.cpp:3923] Authorizing principal 'test-principal' to destroy volumes '[{"disk":{"persistence":{"id":"b75b2cf6-01c0-4a2d-a816-ca65c191522c","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d","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":"f5f2a3f8-ec9b-449e-a6be-14dd6e01506c"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0713 08:55:15.817162 18568 master.cpp:12575] Removing offer 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O4
I0713 08:55:15.817310 18577 sched.cpp:960] Rescinded offer 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O4
I0713 08:55:15.817387 18577 sched.cpp:971] Scheduler::offerRescinded took 22142ns
I0713 08:55:15.818143 18582 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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,test),b75b2cf6-01c0-4a2d-a816-ca65c191522c: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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,test),b75b2cf6-01c0-4a2d-a816-ca65c191522c:volume]:2048, allocat
 ed: {}) on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 from framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:15.818265 18582 hierarchical.cpp:1264] Framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 filtered agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 for 5secs
I0713 08:55:15.822458 18565 master.cpp:12466] Sending operation '' (uuid: 18522758-fc13-40e7-982a-d27a8772a551) to agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:15.823413 18563 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:15.828441 18562 provider.cpp:481] Received APPLY_OPERATION event
I0713 08:55:15.828490 18562 provider.cpp:1295] Received DESTROY operation '' (uuid: 18522758-fc13-40e7-982a-d27a8772a551)
I0713 08:55:15.831856 18570 hierarchical.cpp:1508] Performed allocation for 1 agents in 2.243945ms
I0713 08:55:15.832916 18567 master.cpp:10290] Sending offers [ 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O5 ] to framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:15.833910 18581 sched.cpp:934] Scheduler::resourceOffers took 118532ns
I0713 08:55:15.933034 18580 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 8cbbb277-58e3-4a0c-ad5a-3559bfa0fcf0) for operation UUID 18522758-fc13-40e7-982a-d27a8772a551 on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.933153 18580 status_update_manager_process.hpp:414] Creating operation status update stream 18522758-fc13-40e7-982a-d27a8772a551 checkpoint=true
I0713 08:55:15.933758 18580 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 8cbbb277-58e3-4a0c-ad5a-3559bfa0fcf0) for operation UUID 18522758-fc13-40e7-982a-d27a8772a551 on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:15.999764 18580 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 8cbbb277-58e3-4a0c-ad5a-3559bfa0fcf0) for operation UUID 18522758-fc13-40e7-982a-d27a8772a551 on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:16.001271 18577 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:16.003072 18576 process.cpp:3671] Handling HTTP event for process 'slave(1202)' with path: '/slave(1202)/api/v1/resource_provider'
I0713 08:55:16.008042 18571 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0713 08:55:16.010975 18585 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:54934
I0713 08:55:16.011487 18585 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0713 08:55:16.012727 18585 master.cpp:3815] Authorizing principal 'test-principal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d","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":"f5f2a3f8-ec9b-449e-a6be-14dd6e01506c"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0713 08:55:16.016050 18585 master.cpp:12575] Removing offer 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O5
I0713 08:55:16.016324 18572 sched.cpp:960] Rescinded offer 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O5
I0713 08:55:16.016460 18572 sched.cpp:971] Scheduler::offerRescinded took 28393ns
I0713 08:55:16.017292 18583 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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,test)]:2048, allocated: {}) on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 from framework 74b802e1-68aa-4f
 fd-9ec0-393cae375ffd-0000
I0713 08:55:16.017480 18583 hierarchical.cpp:1264] Framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 filtered agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 for 5secs
I0713 08:55:16.021420 18570 master.cpp:12466] Sending operation '' (uuid: 9e29d5e9-60b6-4a51-bb17-1f190898740d) to agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:16.022292 18562 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:16.026623 18573 provider.cpp:481] Received APPLY_OPERATION event
I0713 08:55:16.026684 18573 provider.cpp:1295] Received UNRESERVE operation '' (uuid: 9e29d5e9-60b6-4a51-bb17-1f190898740d)
I0713 08:55:16.028569 18564 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.891197ms
I0713 08:55:16.029253 18575 master.cpp:10290] Sending offers [ 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O6 ] to framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:16.030243 18569 sched.cpp:934] Scheduler::resourceOffers took 126176ns
I0713 08:55:16.041836 18570 http.cpp:1115] HTTP POST for /slave(1202)/api/v1/resource_provider from 172.17.0.2:54920
I0713 08:55:16.042822 18574 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 18522758-fc13-40e7-982a-d27a8772a551) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0713 08:55:16.043000 18574 slave.cpp:8670] Updating the state of operation with no ID (uuid: 18522758-fc13-40e7-982a-d27a8772a551) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0713 08:55:16.043056 18574 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 18522758-fc13-40e7-982a-d27a8772a551) for an operator API call
I0713 08:55:16.043432 18562 master.cpp:12122] Updating the state of operation '' (uuid: 18522758-fc13-40e7-982a-d27a8772a551) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0713 08:55:16.044059 18568 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:16.125912 18569 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: cbed9637-fd51-45f6-828b-82e10a83b47b) for operation UUID 9e29d5e9-60b6-4a51-bb17-1f190898740d on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:16.126009 18569 status_update_manager_process.hpp:414] Creating operation status update stream 9e29d5e9-60b6-4a51-bb17-1f190898740d checkpoint=true
I0713 08:55:16.126075 18573 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0713 08:55:16.126520 18569 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: cbed9637-fd51-45f6-828b-82e10a83b47b) for operation UUID 9e29d5e9-60b6-4a51-bb17-1f190898740d on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:16.192894 18569 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: cbed9637-fd51-45f6-828b-82e10a83b47b) for operation UUID 9e29d5e9-60b6-4a51-bb17-1f190898740d on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:16.193637 18569 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 8cbbb277-58e3-4a0c-ad5a-3559bfa0fcf0) for stream 18522758-fc13-40e7-982a-d27a8772a551
I0713 08:55:16.193786 18569 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 8cbbb277-58e3-4a0c-ad5a-3559bfa0fcf0) for operation UUID 18522758-fc13-40e7-982a-d27a8772a551 on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:16.194593 18585 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:16.196384 18580 process.cpp:3671] Handling HTTP event for process 'slave(1202)' with path: '/slave(1202)/api/v1/resource_provider'
I0713 08:55:16.234057 18576 http.cpp:1115] HTTP POST for /slave(1202)/api/v1/resource_provider from 172.17.0.2:54920
I0713 08:55:16.234897 18584 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 9e29d5e9-60b6-4a51-bb17-1f190898740d) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0713 08:55:16.235054 18584 slave.cpp:8670] Updating the state of operation with no ID (uuid: 9e29d5e9-60b6-4a51-bb17-1f190898740d) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0713 08:55:16.235098 18584 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 9e29d5e9-60b6-4a51-bb17-1f190898740d) for an operator API call
I0713 08:55:16.235388 18579 master.cpp:12122] Updating the state of operation '' (uuid: 9e29d5e9-60b6-4a51-bb17-1f190898740d) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0713 08:55:16.235832 18571 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0713 08:55:16.237270 18583 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0713 08:55:16.251251 18569 status_update_manager_process.hpp:490] Cleaning up operation status update stream 18522758-fc13-40e7-982a-d27a8772a551
I0713 08:55:16.251670 18569 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: cbed9637-fd51-45f6-828b-82e10a83b47b) for stream 9e29d5e9-60b6-4a51-bb17-1f190898740d
I0713 08:55:16.251783 18569 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: cbed9637-fd51-45f6-828b-82e10a83b47b) for operation UUID 9e29d5e9-60b6-4a51-bb17-1f190898740d on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:16.343276 18569 status_update_manager_process.hpp:490] Cleaning up operation status update stream 9e29d5e9-60b6-4a51-bb17-1f190898740d
I0713 08:55:16.411362 18574 master.cpp:1410] Framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625 disconnected
I0713 08:55:16.411401 18574 master.cpp:3360] Deactivating framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:16.411849 18562 hierarchical.cpp:475] Deactivated framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:16.412328 18574 master.cpp:12575] Removing offer 74b802e1-68aa-4ffd-9ec0-393cae375ffd-O6
I0713 08:55:16.412367 18568 slave.cpp:912] Agent terminating
I0713 08:55:16.412405 18574 master.cpp:3337] Disconnecting framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:16.412456 18574 master.cpp:1425] Giving framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625 0ns to failover
I0713 08:55:16.413306 18568 manager.cpp:163] Terminating resource provider f5f2a3f8-ec9b-449e-a6be-14dd6e01506c
I0713 08:55:16.413332 18562 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,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_YIV9HV/2GB-dccae354-5fb1-41be-93cc-dbe6f6e02b9d,test)]:2048, allocated: {}) on agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 from framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:16.413668 18568 master.cpp:1295] Agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1) disconnected
I0713 08:55:16.413698 18568 master.cpp:3397] Disconnecting agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:16.413766 18568 master.cpp:3416] Deactivating agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 at slave(1202)@172.17.0.2:46625 (854f964fcdc1)
I0713 08:55:16.414103 18584 hierarchical.cpp:799] Agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0 deactivated
I0713 08:55:16.414199 18568 master.cpp:10082] Framework failover timeout, removing framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:16.414264 18568 master.cpp:11074] Removing framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000 (default) at scheduler-14ffab30-34a4-41a0-a234-eaca54ef5f3e@172.17.0.2:46625
I0713 08:55:16.414865 18579 hierarchical.cpp:1432] Allocation paused
E0713 08:55:16.414928 18575 http_connection.hpp:452] End-Of-File received
I0713 08:55:16.415431 18579 hierarchical.cpp:417] Removed framework 74b802e1-68aa-4ffd-9ec0-393cae375ffd-0000
I0713 08:55:16.415535 18575 http_connection.hpp:217] Re-detecting endpoint
I0713 08:55:16.415567 18579 hierarchical.cpp:1442] Allocation resumed
I0713 08:55:16.416276 18575 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0713 08:55:16.416342 18575 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0713 08:55:16.416450 18573 provider.cpp:471] Disconnected from resource provider manager
I0713 08:55:16.416533 18575 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:16.416695 18573 status_update_manager_process.hpp:379] Pausing operation status update manager
I0713 08:55:16.418298 18583 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
I0713 08:55:16.418350 18583 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
I0713 08:55:16.418871 18583 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0713 08:55:16.419989 18579 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
I0713 08:55:16.420742 18585 provider.cpp:459] Connected to resource provider manager
I0713 08:55:16.421418 18564 hierarchical.cpp:1508] Performed allocation for 1 agents in 241750ns
I0713 08:55:16.421561 18573 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:46625/slave(1202)/api/v1/resource_provider
E0713 08:55:16.422322 18573 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
I0713 08:55:16.422624 18586 process.cpp:2781] Returning '404 Not Found' for '/slave(1202)/api/v1/resource_provider'
E0713 08:55:16.423959 18581 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0713 08:55:16.473156 18584 hierarchical.cpp:1508] Performed allocation for 1 agents in 220415ns
I0713 08:55:16.523217 18577 containerizer.cpp:3116] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0713 08:55:16.524672 18574 hierarchical.cpp:1508] Performed allocation for 1 agents in 108785ns
I0713 08:55:16.525075 18571 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
I0713 08:55:16.528642 18575 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'
I0713 08:55:16.528892 18584 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-7qnPzm/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0713 08:55:16.529162 18582 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0713 08:55:16.533299 18586 process.cpp:2781] Returning '404 Not Found' for '/slave(1202)/api/v1'
I0713 08:55:16.546416 18561 master.cpp:1135] Master terminating
I0713 08:55:16.547091 18582 hierarchical.cpp:775] Removed all filters for agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
I0713 08:55:16.547119 18582 hierarchical.cpp:650] Removed agent 74b802e1-68aa-4ffd-9ec0-393cae375ffd-S0
[       OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (2514 ms)
[----------] 50 tests from CSIVersion/StorageLocalResourceProviderTest (96543 ms total)

[----------] Global test environment tear-down
[==========] 2271 tests from 216 test cases ran. (1113998 ms total)
[  PASSED  ] 2269 tests.
[  FAILED  ] 2 tests, listed below:
[  FAILED  ] ContentType/MasterAPITest.DrainAgent/0, where GetParam() = application/x-protobuf
[  FAILED  ] ContentType/MasterAPITest.DrainAgent/1, where GetParam() = application/json

 2 FAILED TESTS
  YOU HAVE 31 DISABLED TESTS

I0713 08:55:16.652973 18586 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-1563002107-20863
Untagged: mesos-1563002107-20863:latest
Deleted: sha256:dd1aacfb02f2f672213477241ef8a21d426ee59e52aa72f7e3762d1b3dccf490
Deleted: sha256:39fb36cd79d35ef9bfcadfea88adbad42670b939181d7e9e7758e59f4ae424b5
Deleted: sha256:ea42f1066acfbda67ef7690cf9699a3b0dfea7cb542bf080033b31efe9ebfd77
Deleted: sha256:c6be6203bcfa12cf2b86f20bec520a3831226c18f7590174416ce58655076fe9
Deleted: sha256:ac69fa662b76dfb5577ac18a6c7f41a6e3fd5064d05347ca575f6b2826f063ef
Deleted: sha256:eb9fb17d5dd27f233d8967c4129135ef6312219b7d8a4690d428fbc50d187e5a
Deleted: sha256:d484dd342c723bab413b8d079503aac54456e032e37bd49b198b49c7793689db
Deleted: sha256:afe46e51d1556d84c07479303d1eea90bd740a833dd426ab13c59db505585326
Deleted: sha256:d682de58d811a504eccbbf09dec8eab67eb97eac345ab60fb42a34f6c72e7aa9
Deleted: sha256:f6087b7acbcc4472734e0927ed0b8b5073f1ead23748a07b10ca8eb16f388ff5
Deleted: sha256:445be692a1715310fcfa2638b1004a9f3d9f77245c633ab850ce989bf7566705
Deleted: sha256:71de12e1b50bb51c2c774c7c3025dfe1cb2d12b075c43921ec1c650f52fc9791
Deleted: sha256:30e075f78238de17cca5090f084b21820c11f9d37a4671cb344e307ff3eb8724
Deleted: sha256:74d60353a3e0d23c87121686ee18a91392009901aec627bb05e7f42fff5545b7
Deleted: sha256:822260471d71582f0ad328007e5d876b85e0bb86910d1f83b7a663bbc03a3e28
Deleted: sha256:e697751a5948bb17f0ced42499bf5a88a105722b260e5e80b08e945fbd8e7128
Deleted: sha256:ae126b092d232f3e1a6a53c3d1a7b35dd85b6524558691700db3d86e6528f665
Deleted: sha256:0f4069bc3277dc30e611307047febbec63bc346434332a1ba880f61d4c2b29fd
Deleted: sha256:241cddd703fadc7f7cc658e9332706c9716d89d9fbf0bb7dd82cd9154d5c4b9b
Deleted: sha256:8765739d02a836cf21b06afa5a5adc3bd70ad35bf392067ed86781526039421f
Deleted: sha256:011c9427ae8e250e5792bd89a659a29213ae11d96ca2eb38a0184463466e092c
Deleted: sha256:4cf37a41ba2bc445bc58b93a608533977df79713698f42a816f651f5296313c4
Deleted: sha256:df6f5fe933fd92819685ec4927bc8750282b6a2237ac9423cb9f6dc501f365b7
Deleted: sha256:601ccb0f3e2b4188fbc9e105b858da7d28075d1590c0a29ecad956c9fba4fa72
Deleted: sha256:f2497e47ca28e88f16d106a565268d42277ff8bf40eef61428daa804f2123d6d
Deleted: sha256:db0979725e1ff006a5bc7bbf7559f83c2c2cec3865adce9aeb675ca2a8fa6df8
Deleted: sha256:876bc3ab56ab053c0ed97414b6c36d9f83535f0d077ae70dcd96bedbdd6b101f
Deleted: sha256:f1db26a0869b5b4b927df70f2faf491e72e98ada4e77b239606c1890ae35b6e6
Deleted: sha256:f758a19b10a88ec2c6a14359c263daba6d8d30ec5681e50e6e06b68b75b86ccc
Deleted: sha256:37cf353b86c8ca4dda3181bb4f24a52a6b4dd4b20736f50cb44b2c56f7fcc7db

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

- Mesos Reviewbot


On July 13, 2019, 12:03 a.m., Greg Mann wrote:
> 
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71069/
> -----------------------------------------------------------
> 
> (Updated July 13, 2019, 12:03 a.m.)
> 
> 
> Review request for mesos, Benno Evers and Joseph Wu.
> 
> 
> Bugs: MESOS-9816
>     https://issues.apache.org/jira/browse/MESOS-9816
> 
> 
> Repository: mesos
> 
> 
> Description
> -------
> 
> This adds a minimal test for the DRAIN_AGENT scheduler call,
> along with verification of master API results once an agent
> has been drained.
> 
> 
> Diffs
> -----
> 
>   include/mesos/v1/mesos.hpp df67f64fc537819bf8607e6d6b4a478b544df69e 
>   src/tests/api_tests.cpp af1d215f00c8c2224e807677afb4af2d3521235a 
>   src/v1/mesos.cpp be479e34042fb4a76b770d4a0e9abe454ff0447b 
> 
> 
> Diff: https://reviews.apache.org/r/71069/diff/1/
> 
> 
> Testing
> -------
> 
> `make check`
> `bin/mesos-tests.sh --gtest_filter="*MasterAPITest.DrainAgent*" --gtest_repeat=-1 --gtest_break_on_failure`
> 
> 
> Thanks,
> 
> Greg Mann
> 
>


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