----------------------------------------------------------- This is an automatically generated e-mail. To reply, visit: https://reviews.apache.org/r/71047/#review216487 -----------------------------------------------------------
Bad patch! Reviews applied: [71047] 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_71047"] Error: ...<truncated>... us UUID: c4a37b8a-d6f4-4c32-ae99-3ddf48e8de12) for operation UUID 814d4696-73e9-4929-8797-bbc5bf7eb5be on agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 I0710 15:54:55.127045 18278 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:44968/slave(1199)/api/v1/resource_provider I0710 15:54:55.128481 18271 process.cpp:3671] Handling HTTP event for process 'slave(1199)' with path: '/slave(1199)/api/v1/resource_provider' I0710 15:54:55.132359 18264 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1' I0710 15:54:55.134366 18274 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:45566 I0710 15:54:55.134639 18274 http.cpp:263] Processing call UNRESERVE_RESOURCES I0710 15:54:55.135423 18274 master.cpp:3785] Authorizing principal 'test-principal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_diZEs1/2GB-fb8728fd-97b6-48f0-a119-3c585c3b43dd","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":"ac49acbc-1b73-421b-9599-b71c27ac1aef"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]' I0710 15:54:55.138424 18266 master.cpp:12470] Removing offer d00b84e5-8718-46ea-940c-e286f72e8ecc-O5 I0710 15:54:55.138586 18263 sched.cpp:960] Rescinded offer d00b84e5-8718-46ea-940c-e286f72e8ecc-O5 I0710 15:54:55.138669 18263 sched.cpp:971] Scheduler::offerRescinded took 23992ns I0710 15:54:55.139626 18277 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_diZEs1/2GB-fb8728fd-97b6-48f0-a119-3c585c3b43dd,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_diZEs1/2GB-fb8728fd-97b6-48f0-a119-3c585c3b43dd,test)]:2048, allocated: {}) on agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 from framework d00b84e5-8718-46 ea-940c-e286f72e8ecc-0000 I0710 15:54:55.139758 18277 hierarchical.cpp:1264] Framework d00b84e5-8718-46ea-940c-e286f72e8ecc-0000 filtered agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 for 5secs I0710 15:54:55.142410 18269 master.cpp:12361] Sending operation '' (uuid: b7639072-1776-41d5-ba53-0e24f7548b4c) to agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 at slave(1199)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:55.142972 18278 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:55.146268 18264 provider.cpp:481] Received APPLY_OPERATION event I0710 15:54:55.146315 18264 provider.cpp:1295] Received UNRESERVE operation '' (uuid: b7639072-1776-41d5-ba53-0e24f7548b4c) I0710 15:54:55.152446 18280 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.127484ms I0710 15:54:55.153100 18262 master.cpp:10195] Sending offers [ d00b84e5-8718-46ea-940c-e286f72e8ecc-O6 ] to framework d00b84e5-8718-46ea-940c-e286f72e8ecc-0000 (default) at [email protected]:44968 I0710 15:54:55.153779 18274 sched.cpp:934] Scheduler::resourceOffers took 138us I0710 15:54:55.166543 18260 http.cpp:1115] HTTP POST for /slave(1199)/api/v1/resource_provider from 172.17.0.2:45554 I0710 15:54:55.167589 18269 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 814d4696-73e9-4929-8797-bbc5bf7eb5be) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0710 15:54:55.167793 18269 slave.cpp:8670] Updating the state of operation with no ID (uuid: 814d4696-73e9-4929-8797-bbc5bf7eb5be) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0710 15:54:55.167843 18269 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 814d4696-73e9-4929-8797-bbc5bf7eb5be) for an operator API call I0710 15:54:55.168205 18273 master.cpp:12017] Updating the state of operation '' (uuid: 814d4696-73e9-4929-8797-bbc5bf7eb5be) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0710 15:54:55.168776 18278 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:55.226965 18274 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 9acea5e1-2ec1-49f1-aaca-6f317e021df4) for operation UUID b7639072-1776-41d5-ba53-0e24f7548b4c on agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 I0710 15:54:55.227031 18274 status_update_manager_process.hpp:414] Creating operation status update stream b7639072-1776-41d5-ba53-0e24f7548b4c checkpoint=true I0710 15:54:55.227058 18264 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event I0710 15:54:55.227363 18274 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 9acea5e1-2ec1-49f1-aaca-6f317e021df4) for operation UUID b7639072-1776-41d5-ba53-0e24f7548b4c on agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 I0710 15:54:55.277416 18274 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 9acea5e1-2ec1-49f1-aaca-6f317e021df4) for operation UUID b7639072-1776-41d5-ba53-0e24f7548b4c on agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 I0710 15:54:55.277727 18274 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: c4a37b8a-d6f4-4c32-ae99-3ddf48e8de12) for stream 814d4696-73e9-4929-8797-bbc5bf7eb5be I0710 15:54:55.277806 18274 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: c4a37b8a-d6f4-4c32-ae99-3ddf48e8de12) for operation UUID 814d4696-73e9-4929-8797-bbc5bf7eb5be on agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 I0710 15:54:55.278232 18268 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:44968/slave(1199)/api/v1/resource_provider I0710 15:54:55.279184 18277 process.cpp:3671] Handling HTTP event for process 'slave(1199)' with path: '/slave(1199)/api/v1/resource_provider' I0710 15:54:55.318950 18278 http.cpp:1115] HTTP POST for /slave(1199)/api/v1/resource_provider from 172.17.0.2:45554 I0710 15:54:55.319809 18272 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: b7639072-1776-41d5-ba53-0e24f7548b4c) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0710 15:54:55.319999 18272 slave.cpp:8670] Updating the state of operation with no ID (uuid: b7639072-1776-41d5-ba53-0e24f7548b4c) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0710 15:54:55.320070 18272 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: b7639072-1776-41d5-ba53-0e24f7548b4c) for an operator API call I0710 15:54:55.320430 18275 master.cpp:12017] Updating the state of operation '' (uuid: b7639072-1776-41d5-ba53-0e24f7548b4c) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0710 15:54:55.320976 18267 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:55.322346 18263 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event I0710 15:54:55.327563 18274 status_update_manager_process.hpp:490] Cleaning up operation status update stream 814d4696-73e9-4929-8797-bbc5bf7eb5be I0710 15:54:55.327778 18274 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 9acea5e1-2ec1-49f1-aaca-6f317e021df4) for stream b7639072-1776-41d5-ba53-0e24f7548b4c I0710 15:54:55.327850 18274 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 9acea5e1-2ec1-49f1-aaca-6f317e021df4) for operation UUID b7639072-1776-41d5-ba53-0e24f7548b4c on agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 I0710 15:54:55.411499 18274 status_update_manager_process.hpp:490] Cleaning up operation status update stream b7639072-1776-41d5-ba53-0e24f7548b4c I0710 15:54:55.471657 18276 master.cpp:1410] Framework d00b84e5-8718-46ea-940c-e286f72e8ecc-0000 (default) at [email protected]:44968 disconnected I0710 15:54:55.471731 18276 master.cpp:3342] Deactivating framework d00b84e5-8718-46ea-940c-e286f72e8ecc-0000 (default) at [email protected]:44968 I0710 15:54:55.472196 18272 hierarchical.cpp:475] Deactivated framework d00b84e5-8718-46ea-940c-e286f72e8ecc-0000 I0710 15:54:55.472796 18259 slave.cpp:912] Agent terminating I0710 15:54:55.473129 18276 master.cpp:12470] Removing offer d00b84e5-8718-46ea-940c-e286f72e8ecc-O6 I0710 15:54:55.473227 18276 master.cpp:3319] Disconnecting framework d00b84e5-8718-46ea-940c-e286f72e8ecc-0000 (default) at [email protected]:44968 I0710 15:54:55.473342 18276 master.cpp:1425] Giving framework d00b84e5-8718-46ea-940c-e286f72e8ecc-0000 (default) at [email protected]:44968 0ns to failover I0710 15:54:55.473845 18259 manager.cpp:163] Terminating resource provider ac49acbc-1b73-421b-9599-b71c27ac1aef I0710 15:54:55.474092 18272 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_diZEs1/2GB-fb8728fd-97b6-48f0-a119-3c585c3b43dd,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_diZEs1/2GB-fb8728fd-97b6-48f0-a119-3c585c3b43dd,test)]:2048, allocated: {}) on agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 from framework d00b84e5-8718-46ea-940c-e286f72e8ecc-0000 I0710 15:54:55.474391 18260 master.cpp:1295] Agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 at slave(1199)@172.17.0.2:44968 (b727e219f54d) disconnected I0710 15:54:55.474423 18260 master.cpp:3379] Disconnecting agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 at slave(1199)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:55.474512 18260 master.cpp:3398] Deactivating agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 at slave(1199)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:55.474665 18271 hierarchical.cpp:799] Agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 deactivated I0710 15:54:55.474961 18273 master.cpp:9987] Framework failover timeout, removing framework d00b84e5-8718-46ea-940c-e286f72e8ecc-0000 (default) at [email protected]:44968 I0710 15:54:55.474997 18273 master.cpp:10979] Removing framework d00b84e5-8718-46ea-940c-e286f72e8ecc-0000 (default) at [email protected]:44968 I0710 15:54:55.475389 18281 hierarchical.cpp:1432] Allocation paused E0710 15:54:55.475473 18261 http_connection.hpp:452] End-Of-File received I0710 15:54:55.475863 18281 hierarchical.cpp:417] Removed framework d00b84e5-8718-46ea-940c-e286f72e8ecc-0000 I0710 15:54:55.475996 18261 http_connection.hpp:217] Re-detecting endpoint I0710 15:54:55.476367 18281 hierarchical.cpp:1442] Allocation resumed I0710 15:54:55.476470 18261 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0710 15:54:55.476534 18261 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0710 15:54:55.476613 18261 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:44968/slave(1199)/api/v1/resource_provider I0710 15:54:55.476698 18264 provider.cpp:471] Disconnected from resource provider manager I0710 15:54:55.477080 18266 status_update_manager_process.hpp:379] Pausing operation status update manager I0710 15:54:55.478046 18260 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 I0710 15:54:55.478081 18260 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 I0710 15:54:55.478484 18260 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0710 15:54:55.479586 18283 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:44968/slave(1199)/api/v1/resource_provider I0710 15:54:55.480159 18265 provider.cpp:459] Connected to resource provider manager I0710 15:54:55.480656 18281 hierarchical.cpp:1508] Performed allocation for 1 agents in 148974ns I0710 15:54:55.480806 18264 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:44968/slave(1199)/api/v1/resource_provider E0710 15:54:55.481459 18264 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 I0710 15:54:55.481587 18284 process.cpp:2781] Returning '404 Not Found' for '/slave(1199)/api/v1/resource_provider' E0710 15:54:55.482741 18261 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' () I0710 15:54:55.531530 18269 hierarchical.cpp:1508] Performed allocation for 1 agents in 130205ns I0710 15:54:55.582430 18263 containerizer.cpp:3116] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited I0710 15:54:55.582932 18267 hierarchical.cpp:1508] Performed allocation for 1 agents in 111204ns I0710 15:54:55.583720 18280 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 I0710 15:54:55.585850 18270 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' I0710 15:54:55.586033 18269 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-MkIz2X/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0710 15:54:55.586253 18271 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0710 15:54:55.588464 18284 process.cpp:2781] Returning '404 Not Found' for '/slave(1199)/api/v1' I0710 15:54:55.599258 18259 master.cpp:1135] Master terminating I0710 15:54:55.599900 18283 hierarchical.cpp:775] Removed all filters for agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 I0710 15:54:55.599928 18283 hierarchical.cpp:650] Removed agent d00b84e5-8718-46ea-940c-e286f72e8ecc-S0 [ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v0 (2409 ms) [ RUN ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 I0710 15:54:55.613960 18259 cluster.cpp:176] Creating default 'local' authorizer I0710 15:54:55.618620 18273 master.cpp:440] Master 753f1040-d566-4097-a9e4-d6acaedc978b (b727e219f54d) started on 172.17.0.2:44968 I0710 15:54:55.618649 18273 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/JG9vsm/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/JG9vsm/master" --zk_session_timeout="10secs" I0710 15:54:55.619024 18273 master.cpp:492] Master only allowing authenticated frameworks to register I0710 15:54:55.619041 18273 master.cpp:498] Master only allowing authenticated agents to register I0710 15:54:55.619048 18273 master.cpp:504] Master only allowing authenticated HTTP frameworks to register I0710 15:54:55.619057 18273 credentials.hpp:37] Loading credentials for authentication from '/tmp/JG9vsm/credentials' I0710 15:54:55.619328 18273 master.cpp:548] Using default 'crammd5' authenticator I0710 15:54:55.619529 18273 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0710 15:54:55.619756 18273 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0710 15:54:55.619948 18273 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0710 15:54:55.620131 18273 master.cpp:629] Authorization enabled I0710 15:54:55.620477 18264 hierarchical.cpp:241] Initialized hierarchical allocator process I0710 15:54:55.620507 18267 whitelist_watcher.cpp:77] No whitelist given I0710 15:54:55.623255 18283 master.cpp:2150] Elected as the leading master! I0710 15:54:55.623289 18283 master.cpp:1664] Recovering from registrar I0710 15:54:55.623486 18263 registrar.cpp:339] Recovering registrar I0710 15:54:55.624450 18263 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns I0710 15:54:55.624621 18263 registrar.cpp:487] Applied 1 operations in 40468ns; attempting to update the registry I0710 15:54:55.625360 18263 registrar.cpp:544] Successfully updated the registry in 0ns I0710 15:54:55.625519 18263 registrar.cpp:416] Successfully recovered registrar I0710 15:54:55.625969 18269 master.cpp:1799] Recovered 0 agents from the registry (143B); allowing 10mins for agents to reregister I0710 15:54:55.626037 18262 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover W0710 15:54:55.631738 18259 process.cpp:2877] Attempted to spawn already running process [email protected]:44968 I0710 15:54:55.632992 18259 containerizer.cpp:314] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } W0710 15:54:55.633550 18259 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges W0710 15:54:55.633708 18259 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges I0710 15:54:55.633749 18259 provisioner.cpp:298] Using default backend 'copy' I0710 15:54:55.636193 18259 cluster.cpp:510] Creating default 'local' authorizer I0710 15:54:55.638526 18282 slave.cpp:265] Mesos agent started on (1200)@172.17.0.2:44968 I0710 15:54:55.638551 18282 slave.cpp:266] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/JG9vsm/rFfW6O/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/JG9vsm/rFfW6O/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/JG9vsm/rFfW6O/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/JG9vsm/rFfW6O/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/JG9vsm/rFfW6O/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/JG9vsm/rFfW6O/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/JG9vsm/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_swqbrs" --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_5iurL5" --zk_session_timeout="10secs" I0710 15:54:55.638978 18282 credentials.hpp:86] Loading credential for authentication from '/tmp/JG9vsm/rFfW6O/credential' I0710 15:54:55.639140 18282 slave.cpp:298] Agent using credential for: test-principal I0710 15:54:55.639166 18282 credentials.hpp:37] Loading credentials for authentication from '/tmp/JG9vsm/rFfW6O/http_credentials' I0710 15:54:55.639358 18282 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0710 15:54:55.639739 18282 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor' I0710 15:54:55.641414 18282 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"}] I0710 15:54:55.641626 18282 slave.cpp:621] Agent attributes: [ ] I0710 15:54:55.641643 18282 slave.cpp:630] Agent hostname: b727e219f54d I0710 15:54:55.641815 18280 status_update_manager_process.hpp:379] Pausing operation status update manager I0710 15:54:55.641865 18260 task_status_update_manager.cpp:181] Pausing sending task status updates I0710 15:54:55.642868 18278 process.cpp:3671] Handling HTTP event for process 'test-disk-profile-server' with path: '/test-disk-profile-server/profiles' I0710 15:54:55.643599 18270 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_5iurL5/meta' I0710 15:54:55.643993 18274 slave.cpp:7246] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_5iurL5/meta', beginning agent recovery I0710 15:54:55.644598 18263 task_status_update_manager.cpp:207] Recovering task status update manager I0710 15:54:55.645124 18276 containerizer.cpp:796] Recovering Mesos containers I0710 15:54:55.645493 18276 containerizer.cpp:1122] Recovering isolators I0710 15:54:55.646478 18270 containerizer.cpp:1161] Recovering provisioner I0710 15:54:55.647233 18272 provisioner.cpp:498] Provisioner recovery complete I0710 15:54:55.647325 18282 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles I0710 15:54:55.648098 18271 composing.cpp:339] Finished recovering all containerizers I0710 15:54:55.648437 18264 slave.cpp:7708] Recovering executors I0710 15:54:55.648560 18264 slave.cpp:7861] Finished recovery I0710 15:54:55.649502 18280 task_status_update_manager.cpp:181] Pausing sending task status updates I0710 15:54:55.649528 18273 status_update_manager_process.hpp:379] Pausing operation status update manager I0710 15:54:55.649550 18276 slave.cpp:1258] New master detected at [email protected]:44968 I0710 15:54:55.649716 18276 slave.cpp:1323] Detecting new master I0710 15:54:55.651036 18261 slave.cpp:1350] Authenticating with master [email protected]:44968 I0710 15:54:55.651165 18261 slave.cpp:1359] Using default CRAM-MD5 authenticatee I0710 15:54:55.651537 18260 authenticatee.cpp:121] Creating new client SASL connection I0710 15:54:55.651901 18270 master.cpp:10380] Authenticating slave(1200)@172.17.0.2:44968 I0710 15:54:55.652092 18275 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2046)@172.17.0.2:44968 I0710 15:54:55.652393 18282 authenticator.cpp:98] Creating new server SASL connection I0710 15:54:55.652652 18274 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0710 15:54:55.652688 18274 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0710 15:54:55.652829 18269 authenticator.cpp:204] Received SASL authentication start I0710 15:54:55.652899 18269 authenticator.cpp:326] Authentication requires more steps I0710 15:54:55.653074 18272 authenticatee.cpp:259] Received SASL authentication step I0710 15:54:55.653265 18268 authenticator.cpp:232] Received SASL authentication step I0710 15:54:55.653313 18268 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b727e219f54d' server FQDN: 'b727e219f54d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0710 15:54:55.653337 18268 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0710 15:54:55.653381 18268 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0710 15:54:55.653405 18268 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b727e219f54d' server FQDN: 'b727e219f54d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0710 15:54:55.653425 18268 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0710 15:54:55.653445 18268 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0710 15:54:55.653479 18268 authenticator.cpp:318] Authentication success I0710 15:54:55.653586 18263 authenticatee.cpp:299] Authentication success I0710 15:54:55.653736 18265 master.cpp:10412] Successfully authenticated principal 'test-principal' at slave(1200)@172.17.0.2:44968 I0710 15:54:55.653945 18262 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2046)@172.17.0.2:44968 I0710 15:54:55.654084 18279 slave.cpp:1450] Successfully authenticated with master [email protected]:44968 I0710 15:54:55.654592 18279 slave.cpp:1900] Will retry registration in 2.8361ms if necessary I0710 15:54:55.654789 18278 master.cpp:6900] Received register agent message from slave(1200)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:55.655156 18278 master.cpp:4099] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal' I0710 15:54:55.655851 18276 master.cpp:6967] Authorized registration of agent at slave(1200)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:55.655946 18276 master.cpp:7082] Registering agent at slave(1200)@172.17.0.2:44968 (b727e219f54d) with id 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:55.656599 18277 registrar.cpp:487] Applied 1 operations in 201842ns; attempting to update the registry I0710 15:54:55.657369 18277 registrar.cpp:544] Successfully updated the registry in 0ns I0710 15:54:55.657579 18282 master.cpp:7130] Admitted agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:55.658396 18282 master.cpp:7175] Registered agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0710 15:54:55.658519 18269 slave.cpp:1483] Registered with master [email protected]:44968; given agent ID 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:55.658514 18272 hierarchical.cpp:617] Added agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 (b727e219f54d) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) I0710 15:54:55.658884 18272 hierarchical.cpp:1508] Performed allocation for 1 agents in 160597ns I0710 15:54:55.658952 18272 task_status_update_manager.cpp:188] Resuming sending task status updates I0710 15:54:55.659119 18269 slave.cpp:1518] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_5iurL5/meta/slaves/753f1040-d566-4097-a9e4-d6acaedc978b-S0/slave.info' I0710 15:54:55.659164 18271 status_update_manager_process.hpp:385] Resuming operation status update manager I0710 15:54:55.660451 18269 slave.cpp:1570] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"mDC/bQFcTX2oywmT2ZtoPw=="},"slave_id":{"value":"753f1040-d566-4097-a9e4-d6acaedc978b-S0"},"update_oversubscribed_resources":false} I0710 15:54:55.661307 18269 master.cpp:8261] Ignoring update on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) as it reports no changes I0710 15:54:55.665872 18274 process.cpp:3671] Handling HTTP event for process 'slave(1200)' with path: '/slave(1200)/api/v1' I0710 15:54:55.667028 18263 http.cpp:1115] HTTP POST for /slave(1200)/api/v1 from 172.17.0.2:45576 I0710 15:54:55.667575 18263 http.cpp:2120] Processing GET_CONTAINERS call I0710 15:54:55.672721 18270 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0710 15:54:55.674996 18274 process.cpp:3671] Handling HTTP event for process 'slave(1200)' with path: '/slave(1200)/api/v1' I0710 15:54:55.675886 18263 http.cpp:1115] HTTP POST for /slave(1200)/api/v1 from 172.17.0.2:45578 I0710 15:54:55.676764 18263 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' I0710 15:54:55.677613 18280 http.cpp:2590] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_5iurL5/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0710 15:54:55.678215 18278 containerizer.cpp:1357] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0710 15:54:55.679428 18278 containerizer.cpp:1529] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_swqbrs/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config' I0710 15:54:55.679471 18278 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 I0710 15:54:55.682049 18273 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_ysEI5I","--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_5iurL5/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-3gRj7h/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperat ionsWithResourceProviderResources_v1_5iurL5/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_swqbrs/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"' I0710 15:54:55.690933 18273 launcher.cpp:145] Forked child with pid '32067' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0710 15:54:55.691730 18273 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 I0710 15:54:55.693229 18273 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 I0710 15:54:55.693655 18274 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_5iurL5/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0710 15:54:55.694941 18271 containerizer.cpp:3277] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from FETCHING to RUNNING I0710 15:54:55.697862 18280 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' I0710 15:54:55.698213 18262 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-3gRj7h/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0710 15:54:55.867539 18270 hierarchical.cpp:1508] Performed allocation for 1 agents in 193315ns I0710 15:54:55.918305 18281 hierarchical.cpp:1508] Performed allocation for 1 agents in 117258ns I0710 15:54:55.969478 18264 hierarchical.cpp:1508] Performed allocation for 1 agents in 111088ns I0710 15:54:56.020999 18261 hierarchical.cpp:1508] Performed allocation for 1 agents in 110577ns I0710 15:54:56.072353 18265 hierarchical.cpp:1508] Performed allocation for 1 agents in 111536ns I0710 15:54:56.123891 18269 hierarchical.cpp:1508] Performed allocation for 1 agents in 131825ns I0710 15:54:56.175595 18278 hierarchical.cpp:1508] Performed allocation for 1 agents in 109317ns I0710 15:54:56.181941 18262 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-3gRj7h/endpoint.sock' with CSI v1 I0710 15:54:56.204383 32071 test_csi_plugin.cpp:909] ProbeRequest '{}' I0710 15:54:56.206501 18275 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0710 15:54:56.209017 32072 test_csi_plugin.cpp:895] GetPluginCapabilitiesRequest '{}' I0710 15:54:56.209856 18263 process.cpp:3671] Handling HTTP event for process 'slave(1200)' with path: '/slave(1200)/api/v1' I0710 15:54:56.210942 18267 http.cpp:1115] HTTP POST for /slave(1200)/api/v1 from 172.17.0.2:45580 I0710 15:54:56.211526 18267 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' I0710 15:54:56.212560 32071 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}' I0710 15:54:56.212852 32072 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}' I0710 15:54:56.214045 18272 v1_volume_manager.cpp:648] NODE_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"} I0710 15:54:56.214884 18272 v1_volume_manager.cpp:648] CONTROLLER_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"} I0710 15:54:56.216624 32071 test_csi_plugin.cpp:1105] ControllerGetCapabilitiesRequest '{}' I0710 15:54:56.219972 32071 test_csi_plugin.cpp:1241] NodeGetCapabilitiesRequest '{}' I0710 15:54:56.222718 32071 test_csi_plugin.cpp:1255] NodeGetInfoRequest '{}' I0710 15:54:56.224335 18277 provider.cpp:659] Finished recovery for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test' I0710 15:54:56.224483 18282 status_update_manager_process.hpp:379] Pausing operation status update manager I0710 15:54:56.224797 18265 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:56.226588 18272 hierarchical.cpp:1508] Performed allocation for 1 agents in 163393ns I0710 15:54:56.227718 18279 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:56.228242 18268 provider.cpp:459] Connected to resource provider manager I0710 15:54:56.228804 18261 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:56.229763 18260 process.cpp:3671] Handling HTTP event for process 'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider' I0710 15:54:56.231209 18273 http.cpp:1115] HTTP POST for /slave(1200)/api/v1/resource_provider from 172.17.0.2:45584 I0710 15:54:56.231808 18265 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_ysEI5I","--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"} I0710 15:54:56.277299 18278 hierarchical.cpp:1508] Performed allocation for 1 agents in 121610ns I0710 15:54:56.283226 18262 slave.cpp:8217] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"deeb488f-4019-4431-a661-c79bd4d23ca7"},"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_ysEI5I","--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"}' I0710 15:54:56.284560 18282 provider.cpp:481] Received SUBSCRIBED event I0710 15:54:56.284598 18282 provider.cpp:1255] Subscribed with ID deeb488f-4019-4431-a661-c79bd4d23ca7 I0710 15:54:56.285327 18273 status_update_manager_process.hpp:314] Recovering operation status update manager I0710 15:54:56.328588 18281 hierarchical.cpp:1508] Performed allocation for 1 agents in 115025ns I0710 15:54:56.335414 32073 test_csi_plugin.cpp:1050] ListVolumesRequest '{}' I0710 15:54:56.337400 18261 provider.cpp:2145] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:56.337610 18261 provider.cpp:745] Resource provider deeb488f-4019-4431-a661-c79bd4d23ca7 is in READY state I0710 15:54:56.337630 18271 http_connection.hpp:131] Sending 3 call to http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:56.337687 18268 status_update_manager_process.hpp:385] Resuming operation status update manager I0710 15:54:56.338284 18275 provider.cpp:1181] Updating profiles { test } for resource provider deeb488f-4019-4431-a661-c79bd4d23ca7 I0710 15:54:56.338624 18273 process.cpp:3671] Handling HTTP event for process 'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider' I0710 15:54:56.340474 18262 http.cpp:1115] HTTP POST for /slave(1200)/api/v1/resource_provider from 172.17.0.2:45582 I0710 15:54:56.340871 18271 manager.cpp:1039] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider deeb488f-4019-4431-a661-c79bd4d23ca7 I0710 15:54:56.341056 18260 slave.cpp:8217] Handling resource provider message 'UPDATE_STATE: deeb488f-4019-4431-a661-c79bd4d23ca7 {}' I0710 15:54:56.341187 18260 slave.cpp:8337] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0710 15:54:56.341464 32073 test_csi_plugin.cpp:1078] GetCapacityRequest '{"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}' I0710 15:54:56.342818 18281 hierarchical.cpp:753] Grew agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 by {} (total), { } (used) I0710 15:54:56.343158 18281 hierarchical.cpp:710] Agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 (b727e219f54d) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] W0710 15:54:56.343935 18259 process.cpp:2877] Attempted to spawn already running process [email protected]:44968 I0710 15:54:56.345468 18259 sched.cpp:239] Version: 1.9.0 I0710 15:54:56.345628 18263 provider.cpp:933] Removing '{}' and adding 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' to the total resources I0710 15:54:56.346227 18262 sched.cpp:343] New master detected at [email protected]:44968 I0710 15:54:56.346357 18262 sched.cpp:408] Authenticating with master [email protected]:44968 I0710 15:54:56.346382 18262 sched.cpp:415] Using default CRAM-MD5 authenticatee I0710 15:54:56.346729 18268 authenticatee.cpp:121] Creating new client SASL connection I0710 15:54:56.347062 18275 master.cpp:10380] Authenticating [email protected]:44968 I0710 15:54:56.347255 18282 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2047)@172.17.0.2:44968 I0710 15:54:56.347353 18270 hierarchical.cpp:1508] Performed allocation for 1 agents in 169243ns I0710 15:54:56.347594 18269 authenticator.cpp:98] Creating new server SASL connection I0710 15:54:56.347849 18272 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0710 15:54:56.347882 18272 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0710 15:54:56.348028 18277 authenticator.cpp:204] Received SASL authentication start I0710 15:54:56.348119 18277 authenticator.cpp:326] Authentication requires more steps I0710 15:54:56.348266 18260 authenticatee.cpp:259] Received SASL authentication step I0710 15:54:56.348433 18276 authenticator.cpp:232] Received SASL authentication step I0710 15:54:56.348484 18276 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b727e219f54d' server FQDN: 'b727e219f54d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0710 15:54:56.348510 18276 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0710 15:54:56.348554 18276 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0710 15:54:56.348578 18276 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b727e219f54d' server FQDN: 'b727e219f54d' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0710 15:54:56.348600 18276 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0710 15:54:56.348623 18276 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0710 15:54:56.348660 18276 authenticator.cpp:318] Authentication success I0710 15:54:56.348771 18281 authenticatee.cpp:299] Authentication success I0710 15:54:56.348960 18265 master.cpp:10412] Successfully authenticated principal 'test-principal' at [email protected]:44968 I0710 15:54:56.349006 18273 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2047)@172.17.0.2:44968 I0710 15:54:56.349265 18280 sched.cpp:520] Successfully authenticated with master [email protected]:44968 I0710 15:54:56.349294 18280 sched.cpp:835] Sending SUBSCRIBE call to [email protected]:44968 I0710 15:54:56.349449 18280 sched.cpp:870] Will retry registration in 247.739203ms if necessary I0710 15:54:56.349658 18279 master.cpp:2890] Received SUBSCRIBE call for framework 'default' at [email protected]:44968 I0710 15:54:56.349696 18279 master.cpp:2222] Authorizing framework principal 'test-principal' to receive offers for roles '{ storage/default-role }' I0710 15:54:56.350291 18271 master.cpp:2977] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] I0710 15:54:56.352841 18271 master.cpp:10610] Adding framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 with roles { } suppressed I0710 15:54:56.353399 18267 sched.cpp:751] Framework registered with 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.353456 18267 sched.cpp:770] Scheduler::registered took 26909ns I0710 15:54:56.353760 18261 hierarchical.cpp:368] Added framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.354961 18261 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.051387ms I0710 15:54:56.355427 18282 master.cpp:10195] Sending offers [ 753f1040-d566-4097-a9e4-d6acaedc978b-O0 ] to framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:56.356053 18269 sched.cpp:934] Scheduler::resourceOffers took 139449ns I0710 15:54:56.356410 18272 master.cpp:6119] Processing DECLINE call for offers: [ 753f1040-d566-4097-a9e4-d6acaedc978b-O0 ] for framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 with 5 seconds filter I0710 15:54:56.356963 18272 master.cpp:12470] Removing offer 753f1040-d566-4097-a9e4-d6acaedc978b-O0 I0710 15:54:56.357631 18277 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 753f1040-d566-4097-a9e4-d6acaedc978b-S0 from framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.357702 18277 hierarchical.cpp:1264] Framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 filtered agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 for 5secs I0710 15:54:56.391975 18263 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 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:56.392410 18260 http_connection.hpp:131] Sending 3 call to http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:56.393395 18265 process.cpp:3671] Handling HTTP event for process 'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider' I0710 15:54:56.430858 18279 http.cpp:1115] HTTP POST for /slave(1200)/api/v1/resource_provider from 172.17.0.2:45582 I0710 15:54:56.431509 18266 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":"deeb488f-4019-4431-a661-c79bd4d23ca7"},"reservations":[{"role":"storage","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]' and 0 operations from resource provider deeb488f-4019-4431-a661-c79bd4d23ca7 I0710 15:54:56.432013 18268 slave.cpp:8217] Handling resource provider message 'UPDATE_STATE: deeb488f-4019-4431-a661-c79bd4d23ca7 disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' I0710 15:54:56.432157 18268 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 I0710 15:54:56.434396 18270 hierarchical.cpp:710] Agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 (b727e219f54d) 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 I0710 15:54:56.435760 18270 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.160176ms I0710 15:54:56.436408 18261 master.cpp:10195] Sending offers [ 753f1040-d566-4097-a9e4-d6acaedc978b-O1 ] to framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:56.437052 18282 sched.cpp:934] Scheduler::resourceOffers took 83409ns I0710 15:54:56.445785 18277 master.cpp:12470] Removing offer 753f1040-d566-4097-a9e4-d6acaedc978b-O1 I0710 15:54:56.446151 18277 master.cpp:4636] Processing ACCEPT call for offers: [ 753f1040-d566-4097-a9e4-d6acaedc978b-O1 ] on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) for framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:56.446249 18263 hierarchical.cpp:1508] Performed allocation for 1 agents in 222457ns I0710 15:54:56.446251 18277 master.cpp:4009] Authorizing principal 'test-principal' to create a MOUNT disk from 'disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' I0710 15:54:56.447263 18281 master.cpp:5911] Processing CREATE_DISK operation with source disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048 from framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 to agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:56.447801 18281 master.cpp:12361] Sending operation '' (uuid: 8b642e27-76f5-40f5-9edf-e9d3c92ae523) to agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:56.448112 18273 hierarchical.cpp:1432] Allocation paused I0710 15:54:56.448308 18283 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:56.449285 18273 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 753f1040-d566-4097-a9e4-d6acaedc978b-S0 from framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.449383 18273 hierarchical.cpp:1264] Framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 filtered agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 for 5secs I0710 15:54:56.449623 18273 hierarchical.cpp:1442] Allocation resumed I0710 15:54:56.450430 18270 provider.cpp:481] Received APPLY_OPERATION event I0710 15:54:56.450471 18270 provider.cpp:1295] Received CREATE_DISK operation '' (uuid: 8b642e27-76f5-40f5-9edf-e9d3c92ae523) I0710 15:54:56.497834 18282 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 for role storage/default-role of framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.498006 18282 hierarchical.cpp:1508] Performed allocation for 1 agents in 681977ns I0710 15:54:56.501154 18272 v1_volume_manager.cpp:292] Creating volume with name '8b642e27-76f5-40f5-9edf-e9d3c92ae523' I0710 15:54:56.503922 32073 test_csi_plugin.cpp:922] CreateVolumeRequest '{"name":"8b642e27-76f5-40f5-9edf-e9d3c92ae523","capacityRange":{"requiredBytes":"2147483648","limitBytes":"2147483648"},"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}' I0710 15:54:56.550108 18264 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 for role storage/default-role of framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.550281 18264 hierarchical.cpp:1508] Performed allocation for 1 agents in 752453ns I0710 15:54:56.577615 18281 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_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,test)]:2048' for operation (uuid: 8b642e27-76f5-40f5-9edf-e9d3c92ae523) I0710 15:54:56.601264 18283 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 for role storage/default-role of framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.601374 18283 hierarchical.cpp:1508] Performed allocation for 1 agents in 452183ns I0710 15:54:56.627866 18280 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: a0199860-02b4-415d-bef8-4e02df705c09) for operation UUID 8b642e27-76f5-40f5-9edf-e9d3c92ae523 of framework '753f1040-d566-4097-a9e4-d6acaedc978b-0000' on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:56.627938 18280 status_update_manager_process.hpp:414] Creating operation status update stream 8b642e27-76f5-40f5-9edf-e9d3c92ae523 checkpoint=true I0710 15:54:56.628327 18280 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: a0199860-02b4-415d-bef8-4e02df705c09) for operation UUID 8b642e27-76f5-40f5-9edf-e9d3c92ae523 of framework '753f1040-d566-4097-a9e4-d6acaedc978b-0000' on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:56.652911 18266 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 for role storage/default-role of framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.653020 18266 hierarchical.cpp:1508] Performed allocation for 1 agents in 429410ns I0710 15:54:56.694715 18280 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: a0199860-02b4-415d-bef8-4e02df705c09) for operation UUID 8b642e27-76f5-40f5-9edf-e9d3c92ae523 of framework '753f1040-d566-4097-a9e4-d6acaedc978b-0000' on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:56.695574 18268 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:56.696682 18267 process.cpp:3671] Handling HTTP event for process 'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider' I0710 15:54:56.704761 18262 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 for role storage/default-role of framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.704869 18262 hierarchical.cpp:1508] Performed allocation for 1 agents in 432398ns I0710 15:54:56.734700 18272 http.cpp:1115] HTTP POST for /slave(1200)/api/v1/resource_provider from 172.17.0.2:45582 I0710 15:54:56.735674 18263 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 8b642e27-76f5-40f5-9edf-e9d3c92ae523) for framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0710 15:54:56.735865 18263 slave.cpp:8670] Updating the state of operation with no ID (uuid: 8b642e27-76f5-40f5-9edf-e9d3c92ae523) for framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0710 15:54:56.736209 18263 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 8b642e27-76f5-40f5-9edf-e9d3c92ae523) for framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.736599 18265 master.cpp:12017] Updating the state of operation '' (uuid: 8b642e27-76f5-40f5-9edf-e9d3c92ae523) for framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0710 15:54:56.737746 18283 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:56.738534 18277 hierarchical.cpp:956] Updated allocation of framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 on agent 753f1040-d566-4097-a9e4-d6acaedc978b-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_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,test)]:2048 I0710 15:54:56.739184 18267 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event I0710 15:54:56.739280 18277 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,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_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,test)]:2048, allocated: {}) on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 from framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.739346 18271 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: a0199860-02b4-415d-bef8-4e02df705c09) for stream 8b642e27-76f5-40f5-9edf-e9d3c92ae523 I0710 15:54:56.739434 18271 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: a0199860-02b4-415d-bef8-4e02df705c09) for operation UUID 8b642e27-76f5-40f5-9edf-e9d3c92ae523 of framework '753f1040-d566-4097-a9e4-d6acaedc978b-0000' on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:56.757321 18270 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.121894ms I0710 15:54:56.757999 18269 master.cpp:10195] Sending offers [ 753f1040-d566-4097-a9e4-d6acaedc978b-O2 ] to framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:56.758687 18260 sched.cpp:934] Scheduler::resourceOffers took 115580ns I0710 15:54:56.761967 18283 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1' I0710 15:54:56.763612 18273 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:45586 I0710 15:54:56.763862 18273 http.cpp:263] Processing call RESERVE_RESOURCES I0710 15:54:56.764611 18273 master.cpp:3721] Authorizing principal 'test-principal' to reserve resources 'disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,test)]:2048' I0710 15:54:56.766291 18277 master.cpp:12470] Removing offer 753f1040-d566-4097-a9e4-d6acaedc978b-O2 I0710 15:54:56.766412 18269 sched.cpp:960] Rescinded offer 753f1040-d566-4097-a9e4-d6acaedc978b-O2 I0710 15:54:56.766491 18269 sched.cpp:971] Scheduler::offerRescinded took 25853ns I0710 15:54:56.767001 18270 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,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_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,test)]:2048, allocated: {}) on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 from framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:56.767104 18270 hierarchical.cpp:1264] Framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 filtered agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 for 5secs I0710 15:54:56.769506 18260 master.cpp:12361] Sending operation '' (uuid: 0169981f-e4ed-4fa2-b733-967d4d9e7db0) to agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:56.770114 18276 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:56.772716 18275 provider.cpp:481] Received APPLY_OPERATION event I0710 15:54:56.772758 18275 provider.cpp:1295] Received RESERVE operation '' (uuid: 0169981f-e4ed-4fa2-b733-967d4d9e7db0) I0710 15:54:56.811566 18271 status_update_manager_process.hpp:490] Cleaning up operation status update stream 8b642e27-76f5-40f5-9edf-e9d3c92ae523 I0710 15:54:56.896086 18273 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 8a2fb5f4-5159-4aaf-a5c5-d375bc343ebb) for operation UUID 0169981f-e4ed-4fa2-b733-967d4d9e7db0 on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:56.896157 18273 status_update_manager_process.hpp:414] Creating operation status update stream 0169981f-e4ed-4fa2-b733-967d4d9e7db0 checkpoint=true I0710 15:54:56.896525 18273 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 8a2fb5f4-5159-4aaf-a5c5-d375bc343ebb) for operation UUID 0169981f-e4ed-4fa2-b733-967d4d9e7db0 on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:56.988219 18273 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 8a2fb5f4-5159-4aaf-a5c5-d375bc343ebb) for operation UUID 0169981f-e4ed-4fa2-b733-967d4d9e7db0 on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.006044 18262 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:57.006985 18269 process.cpp:3671] Handling HTTP event for process 'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider' I0710 15:54:57.010107 18277 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.218049ms I0710 15:54:57.010723 18270 master.cpp:10195] Sending offers [ 753f1040-d566-4097-a9e4-d6acaedc978b-O3 ] to framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:57.011360 18278 sched.cpp:934] Scheduler::resourceOffers took 77043ns I0710 15:54:57.014148 18265 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1' I0710 15:54:57.015740 18279 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:45588 I0710 15:54:57.015970 18279 http.cpp:263] Processing call CREATE_VOLUMES I0710 15:54:57.016724 18279 master.cpp:3848] Authorizing principal 'test-principal' to create volumes '[{"disk":{"persistence":{"id":"000188eb-71e0-428b-b72e-9ee19c1202b8","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523","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":"deeb488f-4019-4431-a661-c79bd4d23ca7"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]' I0710 15:54:57.018628 18268 master.cpp:12470] Removing offer 753f1040-d566-4097-a9e4-d6acaedc978b-O3 I0710 15:54:57.018718 18273 sched.cpp:960] Rescinded offer 753f1040-d566-4097-a9e4-d6acaedc978b-O3 I0710 15:54:57.018797 18273 sched.cpp:971] Scheduler::offerRescinded took 28291ns I0710 15:54:57.019430 18271 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_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,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_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,test)]:2048, allocated: {}) on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 from framework 753f1040-d566-40 97-a9e4-d6acaedc978b-0000 I0710 15:54:57.019541 18271 hierarchical.cpp:1264] Framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 filtered agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 for 5secs I0710 15:54:57.022033 18275 master.cpp:12361] Sending operation '' (uuid: f3510499-e458-4125-83d2-4dc2a94808b0) to agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:57.022624 18269 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:57.022697 18270 master.cpp:6233] Processing REVIVE call for framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:57.023098 18272 hierarchical.cpp:1365] Unsuppressed offers for roles { storage/default-role } of framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:57.023125 18272 hierarchical.cpp:1387] Revived roles { storage/default-role } of framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:57.024349 18272 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.075017ms I0710 15:54:57.024742 18272 hierarchical.cpp:1508] Performed allocation for 1 agents in 197544ns I0710 15:54:57.025082 18264 master.cpp:10195] Sending offers [ 753f1040-d566-4097-a9e4-d6acaedc978b-O4 ] to framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:57.025452 18266 provider.cpp:481] Received APPLY_OPERATION event I0710 15:54:57.025493 18266 provider.cpp:1295] Received CREATE operation '' (uuid: f3510499-e458-4125-83d2-4dc2a94808b0) I0710 15:54:57.025795 18264 sched.cpp:934] Scheduler::resourceOffers took 75900ns I0710 15:54:57.046442 18277 http.cpp:1115] HTTP POST for /slave(1200)/api/v1/resource_provider from 172.17.0.2:45582 I0710 15:54:57.047394 18278 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 0169981f-e4ed-4fa2-b733-967d4d9e7db0) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0710 15:54:57.047575 18278 slave.cpp:8670] Updating the state of operation with no ID (uuid: 0169981f-e4ed-4fa2-b733-967d4d9e7db0) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0710 15:54:57.047644 18278 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 0169981f-e4ed-4fa2-b733-967d4d9e7db0) for an operator API call I0710 15:54:57.047984 18269 master.cpp:12017] Updating the state of operation '' (uuid: 0169981f-e4ed-4fa2-b733-967d4d9e7db0) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0710 15:54:57.048632 18278 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:57.125560 18264 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: abee6e5a-6f4e-4f86-9db2-37c2d33f83ac) for operation UUID f3510499-e458-4125-83d2-4dc2a94808b0 on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.125622 18264 status_update_manager_process.hpp:414] Creating operation status update stream f3510499-e458-4125-83d2-4dc2a94808b0 checkpoint=true I0710 15:54:57.125658 18266 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event I0710 15:54:57.125950 18264 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: abee6e5a-6f4e-4f86-9db2-37c2d33f83ac) for operation UUID f3510499-e458-4125-83d2-4dc2a94808b0 on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.190158 18264 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: abee6e5a-6f4e-4f86-9db2-37c2d33f83ac) for operation UUID f3510499-e458-4125-83d2-4dc2a94808b0 on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.190547 18264 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 8a2fb5f4-5159-4aaf-a5c5-d375bc343ebb) for stream 0169981f-e4ed-4fa2-b733-967d4d9e7db0 I0710 15:54:57.190623 18264 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 8a2fb5f4-5159-4aaf-a5c5-d375bc343ebb) for operation UUID 0169981f-e4ed-4fa2-b733-967d4d9e7db0 on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.191071 18268 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:57.191905 18267 process.cpp:3671] Handling HTTP event for process 'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider' I0710 15:54:57.230448 18265 http.cpp:1115] HTTP POST for /slave(1200)/api/v1/resource_provider from 172.17.0.2:45582 I0710 15:54:57.231448 18276 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: f3510499-e458-4125-83d2-4dc2a94808b0) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0710 15:54:57.231632 18276 slave.cpp:8670] Updating the state of operation with no ID (uuid: f3510499-e458-4125-83d2-4dc2a94808b0) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0710 15:54:57.231695 18276 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: f3510499-e458-4125-83d2-4dc2a94808b0) for an operator API call I0710 15:54:57.232288 18283 master.cpp:12017] Updating the state of operation '' (uuid: f3510499-e458-4125-83d2-4dc2a94808b0) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0710 15:54:57.232827 18272 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:57.234230 18271 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event I0710 15:54:57.257006 18264 status_update_manager_process.hpp:490] Cleaning up operation status update stream 0169981f-e4ed-4fa2-b733-967d4d9e7db0 I0710 15:54:57.257302 18264 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: abee6e5a-6f4e-4f86-9db2-37c2d33f83ac) for stream f3510499-e458-4125-83d2-4dc2a94808b0 I0710 15:54:57.257397 18264 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: abee6e5a-6f4e-4f86-9db2-37c2d33f83ac) for operation UUID f3510499-e458-4125-83d2-4dc2a94808b0 on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.349151 18264 status_update_manager_process.hpp:490] Cleaning up operation status update stream f3510499-e458-4125-83d2-4dc2a94808b0 I0710 15:54:57.420277 18269 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1' I0710 15:54:57.421603 18278 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:45590 I0710 15:54:57.421844 18278 http.cpp:263] Processing call DESTROY_VOLUMES I0710 15:54:57.422623 18278 master.cpp:3893] Authorizing principal 'test-principal' to destroy volumes '[{"disk":{"persistence":{"id":"000188eb-71e0-428b-b72e-9ee19c1202b8","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523","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":"deeb488f-4019-4431-a661-c79bd4d23ca7"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]' I0710 15:54:57.424644 18280 master.cpp:12470] Removing offer 753f1040-d566-4097-a9e4-d6acaedc978b-O4 I0710 15:54:57.424762 18261 sched.cpp:960] Rescinded offer 753f1040-d566-4097-a9e4-d6acaedc978b-O4 I0710 15:54:57.424844 18261 sched.cpp:971] Scheduler::offerRescinded took 24375ns I0710 15:54:57.425653 18279 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_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,test),000188eb-71e0-428b-b72e-9ee19c1202b8: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_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,test),000188eb-71e0-428b-b72e-9ee19c1202b8:volume]:2048, allocat ed: {}) on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 from framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:57.425772 18279 hierarchical.cpp:1264] Framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 filtered agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 for 5secs I0710 15:54:57.428937 18268 master.cpp:12361] Sending operation '' (uuid: bd2414f3-e2c4-405a-8a91-114de961e5da) to agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:57.429464 18264 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:57.432340 18265 provider.cpp:481] Received APPLY_OPERATION event I0710 15:54:57.432381 18265 provider.cpp:1295] Received DESTROY operation '' (uuid: bd2414f3-e2c4-405a-8a91-114de961e5da) I0710 15:54:57.440639 18283 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.141914ms I0710 15:54:57.441336 18272 master.cpp:10195] Sending offers [ 753f1040-d566-4097-a9e4-d6acaedc978b-O5 ] to framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:57.442044 18278 sched.cpp:934] Scheduler::resourceOffers took 91110ns I0710 15:54:57.518096 18281 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: f5c681b3-0e18-4caf-8742-3227b0299965) for operation UUID bd2414f3-e2c4-405a-8a91-114de961e5da on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.518158 18281 status_update_manager_process.hpp:414] Creating operation status update stream bd2414f3-e2c4-405a-8a91-114de961e5da checkpoint=true I0710 15:54:57.518479 18281 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: f5c681b3-0e18-4caf-8742-3227b0299965) for operation UUID bd2414f3-e2c4-405a-8a91-114de961e5da on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.584961 18281 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: f5c681b3-0e18-4caf-8742-3227b0299965) for operation UUID bd2414f3-e2c4-405a-8a91-114de961e5da on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.585769 18261 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:57.586678 18266 process.cpp:3671] Handling HTTP event for process 'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider' I0710 15:54:57.589800 18271 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1' I0710 15:54:57.591208 18276 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:45592 I0710 15:54:57.591426 18276 http.cpp:263] Processing call UNRESERVE_RESOURCES I0710 15:54:57.592108 18276 master.cpp:3785] Authorizing principal 'test-principal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523","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":"deeb488f-4019-4431-a661-c79bd4d23ca7"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]' I0710 15:54:57.593919 18274 master.cpp:12470] Removing offer 753f1040-d566-4097-a9e4-d6acaedc978b-O5 I0710 15:54:57.594043 18272 sched.cpp:960] Rescinded offer 753f1040-d566-4097-a9e4-d6acaedc978b-O5 I0710 15:54:57.594125 18272 sched.cpp:971] Scheduler::offerRescinded took 26321ns I0710 15:54:57.594595 18283 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_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,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_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,test)]:2048, allocated: {}) on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 from framework 753f1040-d566-40 97-a9e4-d6acaedc978b-0000 I0710 15:54:57.594703 18283 hierarchical.cpp:1264] Framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 filtered agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 for 5secs I0710 15:54:57.596918 18278 master.cpp:12361] Sending operation '' (uuid: b5ac6b07-e99c-4719-8302-3c3376b8edaa) to agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:57.597600 18273 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:57.600018 18267 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.094721ms I0710 15:54:57.600392 18263 provider.cpp:481] Received APPLY_OPERATION event I0710 15:54:57.600430 18263 provider.cpp:1295] Received UNRESERVE operation '' (uuid: b5ac6b07-e99c-4719-8302-3c3376b8edaa) I0710 15:54:57.600751 18270 master.cpp:10195] Sending offers [ 753f1040-d566-4097-a9e4-d6acaedc978b-O6 ] to framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:57.601338 18269 sched.cpp:934] Scheduler::resourceOffers took 70245ns I0710 15:54:57.626344 18261 http.cpp:1115] HTTP POST for /slave(1200)/api/v1/resource_provider from 172.17.0.2:45582 I0710 15:54:57.627351 18279 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: bd2414f3-e2c4-405a-8a91-114de961e5da) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0710 15:54:57.627542 18279 slave.cpp:8670] Updating the state of operation with no ID (uuid: bd2414f3-e2c4-405a-8a91-114de961e5da) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0710 15:54:57.627595 18279 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: bd2414f3-e2c4-405a-8a91-114de961e5da) for an operator API call I0710 15:54:57.627940 18273 master.cpp:12017] Updating the state of operation '' (uuid: bd2414f3-e2c4-405a-8a91-114de961e5da) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0710 15:54:57.628506 18262 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:57.703088 18269 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: b3ed4442-bcf6-49bf-9f9d-ff3f464befe4) for operation UUID b5ac6b07-e99c-4719-8302-3c3376b8edaa on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.703150 18269 status_update_manager_process.hpp:414] Creating operation status update stream b5ac6b07-e99c-4719-8302-3c3376b8edaa checkpoint=true I0710 15:54:57.703176 18263 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event I0710 15:54:57.703485 18269 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: b3ed4442-bcf6-49bf-9f9d-ff3f464befe4) for operation UUID b5ac6b07-e99c-4719-8302-3c3376b8edaa on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.753279 18269 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: b3ed4442-bcf6-49bf-9f9d-ff3f464befe4) for operation UUID b5ac6b07-e99c-4719-8302-3c3376b8edaa on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.753623 18269 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: f5c681b3-0e18-4caf-8742-3227b0299965) for stream bd2414f3-e2c4-405a-8a91-114de961e5da I0710 15:54:57.753707 18269 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: f5c681b3-0e18-4caf-8742-3227b0299965) for operation UUID bd2414f3-e2c4-405a-8a91-114de961e5da on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.754077 18260 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:57.754922 18265 process.cpp:3671] Handling HTTP event for process 'slave(1200)' with path: '/slave(1200)/api/v1/resource_provider' I0710 15:54:57.794430 18266 http.cpp:1115] HTTP POST for /slave(1200)/api/v1/resource_provider from 172.17.0.2:45582 I0710 15:54:57.795214 18262 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: b5ac6b07-e99c-4719-8302-3c3376b8edaa) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0710 15:54:57.795406 18262 slave.cpp:8670] Updating the state of operation with no ID (uuid: b5ac6b07-e99c-4719-8302-3c3376b8edaa) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0710 15:54:57.795460 18262 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: b5ac6b07-e99c-4719-8302-3c3376b8edaa) for an operator API call I0710 15:54:57.795794 18268 master.cpp:12017] Updating the state of operation '' (uuid: b5ac6b07-e99c-4719-8302-3c3376b8edaa) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0710 15:54:57.796332 18264 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version I0710 15:54:57.797659 18274 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event I0710 15:54:57.820168 18269 status_update_manager_process.hpp:490] Cleaning up operation status update stream bd2414f3-e2c4-405a-8a91-114de961e5da I0710 15:54:57.820400 18269 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: b3ed4442-bcf6-49bf-9f9d-ff3f464befe4) for stream b5ac6b07-e99c-4719-8302-3c3376b8edaa I0710 15:54:57.820490 18269 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: b3ed4442-bcf6-49bf-9f9d-ff3f464befe4) for operation UUID b5ac6b07-e99c-4719-8302-3c3376b8edaa on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:57.895653 18269 status_update_manager_process.hpp:490] Cleaning up operation status update stream b5ac6b07-e99c-4719-8302-3c3376b8edaa I0710 15:54:57.955536 18281 master.cpp:1410] Framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 disconnected I0710 15:54:57.955579 18281 master.cpp:3342] Deactivating framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:57.955891 18266 hierarchical.cpp:475] Deactivated framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:57.956406 18264 slave.cpp:912] Agent terminating I0710 15:54:57.956544 18281 master.cpp:12470] Removing offer 753f1040-d566-4097-a9e4-d6acaedc978b-O6 I0710 15:54:57.956634 18281 master.cpp:3319] Disconnecting framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:57.956693 18281 master.cpp:1425] Giving framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 0ns to failover I0710 15:54:57.957386 18264 manager.cpp:163] Terminating resource provider deeb488f-4019-4431-a661-c79bd4d23ca7 I0710 15:54:57.957423 18266 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,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_ysEI5I/2GB-8b642e27-76f5-40f5-9edf-e9d3c92ae523,test)]:2048, allocated: {}) on agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 from framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:57.957800 18279 master.cpp:9987] Framework failover timeout, removing framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:57.957850 18279 master.cpp:10979] Removing framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 (default) at [email protected]:44968 I0710 15:54:57.958344 18275 hierarchical.cpp:1432] Allocation paused E0710 15:54:57.958384 18271 http_connection.hpp:452] End-Of-File received I0710 15:54:57.958407 18279 master.cpp:1295] Agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) disconnected I0710 15:54:57.958442 18279 master.cpp:3379] Disconnecting agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:57.958540 18279 master.cpp:3398] Deactivating agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 at slave(1200)@172.17.0.2:44968 (b727e219f54d) I0710 15:54:57.958884 18275 hierarchical.cpp:417] Removed framework 753f1040-d566-4097-a9e4-d6acaedc978b-0000 I0710 15:54:57.958914 18271 http_connection.hpp:217] Re-detecting endpoint I0710 15:54:57.958948 18275 hierarchical.cpp:1442] Allocation resumed I0710 15:54:57.959019 18275 hierarchical.cpp:799] Agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 deactivated I0710 15:54:57.959326 18271 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0710 15:54:57.959399 18271 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0710 15:54:57.959434 18260 provider.cpp:471] Disconnected from resource provider manager I0710 15:54:57.959463 18271 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:57.959538 18260 status_update_manager_process.hpp:379] Pausing operation status update manager I0710 15:54:57.962882 18278 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 I0710 15:54:57.962920 18278 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 I0710 15:54:57.963286 18278 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0710 15:54:57.967454 18280 hierarchical.cpp:1508] Performed allocation for 1 agents in 203369ns I0710 15:54:57.968794 18268 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:57.969382 18274 provider.cpp:459] Connected to resource provider manager I0710 15:54:57.969918 18271 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:44968/slave(1200)/api/v1/resource_provider I0710 15:54:57.971184 18284 process.cpp:2781] Returning '404 Not Found' for '/slave(1200)/api/v1/resource_provider' E0710 15:54:57.972980 18273 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' () I0710 15:54:58.020848 18262 hierarchical.cpp:1508] Performed allocation for 1 agents in 109371ns I0710 15:54:58.070951 18280 containerizer.cpp:3116] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited I0710 15:54:58.071569 18272 hierarchical.cpp:1508] Performed allocation for 1 agents in 110797ns I0710 15:54:58.072373 18276 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 I0710 15:54:58.074474 18269 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' I0710 15:54:58.074630 18262 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-3gRj7h/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0710 15:54:58.074837 18264 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0710 15:54:58.077095 18284 process.cpp:2781] Returning '404 Not Found' for '/slave(1200)/api/v1' I0710 15:54:58.089488 18264 master.cpp:1135] Master terminating I0710 15:54:58.090018 18281 hierarchical.cpp:775] Removed all filters for agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 I0710 15:54:58.090042 18281 hierarchical.cpp:650] Removed agent 753f1040-d566-4097-a9e4-d6acaedc978b-S0 [ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (2487 ms) [----------] 50 tests from CSIVersion/StorageLocalResourceProviderTest (94575 ms total) [----------] Global test environment tear-down [==========] 2265 tests from 216 test cases ran. (1037996 ms total) [ PASSED ] 2264 tests. [ FAILED ] 1 test, listed below: [ FAILED ] CSIVersion/StorageLocalResourceProviderTest.RetryOperationStatusUpdateAfterRecovery/v1, where GetParam() = "v1" 1 FAILED TEST YOU HAVE 31 DISABLED TESTS I0710 15:54:58.192019 18284 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-1562768556-3754 Untagged: mesos-1562768556-3754:latest Deleted: sha256:20ef9658792a32ab825e75fd71767d8d84ce0368323a1cd5ed39c48445bb1cb2 Deleted: sha256:bf2e8aabf94da706b12c50f228ffbe1954d7f277a17b018b08429f3cc7851b4a Deleted: sha256:c1c85f6fd63b76d9fa0c2e084533f539ef866101631940c6859f7a78f4779935 Deleted: sha256:bde1b4a5c541f11a66120d46521bd37b6b958066cf295ba5e7a0a00e1b03b994 Deleted: sha256:e1405b08760cc10b860ff6d5aced3559bb8f9d164b7a16a9e1a29380f636787c Deleted: sha256:2230eee1143d930573ad24f178179d35797822f9eeb23b007d24cd45b2aae85c Deleted: sha256:f6276d535b1610a82c67f4edbccdf813533637adf321100fe96374cd04383442 Deleted: sha256:ed539eda2d0c1424a648b73bb6fd86d285e1377c1bca5cb8b05423d61fd0ce73 Deleted: sha256:1f1c18c25c27fc1fac7419cd67989f373b910becc317be77d34b27aaf92e27a6 Deleted: sha256:ea986e521c773ccd803c5bbaec13e2040f87ac481ef7010885723bd0f361fe3d Deleted: sha256:7612c0c153960f73385a331e2a2de4cc8b0fe345fb64b11a2e3a41731c88430b Deleted: sha256:2ce83bf3f2e4d89907e4f7942650a30eceb988359e8961d18a12c657bb4d9932 Deleted: sha256:3040855a3b5b6be43bb9b848e5712e80673d3dd3a64b6da4cae7e75b57495cd0 Deleted: sha256:68d4933bd07589319151ea44347f81946028589e8c5df6570c5d5b96374c052f Deleted: sha256:9f0efb9e437d280a3149b2339a9c513bde8e69d6b1fe97b2f61c4f405c423d0f Deleted: sha256:d0e4dfe8a25a6aaa8faa716151ff8e654eeac7be2632a65fa236721aabe5ea54 Deleted: sha256:ce93157cd83916aced43fb39cb7d3e1f336133f017362614e3d5ebd0565155bf Deleted: sha256:23f112f51cc799124863f62285525c68398b6fd687be18509cb13e1570b59e61 Deleted: sha256:7cccffdbc28f8703b198c1fbb764513c0eedc2b123c8ed7ee6966e5b13f959c0 Deleted: sha256:5e7034e99a4153565397fef5584a66ac525c40bfbe96c19500ab0785ba71db48 Deleted: sha256:f7a6a36953fd860b6f4dcb5671fdad846444229aae83faf80fd105d1b6310dcd Deleted: sha256:23f5c854d6499090181d254a63b72b7b6cf509e1f529859c7d4d254289e2ea38 Deleted: sha256:be948a2179a340181379df62c5830f32c173a4baf47d67a781d4f2e7d972df5c Deleted: sha256:de1b8e069fd4b9c9275920620b89c96194ba0e88096506450418c3fff973c629 Deleted: sha256:8da433c8be680445723751039d23af26c13649fdba7cdf7e8cfbab0ab8ae8874 Deleted: sha256:4cb1695f789d9b9965d08d6c7b7ef47a4cd3a92d387c6c0f3a6fc9a75ded20bb Deleted: sha256:956af603748e757356e0fa4ddd0ef045ec7c88083b8d7755ae23a940beaf7af0 Deleted: sha256:2c1449f8864ccf114fe300f7378387ec6f2246baedb9d0a658d91a169d08bfc4 Deleted: sha256:c46df4f3f424d55d15c656c5ee11bd8ad82e38c8da269f1c00bd195a8e8e6dfb Deleted: sha256:51cc61df50eb09a351206d7fcebaf121173313a7ebfca49d47afa69fe693e3cc Full log: https://builds.apache.org/job/Mesos-Reviewbot-Linux/2477/console - Mesos Reviewbot On July 10, 2019, 1:16 p.m., Andrei Sekretenko wrote: > > ----------------------------------------------------------- > This is an automatically generated e-mail. To reply, visit: > https://reviews.apache.org/r/71047/ > ----------------------------------------------------------- > > (Updated July 10, 2019, 1:16 p.m.) > > > Review request for mesos and Benjamin Mahler. > > > Bugs: MESOS-9849 > https://issues.apache.org/jira/browse/MESOS-9849 > > > Repository: mesos > > > Description > ------- > > This patch adds exercising per-role suppress/revival to the Java test > framework to ensure that passing the corresponding arguments through the > Java bindings works. > > > Diffs > ----- > > src/examples/java/TestFramework.java > c8b0ceacd1305f7ff67f2ef490e14513d2757f5a > > > Diff: https://reviews.apache.org/r/71047/diff/1/ > > > Testing > ------- > > > Thanks, > > Andrei Sekretenko > >
