You are viewing a plain text version of this content. The canonical link for it is here.
Posted to reviews@mesos.apache.org by Joseph Wu <jo...@mesosphere.io> on 2019/07/09 19:29:17 UTC
Review Request 71041: Added best-effort validation for DRAIN_AGENT
master call.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71041/
-----------------------------------------------------------
Review request for mesos, Benjamin Bannier, Benjamin Mahler, Greg Mann, and Vinod Kone.
Bugs: MESOS-9814
https://issues.apache.org/jira/browse/MESOS-9814
Repository: mesos
Description
-------
This adds two cases which the master cannot deterministically enforce
when using the DRAIN_AGENT call. The draining feature is currently
incompatible with maintenance schedules and older versions of the
Mesos agent. However, in both cases, an agent can reregister with
incompatible info after starting to drain. Also, unreachable agents
do not have enough info to enforce either case.
These are unexpected cases and are not expected to cause any problems
if circumvented. However, the agent draining feature is also not
expected to work correctly if circumvented.
Diffs
-----
src/master/http.cpp b42ebb953e0510e83ec6bd041cbddbeb8f60067c
Diff: https://reviews.apache.org/r/71041/diff/1/
Testing
-------
TODO
Thanks,
Joseph Wu
Re: Review Request 71041: Added best-effort validation for DRAIN_AGENT
master call.
Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71041/#review216456
-----------------------------------------------------------
Bad patch!
Reviews applied: [70822, 70910, 70911, 70923, 70956, 70957, 70924, 70996, 71008, 71041]
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_71041"]
Error:
...<truncated>...
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_1I1e7Z/2GB-087b5726-06f9-46d7-b18f-14d0eeee851b,test)]:2048, allocated: {}) on agent edfee672-462d-4331-8322-6adb4700ba32-S0 from framework edfee672-462d-4331-8322-6adb4700ba32-0000
I0709 22:11:10.767264 18266 hierarchical.cpp:1264] Framework edfee672-462d-4331-8322-6adb4700ba32-0000 filtered agent edfee672-462d-4331-8322-6adb4700ba32-S0 for 5secs
I0709 22:11:10.769640 18269 master.cpp:12458] Sending operation '' (uuid: 8506e27d-f32d-41f5-b197-32f49a2cf12f) to agent edfee672-462d-4331-8322-6adb4700ba32-S0 at slave(1196)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:10.770225 18261 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:10.772866 18276 provider.cpp:481] Received APPLY_OPERATION event
I0709 22:11:10.772912 18276 provider.cpp:1295] Received UNRESERVE operation '' (uuid: 8506e27d-f32d-41f5-b197-32f49a2cf12f)
I0709 22:11:10.782527 18277 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.196336ms
I0709 22:11:10.783165 18279 master.cpp:10285] Sending offers [ edfee672-462d-4331-8322-6adb4700ba32-O6 ] to framework edfee672-462d-4331-8322-6adb4700ba32-0000 (default) at scheduler-49ebc75f-5e98-4bcf-b542-02ed7f665b49@172.17.0.2:40589
I0709 22:11:10.783885 18268 sched.cpp:934] Scheduler::resourceOffers took 82227ns
I0709 22:11:10.798616 18281 http.cpp:1115] HTTP POST for /slave(1196)/api/v1/resource_provider from 172.17.0.2:52982
I0709 22:11:10.799553 18271 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 65766c22-ff7c-4d23-b04b-95daab273396) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 22:11:10.799732 18271 slave.cpp:8670] Updating the state of operation with no ID (uuid: 65766c22-ff7c-4d23-b04b-95daab273396) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 22:11:10.799787 18271 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 65766c22-ff7c-4d23-b04b-95daab273396) for an operator API call
I0709 22:11:10.800212 18261 master.cpp:12114] Updating the state of operation '' (uuid: 65766c22-ff7c-4d23-b04b-95daab273396) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 22:11:10.800714 18265 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:10.958915 18268 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 52c98f82-3882-4062-95d2-85959fc82d11) for operation UUID 8506e27d-f32d-41f5-b197-32f49a2cf12f on agent edfee672-462d-4331-8322-6adb4700ba32-S0
I0709 22:11:10.958999 18268 status_update_manager_process.hpp:414] Creating operation status update stream 8506e27d-f32d-41f5-b197-32f49a2cf12f checkpoint=true
I0709 22:11:10.959054 18276 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 22:11:10.959499 18268 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 52c98f82-3882-4062-95d2-85959fc82d11) for operation UUID 8506e27d-f32d-41f5-b197-32f49a2cf12f on agent edfee672-462d-4331-8322-6adb4700ba32-S0
I0709 22:11:11.110026 18268 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 52c98f82-3882-4062-95d2-85959fc82d11) for operation UUID 8506e27d-f32d-41f5-b197-32f49a2cf12f on agent edfee672-462d-4331-8322-6adb4700ba32-S0
I0709 22:11:11.110631 18268 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 35375938-c9a3-43fd-a70c-a6dcff68c30d) for stream 65766c22-ff7c-4d23-b04b-95daab273396
I0709 22:11:11.110751 18268 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 35375938-c9a3-43fd-a70c-a6dcff68c30d) for operation UUID 65766c22-ff7c-4d23-b04b-95daab273396 on agent edfee672-462d-4331-8322-6adb4700ba32-S0
I0709 22:11:11.111304 18259 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40589/slave(1196)/api/v1/resource_provider
I0709 22:11:11.112715 18269 process.cpp:3671] Handling HTTP event for process 'slave(1196)' with path: '/slave(1196)/api/v1/resource_provider'
I0709 22:11:11.151413 18280 http.cpp:1115] HTTP POST for /slave(1196)/api/v1/resource_provider from 172.17.0.2:52982
I0709 22:11:11.152616 18270 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 8506e27d-f32d-41f5-b197-32f49a2cf12f) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 22:11:11.152853 18270 slave.cpp:8670] Updating the state of operation with no ID (uuid: 8506e27d-f32d-41f5-b197-32f49a2cf12f) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 22:11:11.152933 18270 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 8506e27d-f32d-41f5-b197-32f49a2cf12f) for an operator API call
I0709 22:11:11.153434 18264 master.cpp:12114] Updating the state of operation '' (uuid: 8506e27d-f32d-41f5-b197-32f49a2cf12f) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 22:11:11.154074 18273 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:11.155797 18275 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 22:11:11.226742 18268 status_update_manager_process.hpp:490] Cleaning up operation status update stream 65766c22-ff7c-4d23-b04b-95daab273396
I0709 22:11:11.227064 18268 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 52c98f82-3882-4062-95d2-85959fc82d11) for stream 8506e27d-f32d-41f5-b197-32f49a2cf12f
I0709 22:11:11.227157 18268 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 52c98f82-3882-4062-95d2-85959fc82d11) for operation UUID 8506e27d-f32d-41f5-b197-32f49a2cf12f on agent edfee672-462d-4331-8322-6adb4700ba32-S0
I0709 22:11:11.385468 18268 status_update_manager_process.hpp:490] Cleaning up operation status update stream 8506e27d-f32d-41f5-b197-32f49a2cf12f
I0709 22:11:11.453999 18271 master.cpp:1410] Framework edfee672-462d-4331-8322-6adb4700ba32-0000 (default) at scheduler-49ebc75f-5e98-4bcf-b542-02ed7f665b49@172.17.0.2:40589 disconnected
I0709 22:11:11.454051 18271 master.cpp:3360] Deactivating framework edfee672-462d-4331-8322-6adb4700ba32-0000 (default) at scheduler-49ebc75f-5e98-4bcf-b542-02ed7f665b49@172.17.0.2:40589
I0709 22:11:11.454521 18265 hierarchical.cpp:475] Deactivated framework edfee672-462d-4331-8322-6adb4700ba32-0000
I0709 22:11:11.454954 18258 slave.cpp:912] Agent terminating
I0709 22:11:11.455152 18271 master.cpp:12567] Removing offer edfee672-462d-4331-8322-6adb4700ba32-O6
I0709 22:11:11.455248 18271 master.cpp:3337] Disconnecting framework edfee672-462d-4331-8322-6adb4700ba32-0000 (default) at scheduler-49ebc75f-5e98-4bcf-b542-02ed7f665b49@172.17.0.2:40589
I0709 22:11:11.455322 18271 master.cpp:1425] Giving framework edfee672-462d-4331-8322-6adb4700ba32-0000 (default) at scheduler-49ebc75f-5e98-4bcf-b542-02ed7f665b49@172.17.0.2:40589 0ns to failover
I0709 22:11:11.455966 18258 manager.cpp:163] Terminating resource provider 577a259a-9d56-402f-842c-990bd197e950
I0709 22:11:11.456038 18265 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_1I1e7Z/2GB-087b5726-06f9-46d7-b18f-14d0eeee851b,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_1I1e7Z/2GB-087b5726-06f9-46d7-b18f-14d0eeee851b,test)]:2048, allocated: {}) on agent edfee672-462d-4331-8322-6adb4700ba32-S0 from framework edfee672-462d-4331-8322-6adb4700ba32-0000
I0709 22:11:11.456450 18281 master.cpp:1295] Agent edfee672-462d-4331-8322-6adb4700ba32-S0 at slave(1196)@172.17.0.2:40589 (c9834652b228) disconnected
I0709 22:11:11.456485 18281 master.cpp:3397] Disconnecting agent edfee672-462d-4331-8322-6adb4700ba32-S0 at slave(1196)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:11.456596 18281 master.cpp:3416] Deactivating agent edfee672-462d-4331-8322-6adb4700ba32-S0 at slave(1196)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:11.456763 18270 hierarchical.cpp:799] Agent edfee672-462d-4331-8322-6adb4700ba32-S0 deactivated
I0709 22:11:11.456843 18281 master.cpp:10077] Framework failover timeout, removing framework edfee672-462d-4331-8322-6adb4700ba32-0000 (default) at scheduler-49ebc75f-5e98-4bcf-b542-02ed7f665b49@172.17.0.2:40589
I0709 22:11:11.456938 18281 master.cpp:11069] Removing framework edfee672-462d-4331-8322-6adb4700ba32-0000 (default) at scheduler-49ebc75f-5e98-4bcf-b542-02ed7f665b49@172.17.0.2:40589
E0709 22:11:11.457177 18280 http_connection.hpp:452] End-Of-File received
I0709 22:11:11.457497 18274 hierarchical.cpp:1432] Allocation paused
I0709 22:11:11.457665 18280 http_connection.hpp:217] Re-detecting endpoint
I0709 22:11:11.457939 18274 hierarchical.cpp:417] Removed framework edfee672-462d-4331-8322-6adb4700ba32-0000
I0709 22:11:11.458003 18274 hierarchical.cpp:1442] Allocation resumed
I0709 22:11:11.458276 18280 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0709 22:11:11.458353 18280 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0709 22:11:11.458396 18282 provider.cpp:471] Disconnected from resource provider manager
I0709 22:11:11.458432 18280 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:40589/slave(1196)/api/v1/resource_provider
I0709 22:11:11.458585 18269 status_update_manager_process.hpp:379] Pausing operation status update manager
I0709 22:11:11.459796 18270 containerizer.cpp:2575] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0709 22:11:11.459848 18270 containerizer.cpp:3277] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING
I0709 22:11:11.460229 18270 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 22:11:11.461691 18278 hierarchical.cpp:1508] Performed allocation for 1 agents in 144752ns
I0709 22:11:11.461974 18279 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:40589/slave(1196)/api/v1/resource_provider
I0709 22:11:11.462569 18282 provider.cpp:459] Connected to resource provider manager
I0709 22:11:11.463165 18266 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:40589/slave(1196)/api/v1/resource_provider
I0709 22:11:11.463892 18283 process.cpp:2781] Returning '404 Not Found' for '/slave(1196)/api/v1/resource_provider'
E0709 22:11:11.465369 18263 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0709 22:11:11.513227 18275 hierarchical.cpp:1508] Performed allocation for 1 agents in 172608ns
I0709 22:11:11.563241 18262 containerizer.cpp:3116] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0709 22:11:11.564697 18274 provisioner.cpp:609] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 22:11:11.564705 18281 hierarchical.cpp:1508] Performed allocation for 1 agents in 128814ns
I0709 22:11:11.567368 18280 container_daemon.cpp:189] Invoking post-stop hook for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 22:11:11.567579 18275 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-YYnbyL/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 22:11:11.567862 18260 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 22:11:11.570437 18283 process.cpp:2781] Returning '404 Not Found' for '/slave(1196)/api/v1'
I0709 22:11:11.582160 18263 master.cpp:1135] Master terminating
I0709 22:11:11.582813 18261 hierarchical.cpp:775] Removed all filters for agent edfee672-462d-4331-8322-6adb4700ba32-S0
I0709 22:11:11.582842 18261 hierarchical.cpp:650] Removed agent edfee672-462d-4331-8322-6adb4700ba32-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v0 (3543 ms)
[ RUN ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1
I0709 22:11:11.606096 18258 cluster.cpp:176] Creating default 'local' authorizer
I0709 22:11:11.613108 18273 master.cpp:440] Master e1a2c8b8-da36-483c-80a7-699cbba21f25 (c9834652b228) started on 172.17.0.2:40589
I0709 22:11:11.613152 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/f8nmrW/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/f8nmrW/master" --zk_session_timeout="10secs"
I0709 22:11:11.613740 18273 master.cpp:492] Master only allowing authenticated frameworks to register
I0709 22:11:11.613765 18273 master.cpp:498] Master only allowing authenticated agents to register
I0709 22:11:11.613783 18273 master.cpp:504] Master only allowing authenticated HTTP frameworks to register
I0709 22:11:11.613802 18273 credentials.hpp:37] Loading credentials for authentication from '/tmp/f8nmrW/credentials'
I0709 22:11:11.614123 18273 master.cpp:548] Using default 'crammd5' authenticator
I0709 22:11:11.614338 18273 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0709 22:11:11.614560 18273 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0709 22:11:11.614738 18273 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0709 22:11:11.614899 18273 master.cpp:629] Authorization enabled
I0709 22:11:11.615240 18261 hierarchical.cpp:241] Initialized hierarchical allocator process
I0709 22:11:11.615326 18264 whitelist_watcher.cpp:77] No whitelist given
I0709 22:11:11.618363 18263 master.cpp:2168] Elected as the leading master!
I0709 22:11:11.618418 18263 master.cpp:1664] Recovering from registrar
I0709 22:11:11.618722 18276 registrar.cpp:339] Recovering registrar
I0709 22:11:11.619788 18276 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0709 22:11:11.619966 18276 registrar.cpp:487] Applied 1 operations in 53524ns; attempting to update the registry
I0709 22:11:11.620877 18276 registrar.cpp:544] Successfully updated the registry in 0ns
I0709 22:11:11.621089 18276 registrar.cpp:416] Successfully recovered registrar
I0709 22:11:11.621712 18278 master.cpp:1817] Recovered 0 agents from the registry (139B); allowing 10mins for agents to reregister
I0709 22:11:11.621753 18277 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover
W0709 22:11:11.628962 18258 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:40589
I0709 22:11:11.630316 18258 containerizer.cpp:314] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0709 22:11:11.630935 18258 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0709 22:11:11.631093 18258 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0709 22:11:11.631136 18258 provisioner.cpp:298] Using default backend 'copy'
I0709 22:11:11.633805 18258 cluster.cpp:510] Creating default 'local' authorizer
I0709 22:11:11.636238 18275 slave.cpp:265] Mesos agent started on (1197)@172.17.0.2:40589
I0709 22:11:11.636263 18275 slave.cpp:266] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/f8nmrW/M31fdt/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/f8nmrW/M31fdt/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/f8nmrW/M31fdt/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/f8nmrW/M31fdt/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/f8nmrW/M31fdt/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/f8nmrW/M31fdt/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/f8nmrW/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_i0jpv5" --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_WoyzNH" --zk_session_timeout="10secs"
I0709 22:11:11.636705 18275 credentials.hpp:86] Loading credential for authentication from '/tmp/f8nmrW/M31fdt/credential'
I0709 22:11:11.636889 18275 slave.cpp:298] Agent using credential for: test-principal
I0709 22:11:11.636921 18275 credentials.hpp:37] Loading credentials for authentication from '/tmp/f8nmrW/M31fdt/http_credentials'
I0709 22:11:11.637197 18275 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0709 22:11:11.637624 18275 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0709 22:11:11.639369 18275 slave.cpp:613] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0709 22:11:11.639585 18275 slave.cpp:621] Agent attributes: [ ]
I0709 22:11:11.639609 18275 slave.cpp:630] Agent hostname: c9834652b228
I0709 22:11:11.640161 18273 task_status_update_manager.cpp:181] Pausing sending task status updates
I0709 22:11:11.640231 18273 status_update_manager_process.hpp:379] Pausing operation status update manager
I0709 22:11:11.641710 18270 process.cpp:3671] Handling HTTP event for process 'test-disk-profile-server' with path: '/test-disk-profile-server/profiles'
I0709 22:11:11.641813 18265 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_WoyzNH/meta'
I0709 22:11:11.642083 18269 slave.cpp:7246] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_WoyzNH/meta', beginning agent recovery
I0709 22:11:11.642745 18266 task_status_update_manager.cpp:207] Recovering task status update manager
I0709 22:11:11.643177 18277 containerizer.cpp:796] Recovering Mesos containers
I0709 22:11:11.643550 18277 containerizer.cpp:1122] Recovering isolators
I0709 22:11:11.644328 18275 containerizer.cpp:1161] Recovering provisioner
I0709 22:11:11.645176 18270 provisioner.cpp:498] Provisioner recovery complete
I0709 22:11:11.645901 18269 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I0709 22:11:11.646227 18261 composing.cpp:339] Finished recovering all containerizers
I0709 22:11:11.646569 18267 slave.cpp:7708] Recovering executors
I0709 22:11:11.646701 18267 slave.cpp:7861] Finished recovery
I0709 22:11:11.647737 18277 task_status_update_manager.cpp:181] Pausing sending task status updates
I0709 22:11:11.647758 18281 status_update_manager_process.hpp:379] Pausing operation status update manager
I0709 22:11:11.647733 18267 slave.cpp:1258] New master detected at master@172.17.0.2:40589
I0709 22:11:11.647922 18267 slave.cpp:1323] Detecting new master
I0709 22:11:11.649230 18265 slave.cpp:1350] Authenticating with master master@172.17.0.2:40589
I0709 22:11:11.649339 18265 slave.cpp:1359] Using default CRAM-MD5 authenticatee
I0709 22:11:11.649690 18273 authenticatee.cpp:121] Creating new client SASL connection
I0709 22:11:11.650096 18262 master.cpp:10470] Authenticating slave(1197)@172.17.0.2:40589
I0709 22:11:11.650275 18266 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2044)@172.17.0.2:40589
I0709 22:11:11.650609 18268 authenticator.cpp:98] Creating new server SASL connection
I0709 22:11:11.650912 18260 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0709 22:11:11.650944 18260 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0709 22:11:11.651101 18270 authenticator.cpp:204] Received SASL authentication start
I0709 22:11:11.651199 18270 authenticator.cpp:326] Authentication requires more steps
I0709 22:11:11.651357 18276 authenticatee.cpp:259] Received SASL authentication step
I0709 22:11:11.651536 18280 authenticator.cpp:232] Received SASL authentication step
I0709 22:11:11.651587 18280 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'c9834652b228' server FQDN: 'c9834652b228' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0709 22:11:11.651607 18280 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0709 22:11:11.651655 18280 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0709 22:11:11.651684 18280 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'c9834652b228' server FQDN: 'c9834652b228' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0709 22:11:11.651700 18280 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0709 22:11:11.651712 18280 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0709 22:11:11.651733 18280 authenticator.cpp:318] Authentication success
I0709 22:11:11.651862 18274 authenticatee.cpp:299] Authentication success
I0709 22:11:11.652045 18272 master.cpp:10502] Successfully authenticated principal 'test-principal' at slave(1197)@172.17.0.2:40589
I0709 22:11:11.652079 18269 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2044)@172.17.0.2:40589
I0709 22:11:11.652321 18279 slave.cpp:1450] Successfully authenticated with master master@172.17.0.2:40589
I0709 22:11:11.652742 18279 slave.cpp:1900] Will retry registration in 253754ns if necessary
I0709 22:11:11.652961 18263 master.cpp:6982] Received register agent message from slave(1197)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:11.653347 18263 master.cpp:4129] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I0709 22:11:11.654081 18267 master.cpp:7049] Authorized registration of agent at slave(1197)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:11.654178 18267 master.cpp:7161] Registering agent at slave(1197)@172.17.0.2:40589 (c9834652b228) with id e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:11.654917 18282 registrar.cpp:487] Applied 1 operations in 213414ns; attempting to update the registry
I0709 22:11:11.655696 18282 registrar.cpp:544] Successfully updated the registry in 0ns
I0709 22:11:11.655900 18268 master.cpp:7209] Admitted agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:11.656698 18268 master.cpp:7254] Registered agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0709 22:11:11.656883 18260 slave.cpp:1483] Registered with master master@172.17.0.2:40589; given agent ID e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:11.656931 18270 hierarchical.cpp:617] Added agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 (c9834652b228) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I0709 22:11:11.657027 18261 task_status_update_manager.cpp:188] Resuming sending task status updates
I0709 22:11:11.657315 18270 hierarchical.cpp:1508] Performed allocation for 1 agents in 152853ns
I0709 22:11:11.657503 18260 slave.cpp:1518] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_WoyzNH/meta/slaves/e1a2c8b8-da36-483c-80a7-699cbba21f25-S0/slave.info'
I0709 22:11:11.657548 18274 status_update_manager_process.hpp:385] Resuming operation status update manager
I0709 22:11:11.658824 18260 slave.cpp:1570] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"KkvzqfWsT7uCUZ291GyA2w=="},"slave_id":{"value":"e1a2c8b8-da36-483c-80a7-699cbba21f25-S0"},"update_oversubscribed_resources":false}
I0709 22:11:11.660070 18272 master.cpp:8349] Ignoring update on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228) as it reports no changes
I0709 22:11:11.664242 18262 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1'
I0709 22:11:11.665566 18261 http.cpp:1115] HTTP POST for /slave(1197)/api/v1 from 172.17.0.2:53002
I0709 22:11:11.666011 18261 http.cpp:2120] Processing GET_CONTAINERS call
I0709 22:11:11.671545 18266 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 22:11:11.674106 18276 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1'
I0709 22:11:11.675035 18264 http.cpp:1115] HTTP POST for /slave(1197)/api/v1 from 172.17.0.2:53004
I0709 22:11:11.675868 18264 http.cpp:2486] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 22:11:11.676745 18280 http.cpp:2590] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_WoyzNH/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 22:11:11.677508 18272 containerizer.cpp:1357] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 22:11:11.679396 18272 containerizer.cpp:1529] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_i0jpv5/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0709 22:11:11.679452 18272 containerizer.cpp:3277] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PROVISIONING to PREPARING
I0709 22:11:11.682754 18263 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_C4ZL5j","--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_WoyzNH/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-VHi8m0/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperat
ionsWithResourceProviderResources_v1_WoyzNH/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="87" --pipe_write="88" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_i0jpv5/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I0709 22:11:11.691924 18263 launcher.cpp:145] Forked child with pid '32051' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 22:11:11.692744 18263 containerizer.cpp:3277] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PREPARING to ISOLATING
I0709 22:11:11.694243 18263 containerizer.cpp:3277] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from ISOLATING to FETCHING
I0709 22:11:11.694674 18268 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_WoyzNH/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 22:11:11.695960 18276 containerizer.cpp:3277] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from FETCHING to RUNNING
I0709 22:11:11.699132 18279 container_daemon.cpp:140] Invoking post-start hook for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 22:11:11.699383 18264 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-VHi8m0/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 22:11:11.979646 18273 hierarchical.cpp:1508] Performed allocation for 1 agents in 228817ns
I0709 22:11:12.031107 18270 hierarchical.cpp:1508] Performed allocation for 1 agents in 218005ns
I0709 22:11:12.082700 18277 hierarchical.cpp:1508] Performed allocation for 1 agents in 226822ns
I0709 22:11:12.134255 18269 hierarchical.cpp:1508] Performed allocation for 1 agents in 240214ns
I0709 22:11:12.168726 18266 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-VHi8m0/endpoint.sock' with CSI v1
I0709 22:11:12.184051 32055 test_csi_plugin.cpp:909] ProbeRequest '{}'
I0709 22:11:12.185278 18263 hierarchical.cpp:1508] Performed allocation for 1 agents in 173130ns
I0709 22:11:12.185917 18261 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 22:11:12.188401 32056 test_csi_plugin.cpp:895] GetPluginCapabilitiesRequest '{}'
I0709 22:11:12.189244 18278 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1'
I0709 22:11:12.190618 18266 http.cpp:1115] HTTP POST for /slave(1197)/api/v1 from 172.17.0.2:53006
I0709 22:11:12.191200 18266 http.cpp:2704] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 22:11:12.192128 32056 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0709 22:11:12.192437 32055 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0709 22:11:12.193768 18260 v1_volume_manager.cpp:648] NODE_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"}
I0709 22:11:12.194295 18260 v1_volume_manager.cpp:648] CONTROLLER_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"}
I0709 22:11:12.196338 32057 test_csi_plugin.cpp:1105] ControllerGetCapabilitiesRequest '{}'
I0709 22:11:12.199906 32057 test_csi_plugin.cpp:1241] NodeGetCapabilitiesRequest '{}'
I0709 22:11:12.202924 32056 test_csi_plugin.cpp:1255] NodeGetInfoRequest '{}'
I0709 22:11:12.204793 18261 provider.cpp:659] Finished recovery for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0709 22:11:12.204916 18271 status_update_manager_process.hpp:379] Pausing operation status update manager
I0709 22:11:12.205288 18268 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:12.208376 18272 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:12.209024 18259 provider.cpp:459] Connected to resource provider manager
I0709 22:11:12.209712 18275 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:12.210800 18282 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 22:11:12.212456 18276 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.2:53010
I0709 22:11:12.213097 18261 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_C4ZL5j","--available_capacity=2GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.9.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"}},"type":"org.apache.mesos.rp.local.storage"}
I0709 22:11:12.236898 18278 hierarchical.cpp:1508] Performed allocation for 1 agents in 179874ns
I0709 22:11:12.254642 18272 slave.cpp:8217] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"d3f0df67-ab2e-4b8a-9e00-6a1982d89715"},"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_C4ZL5j","--available_capacity=2GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.9.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"}},"type":"org.apache.mesos.rp.local.storage"}'
I0709 22:11:12.256312 18281 provider.cpp:481] Received SUBSCRIBED event
I0709 22:11:12.256355 18281 provider.cpp:1255] Subscribed with ID d3f0df67-ab2e-4b8a-9e00-6a1982d89715
I0709 22:11:12.257233 18271 status_update_manager_process.hpp:314] Recovering operation status update manager
I0709 22:11:12.288693 18263 hierarchical.cpp:1508] Performed allocation for 1 agents in 161687ns
I0709 22:11:12.339557 18268 hierarchical.cpp:1508] Performed allocation for 1 agents in 108670ns
I0709 22:11:12.345688 32056 test_csi_plugin.cpp:1050] ListVolumesRequest '{}'
I0709 22:11:12.348196 18272 provider.cpp:2145] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:12.348418 18272 provider.cpp:745] Resource provider d3f0df67-ab2e-4b8a-9e00-6a1982d89715 is in READY state
I0709 22:11:12.348469 18273 status_update_manager_process.hpp:385] Resuming operation status update manager
I0709 22:11:12.348471 18265 http_connection.hpp:131] Sending 3 call to http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:12.349143 18282 provider.cpp:1181] Updating profiles { test } for resource provider d3f0df67-ab2e-4b8a-9e00-6a1982d89715
I0709 22:11:12.349524 18261 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 22:11:12.351155 18259 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.2:53008
I0709 22:11:12.351615 18265 manager.cpp:1039] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider d3f0df67-ab2e-4b8a-9e00-6a1982d89715
I0709 22:11:12.351848 18275 slave.cpp:8217] Handling resource provider message 'UPDATE_STATE: d3f0df67-ab2e-4b8a-9e00-6a1982d89715 {}'
I0709 22:11:12.351958 18275 slave.cpp:8337] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0709 22:11:12.352785 32056 test_csi_plugin.cpp:1078] GetCapacityRequest '{"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0709 22:11:12.354382 18274 hierarchical.cpp:753] Grew agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 by {} (total), { } (used)
I0709 22:11:12.354743 18274 hierarchical.cpp:710] Agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 (c9834652b228) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
W0709 22:11:12.355566 18258 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:40589
I0709 22:11:12.356752 18258 sched.cpp:239] Version: 1.9.0
I0709 22:11:12.357442 18269 provider.cpp:933] Removing '{}' and adding 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' to the total resources
I0709 22:11:12.357599 18259 sched.cpp:343] New master detected at master@172.17.0.2:40589
I0709 22:11:12.357748 18259 sched.cpp:408] Authenticating with master master@172.17.0.2:40589
I0709 22:11:12.357771 18259 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0709 22:11:12.358152 18279 authenticatee.cpp:121] Creating new client SASL connection
I0709 22:11:12.358541 18268 master.cpp:10470] Authenticating scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:12.358609 18272 hierarchical.cpp:1508] Performed allocation for 1 agents in 157236ns
I0709 22:11:12.358719 18262 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2045)@172.17.0.2:40589
I0709 22:11:12.359041 18272 authenticator.cpp:98] Creating new server SASL connection
I0709 22:11:12.359302 18270 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0709 22:11:12.359336 18270 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0709 22:11:12.359491 18263 authenticator.cpp:204] Received SASL authentication start
I0709 22:11:12.359561 18263 authenticator.cpp:326] Authentication requires more steps
I0709 22:11:12.359710 18266 authenticatee.cpp:259] Received SASL authentication step
I0709 22:11:12.359869 18281 authenticator.cpp:232] Received SASL authentication step
I0709 22:11:12.359906 18281 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'c9834652b228' server FQDN: 'c9834652b228' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0709 22:11:12.359925 18281 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0709 22:11:12.359977 18281 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0709 22:11:12.360003 18281 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'c9834652b228' server FQDN: 'c9834652b228' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0709 22:11:12.360018 18281 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0709 22:11:12.360029 18281 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0709 22:11:12.360049 18281 authenticator.cpp:318] Authentication success
I0709 22:11:12.360148 18274 authenticatee.cpp:299] Authentication success
I0709 22:11:12.360293 18277 master.cpp:10502] Successfully authenticated principal 'test-principal' at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:12.360355 18280 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2045)@172.17.0.2:40589
I0709 22:11:12.360607 18260 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:40589
I0709 22:11:12.360635 18260 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:40589
I0709 22:11:12.360817 18260 sched.cpp:870] Will retry registration in 401.105951ms if necessary
I0709 22:11:12.361043 18273 master.cpp:2908] Received SUBSCRIBE call for framework 'default' at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:12.361099 18273 master.cpp:2240] Authorizing framework principal 'test-principal' to receive offers for roles '{ storage/default-role }'
I0709 22:11:12.361734 18265 master.cpp:2995] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0709 22:11:12.364300 18265 master.cpp:10700] Adding framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589 with roles { } suppressed
I0709 22:11:12.364876 18282 sched.cpp:751] Framework registered with e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.364936 18282 sched.cpp:770] Scheduler::registered took 26716ns
I0709 22:11:12.365227 18279 hierarchical.cpp:368] Added framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.366394 18279 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.018695ms
I0709 22:11:12.366847 18272 master.cpp:10285] Sending offers [ e1a2c8b8-da36-483c-80a7-699cbba21f25-O0 ] to framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:12.367388 18272 sched.cpp:934] Scheduler::resourceOffers took 110446ns
I0709 22:11:12.367776 18263 master.cpp:6149] Processing DECLINE call for offers: [ e1a2c8b8-da36-483c-80a7-699cbba21f25-O0 ] for framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589 with 5 seconds filter
I0709 22:11:12.368376 18263 master.cpp:12567] Removing offer e1a2c8b8-da36-483c-80a7-699cbba21f25-O0
I0709 22:11:12.369093 18266 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 e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 from framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.369170 18266 hierarchical.cpp:1264] Framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 filtered agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for 5secs
I0709 22:11:12.461185 18269 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 e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:12.462085 18281 http_connection.hpp:131] Sending 3 call to http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:12.463541 18267 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 22:11:12.504012 18273 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.2:53008
I0709 22:11:12.505041 18275 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":"d3f0df67-ab2e-4b8a-9e00-6a1982d89715"},"reservations":[{"role":"storage","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]' and 0 operations from resource provider d3f0df67-ab2e-4b8a-9e00-6a1982d89715
I0709 22:11:12.505888 18259 slave.cpp:8217] Handling resource provider message 'UPDATE_STATE: d3f0df67-ab2e-4b8a-9e00-6a1982d89715 disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048'
I0709 22:11:12.506100 18259 slave.cpp:8337] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048
I0709 22:11:12.508944 18262 hierarchical.cpp:710] Agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 (c9834652b228) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048
I0709 22:11:12.510522 18262 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.321459ms
I0709 22:11:12.511289 18279 master.cpp:10285] Sending offers [ e1a2c8b8-da36-483c-80a7-699cbba21f25-O1 ] to framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:12.512006 18270 sched.cpp:934] Scheduler::resourceOffers took 90344ns
I0709 22:11:12.516261 18266 master.cpp:12567] Removing offer e1a2c8b8-da36-483c-80a7-699cbba21f25-O1
I0709 22:11:12.516903 18266 master.cpp:4666] Processing ACCEPT call for offers: [ e1a2c8b8-da36-483c-80a7-699cbba21f25-O1 ] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228) for framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:12.516957 18269 hierarchical.cpp:1508] Performed allocation for 1 agents in 381457ns
I0709 22:11:12.517038 18266 master.cpp:4039] Authorizing principal 'test-principal' to create a MOUNT disk from 'disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048'
I0709 22:11:12.518478 18274 master.cpp:5941] Processing CREATE_DISK operation with source disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048 from framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589 to agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:12.519125 18274 master.cpp:12458] Sending operation '' (uuid: bf15d377-cad5-4518-aedc-f12ae00ea5e7) to agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:12.519488 18276 hierarchical.cpp:1432] Allocation paused
I0709 22:11:12.519661 18280 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:12.520591 18276 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 e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 from framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.520691 18276 hierarchical.cpp:1264] Framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 filtered agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for 5secs
I0709 22:11:12.520939 18276 hierarchical.cpp:1442] Allocation resumed
I0709 22:11:12.522260 18262 provider.cpp:481] Received APPLY_OPERATION event
I0709 22:11:12.522344 18262 provider.cpp:1295] Received CREATE_DISK operation '' (uuid: bf15d377-cad5-4518-aedc-f12ae00ea5e7)
I0709 22:11:12.568545 18270 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.568745 18270 hierarchical.cpp:1508] Performed allocation for 1 agents in 793488ns
I0709 22:11:12.620443 18272 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.620672 18272 hierarchical.cpp:1508] Performed allocation for 1 agents in 976464ns
I0709 22:11:12.621381 18281 v1_volume_manager.cpp:292] Creating volume with name 'bf15d377-cad5-4518-aedc-f12ae00ea5e7'
I0709 22:11:12.623962 32056 test_csi_plugin.cpp:922] CreateVolumeRequest '{"name":"bf15d377-cad5-4518-aedc-f12ae00ea5e7","capacityRange":{"requiredBytes":"2147483648","limitBytes":"2147483648"},"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0709 22:11:12.671851 18278 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.671969 18278 hierarchical.cpp:1508] Performed allocation for 1 agents in 450006ns
I0709 22:11:12.722939 18273 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.723054 18273 hierarchical.cpp:1508] Performed allocation for 1 agents in 435932ns
I0709 22:11:12.774462 18260 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.774685 18260 hierarchical.cpp:1508] Performed allocation for 1 agents in 790683ns
I0709 22:11:12.825642 18275 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.825748 18275 hierarchical.cpp:1508] Performed allocation for 1 agents in 430897ns
I0709 22:11:12.864477 18276 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_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,test)]:2048' for operation (uuid: bf15d377-cad5-4518-aedc-f12ae00ea5e7)
I0709 22:11:12.876924 18271 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.877121 18271 hierarchical.cpp:1508] Performed allocation for 1 agents in 646142ns
I0709 22:11:12.928722 18268 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.928911 18268 hierarchical.cpp:1508] Performed allocation for 1 agents in 706196ns
I0709 22:11:12.980233 18265 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:12.980432 18265 hierarchical.cpp:1508] Performed allocation for 1 agents in 732143ns
I0709 22:11:12.997941 18279 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: db473d49-6056-4084-979c-fd4981965ac6) for operation UUID bf15d377-cad5-4518-aedc-f12ae00ea5e7 of framework 'e1a2c8b8-da36-483c-80a7-699cbba21f25-0000' on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:12.998026 18279 status_update_manager_process.hpp:414] Creating operation status update stream bf15d377-cad5-4518-aedc-f12ae00ea5e7 checkpoint=true
I0709 22:11:12.998534 18279 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: db473d49-6056-4084-979c-fd4981965ac6) for operation UUID bf15d377-cad5-4518-aedc-f12ae00ea5e7 of framework 'e1a2c8b8-da36-483c-80a7-699cbba21f25-0000' on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:13.031958 18263 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:13.032140 18263 hierarchical.cpp:1508] Performed allocation for 1 agents in 749146ns
I0709 22:11:13.083493 18272 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:13.083698 18272 hierarchical.cpp:1508] Performed allocation for 1 agents in 727302ns
I0709 22:11:13.131539 18279 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: db473d49-6056-4084-979c-fd4981965ac6) for operation UUID bf15d377-cad5-4518-aedc-f12ae00ea5e7 of framework 'e1a2c8b8-da36-483c-80a7-699cbba21f25-0000' on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:13.132577 18269 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:13.134057 18261 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 22:11:13.136078 18267 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for role storage/default-role of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:13.136202 18267 hierarchical.cpp:1508] Performed allocation for 1 agents in 483013ns
I0709 22:11:13.174808 18275 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.2:53008
I0709 22:11:13.175806 18271 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: bf15d377-cad5-4518-aedc-f12ae00ea5e7) for framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 22:11:13.176023 18271 slave.cpp:8670] Updating the state of operation with no ID (uuid: bf15d377-cad5-4518-aedc-f12ae00ea5e7) for framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 22:11:13.176446 18271 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: bf15d377-cad5-4518-aedc-f12ae00ea5e7) for framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:13.176829 18265 master.cpp:12114] Updating the state of operation '' (uuid: bf15d377-cad5-4518-aedc-f12ae00ea5e7) for framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 22:11:13.178022 18263 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:13.178666 18270 hierarchical.cpp:956] Updated allocation of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-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_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,test)]:2048
I0709 22:11:13.179327 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_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,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_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,test)]:2048, allocated: {}) on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 from framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:13.179509 18267 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 22:11:13.179670 18274 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: db473d49-6056-4084-979c-fd4981965ac6) for stream bf15d377-cad5-4518-aedc-f12ae00ea5e7
I0709 22:11:13.179759 18274 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: db473d49-6056-4084-979c-fd4981965ac6) for operation UUID bf15d377-cad5-4518-aedc-f12ae00ea5e7 of framework 'e1a2c8b8-da36-483c-80a7-699cbba21f25-0000' on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:13.188367 18280 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.146407ms
I0709 22:11:13.189080 18273 master.cpp:10285] Sending offers [ e1a2c8b8-da36-483c-80a7-699cbba21f25-O2 ] to framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:13.189780 18260 sched.cpp:934] Scheduler::resourceOffers took 137500ns
I0709 22:11:13.193053 18268 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0709 22:11:13.194733 18281 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:53012
I0709 22:11:13.194990 18281 http.cpp:263] Processing call RESERVE_RESOURCES
I0709 22:11:13.195739 18281 master.cpp:3751] Authorizing principal 'test-principal' to reserve resources 'disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,test)]:2048'
I0709 22:11:13.197486 18278 master.cpp:12567] Removing offer e1a2c8b8-da36-483c-80a7-699cbba21f25-O2
I0709 22:11:13.197621 18280 sched.cpp:960] Rescinded offer e1a2c8b8-da36-483c-80a7-699cbba21f25-O2
I0709 22:11:13.197695 18280 sched.cpp:971] Scheduler::offerRescinded took 21874ns
I0709 22:11:13.198287 18261 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,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_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,test)]:2048, allocated: {}) on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 from framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:13.198393 18261 hierarchical.cpp:1264] Framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 filtered agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for 5secs
I0709 22:11:13.200678 18273 master.cpp:12458] Sending operation '' (uuid: 611defae-850a-47bf-a85a-7964e30661c2) to agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:13.201226 18264 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:13.203683 18277 provider.cpp:481] Received APPLY_OPERATION event
I0709 22:11:13.203724 18277 provider.cpp:1295] Received RESERVE operation '' (uuid: 611defae-850a-47bf-a85a-7964e30661c2)
I0709 22:11:13.340099 18274 status_update_manager_process.hpp:490] Cleaning up operation status update stream bf15d377-cad5-4518-aedc-f12ae00ea5e7
I0709 22:11:13.407781 18281 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 5fe0d97b-4189-45c5-b6f5-3d666297271b) for operation UUID 611defae-850a-47bf-a85a-7964e30661c2 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:13.407852 18281 status_update_manager_process.hpp:414] Creating operation status update stream 611defae-850a-47bf-a85a-7964e30661c2 checkpoint=true
I0709 22:11:13.408360 18281 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 5fe0d97b-4189-45c5-b6f5-3d666297271b) for operation UUID 611defae-850a-47bf-a85a-7964e30661c2 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:13.549826 18281 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 5fe0d97b-4189-45c5-b6f5-3d666297271b) for operation UUID 611defae-850a-47bf-a85a-7964e30661c2 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:13.567740 18266 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:13.568974 18280 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 22:11:13.572429 18261 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.372696ms
I0709 22:11:13.573207 18260 master.cpp:10285] Sending offers [ e1a2c8b8-da36-483c-80a7-699cbba21f25-O3 ] to framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:13.573981 18259 sched.cpp:934] Scheduler::resourceOffers took 97785ns
I0709 22:11:13.577028 18275 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0709 22:11:13.578781 18263 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:53014
I0709 22:11:13.579023 18263 http.cpp:263] Processing call CREATE_VOLUMES
I0709 22:11:13.579907 18263 master.cpp:3878] Authorizing principal 'test-principal' to create volumes '[{"disk":{"persistence":{"id":"39bc767f-3a1c-452a-b42d-2b9168b9fbd6","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7","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":"d3f0df67-ab2e-4b8a-9e00-6a1982d89715"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0709 22:11:13.581919 18279 master.cpp:12567] Removing offer e1a2c8b8-da36-483c-80a7-699cbba21f25-O3
I0709 22:11:13.582057 18281 sched.cpp:960] Rescinded offer e1a2c8b8-da36-483c-80a7-699cbba21f25-O3
I0709 22:11:13.582162 18281 sched.cpp:971] Scheduler::offerRescinded took 40195ns
I0709 22:11:13.582638 18274 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_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,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_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,test)]:2048, allocated: {}) on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 from framework e1a2c8b8-da36-48
3c-80a7-699cbba21f25-0000
I0709 22:11:13.582762 18274 hierarchical.cpp:1264] Framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 filtered agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for 5secs
I0709 22:11:13.585103 18277 master.cpp:12458] Sending operation '' (uuid: b3b76297-6c3a-46e4-8acf-f0f98ebe98ea) to agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:13.585669 18280 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:13.588294 18271 provider.cpp:481] Received APPLY_OPERATION event
I0709 22:11:13.588335 18271 provider.cpp:1295] Received CREATE operation '' (uuid: b3b76297-6c3a-46e4-8acf-f0f98ebe98ea)
I0709 22:11:13.595654 18262 master.cpp:6311] Processing REVIVE call for framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:13.596091 18263 hierarchical.cpp:1365] Unsuppressed offers for roles { storage/default-role } of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:13.596119 18263 hierarchical.cpp:1387] Revived roles { storage/default-role } of framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:13.597404 18263 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.129557ms
I0709 22:11:13.597826 18263 hierarchical.cpp:1508] Performed allocation for 1 agents in 205668ns
I0709 22:11:13.598160 18272 master.cpp:10285] Sending offers [ e1a2c8b8-da36-483c-80a7-699cbba21f25-O4 ] to framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:13.598768 18269 sched.cpp:934] Scheduler::resourceOffers took 81899ns
I0709 22:11:13.606554 18267 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.2:53008
I0709 22:11:13.607467 18270 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 611defae-850a-47bf-a85a-7964e30661c2) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 22:11:13.607663 18270 slave.cpp:8670] Updating the state of operation with no ID (uuid: 611defae-850a-47bf-a85a-7964e30661c2) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 22:11:13.607717 18270 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 611defae-850a-47bf-a85a-7964e30661c2) for an operator API call
I0709 22:11:13.608070 18280 master.cpp:12114] Updating the state of operation '' (uuid: 611defae-850a-47bf-a85a-7964e30661c2) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 22:11:13.608603 18260 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:13.734643 18269 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 6c0a9dc5-e860-4a46-ac31-fd2d5f641acc) for operation UUID b3b76297-6c3a-46e4-8acf-f0f98ebe98ea on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:13.734710 18269 status_update_manager_process.hpp:414] Creating operation status update stream b3b76297-6c3a-46e4-8acf-f0f98ebe98ea checkpoint=true
I0709 22:11:13.734750 18271 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 22:11:13.735164 18269 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 6c0a9dc5-e860-4a46-ac31-fd2d5f641acc) for operation UUID b3b76297-6c3a-46e4-8acf-f0f98ebe98ea on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:13.859908 18269 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 6c0a9dc5-e860-4a46-ac31-fd2d5f641acc) for operation UUID b3b76297-6c3a-46e4-8acf-f0f98ebe98ea on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:13.860266 18269 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 5fe0d97b-4189-45c5-b6f5-3d666297271b) for stream 611defae-850a-47bf-a85a-7964e30661c2
I0709 22:11:13.860343 18269 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 5fe0d97b-4189-45c5-b6f5-3d666297271b) for operation UUID 611defae-850a-47bf-a85a-7964e30661c2 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:13.860817 18279 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:13.861743 18277 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 22:11:13.902588 18282 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.2:53008
I0709 22:11:13.903587 18260 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: b3b76297-6c3a-46e4-8acf-f0f98ebe98ea) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 22:11:13.903800 18260 slave.cpp:8670] Updating the state of operation with no ID (uuid: b3b76297-6c3a-46e4-8acf-f0f98ebe98ea) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 22:11:13.903851 18260 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: b3b76297-6c3a-46e4-8acf-f0f98ebe98ea) for an operator API call
I0709 22:11:13.904268 18264 master.cpp:12114] Updating the state of operation '' (uuid: b3b76297-6c3a-46e4-8acf-f0f98ebe98ea) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 22:11:13.904799 18273 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:13.906139 18274 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 22:11:13.968410 18269 status_update_manager_process.hpp:490] Cleaning up operation status update stream 611defae-850a-47bf-a85a-7964e30661c2
I0709 22:11:13.968645 18269 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 6c0a9dc5-e860-4a46-ac31-fd2d5f641acc) for stream b3b76297-6c3a-46e4-8acf-f0f98ebe98ea
I0709 22:11:13.968856 18269 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 6c0a9dc5-e860-4a46-ac31-fd2d5f641acc) for operation UUID b3b76297-6c3a-46e4-8acf-f0f98ebe98ea on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:14.127146 18269 status_update_manager_process.hpp:490] Cleaning up operation status update stream b3b76297-6c3a-46e4-8acf-f0f98ebe98ea
I0709 22:11:14.215260 18261 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0709 22:11:14.216950 18264 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:53016
I0709 22:11:14.217229 18264 http.cpp:263] Processing call DESTROY_VOLUMES
I0709 22:11:14.218148 18264 master.cpp:3923] Authorizing principal 'test-principal' to destroy volumes '[{"disk":{"persistence":{"id":"39bc767f-3a1c-452a-b42d-2b9168b9fbd6","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7","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":"d3f0df67-ab2e-4b8a-9e00-6a1982d89715"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0709 22:11:14.220311 18276 master.cpp:12567] Removing offer e1a2c8b8-da36-483c-80a7-699cbba21f25-O4
I0709 22:11:14.220427 18272 sched.cpp:960] Rescinded offer e1a2c8b8-da36-483c-80a7-699cbba21f25-O4
I0709 22:11:14.220504 18272 sched.cpp:971] Scheduler::offerRescinded took 24654ns
I0709 22:11:14.221359 18265 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_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,test),39bc767f-3a1c-452a-b42d-2b9168b9fbd6: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_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,test),39bc767f-3a1c-452a-b42d-2b9168b9fbd6:volume]:2048, allocat
ed: {}) on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 from framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:14.221484 18265 hierarchical.cpp:1264] Framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 filtered agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for 5secs
I0709 22:11:14.224418 18263 master.cpp:12458] Sending operation '' (uuid: 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1) to agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:14.224934 18266 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:14.227852 18275 provider.cpp:481] Received APPLY_OPERATION event
I0709 22:11:14.227895 18275 provider.cpp:1295] Received DESTROY operation '' (uuid: 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1)
I0709 22:11:14.235805 18268 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.193599ms
I0709 22:11:14.236570 18264 master.cpp:10285] Sending offers [ e1a2c8b8-da36-483c-80a7-699cbba21f25-O5 ] to framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:14.237248 18273 sched.cpp:934] Scheduler::resourceOffers took 75130ns
I0709 22:11:14.346268 18262 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: cbacae3a-e71d-4aeb-8c86-d64d71e427a2) for operation UUID 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:14.346336 18262 status_update_manager_process.hpp:414] Creating operation status update stream 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1 checkpoint=true
I0709 22:11:14.346834 18262 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: cbacae3a-e71d-4aeb-8c86-d64d71e427a2) for operation UUID 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:14.413264 18262 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: cbacae3a-e71d-4aeb-8c86-d64d71e427a2) for operation UUID 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:14.414055 18276 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:14.415081 18271 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 22:11:14.418292 18279 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0709 22:11:14.419926 18280 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.2:53018
I0709 22:11:14.420152 18280 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0709 22:11:14.420781 18280 master.cpp:3815] Authorizing principal 'test-principal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7","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":"d3f0df67-ab2e-4b8a-9e00-6a1982d89715"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0709 22:11:14.422708 18260 master.cpp:12567] Removing offer e1a2c8b8-da36-483c-80a7-699cbba21f25-O5
I0709 22:11:14.422865 18264 sched.cpp:960] Rescinded offer e1a2c8b8-da36-483c-80a7-699cbba21f25-O5
I0709 22:11:14.422951 18264 sched.cpp:971] Scheduler::offerRescinded took 28328ns
I0709 22:11:14.423427 18268 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,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_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,test)]:2048, allocated: {}) on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 from framework e1a2c8b8-da36-48
3c-80a7-699cbba21f25-0000
I0709 22:11:14.423545 18268 hierarchical.cpp:1264] Framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 filtered agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 for 5secs
I0709 22:11:14.425799 18273 master.cpp:12458] Sending operation '' (uuid: 94753052-28b8-4dfb-9898-0b45c5f37c57) to agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:14.426314 18276 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:14.429023 18263 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.476728ms
I0709 22:11:14.429045 18270 provider.cpp:481] Received APPLY_OPERATION event
I0709 22:11:14.429102 18270 provider.cpp:1295] Received UNRESERVE operation '' (uuid: 94753052-28b8-4dfb-9898-0b45c5f37c57)
I0709 22:11:14.429730 18261 master.cpp:10285] Sending offers [ e1a2c8b8-da36-483c-80a7-699cbba21f25-O6 ] to framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:14.430312 18280 sched.cpp:934] Scheduler::resourceOffers took 73717ns
I0709 22:11:14.454510 18272 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.2:53008
I0709 22:11:14.455399 18273 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 22:11:14.455565 18273 slave.cpp:8670] Updating the state of operation with no ID (uuid: 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 22:11:14.455631 18273 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1) for an operator API call
I0709 22:11:14.456043 18262 master.cpp:12114] Updating the state of operation '' (uuid: 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 22:11:14.456609 18265 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:15.840085 18280 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 786b5134-1d72-4c5f-893d-fb49138b561f) for operation UUID 94753052-28b8-4dfb-9898-0b45c5f37c57 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:15.840165 18280 status_update_manager_process.hpp:414] Creating operation status update stream 94753052-28b8-4dfb-9898-0b45c5f37c57 checkpoint=true
I0709 22:11:15.840219 18270 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 22:11:15.840636 18280 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 786b5134-1d72-4c5f-893d-fb49138b561f) for operation UUID 94753052-28b8-4dfb-9898-0b45c5f37c57 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:15.940317 18280 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 786b5134-1d72-4c5f-893d-fb49138b561f) for operation UUID 94753052-28b8-4dfb-9898-0b45c5f37c57 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:15.940657 18280 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: cbacae3a-e71d-4aeb-8c86-d64d71e427a2) for stream 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1
I0709 22:11:15.940726 18280 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: cbacae3a-e71d-4aeb-8c86-d64d71e427a2) for operation UUID 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:15.941081 18259 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:15.942065 18268 process.cpp:3671] Handling HTTP event for process 'slave(1197)' with path: '/slave(1197)/api/v1/resource_provider'
I0709 22:11:15.982575 18271 http.cpp:1115] HTTP POST for /slave(1197)/api/v1/resource_provider from 172.17.0.2:53008
I0709 22:11:15.983412 18274 slave.cpp:8217] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 94753052-28b8-4dfb-9898-0b45c5f37c57) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0709 22:11:15.983588 18274 slave.cpp:8670] Updating the state of operation with no ID (uuid: 94753052-28b8-4dfb-9898-0b45c5f37c57) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0709 22:11:15.983659 18274 slave.cpp:8424] Forwarding status update of operation with no ID (operation_uuid: 94753052-28b8-4dfb-9898-0b45c5f37c57) for an operator API call
I0709 22:11:15.983984 18277 master.cpp:12114] Updating the state of operation '' (uuid: 94753052-28b8-4dfb-9898-0b45c5f37c57) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0709 22:11:15.984449 18266 slave.cpp:4198] Ignoring new checkpointed resources and operations identical to the current version
I0709 22:11:15.985762 18264 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0709 22:11:16.032121 18280 status_update_manager_process.hpp:490] Cleaning up operation status update stream 5063813d-e8fd-4d31-90a3-6f1ce95fc5a1
I0709 22:11:16.032330 18280 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 786b5134-1d72-4c5f-893d-fb49138b561f) for stream 94753052-28b8-4dfb-9898-0b45c5f37c57
I0709 22:11:16.032402 18280 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 786b5134-1d72-4c5f-893d-fb49138b561f) for operation UUID 94753052-28b8-4dfb-9898-0b45c5f37c57 on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:16.174257 18280 status_update_manager_process.hpp:490] Cleaning up operation status update stream 94753052-28b8-4dfb-9898-0b45c5f37c57
I0709 22:11:16.359683 18273 master.cpp:1410] Framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589 disconnected
I0709 22:11:16.359751 18273 master.cpp:3360] Deactivating framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:16.360456 18271 hierarchical.cpp:475] Deactivated framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:16.360970 18269 slave.cpp:912] Agent terminating
I0709 22:11:16.361047 18273 master.cpp:12567] Removing offer e1a2c8b8-da36-483c-80a7-699cbba21f25-O6
I0709 22:11:16.361148 18273 master.cpp:3337] Disconnecting framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:16.361213 18273 master.cpp:1425] Giving framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589 0ns to failover
I0709 22:11:16.361732 18271 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,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_C4ZL5j/2GB-bf15d377-cad5-4518-aedc-f12ae00ea5e7,test)]:2048, allocated: {}) on agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 from framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:16.361815 18269 manager.cpp:163] Terminating resource provider d3f0df67-ab2e-4b8a-9e00-6a1982d89715
I0709 22:11:16.362221 18275 master.cpp:1295] Agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228) disconnected
I0709 22:11:16.362251 18275 master.cpp:3397] Disconnecting agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:16.362325 18275 master.cpp:3416] Deactivating agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 at slave(1197)@172.17.0.2:40589 (c9834652b228)
I0709 22:11:16.362452 18262 hierarchical.cpp:799] Agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0 deactivated
I0709 22:11:16.362501 18275 master.cpp:10077] Framework failover timeout, removing framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
I0709 22:11:16.362529 18275 master.cpp:11069] Removing framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000 (default) at scheduler-b149e7a1-0971-49fc-9ea1-dcc37b2a22aa@172.17.0.2:40589
E0709 22:11:16.362821 18266 http_connection.hpp:452] End-Of-File received
I0709 22:11:16.362867 18278 hierarchical.cpp:1432] Allocation paused
I0709 22:11:16.363214 18278 hierarchical.cpp:417] Removed framework e1a2c8b8-da36-483c-80a7-699cbba21f25-0000
I0709 22:11:16.363258 18266 http_connection.hpp:217] Re-detecting endpoint
I0709 22:11:16.363314 18278 hierarchical.cpp:1442] Allocation resumed
I0709 22:11:16.363651 18266 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0709 22:11:16.363729 18266 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0709 22:11:16.363734 18270 provider.cpp:471] Disconnected from resource provider manager
I0709 22:11:16.363821 18266 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:16.363853 18268 status_update_manager_process.hpp:379] Pausing operation status update manager
I0709 22:11:16.365088 18276 containerizer.cpp:2575] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0709 22:11:16.365130 18276 containerizer.cpp:3277] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING
I0709 22:11:16.365471 18276 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 22:11:16.366397 18278 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:16.366875 18270 provider.cpp:459] Connected to resource provider manager
I0709 22:11:16.367383 18271 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:40589/slave(1197)/api/v1/resource_provider
I0709 22:11:16.367393 18260 hierarchical.cpp:1508] Performed allocation for 1 agents in 178014ns
I0709 22:11:16.368013 18283 process.cpp:2781] Returning '404 Not Found' for '/slave(1197)/api/v1/resource_provider'
E0709 22:11:16.369006 18266 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0709 22:11:16.418712 18281 hierarchical.cpp:1508] Performed allocation for 1 agents in 96910ns
I0709 22:11:16.468713 18275 containerizer.cpp:3116] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0709 22:11:16.469223 18280 hierarchical.cpp:1508] Performed allocation for 1 agents in 102894ns
I0709 22:11:16.470007 18282 provisioner.cpp:609] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 22:11:16.472103 18281 container_daemon.cpp:189] Invoking post-stop hook for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 22:11:16.472251 18277 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-VHi8m0/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0709 22:11:16.472458 18259 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0709 22:11:16.474400 18283 process.cpp:2781] Returning '404 Not Found' for '/slave(1197)/api/v1'
I0709 22:11:16.486601 18258 master.cpp:1135] Master terminating
I0709 22:11:16.487258 18259 hierarchical.cpp:775] Removed all filters for agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
I0709 22:11:16.487280 18259 hierarchical.cpp:650] Removed agent e1a2c8b8-da36-483c-80a7-699cbba21f25-S0
[ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (4899 ms)
[----------] 50 tests from CSIVersion/StorageLocalResourceProviderTest (138657 ms total)
[----------] Global test environment tear-down
[==========] 2267 tests from 216 test cases ran. (1121048 ms total)
[ PASSED ] 2266 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] CSIVersion/StorageLocalResourceProviderTest.RetryOperationStatusUpdateAfterRecovery/v0, where GetParam() = "v0"
1 FAILED TEST
YOU HAVE 32 DISABLED TESTS
I0709 22:11:16.592486 18283 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-1562704642-13967
Untagged: mesos-1562704642-13967:latest
Deleted: sha256:3f87af1992bb897d57caf40bac44e8e86df2fc9c722d58312b47857a8ebbc9dc
Deleted: sha256:f7c13edfdd7c37bf780070943db5801089ca135659c2eda28c6205150b07eacd
Deleted: sha256:8b19aaec6ae9ba82b7bce58c77528e17674d8b31176584625ac872a68892fdb4
Deleted: sha256:d364f275f0b8857fd96177d40d078f67b9f44da321c73697ba1e05e919e2579c
Deleted: sha256:801fba4ba95bd832213ccfc07e2bc755847efc7e7dd2f17efaed16852361fa88
Deleted: sha256:e6938baec349e01740bf864a846c49a53a530fd45fdb889f3ec08239dceba90d
Deleted: sha256:18ec24cb10e4cbbe354d63b6ec4343b885d43362279547677d8b528a4f76c8d4
Deleted: sha256:2e4ae3d924cbb8b397c6032ed3db712735cf9160442e3aa7dd40507d9b604adc
Deleted: sha256:73620412ad6fdd5d39bf56468c11b244e94000e9b2f866089e639449fdd57319
Deleted: sha256:110811cb8a6c0e970998228c1d0a1f5851b53db7a4bdde2c5b2e2dcd939989d7
Deleted: sha256:4089f94d8784d592c2e4a98aaee3d79bcbb058c2f0cc5d36ecf317fd78185646
Deleted: sha256:ad9abc916dda0eaff9bcafe511543e5ee09f5515fec2c99f8246a9c2fa63a235
Deleted: sha256:3dc2597d49fa9fce2689910308b31094dfaf0769de90730c9e42c2cde317cf66
Deleted: sha256:d87ac565c536d658d51de244027b7b4fc2e61af21f640fc27a9bacbefe94b9ed
Deleted: sha256:8ba19cdee88bf18e271d06fd6b3b8ada66f7c48659749a0457fdda638feddce9
Deleted: sha256:3d8dfaba93b8ebe63d4273d267503ce3c4aafc779398ad7d6f01c13554dcdfb2
Deleted: sha256:b9cb78879e2ceca67d7c4a5918c2bf3b7e4e62312d2508a39ef8828df5ba00d5
Deleted: sha256:c2a5108bf4be19aa6a730aa60ab6a74d6982982fdb43885da1dd16ad5a73ed5f
Deleted: sha256:7aa8cf225b45bd293a2a5577e409b835ae117b2492b66f691a1a69783f453e32
Deleted: sha256:6b15f844748fa118f18aa9ad8a3697af8fa8d28b218a140dd0fc44c52ef02f23
Deleted: sha256:75f33974f81e7cc531cce5f1a431561b8b9ed1a1ca65d8b4ada73f979c2425e8
Deleted: sha256:510dc40fe64573978b971462f848a7e847ce647cf8161669767100d8732cb08b
Deleted: sha256:8ce5ef6ca1a65538f24ad1d69b997a640c99bff01c2904420e0b1893d626c79c
Deleted: sha256:7f4a87c3c7b549c74bc1a104ab22e77757281bd338ef3922d684d9be06fd3a41
Deleted: sha256:7d7f6f77ab53a0da4d13b3152a71da7af311a4ea8f25e74ef94504858b94f70f
Deleted: sha256:83c7633f1c3d39bad7dd3538ca284ae7d801f33256cfca82403f0169e5a3e8a7
Deleted: sha256:81013b3a4c54dbeeddf167c752c2b62f340ebebbe8597340f1a1162294cae0f5
Deleted: sha256:a71ccfebf5f546f9806a3aaeb10ded3a224e96f6cf8ecb67b50398f701c854f0
Deleted: sha256:52a1688aab699fa4dd02d87f476616b8afa82cb7dc41f446503c792ea573888d
Deleted: sha256:2ab72a136f5e2cf0055fa6ccd17857931a6b9a1c09ca4fc2b9d75e35d859d966
Full log: https://builds.apache.org/job/Mesos-Reviewbot-Linux/2467/console
- Mesos Reviewbot
On July 9, 2019, 7:29 p.m., Joseph Wu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71041/
> -----------------------------------------------------------
>
> (Updated July 9, 2019, 7:29 p.m.)
>
>
> Review request for mesos, Benjamin Bannier, Benjamin Mahler, Greg Mann, and Vinod Kone.
>
>
> Bugs: MESOS-9814
> https://issues.apache.org/jira/browse/MESOS-9814
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This adds two cases which the master cannot deterministically enforce
> when using the DRAIN_AGENT call. The draining feature is currently
> incompatible with maintenance schedules and older versions of the
> Mesos agent. However, in both cases, an agent can reregister with
> incompatible info after starting to drain. Also, unreachable agents
> do not have enough info to enforce either case.
>
> These are unexpected cases and are not expected to cause any problems
> if circumvented. However, the agent draining feature is also not
> expected to work correctly if circumvented.
>
>
> Diffs
> -----
>
> src/master/http.cpp b42ebb953e0510e83ec6bd041cbddbeb8f60067c
>
>
> Diff: https://reviews.apache.org/r/71041/diff/1/
>
>
> Testing
> -------
>
> TODO
>
>
> Thanks,
>
> Joseph Wu
>
>
Re: Review Request 71041: Added best-effort validation for DRAIN_AGENT
master call.
Posted by Greg Mann <gr...@mesosphere.io>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71041/#review216458
-----------------------------------------------------------
Fix it, then Ship it!
src/master/http.cpp
Lines 3937-3969 (patched)
<https://reviews.apache.org/r/71041/#comment303695>
Could you add a TODO somewhere here to perform these checks on unreachable agents once we keep their full SlaveInfo? You could reference this JIRA: https://issues.apache.org/jira/browse/MESOS-9884
- Greg Mann
On July 9, 2019, 7:29 p.m., Joseph Wu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71041/
> -----------------------------------------------------------
>
> (Updated July 9, 2019, 7:29 p.m.)
>
>
> Review request for mesos, Benjamin Bannier, Benjamin Mahler, Greg Mann, and Vinod Kone.
>
>
> Bugs: MESOS-9814
> https://issues.apache.org/jira/browse/MESOS-9814
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This adds two cases which the master cannot deterministically enforce
> when using the DRAIN_AGENT call. The draining feature is currently
> incompatible with maintenance schedules and older versions of the
> Mesos agent. However, in both cases, an agent can reregister with
> incompatible info after starting to drain. Also, unreachable agents
> do not have enough info to enforce either case.
>
> These are unexpected cases and are not expected to cause any problems
> if circumvented. However, the agent draining feature is also not
> expected to work correctly if circumvented.
>
>
> Diffs
> -----
>
> src/master/http.cpp b42ebb953e0510e83ec6bd041cbddbeb8f60067c
>
>
> Diff: https://reviews.apache.org/r/71041/diff/1/
>
>
> Testing
> -------
>
> TODO
>
>
> Thanks,
>
> Joseph Wu
>
>
Re: Review Request 71041: Added best-effort validation for DRAIN_AGENT
master call.
Posted by Greg Mann <gr...@mesosphere.io>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71041/#review216501
-----------------------------------------------------------
src/master/http.cpp
Lines 3950 (patched)
<https://reviews.apache.org/r/71041/#comment303728>
This line assumes that the schedules are non-empty. We should guard this loop with a conditional to prevent a segfault.
- Greg Mann
On July 9, 2019, 7:29 p.m., Joseph Wu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71041/
> -----------------------------------------------------------
>
> (Updated July 9, 2019, 7:29 p.m.)
>
>
> Review request for mesos, Benjamin Bannier, Benjamin Mahler, Greg Mann, and Vinod Kone.
>
>
> Bugs: MESOS-9814
> https://issues.apache.org/jira/browse/MESOS-9814
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This adds two cases which the master cannot deterministically enforce
> when using the DRAIN_AGENT call. The draining feature is currently
> incompatible with maintenance schedules and older versions of the
> Mesos agent. However, in both cases, an agent can reregister with
> incompatible info after starting to drain. Also, unreachable agents
> do not have enough info to enforce either case.
>
> These are unexpected cases and are not expected to cause any problems
> if circumvented. However, the agent draining feature is also not
> expected to work correctly if circumvented.
>
>
> Diffs
> -----
>
> src/master/http.cpp b42ebb953e0510e83ec6bd041cbddbeb8f60067c
>
>
> Diff: https://reviews.apache.org/r/71041/diff/1/
>
>
> Testing
> -------
>
> TODO
>
>
> Thanks,
>
> Joseph Wu
>
>
Re: Review Request 71041: Added best-effort validation for DRAIN_AGENT
master call.
Posted by Greg Mann <gr...@mesosphere.io>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71041/#review216665
-----------------------------------------------------------
Ship it!
Ship It!
- Greg Mann
On July 11, 2019, 11:01 p.m., Joseph Wu wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71041/
> -----------------------------------------------------------
>
> (Updated July 11, 2019, 11:01 p.m.)
>
>
> Review request for mesos, Benjamin Bannier, Benjamin Mahler, Greg Mann, and Vinod Kone.
>
>
> Bugs: MESOS-9814
> https://issues.apache.org/jira/browse/MESOS-9814
>
>
> Repository: mesos
>
>
> Description
> -------
>
> This adds two cases which the master cannot deterministically enforce
> when using the DRAIN_AGENT call. The draining feature is currently
> incompatible with maintenance schedules and older versions of the
> Mesos agent. However, in both cases, an agent can reregister with
> incompatible info after starting to drain. Also, unreachable agents
> do not have enough info to enforce either case.
>
> These are unexpected cases and are not expected to cause any problems
> if circumvented. However, the agent draining feature is also not
> expected to work correctly if circumvented.
>
>
> Diffs
> -----
>
> src/master/http.cpp b42ebb953e0510e83ec6bd041cbddbeb8f60067c
>
>
> Diff: https://reviews.apache.org/r/71041/diff/2/
>
>
> Testing
> -------
>
> TODO
>
>
> Thanks,
>
> Joseph Wu
>
>
Re: Review Request 71041: Added best-effort validation for DRAIN_AGENT
master call.
Posted by Joseph Wu <jo...@mesosphere.io>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71041/
-----------------------------------------------------------
(Updated July 11, 2019, 4:01 p.m.)
Review request for mesos, Benjamin Bannier, Benjamin Mahler, Greg Mann, and Vinod Kone.
Changes
-------
Added TODO for MESOS-9884 + guard against empty maintenance schedules.
Bugs: MESOS-9814
https://issues.apache.org/jira/browse/MESOS-9814
Repository: mesos
Description
-------
This adds two cases which the master cannot deterministically enforce
when using the DRAIN_AGENT call. The draining feature is currently
incompatible with maintenance schedules and older versions of the
Mesos agent. However, in both cases, an agent can reregister with
incompatible info after starting to drain. Also, unreachable agents
do not have enough info to enforce either case.
These are unexpected cases and are not expected to cause any problems
if circumvented. However, the agent draining feature is also not
expected to work correctly if circumvented.
Diffs (updated)
-----
src/master/http.cpp b42ebb953e0510e83ec6bd041cbddbeb8f60067c
Diff: https://reviews.apache.org/r/71041/diff/2/
Changes: https://reviews.apache.org/r/71041/diff/1-2/
Testing
-------
TODO
Thanks,
Joseph Wu