----------------------------------------------------------- This is an automatically generated e-mail. To reply, visit: https://reviews.apache.org/r/72124/#review219566 -----------------------------------------------------------
Bad patch! Reviews applied: [72116, 72124] Failed command: ['bash', '-c', "set -o pipefail; export OS='ubuntu:16.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/jenkins/buildbot.sh 2>&1 | tee build_72124"] Error: ...<truncated>... atus UUID: 669821c1-5489-478b-80e8-1dd91595fcc9) for operation UUID 2ad6f8ef-7e07-4cb2-9ed6-6e4fedef7ac1 on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:48.713289 3212 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:35463/slave(1249)/api/v1/resource_provider I0213 04:26:48.714692 3207 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider' I0213 04:26:48.717862 3201 hierarchical.cpp:1853] Performed allocation for 1 agents in 1.105794ms I0213 04:26:48.718572 3205 master.cpp:9984] Sending offers [ 151edfad-ed42-4be7-ab8c-7ba386418c27-O3 ] to framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 (default) at [email protected]:35463 I0213 04:26:48.719197 3213 sched.cpp:934] Scheduler::resourceOffers took 80091ns I0213 04:26:48.722455 3202 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1' I0213 04:26:48.724655 3204 http.cpp:1405] HTTP POST for /master/api/v1 from 172.17.0.2:58734 I0213 04:26:48.724882 3204 http.cpp:277] Processing call CREATE_VOLUMES I0213 04:26:48.725682 3204 master.cpp:3712] Authorizing principal 'test-principal' to perform action CREATE_VOLUME on object {"value":"storage/default-role","resource":{"provider_id":{"value":"e6055421-9a82-47dd-a6f7-081093bd1dce"},"name":"disk","type":"SCALAR","scalar":{"value":2048.0},"reservations":[{"type":"DYNAMIC","role":"storage"},{"type":"DYNAMIC","role":"storage/default-role","principal":"test-principal"}],"disk":{"persistence":{"id":"6fbc7ae9-a342-48df-8cc9-e38c2c917e8f","principal":"test-principal"},"volume":{"mode":"RW","container_path":"volume"},"source":{"type":"MOUNT","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"vendor":"org.apache.mesos.csi.test.local","id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1qWwL/2GB-2dbf5c35-ae2d-4808-8b1a-51b3270cbd3e","profile":"test"}}}} I0213 04:26:48.727363 3213 sched.cpp:960] Rescinded offer 151edfad-ed42-4be7-ab8c-7ba386418c27-O3 I0213 04:26:48.727440 3213 sched.cpp:971] Scheduler::offerRescinded took 22012ns I0213 04:26:48.727886 3201 master.cpp:12283] Removing offer 151edfad-ed42-4be7-ab8c-7ba386418c27-O3 I0213 04:26:48.728142 3208 hierarchical.cpp:1576] Recovered ports(allocated: storage/default-role):[31000-32000]; disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1qWwL/2GB-2dbf5c35-ae2d-4808-8b1a-51b3270cbd3e,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1qWwL/2GB-2dbf5c35-ae2d-4808-8b1a-51b3270cbd3e,test)]:2048, offered or allocated: {}) on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 from framework 151ed fad-ed42-4be7-ab8c-7ba386418c27-0000 I0213 04:26:48.730003 3208 hierarchical.cpp:1625] Framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 filtered agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 for 5secs I0213 04:26:48.733232 3202 master.cpp:12148] Sending operation '' (uuid: 10892765-5e3f-429e-971d-91c24de982d1) to agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 at slave(1249)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:48.734086 3209 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version I0213 04:26:48.737071 3200 provider.cpp:498] Received APPLY_OPERATION event I0213 04:26:48.737115 3200 provider.cpp:1351] Received CREATE operation '' (uuid: 10892765-5e3f-429e-971d-91c24de982d1) I0213 04:26:48.740974 3214 master.cpp:5968] Processing REVIVE call for framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 (default) at [email protected]:35463 I0213 04:26:48.741410 3214 hierarchical.cpp:1721] Unsuppressed offers and cleared filters for roles { storage/default-role } of framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 I0213 04:26:48.742600 3214 hierarchical.cpp:1853] Performed allocation for 1 agents in 1.027555ms I0213 04:26:48.742954 3214 hierarchical.cpp:1853] Performed allocation for 1 agents in 137777ns I0213 04:26:48.743592 3212 master.cpp:9984] Sending offers [ 151edfad-ed42-4be7-ab8c-7ba386418c27-O4 ] to framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 (default) at [email protected]:35463 I0213 04:26:48.744463 3211 sched.cpp:934] Scheduler::resourceOffers took 104069ns I0213 04:26:48.757935 3203 http.cpp:1405] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.2:58728 I0213 04:26:48.758998 3205 slave.cpp:8597] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 2ad6f8ef-7e07-4cb2-9ed6-6e4fedef7ac1) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0213 04:26:48.759193 3205 slave.cpp:9050] Updating the state of operation with no ID (uuid: 2ad6f8ef-7e07-4cb2-9ed6-6e4fedef7ac1) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0213 04:26:48.759253 3205 slave.cpp:8804] Forwarding status update of operation with no ID (operation_uuid: 2ad6f8ef-7e07-4cb2-9ed6-6e4fedef7ac1) for an operator API call I0213 04:26:48.759621 3206 master.cpp:11800] Updating the state of operation '' (uuid: 2ad6f8ef-7e07-4cb2-9ed6-6e4fedef7ac1) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0213 04:26:48.760272 3202 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version I0213 04:26:48.855254 3205 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: a92444a0-5ce3-475c-a112-0cbb03225b0b) for operation UUID 10892765-5e3f-429e-971d-91c24de982d1 on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:48.855324 3205 status_update_manager_process.hpp:414] Creating operation status update stream 10892765-5e3f-429e-971d-91c24de982d1 checkpoint=true I0213 04:26:48.855330 3200 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event I0213 04:26:48.855583 3205 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: a92444a0-5ce3-475c-a112-0cbb03225b0b) for operation UUID 10892765-5e3f-429e-971d-91c24de982d1 on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:48.993577 3205 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: a92444a0-5ce3-475c-a112-0cbb03225b0b) for operation UUID 10892765-5e3f-429e-971d-91c24de982d1 on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:48.994222 3205 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 669821c1-5489-478b-80e8-1dd91595fcc9) for stream 2ad6f8ef-7e07-4cb2-9ed6-6e4fedef7ac1 I0213 04:26:48.994341 3205 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 669821c1-5489-478b-80e8-1dd91595fcc9) for operation UUID 2ad6f8ef-7e07-4cb2-9ed6-6e4fedef7ac1 on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:48.994956 3206 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:35463/slave(1249)/api/v1/resource_provider I0213 04:26:48.996517 3212 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider' I0213 04:26:49.037899 3213 http.cpp:1405] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.2:58728 I0213 04:26:49.038931 3204 slave.cpp:8597] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 10892765-5e3f-429e-971d-91c24de982d1) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0213 04:26:49.039180 3204 slave.cpp:9050] Updating the state of operation with no ID (uuid: 10892765-5e3f-429e-971d-91c24de982d1) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0213 04:26:49.039239 3204 slave.cpp:8804] Forwarding status update of operation with no ID (operation_uuid: 10892765-5e3f-429e-971d-91c24de982d1) for an operator API call I0213 04:26:49.039630 3200 master.cpp:11800] Updating the state of operation '' (uuid: 10892765-5e3f-429e-971d-91c24de982d1) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0213 04:26:49.040450 3206 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version I0213 04:26:49.042018 3213 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event I0213 04:26:49.072816 3205 status_update_manager_process.hpp:490] Cleaning up operation status update stream 2ad6f8ef-7e07-4cb2-9ed6-6e4fedef7ac1 I0213 04:26:49.073174 3205 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: a92444a0-5ce3-475c-a112-0cbb03225b0b) for stream 10892765-5e3f-429e-971d-91c24de982d1 I0213 04:26:49.073289 3205 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: a92444a0-5ce3-475c-a112-0cbb03225b0b) for operation UUID 10892765-5e3f-429e-971d-91c24de982d1 on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:49.123417 3205 status_update_manager_process.hpp:490] Cleaning up operation status update stream 10892765-5e3f-429e-971d-91c24de982d1 I0213 04:26:49.184592 3206 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1' I0213 04:26:49.186825 3202 http.cpp:1405] HTTP POST for /master/api/v1 from 172.17.0.2:58736 I0213 04:26:49.187237 3202 http.cpp:277] Processing call DESTROY_VOLUMES I0213 04:26:49.188421 3202 master.cpp:3712] Authorizing principal 'test-principal' to perform action DESTROY_VOLUME on object {"value":"test-principal","resource":{"provider_id":{"value":"e6055421-9a82-47dd-a6f7-081093bd1dce"},"name":"disk","type":"SCALAR","scalar":{"value":2048.0},"reservations":[{"type":"DYNAMIC","role":"storage"},{"type":"DYNAMIC","role":"storage/default-role","principal":"test-principal"}],"disk":{"persistence":{"id":"6fbc7ae9-a342-48df-8cc9-e38c2c917e8f","principal":"test-principal"},"volume":{"mode":"RW","container_path":"volume"},"source":{"type":"MOUNT","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"vendor":"org.apache.mesos.csi.test.local","id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1qWwL/2GB-2dbf5c35-ae2d-4808-8b1a-51b3270cbd3e","profile":"test"}}}} I0213 04:26:49.190248 3205 sched.cpp:960] Rescinded offer 151edfad-ed42-4be7-ab8c-7ba386418c27-O4 I0213 04:26:49.190357 3205 sched.cpp:971] Scheduler::offerRescinded took 32106ns I0213 04:26:49.190759 3204 master.cpp:12283] Removing offer 151edfad-ed42-4be7-ab8c-7ba386418c27-O4 I0213 04:26:49.190897 3203 hierarchical.cpp:1576] Recovered ports(allocated: storage/default-role):[31000-32000]; disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1qWwL/2GB-2dbf5c35-ae2d-4808-8b1a-51b3270cbd3e,test),6fbc7ae9-a342-48df-8cc9-e38c2c917e8f:volume]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1qWwL/2GB-2dbf5c35-ae2d-4808-8b1a-51b3270cbd3e,test),6fbc7ae9-a342-48df-8cc9-e38c2c917e8f:volume]:2048, offered or allocated: {}) on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 from framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 I0213 04:26:49.192636 3203 hierarchical.cpp:1625] Framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 filtered agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 for 5secs I0213 04:26:49.195909 3200 master.cpp:12148] Sending operation '' (uuid: 4011826d-c410-4135-87ae-4199e4647a9f) to agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 at slave(1249)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:49.196568 3206 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version I0213 04:26:49.199961 3214 provider.cpp:498] Received APPLY_OPERATION event I0213 04:26:49.200009 3214 provider.cpp:1351] Received DESTROY operation '' (uuid: 4011826d-c410-4135-87ae-4199e4647a9f) I0213 04:26:49.205132 3211 hierarchical.cpp:1853] Performed allocation for 1 agents in 1.499615ms I0213 04:26:49.205956 3212 master.cpp:9984] Sending offers [ 151edfad-ed42-4be7-ab8c-7ba386418c27-O5 ] to framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 (default) at [email protected]:35463 I0213 04:26:49.206737 3200 sched.cpp:934] Scheduler::resourceOffers took 95430ns I0213 04:26:49.274662 3215 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 26a001aa-2e5f-4783-afce-b7d6b29f80a7) for operation UUID 4011826d-c410-4135-87ae-4199e4647a9f on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:49.274830 3215 status_update_manager_process.hpp:414] Creating operation status update stream 4011826d-c410-4135-87ae-4199e4647a9f checkpoint=true I0213 04:26:49.275250 3215 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 26a001aa-2e5f-4783-afce-b7d6b29f80a7) for operation UUID 4011826d-c410-4135-87ae-4199e4647a9f on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:49.336695 3215 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 26a001aa-2e5f-4783-afce-b7d6b29f80a7) for operation UUID 4011826d-c410-4135-87ae-4199e4647a9f on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:49.338199 3206 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:35463/slave(1249)/api/v1/resource_provider I0213 04:26:49.339920 3207 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider' I0213 04:26:49.343899 3213 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1' I0213 04:26:49.346374 3212 http.cpp:1405] HTTP POST for /master/api/v1 from 172.17.0.2:58738 I0213 04:26:49.346715 3212 http.cpp:277] Processing call UNRESERVE_RESOURCES I0213 04:26:49.347602 3212 master.cpp:3712] Authorizing principal 'test-principal' to perform action UNRESERVE_RESOURCES on object {"value":"test-principal","resource":{"provider_id":{"value":"e6055421-9a82-47dd-a6f7-081093bd1dce"},"name":"disk","type":"SCALAR","scalar":{"value":2048.0},"reservations":[{"type":"DYNAMIC","role":"storage"},{"type":"DYNAMIC","role":"storage/default-role","principal":"test-principal"}],"disk":{"source":{"type":"MOUNT","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"vendor":"org.apache.mesos.csi.test.local","id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1qWwL/2GB-2dbf5c35-ae2d-4808-8b1a-51b3270cbd3e","profile":"test"}}}} I0213 04:26:49.349293 3210 sched.cpp:960] Rescinded offer 151edfad-ed42-4be7-ab8c-7ba386418c27-O5 I0213 04:26:49.349404 3210 sched.cpp:971] Scheduler::offerRescinded took 30767ns I0213 04:26:49.349872 3206 master.cpp:12283] Removing offer 151edfad-ed42-4be7-ab8c-7ba386418c27-O5 I0213 04:26:49.349825 3207 hierarchical.cpp:1576] Recovered ports(allocated: storage/default-role):[31000-32000]; disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1qWwL/2GB-2dbf5c35-ae2d-4808-8b1a-51b3270cbd3e,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1qWwL/2GB-2dbf5c35-ae2d-4808-8b1a-51b3270cbd3e,test)]:2048, offered or allocated: {}) on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 from framework 151ed fad-ed42-4be7-ab8c-7ba386418c27-0000 I0213 04:26:49.351501 3207 hierarchical.cpp:1625] Framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 filtered agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 for 5secs I0213 04:26:49.354372 3208 master.cpp:12148] Sending operation '' (uuid: d9ae65aa-c6ed-4ca8-8f94-da8762379579) to agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 at slave(1249)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:49.355154 3211 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version I0213 04:26:49.358501 3205 provider.cpp:498] Received APPLY_OPERATION event I0213 04:26:49.358569 3205 provider.cpp:1351] Received UNRESERVE operation '' (uuid: d9ae65aa-c6ed-4ca8-8f94-da8762379579) I0213 04:26:49.364490 3213 hierarchical.cpp:1853] Performed allocation for 1 agents in 1.339321ms I0213 04:26:49.365231 3208 master.cpp:9984] Sending offers [ 151edfad-ed42-4be7-ab8c-7ba386418c27-O6 ] to framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 (default) at [email protected]:35463 I0213 04:26:49.365917 3208 sched.cpp:934] Scheduler::resourceOffers took 89456ns I0213 04:26:49.381501 3201 http.cpp:1405] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.2:58728 I0213 04:26:49.382490 3210 slave.cpp:8597] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 4011826d-c410-4135-87ae-4199e4647a9f) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0213 04:26:49.382668 3210 slave.cpp:9050] Updating the state of operation with no ID (uuid: 4011826d-c410-4135-87ae-4199e4647a9f) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0213 04:26:49.382711 3210 slave.cpp:8804] Forwarding status update of operation with no ID (operation_uuid: 4011826d-c410-4135-87ae-4199e4647a9f) for an operator API call I0213 04:26:49.383102 3214 master.cpp:11800] Updating the state of operation '' (uuid: 4011826d-c410-4135-87ae-4199e4647a9f) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0213 04:26:49.383754 3207 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version I0213 04:26:49.458861 3210 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 5e7b641c-0c2b-43b6-bf40-a6cd8183f977) for operation UUID d9ae65aa-c6ed-4ca8-8f94-da8762379579 on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:49.458920 3210 status_update_manager_process.hpp:414] Creating operation status update stream d9ae65aa-c6ed-4ca8-8f94-da8762379579 checkpoint=true I0213 04:26:49.459008 3205 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event I0213 04:26:49.459226 3210 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 5e7b641c-0c2b-43b6-bf40-a6cd8183f977) for operation UUID d9ae65aa-c6ed-4ca8-8f94-da8762379579 on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:49.534001 3210 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 5e7b641c-0c2b-43b6-bf40-a6cd8183f977) for operation UUID d9ae65aa-c6ed-4ca8-8f94-da8762379579 on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:49.534304 3210 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 26a001aa-2e5f-4783-afce-b7d6b29f80a7) for stream 4011826d-c410-4135-87ae-4199e4647a9f I0213 04:26:49.534384 3210 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 26a001aa-2e5f-4783-afce-b7d6b29f80a7) for operation UUID 4011826d-c410-4135-87ae-4199e4647a9f on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:49.534688 3213 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:35463/slave(1249)/api/v1/resource_provider I0213 04:26:49.535948 3202 process.cpp:3671] Handling HTTP event for process 'slave(1249)' with path: '/slave(1249)/api/v1/resource_provider' I0213 04:26:49.577675 3211 http.cpp:1405] HTTP POST for /slave(1249)/api/v1/resource_provider from 172.17.0.2:58728 I0213 04:26:49.578591 3206 slave.cpp:8597] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: d9ae65aa-c6ed-4ca8-8f94-da8762379579) for framework (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0213 04:26:49.578894 3206 slave.cpp:9050] Updating the state of operation with no ID (uuid: d9ae65aa-c6ed-4ca8-8f94-da8762379579) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0213 04:26:49.578971 3206 slave.cpp:8804] Forwarding status update of operation with no ID (operation_uuid: d9ae65aa-c6ed-4ca8-8f94-da8762379579) for an operator API call I0213 04:26:49.579349 3201 master.cpp:11800] Updating the state of operation '' (uuid: d9ae65aa-c6ed-4ca8-8f94-da8762379579) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0213 04:26:49.579838 3214 slave.cpp:4466] Ignoring new checkpointed resources and operations identical to the current version I0213 04:26:49.581287 3212 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event I0213 04:26:49.582345 3210 status_update_manager_process.hpp:490] Cleaning up operation status update stream 4011826d-c410-4135-87ae-4199e4647a9f I0213 04:26:49.582538 3210 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 5e7b641c-0c2b-43b6-bf40-a6cd8183f977) for stream d9ae65aa-c6ed-4ca8-8f94-da8762379579 I0213 04:26:49.582602 3210 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 5e7b641c-0c2b-43b6-bf40-a6cd8183f977) for operation UUID d9ae65aa-c6ed-4ca8-8f94-da8762379579 on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:49.633093 3210 status_update_manager_process.hpp:490] Cleaning up operation status update stream d9ae65aa-c6ed-4ca8-8f94-da8762379579 I0213 04:26:49.684736 3206 master.cpp:1414] Framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 (default) at [email protected]:35463 disconnected I0213 04:26:49.684798 3206 master.cpp:3333] Deactivating framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 (default) at [email protected]:35463 I0213 04:26:49.685256 3203 hierarchical.cpp:813] Deactivated framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 I0213 04:26:49.685847 3199 slave.cpp:995] Agent terminating I0213 04:26:49.685974 3203 hierarchical.cpp:1576] Recovered ports(allocated: storage/default-role):[31000-32000]; disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1qWwL/2GB-2dbf5c35-ae2d-4808-8b1a-51b3270cbd3e,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_u1qWwL/2GB-2dbf5c35-ae2d-4808-8b1a-51b3270cbd3e,test)]:2048, offered or allocated: {}) on agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 from framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 I0213 04:26:49.686148 3206 master.cpp:12283] Removing offer 151edfad-ed42-4be7-ab8c-7ba386418c27-O6 I0213 04:26:49.686264 3206 master.cpp:3310] Disconnecting framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 (default) at [email protected]:35463 I0213 04:26:49.686338 3206 master.cpp:1429] Giving framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 (default) at [email protected]:35463 0ns to failover I0213 04:26:49.686923 3199 manager.cpp:127] Terminating resource provider e6055421-9a82-47dd-a6f7-081093bd1dce I0213 04:26:49.687378 3200 master.cpp:1299] Agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 at slave(1249)@172.17.0.2:35463 (9a146ed47ce9) disconnected I0213 04:26:49.687417 3200 master.cpp:3368] Disconnecting agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 at slave(1249)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:49.687517 3200 master.cpp:3387] Deactivating agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 at slave(1249)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:49.687747 3200 master.cpp:9770] Framework failover timeout, removing framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 (default) at [email protected]:35463 I0213 04:26:49.687786 3200 master.cpp:10772] Removing framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 (default) at [email protected]:35463 E0213 04:26:49.688015 3211 http_connection.hpp:449] End-Of-File received I0213 04:26:49.688069 3203 hierarchical.cpp:1156] Agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 deactivated I0213 04:26:49.688297 3201 hierarchical.cpp:1777] Allocation paused I0213 04:26:49.688580 3211 http_connection.hpp:217] Re-detecting endpoint I0213 04:26:49.688735 3201 hierarchical.cpp:757] Removed framework 151edfad-ed42-4be7-ab8c-7ba386418c27-0000 I0213 04:26:49.688848 3201 hierarchical.cpp:1787] Allocation resumed I0213 04:26:49.689106 3211 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0213 04:26:49.689172 3211 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0213 04:26:49.689210 3209 provider.cpp:488] Disconnected from resource provider manager I0213 04:26:49.689249 3211 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:35463/slave(1249)/api/v1/resource_provider I0213 04:26:49.689313 3214 status_update_manager_process.hpp:379] Pausing operation status update manager I0213 04:26:49.690642 3213 containerizer.cpp:2619] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state I0213 04:26:49.690708 3213 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 2.497627008secs I0213 04:26:49.691169 3213 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:49.692636 3210 hierarchical.cpp:1853] Performed allocation for 1 agents in 179223ns I0213 04:26:49.692984 3212 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:35463/slave(1249)/api/v1/resource_provider I0213 04:26:49.693608 3202 provider.cpp:476] Connected to resource provider manager I0213 04:26:49.694547 3206 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:35463/slave(1249)/api/v1/resource_provider I0213 04:26:49.695549 3216 process.cpp:2781] Returning '404 Not Found' for '/slave(1249)/api/v1/resource_provider' E0213 04:26:49.696811 3204 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' () I0213 04:26:49.743690 3205 hierarchical.cpp:1853] Performed allocation for 1 agents in 144859ns I0213 04:26:49.795258 3211 containerizer.cpp:3155] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited I0213 04:26:49.795437 3201 hierarchical.cpp:1853] Performed allocation for 1 agents in 138246ns I0213 04:26:49.797081 3213 provisioner.cpp:652] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:49.799796 3215 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' I0213 04:26:49.800132 3207 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-3UGeYg/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:49.800458 3207 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:49.803198 3216 process.cpp:2781] Returning '404 Not Found' for '/slave(1249)/api/v1' I0213 04:26:49.816155 3199 master.cpp:1140] Master terminating I0213 04:26:49.817059 3215 hierarchical.cpp:1132] Removed all filters for agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 I0213 04:26:49.817090 3215 hierarchical.cpp:1008] Removed agent 151edfad-ed42-4be7-ab8c-7ba386418c27-S0 [ OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (2382 ms) [ RUN ] CSIVersion/StorageLocalResourceProviderTest.Update/v0 I0213 04:26:49.831480 3199 cluster.cpp:186] Creating default 'local' authorizer I0213 04:26:49.836259 3203 master.cpp:443] Master d56eed47-9d96-441a-ad11-41e6d963193e (9a146ed47ce9) started on 172.17.0.2:35463 I0213 04:26:49.836305 3203 master.cpp:446] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/uZpIWb/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_alloca table_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.10.0/_inst/share/mesos/webui" --work_dir="/tmp/uZpIWb/master" --zk_session_timeout="10secs" I0213 04:26:49.837040 3203 master.cpp:495] Master only allowing authenticated frameworks to register I0213 04:26:49.837102 3203 master.cpp:501] Master only allowing authenticated agents to register I0213 04:26:49.837152 3203 master.cpp:507] Master only allowing authenticated HTTP frameworks to register I0213 04:26:49.837178 3203 credentials.hpp:37] Loading credentials for authentication from '/tmp/uZpIWb/credentials' I0213 04:26:49.837702 3203 master.cpp:551] Using default 'crammd5' authenticator I0213 04:26:49.838032 3203 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0213 04:26:49.838376 3203 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0213 04:26:49.838670 3203 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0213 04:26:49.838951 3203 master.cpp:632] Authorization enabled I0213 04:26:49.839534 3202 hierarchical.cpp:567] Initialized hierarchical allocator process I0213 04:26:49.839587 3210 whitelist_watcher.cpp:77] No whitelist given I0213 04:26:49.844841 3213 master.cpp:2172] Elected as the leading master! I0213 04:26:49.844880 3213 master.cpp:1668] Recovering from registrar I0213 04:26:49.845137 3209 registrar.cpp:339] Recovering registrar I0213 04:26:49.846180 3209 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns I0213 04:26:49.846326 3209 registrar.cpp:487] Applied 1 operations in 54439ns; attempting to update the registry I0213 04:26:49.847141 3209 registrar.cpp:544] Successfully updated the registry in 0ns I0213 04:26:49.847275 3209 registrar.cpp:416] Successfully recovered registrar I0213 04:26:49.847839 3212 master.cpp:1821] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister I0213 04:26:49.847890 3208 hierarchical.cpp:606] Skipping recovery of hierarchical allocator: nothing to recover W0213 04:26:49.853590 3199 process.cpp:2877] Attempted to spawn already running process [email protected]:35463 I0213 04:26:49.855123 3199 containerizer.cpp:317] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } W0213 04:26:49.855664 3199 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges W0213 04:26:49.855690 3199 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges W0213 04:26:49.855705 3199 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges I0213 04:26:49.855736 3199 provisioner.cpp:294] Using default backend 'copy' I0213 04:26:49.858400 3199 cluster.cpp:533] Creating default 'local' authorizer I0213 04:26:49.860903 3206 slave.cpp:274] Mesos agent started on (1250)@172.17.0.2:35463 I0213 04:26:49.860937 3206 slave.cpp:275] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/uZpIWb/idRNma/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/uZpIWb/idRNma/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/uZpIWb/idRNma/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/uZpIWb/idRNma/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/uZpIWb/idRNma/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/uZpIWb/idRNma/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posi x" --launcher_dir="/tmp/SRC/build/mesos-1.10.0/_build/sub/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/uZpIWb/resource_provider_configs" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_FKJjfq" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/CSIVersion_StorageLoca lResourceProviderTest_Update_v0_GYiQ7F" --zk_session_timeout="10secs" I0213 04:26:49.861574 3206 credentials.hpp:86] Loading credential for authentication from '/tmp/uZpIWb/idRNma/credential' I0213 04:26:49.861781 3206 slave.cpp:307] Agent using credential for: test-principal I0213 04:26:49.861810 3206 credentials.hpp:37] Loading credentials for authentication from '/tmp/uZpIWb/idRNma/http_credentials' I0213 04:26:49.862105 3206 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0213 04:26:49.862608 3206 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor' I0213 04:26:49.864470 3203 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles I0213 04:26:49.864526 3206 slave.cpp:622] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] I0213 04:26:49.864791 3206 slave.cpp:630] Agent attributes: [ ] I0213 04:26:49.864820 3206 slave.cpp:639] Agent hostname: 9a146ed47ce9 I0213 04:26:49.865046 3215 status_update_manager_process.hpp:379] Pausing operation status update manager I0213 04:26:49.865116 3205 task_status_update_manager.cpp:181] Pausing sending task status updates I0213 04:26:49.866847 3207 state.cpp:68] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_GYiQ7F/meta' I0213 04:26:49.867115 3204 slave.cpp:7606] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_GYiQ7F/meta', beginning agent recovery I0213 04:26:49.867835 3210 task_status_update_manager.cpp:207] Recovering task status update manager I0213 04:26:49.868147 3201 hierarchical.cpp:1853] Performed allocation for 0 agents in 108646ns I0213 04:26:49.868366 3212 containerizer.cpp:820] Recovering Mesos containers I0213 04:26:49.868818 3212 containerizer.cpp:1160] Recovering isolators I0213 04:26:49.869772 3204 containerizer.cpp:1199] Recovering provisioner I0213 04:26:49.870668 3201 provisioner.cpp:518] Provisioner recovery complete I0213 04:26:49.871513 3205 composing.cpp:339] Finished recovering all containerizers I0213 04:26:49.871866 3212 slave.cpp:8088] Recovering executors I0213 04:26:49.872027 3212 slave.cpp:8241] Finished recovery I0213 04:26:49.872931 3214 task_status_update_manager.cpp:181] Pausing sending task status updates I0213 04:26:49.872951 3202 status_update_manager_process.hpp:379] Pausing operation status update manager I0213 04:26:49.872974 3204 slave.cpp:1454] New master detected at [email protected]:35463 I0213 04:26:49.873129 3204 slave.cpp:1519] Detecting new master I0213 04:26:49.882612 3213 slave.cpp:1546] Authenticating with master [email protected]:35463 I0213 04:26:49.882726 3213 slave.cpp:1555] Using default CRAM-MD5 authenticatee I0213 04:26:49.883085 3200 authenticatee.cpp:121] Creating new client SASL connection I0213 04:26:49.883440 3201 master.cpp:10169] Authenticating slave(1250)@172.17.0.2:35463 I0213 04:26:49.883658 3211 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2109)@172.17.0.2:35463 I0213 04:26:49.884167 3207 authenticator.cpp:98] Creating new server SASL connection I0213 04:26:49.884423 3205 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0213 04:26:49.884467 3205 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0213 04:26:49.884634 3203 authenticator.cpp:204] Received SASL authentication start I0213 04:26:49.884722 3203 authenticator.cpp:326] Authentication requires more steps I0213 04:26:49.884892 3203 authenticatee.cpp:259] Received SASL authentication step I0213 04:26:49.885079 3212 authenticator.cpp:232] Received SASL authentication step I0213 04:26:49.885125 3212 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9a146ed47ce9' server FQDN: '9a146ed47ce9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0213 04:26:49.885146 3212 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0213 04:26:49.885200 3212 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0213 04:26:49.885234 3212 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9a146ed47ce9' server FQDN: '9a146ed47ce9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0213 04:26:49.885253 3212 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0213 04:26:49.885264 3212 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0213 04:26:49.885287 3212 authenticator.cpp:318] Authentication success I0213 04:26:49.885416 3210 authenticatee.cpp:299] Authentication success I0213 04:26:49.885527 3208 master.cpp:10201] Successfully authenticated principal 'test-principal' at slave(1250)@172.17.0.2:35463 I0213 04:26:49.885565 3214 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2109)@172.17.0.2:35463 I0213 04:26:49.886005 3212 slave.cpp:1646] Successfully authenticated with master [email protected]:35463 I0213 04:26:49.886476 3212 slave.cpp:2096] Will retry registration in 5.413136ms if necessary I0213 04:26:49.886664 3201 master.cpp:6639] Received register agent message from slave(1250)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:49.887115 3201 master.cpp:3712] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object I0213 04:26:49.887976 3209 master.cpp:6706] Authorized registration of agent at slave(1250)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:49.888106 3209 master.cpp:6818] Registering agent at slave(1250)@172.17.0.2:35463 (9a146ed47ce9) with id d56eed47-9d96-441a-ad11-41e6d963193e-S0 I0213 04:26:49.888957 3202 registrar.cpp:487] Applied 1 operations in 288761ns; attempting to update the registry I0213 04:26:49.889698 3213 registrar.cpp:544] Successfully updated the registry in 663040ns I0213 04:26:49.889919 3200 master.cpp:6866] Admitted agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 at slave(1250)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:49.890785 3200 master.cpp:6911] Registered agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 at slave(1250)@172.17.0.2:35463 (9a146ed47ce9) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0213 04:26:49.890954 3214 slave.cpp:1679] Registered with master [email protected]:35463; given agent ID d56eed47-9d96-441a-ad11-41e6d963193e-S0 I0213 04:26:49.891089 3212 hierarchical.cpp:959] Added agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 (9a146ed47ce9) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {}) I0213 04:26:49.891144 3201 task_status_update_manager.cpp:188] Resuming sending task status updates I0213 04:26:49.891476 3214 slave.cpp:1714] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_GYiQ7F/meta/slaves/d56eed47-9d96-441a-ad11-41e6d963193e-S0/slave.info' I0213 04:26:49.891482 3212 hierarchical.cpp:1853] Performed allocation for 1 agents in 164176ns I0213 04:26:49.891608 3205 status_update_manager_process.hpp:385] Resuming operation status update manager I0213 04:26:49.892967 3214 slave.cpp:1766] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"K/nFeOm0Quys9WAz1IbiYA=="},"slave_id":{"value":"d56eed47-9d96-441a-ad11-41e6d963193e-S0"},"update_oversubscribed_resources":false} I0213 04:26:49.893788 3204 master.cpp:8049] Ignoring update on agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 at slave(1250)@172.17.0.2:35463 (9a146ed47ce9) as it reports no changes I0213 04:26:49.898011 3212 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1' I0213 04:26:49.899482 3213 http.cpp:1405] HTTP POST for /slave(1250)/api/v1 from 172.17.0.2:58746 I0213 04:26:49.900028 3213 http.cpp:2146] Processing GET_CONTAINERS call I0213 04:26:49.906186 3213 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:49.908845 3210 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1' I0213 04:26:49.910040 3209 http.cpp:1405] HTTP POST for /slave(1250)/api/v1 from 172.17.0.2:58748 I0213 04:26:49.910943 3209 http.cpp:2606] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:49.911972 3214 http.cpp:2710] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_GYiQ7F/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:49.920094 3208 hierarchical.cpp:1853] Performed allocation for 1 agents in 157365ns I0213 04:26:49.943642 3213 containerizer.cpp:1395] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:49.944270 3213 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from STARTING to PROVISIONING after 232960ns I0213 04:26:49.944917 3213 containerizer.cpp:1573] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_FKJjfq/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config' I0213 04:26:49.944967 3213 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PROVISIONING to PREPARING after 698112ns I0213 04:26:49.947528 3205 containerizer.cpp:2099] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_BR0n0V","--available_capacity=0B","--volumes=","--forward=unix:///tmp/uZpIWb/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_GYiQ7F/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-v40Ci9/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_GYiQ7F/containers/o rg-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="108" --pipe_write="109" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_FKJjfq/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"' I0213 04:26:49.956470 3205 launcher.cpp:145] Forked child with pid '14810' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:49.957469 3205 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PREPARING to ISOLATING after 12.489984ms I0213 04:26:49.958994 3205 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from ISOLATING to FETCHING after 1.529088ms I0213 04:26:49.959386 3201 fetcher.cpp:369] Starting to fetch URIs for container: org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE, directory: /tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_GYiQ7F/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:49.971487 3203 hierarchical.cpp:1853] Performed allocation for 1 agents in 212351ns I0213 04:26:49.986850 3206 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from FETCHING to RUNNING after 27.823872ms I0213 04:26:49.989017 3200 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' I0213 04:26:49.989248 3213 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-v40Ci9/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:50.023263 3215 hierarchical.cpp:1853] Performed allocation for 1 agents in 218291ns I0213 04:26:50.075073 3204 hierarchical.cpp:1853] Performed allocation for 1 agents in 313642ns I0213 04:26:50.126235 3201 hierarchical.cpp:1853] Performed allocation for 1 agents in 140427ns I0213 04:26:50.178263 3214 hierarchical.cpp:1853] Performed allocation for 1 agents in 227700ns I0213 04:26:50.229642 3213 hierarchical.cpp:1853] Performed allocation for 1 agents in 170198ns I0213 04:26:50.281378 3212 hierarchical.cpp:1853] Performed allocation for 1 agents in 186752ns I0213 04:26:50.300426 3204 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-v40Ci9/endpoint.sock' with CSI v1 I0213 04:26:50.303153 3205 service_manager.cpp:532] Probing endpoint 'unix:///tmp/mesos-csi-v40Ci9/endpoint.sock' with CSI v0 I0213 04:26:50.304383 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/Probe call I0213 04:26:50.307516 3207 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:50.310528 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginCapabilities call I0213 04:26:50.311131 3202 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1' I0213 04:26:50.312417 3200 http.cpp:1405] HTTP POST for /slave(1250)/api/v1 from 172.17.0.2:58750 I0213 04:26:50.312952 3200 http.cpp:2824] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:50.315188 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginInfo call I0213 04:26:50.315517 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Identity/GetPluginInfo call I0213 04:26:50.317335 3203 v0_volume_manager.cpp:628] NODE_SERVICE loaded: {} I0213 04:26:50.317982 3203 v0_volume_manager.cpp:628] CONTROLLER_SERVICE loaded: {} I0213 04:26:50.320160 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ControllerGetCapabilities call I0213 04:26:50.323884 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Node/NodeGetCapabilities call I0213 04:26:50.327433 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Node/NodeGetId call I0213 04:26:50.329864 3203 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test' I0213 04:26:50.330047 3212 status_update_manager_process.hpp:379] Pausing operation status update manager I0213 04:26:50.330420 3206 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:35463/slave(1250)/api/v1/resource_provider I0213 04:26:50.332549 3214 hierarchical.cpp:1853] Performed allocation for 1 agents in 182384ns I0213 04:26:50.333824 3211 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:35463/slave(1250)/api/v1/resource_provider I0213 04:26:50.334504 3215 provider.cpp:476] Connected to resource provider manager I0213 04:26:50.335208 3204 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:35463/slave(1250)/api/v1/resource_provider I0213 04:26:50.336412 3203 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1/resource_provider' I0213 04:26:50.338235 3207 http.cpp:1405] HTTP POST for /slave(1250)/api/v1/resource_provider from 172.17.0.2:58754 I0213 04:26:50.338939 3207 manager.cpp:779] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_BR0n0V","--available_capacity=0B","--volumes=","--forward=unix:///tmp/uZpIWb/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"} I0213 04:26:50.384809 3206 hierarchical.cpp:1853] Performed allocation for 1 agents in 154819ns I0213 04:26:50.386968 3214 slave.cpp:8597] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"d9598664-0e4a-47fb-b853-013755d81a7e"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v0","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v0_BR0n0V","--available_capacity=0B","--volumes=","--forward=unix:///tmp/uZpIWb/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}' I0213 04:26:50.388593 3215 provider.cpp:498] Received SUBSCRIBED event I0213 04:26:50.388646 3215 provider.cpp:1309] Subscribed with ID d9598664-0e4a-47fb-b853-013755d81a7e I0213 04:26:50.389500 3204 status_update_manager_process.hpp:314] Recovering operation status update manager I0213 04:26:50.428577 3206 provider.cpp:790] Reconciling storage pools and volumes I0213 04:26:50.431025 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call I0213 04:26:50.433893 3203 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 I0213 04:26:50.434182 3206 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.2:35463/slave(1250)/api/v1/resource_provider I0213 04:26:50.434242 3203 provider.cpp:748] Resource provider d9598664-0e4a-47fb-b853-013755d81a7e is in READY state I0213 04:26:50.434298 3210 status_update_manager_process.hpp:385] Resuming operation status update manager I0213 04:26:50.435017 3207 provider.cpp:1235] Updating profiles { test } for resource provider d9598664-0e4a-47fb-b853-013755d81a7e I0213 04:26:50.435533 3200 process.cpp:3671] Handling HTTP event for process 'slave(1250)' with path: '/slave(1250)/api/v1/resource_provider' I0213 04:26:50.436111 3211 provider.cpp:790] Reconciling storage pools and volumes I0213 04:26:50.437115 3202 http.cpp:1405] HTTP POST for /slave(1250)/api/v1/resource_provider from 172.17.0.2:58752 I0213 04:26:50.437641 3212 manager.cpp:1011] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider d9598664-0e4a-47fb-b853-013755d81a7e I0213 04:26:50.437674 3202 hierarchical.cpp:1853] Performed allocation for 1 agents in 200734ns I0213 04:26:50.437834 3205 slave.cpp:8597] Handling resource provider message 'UPDATE_STATE: d9598664-0e4a-47fb-b853-013755d81a7e {}' I0213 04:26:50.437934 3205 slave.cpp:8717] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0213 04:26:50.438290 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call I0213 04:26:50.438664 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/GetCapacity call I0213 04:26:50.439266 3214 hierarchical.cpp:1110] Grew agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 by {} (total), { } (used) I0213 04:26:50.439733 3214 hierarchical.cpp:1067] Agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 (9a146ed47ce9) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0213 04:26:50.444921 3210 hierarchical.cpp:1853] Performed allocation for 1 agents in 152503ns I0213 04:26:50.445353 3200 provider.cpp:790] Reconciling storage pools and volumes I0213 04:26:50.447358 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/ListVolumes call I0213 04:26:50.447849 14814 test_csi_plugin.cpp:1915] Forwarding /csi.v0.Controller/GetCapacity call I0213 04:26:50.458132 3203 slave.cpp:995] Agent terminating I0213 04:26:50.458765 3203 manager.cpp:127] Terminating resource provider d9598664-0e4a-47fb-b853-013755d81a7e I0213 04:26:50.459200 3208 master.cpp:1299] Agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 at slave(1250)@172.17.0.2:35463 (9a146ed47ce9) disconnected I0213 04:26:50.459233 3208 master.cpp:3368] Disconnecting agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 at slave(1250)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:50.459314 3208 master.cpp:3387] Deactivating agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 at slave(1250)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:50.459470 3206 hierarchical.cpp:1156] Agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 deactivated E0213 04:26:50.459745 3211 http_connection.hpp:449] End-Of-File received I0213 04:26:50.460325 3211 http_connection.hpp:217] Re-detecting endpoint I0213 04:26:50.460866 3211 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0213 04:26:50.460942 3211 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0213 04:26:50.460970 3207 provider.cpp:488] Disconnected from resource provider manager I0213 04:26:50.461004 3211 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:35463/slave(1250)/api/v1/resource_provider I0213 04:26:50.461077 3207 status_update_manager_process.hpp:379] Pausing operation status update manager I0213 04:26:50.462508 3202 containerizer.cpp:2619] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state I0213 04:26:50.462589 3202 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 15.47577088secs I0213 04:26:50.463042 3202 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:50.464071 3205 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:35463/slave(1250)/api/v1/resource_provider I0213 04:26:50.464577 3208 provider.cpp:476] Connected to resource provider manager I0213 04:26:50.465267 3211 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:35463/slave(1250)/api/v1/resource_provider I0213 04:26:50.466166 3216 process.cpp:2781] Returning '404 Not Found' for '/slave(1250)/api/v1/resource_provider' E0213 04:26:50.467377 3210 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' () I0213 04:26:50.490370 3212 hierarchical.cpp:1853] Performed allocation for 1 agents in 134589ns I0213 04:26:50.541518 3209 containerizer.cpp:3155] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited I0213 04:26:50.542019 3201 hierarchical.cpp:1853] Performed allocation for 1 agents in 148564ns I0213 04:26:50.543010 3202 provisioner.cpp:652] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:50.545491 3215 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' I0213 04:26:50.545796 3200 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-v40Ci9/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:50.546030 3200 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:50.548533 3216 process.cpp:2781] Returning '404 Not Found' for '/slave(1250)/api/v1' I0213 04:26:50.558240 3199 master.cpp:1140] Master terminating I0213 04:26:50.558620 3207 hierarchical.cpp:1132] Removed all filters for agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 I0213 04:26:50.558647 3207 hierarchical.cpp:1008] Removed agent d56eed47-9d96-441a-ad11-41e6d963193e-S0 [ OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v0 (740 ms) [ RUN ] CSIVersion/StorageLocalResourceProviderTest.Update/v1 I0213 04:26:50.572973 3199 cluster.cpp:186] Creating default 'local' authorizer I0213 04:26:50.577627 3209 master.cpp:443] Master 2aaecfe9-c3b2-42f7-ad25-f230400a92ce (9a146ed47ce9) started on 172.17.0.2:35463 I0213 04:26:50.577661 3209 master.cpp:446] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/N95WkG/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_alloca table_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/tmp/SRC/build/mesos-1.10.0/_inst/share/mesos/webui" --work_dir="/tmp/N95WkG/master" --zk_session_timeout="10secs" I0213 04:26:50.578114 3209 master.cpp:495] Master only allowing authenticated frameworks to register I0213 04:26:50.578138 3209 master.cpp:501] Master only allowing authenticated agents to register I0213 04:26:50.578153 3209 master.cpp:507] Master only allowing authenticated HTTP frameworks to register I0213 04:26:50.578169 3209 credentials.hpp:37] Loading credentials for authentication from '/tmp/N95WkG/credentials' I0213 04:26:50.578495 3209 master.cpp:551] Using default 'crammd5' authenticator I0213 04:26:50.578733 3209 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0213 04:26:50.578995 3209 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0213 04:26:50.579210 3209 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0213 04:26:50.579416 3209 master.cpp:632] Authorization enabled I0213 04:26:50.579905 3210 whitelist_watcher.cpp:77] No whitelist given I0213 04:26:50.580015 3201 hierarchical.cpp:567] Initialized hierarchical allocator process I0213 04:26:50.583278 3208 master.cpp:2172] Elected as the leading master! I0213 04:26:50.583315 3208 master.cpp:1668] Recovering from registrar I0213 04:26:50.583503 3204 registrar.cpp:339] Recovering registrar I0213 04:26:50.584357 3204 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns I0213 04:26:50.584503 3204 registrar.cpp:487] Applied 1 operations in 47690ns; attempting to update the registry I0213 04:26:50.585281 3204 registrar.cpp:544] Successfully updated the registry in 0ns I0213 04:26:50.585434 3204 registrar.cpp:416] Successfully recovered registrar I0213 04:26:50.585990 3201 master.cpp:1821] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister I0213 04:26:50.586043 3206 hierarchical.cpp:606] Skipping recovery of hierarchical allocator: nothing to recover W0213 04:26:50.591876 3199 process.cpp:2877] Attempted to spawn already running process [email protected]:35463 I0213 04:26:50.593216 3199 containerizer.cpp:317] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } W0213 04:26:50.593753 3199 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges W0213 04:26:50.593781 3199 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges W0213 04:26:50.593796 3199 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges I0213 04:26:50.593829 3199 provisioner.cpp:294] Using default backend 'copy' I0213 04:26:50.596448 3199 cluster.cpp:533] Creating default 'local' authorizer I0213 04:26:50.598861 3202 slave.cpp:274] Mesos agent started on (1251)@172.17.0.2:35463 I0213 04:26:50.598891 3202 slave.cpp:275] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/N95WkG/h9zbvM/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/N95WkG/h9zbvM/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/N95WkG/h9zbvM/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/N95WkG/h9zbvM/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/N95WkG/h9zbvM/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/N95WkG/h9zbvM/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posi x" --launcher_dir="/tmp/SRC/build/mesos-1.10.0/_build/sub/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/N95WkG/resource_provider_configs" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_MLmNr0" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/CSIVersion_StorageLoca lResourceProviderTest_Update_v1_ZyLpoe" --zk_session_timeout="10secs" I0213 04:26:50.599292 3202 credentials.hpp:86] Loading credential for authentication from '/tmp/N95WkG/h9zbvM/credential' I0213 04:26:50.599462 3202 slave.cpp:307] Agent using credential for: test-principal I0213 04:26:50.599485 3202 credentials.hpp:37] Loading credentials for authentication from '/tmp/N95WkG/h9zbvM/http_credentials' I0213 04:26:50.599685 3202 http.cpp:1265] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0213 04:26:50.600088 3202 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor' I0213 04:26:50.601589 3209 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles I0213 04:26:50.601541 3202 slave.cpp:622] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] I0213 04:26:50.601761 3202 slave.cpp:630] Agent attributes: [ ] I0213 04:26:50.601776 3202 slave.cpp:639] Agent hostname: 9a146ed47ce9 I0213 04:26:50.601900 3212 status_update_manager_process.hpp:379] Pausing operation status update manager I0213 04:26:50.601922 3208 task_status_update_manager.cpp:181] Pausing sending task status updates I0213 04:26:50.603401 3205 state.cpp:68] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_ZyLpoe/meta' I0213 04:26:50.603606 3211 slave.cpp:7606] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_ZyLpoe/meta', beginning agent recovery I0213 04:26:50.604264 3200 task_status_update_manager.cpp:207] Recovering task status update manager I0213 04:26:50.604914 3204 containerizer.cpp:820] Recovering Mesos containers I0213 04:26:50.605329 3204 containerizer.cpp:1160] Recovering isolators I0213 04:26:50.606374 3215 containerizer.cpp:1199] Recovering provisioner I0213 04:26:50.607285 3203 provisioner.cpp:518] Provisioner recovery complete I0213 04:26:50.608261 3214 composing.cpp:339] Finished recovering all containerizers I0213 04:26:50.608721 3213 slave.cpp:8088] Recovering executors I0213 04:26:50.608848 3213 slave.cpp:8241] Finished recovery I0213 04:26:50.609772 3215 task_status_update_manager.cpp:181] Pausing sending task status updates I0213 04:26:50.609798 3213 slave.cpp:1454] New master detected at [email protected]:35463 I0213 04:26:50.609805 3204 status_update_manager_process.hpp:379] Pausing operation status update manager I0213 04:26:50.609994 3213 slave.cpp:1519] Detecting new master I0213 04:26:50.610414 3201 hierarchical.cpp:1853] Performed allocation for 0 agents in 137611ns I0213 04:26:50.615479 3203 slave.cpp:1546] Authenticating with master [email protected]:35463 I0213 04:26:50.615594 3203 slave.cpp:1555] Using default CRAM-MD5 authenticatee I0213 04:26:50.616041 3212 authenticatee.cpp:121] Creating new client SASL connection I0213 04:26:50.616401 3212 master.cpp:10169] Authenticating slave(1251)@172.17.0.2:35463 I0213 04:26:50.616626 3202 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2110)@172.17.0.2:35463 I0213 04:26:50.617029 3214 authenticator.cpp:98] Creating new server SASL connection I0213 04:26:50.617285 3209 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0213 04:26:50.617326 3209 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0213 04:26:50.617487 3211 authenticator.cpp:204] Received SASL authentication start I0213 04:26:50.617571 3211 authenticator.cpp:326] Authentication requires more steps I0213 04:26:50.617704 3211 authenticatee.cpp:259] Received SASL authentication step I0213 04:26:50.617858 3211 authenticator.cpp:232] Received SASL authentication step I0213 04:26:50.617902 3211 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9a146ed47ce9' server FQDN: '9a146ed47ce9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0213 04:26:50.617933 3211 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0213 04:26:50.618000 3211 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0213 04:26:50.618050 3211 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9a146ed47ce9' server FQDN: '9a146ed47ce9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0213 04:26:50.618082 3211 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0213 04:26:50.618105 3211 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0213 04:26:50.618139 3211 authenticator.cpp:318] Authentication success I0213 04:26:50.618254 3206 authenticatee.cpp:299] Authentication success I0213 04:26:50.618382 3215 master.cpp:10201] Successfully authenticated principal 'test-principal' at slave(1251)@172.17.0.2:35463 I0213 04:26:50.618417 3213 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2110)@172.17.0.2:35463 I0213 04:26:50.618726 3211 slave.cpp:1646] Successfully authenticated with master [email protected]:35463 I0213 04:26:50.619205 3211 slave.cpp:2096] Will retry registration in 13.600561ms if necessary I0213 04:26:50.619458 3208 master.cpp:6639] Received register agent message from slave(1251)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:50.619933 3208 master.cpp:3712] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object I0213 04:26:50.620635 3209 master.cpp:6706] Authorized registration of agent at slave(1251)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:50.620769 3209 master.cpp:6818] Registering agent at slave(1251)@172.17.0.2:35463 (9a146ed47ce9) with id 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 I0213 04:26:50.621507 3205 registrar.cpp:487] Applied 1 operations in 255333ns; attempting to update the registry I0213 04:26:50.622318 3205 registrar.cpp:544] Successfully updated the registry in 730112ns I0213 04:26:50.622539 3206 master.cpp:6866] Admitted agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 at slave(1251)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:50.623423 3206 master.cpp:6911] Registered agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 at slave(1251)@172.17.0.2:35463 (9a146ed47ce9) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0213 04:26:50.623500 3213 slave.cpp:1679] Registered with master [email protected]:35463; given agent ID 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 I0213 04:26:50.623697 3202 task_status_update_manager.cpp:188] Resuming sending task status updates I0213 04:26:50.623695 3207 hierarchical.cpp:959] Added agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 (9a146ed47ce9) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {}) I0213 04:26:50.624122 3213 slave.cpp:1714] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_ZyLpoe/meta/slaves/2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0/slave.info' I0213 04:26:50.624200 3207 hierarchical.cpp:1853] Performed allocation for 1 agents in 201874ns I0213 04:26:50.624274 3208 status_update_manager_process.hpp:385] Resuming operation status update manager I0213 04:26:50.625430 3213 slave.cpp:1766] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"XreDs5ZzTGG/R2VwzshZEw=="},"slave_id":{"value":"2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0"},"update_oversubscribed_resources":false} I0213 04:26:50.626317 3204 master.cpp:8049] Ignoring update on agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 at slave(1251)@172.17.0.2:35463 (9a146ed47ce9) as it reports no changes I0213 04:26:50.630641 3209 process.cpp:3671] Handling HTTP event for process 'slave(1251)' with path: '/slave(1251)/api/v1' I0213 04:26:50.632127 3204 http.cpp:1405] HTTP POST for /slave(1251)/api/v1 from 172.17.0.2:58762 I0213 04:26:50.632660 3204 http.cpp:2146] Processing GET_CONTAINERS call I0213 04:26:50.639183 3204 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:50.641700 3202 process.cpp:3671] Handling HTTP event for process 'slave(1251)' with path: '/slave(1251)/api/v1' I0213 04:26:50.642812 3213 http.cpp:1405] HTTP POST for /slave(1251)/api/v1 from 172.17.0.2:58764 I0213 04:26:50.643546 3213 http.cpp:2606] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:50.644755 3205 http.cpp:2710] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_ZyLpoe/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:50.645663 3200 containerizer.cpp:1395] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:50.646350 3200 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from STARTING to PROVISIONING after 291072ns I0213 04:26:50.647193 3200 containerizer.cpp:1573] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_MLmNr0/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config' I0213 04:26:50.647253 3200 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PROVISIONING to PREPARING after 904704ns I0213 04:26:50.661769 3209 hierarchical.cpp:1853] Performed allocation for 1 agents in 148197ns I0213 04:26:50.671901 3212 containerizer.cpp:2099] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_uHo3ks","--available_capacity=0B","--volumes=","--forward=unix:///tmp/N95WkG/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_ZyLpoe/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-uBCM7S/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_ZyLpoe/containers/o rg-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="108" --pipe_write="109" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_MLmNr0/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"' I0213 04:26:50.681489 3212 launcher.cpp:145] Forked child with pid '14823' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:50.701040 3212 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PREPARING to ISOLATING after 53.781248ms I0213 04:26:50.702122 3212 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from ISOLATING to FETCHING after 1.079808ms I0213 04:26:50.702374 3206 fetcher.cpp:369] Starting to fetch URIs for container: org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE, directory: /tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_ZyLpoe/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:50.703533 3203 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from FETCHING to RUNNING after 1.387264ms I0213 04:26:50.705914 3211 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' I0213 04:26:50.706075 3211 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-uBCM7S/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:50.713749 3208 hierarchical.cpp:1853] Performed allocation for 1 agents in 186365ns I0213 04:26:50.765188 3205 hierarchical.cpp:1853] Performed allocation for 1 agents in 144414ns I0213 04:26:50.816210 3208 hierarchical.cpp:1853] Performed allocation for 1 agents in 132314ns I0213 04:26:50.868026 3209 hierarchical.cpp:1853] Performed allocation for 1 agents in 130232ns I0213 04:26:50.919426 3204 hierarchical.cpp:1853] Performed allocation for 1 agents in 225872ns I0213 04:26:50.970679 3213 hierarchical.cpp:1853] Performed allocation for 1 agents in 171186ns I0213 04:26:51.021564 3202 hierarchical.cpp:1853] Performed allocation for 1 agents in 189680ns I0213 04:26:51.028874 3207 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-uBCM7S/endpoint.sock' with CSI v1 I0213 04:26:51.030985 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/Probe call I0213 04:26:51.034185 3208 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:51.037178 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginCapabilities call I0213 04:26:51.038090 3215 process.cpp:3671] Handling HTTP event for process 'slave(1251)' with path: '/slave(1251)/api/v1' I0213 04:26:51.039456 3208 http.cpp:1405] HTTP POST for /slave(1251)/api/v1 from 172.17.0.2:58766 I0213 04:26:51.040005 3208 http.cpp:2824] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:51.041369 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call I0213 04:26:51.041733 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call I0213 04:26:51.043517 3200 v1_volume_manager.cpp:649] NODE_SERVICE loaded: {} I0213 04:26:51.044116 3200 v1_volume_manager.cpp:649] CONTROLLER_SERVICE loaded: {} I0213 04:26:51.046097 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ControllerGetCapabilities call I0213 04:26:51.050067 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetCapabilities call I0213 04:26:51.053671 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetInfo call I0213 04:26:51.056046 3205 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test' I0213 04:26:51.056250 3210 status_update_manager_process.hpp:379] Pausing operation status update manager I0213 04:26:51.056625 3203 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:35463/slave(1251)/api/v1/resource_provider I0213 04:26:51.060204 3215 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:35463/slave(1251)/api/v1/resource_provider I0213 04:26:51.060925 3200 provider.cpp:476] Connected to resource provider manager I0213 04:26:51.061656 3210 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:35463/slave(1251)/api/v1/resource_provider I0213 04:26:51.062871 3209 process.cpp:3671] Handling HTTP event for process 'slave(1251)' with path: '/slave(1251)/api/v1/resource_provider' I0213 04:26:51.064865 3204 http.cpp:1405] HTTP POST for /slave(1251)/api/v1/resource_provider from 172.17.0.2:58770 I0213 04:26:51.065791 3214 manager.cpp:779] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_uHo3ks","--available_capacity=0B","--volumes=","--forward=unix:///tmp/N95WkG/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"} I0213 04:26:51.072805 3206 hierarchical.cpp:1853] Performed allocation for 1 agents in 186025ns I0213 04:26:51.106544 3203 slave.cpp:8597] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"2329cb5a-a6ce-4e61-8d8c-c6132b772e0d"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_uHo3ks","--available_capacity=0B","--volumes=","--forward=unix:///tmp/N95WkG/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/mesos-1.10.0/_build/sub/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"},"reconciliation_interval_seconds":15.0},"type":"org.apache.mesos.rp.local.storage"}' I0213 04:26:51.108395 3208 provider.cpp:498] Received SUBSCRIBED event I0213 04:26:51.108450 3208 provider.cpp:1309] Subscribed with ID 2329cb5a-a6ce-4e61-8d8c-c6132b772e0d I0213 04:26:51.109287 3211 status_update_manager_process.hpp:314] Recovering operation status update manager I0213 04:26:51.124178 3212 hierarchical.cpp:1853] Performed allocation for 1 agents in 134616ns I0213 04:26:51.175019 3215 hierarchical.cpp:1853] Performed allocation for 1 agents in 206504ns I0213 04:26:51.201443 3210 provider.cpp:790] Reconciling storage pools and volumes I0213 04:26:51.204073 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call I0213 04:26:51.206923 3207 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 I0213 04:26:51.207329 3210 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.2:35463/slave(1251)/api/v1/resource_provider I0213 04:26:51.207391 3207 provider.cpp:748] Resource provider 2329cb5a-a6ce-4e61-8d8c-c6132b772e0d is in READY state I0213 04:26:51.207494 3201 status_update_manager_process.hpp:385] Resuming operation status update manager I0213 04:26:51.208325 3214 provider.cpp:1235] Updating profiles { test } for resource provider 2329cb5a-a6ce-4e61-8d8c-c6132b772e0d I0213 04:26:51.208588 3204 process.cpp:3671] Handling HTTP event for process 'slave(1251)' with path: '/slave(1251)/api/v1/resource_provider' I0213 04:26:51.209595 3213 provider.cpp:790] Reconciling storage pools and volumes I0213 04:26:51.210124 3205 http.cpp:1405] HTTP POST for /slave(1251)/api/v1/resource_provider from 172.17.0.2:58768 I0213 04:26:51.210796 3205 manager.cpp:1011] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 2329cb5a-a6ce-4e61-8d8c-c6132b772e0d I0213 04:26:51.211025 3211 slave.cpp:8597] Handling resource provider message 'UPDATE_STATE: 2329cb5a-a6ce-4e61-8d8c-c6132b772e0d {}' I0213 04:26:51.211130 3211 slave.cpp:8717] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0213 04:26:51.212251 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call I0213 04:26:51.212730 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call I0213 04:26:51.212726 3214 hierarchical.cpp:1110] Grew agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 by {} (total), { } (used) I0213 04:26:51.213199 3214 hierarchical.cpp:1067] Agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 (9a146ed47ce9) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0213 04:26:51.218809 3203 hierarchical.cpp:1853] Performed allocation for 1 agents in 189410ns I0213 04:26:51.219166 3206 provider.cpp:790] Reconciling storage pools and volumes I0213 04:26:51.221515 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call I0213 04:26:51.221858 14827 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call I0213 04:26:51.232313 3213 slave.cpp:995] Agent terminating I0213 04:26:51.233172 3213 manager.cpp:127] Terminating resource provider 2329cb5a-a6ce-4e61-8d8c-c6132b772e0d I0213 04:26:51.233676 3206 master.cpp:1299] Agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 at slave(1251)@172.17.0.2:35463 (9a146ed47ce9) disconnected I0213 04:26:51.233736 3206 master.cpp:3368] Disconnecting agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 at slave(1251)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:51.233841 3206 master.cpp:3387] Deactivating agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 at slave(1251)@172.17.0.2:35463 (9a146ed47ce9) I0213 04:26:51.234055 3214 hierarchical.cpp:1156] Agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 deactivated E0213 04:26:51.234330 3205 http_connection.hpp:449] End-Of-File received I0213 04:26:51.234943 3205 http_connection.hpp:217] Re-detecting endpoint I0213 04:26:51.235438 3205 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0213 04:26:51.235517 3205 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0213 04:26:51.235566 3202 provider.cpp:488] Disconnected from resource provider manager I0213 04:26:51.235605 3205 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:35463/slave(1251)/api/v1/resource_provider I0213 04:26:51.235729 3210 status_update_manager_process.hpp:379] Pausing operation status update manager I0213 04:26:51.237304 3201 containerizer.cpp:2619] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state I0213 04:26:51.237361 3201 containerizer.cpp:3317] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 15.533861888secs I0213 04:26:51.237807 3201 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:51.239223 3203 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:35463/slave(1251)/api/v1/resource_provider I0213 04:26:51.239914 3205 provider.cpp:476] Connected to resource provider manager I0213 04:26:51.240643 3209 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:35463/slave(1251)/api/v1/resource_provider I0213 04:26:51.241609 3216 process.cpp:2781] Returning '404 Not Found' for '/slave(1251)/api/v1/resource_provider' E0213 04:26:51.242941 3213 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' () I0213 04:26:51.264963 3210 hierarchical.cpp:1853] Performed allocation for 1 agents in 152124ns I0213 04:26:51.315696 3207 containerizer.cpp:3155] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited I0213 04:26:51.316916 3200 hierarchical.cpp:1853] Performed allocation for 1 agents in 170914ns I0213 04:26:51.317678 3213 provisioner.cpp:652] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:51.320996 3212 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' I0213 04:26:51.321271 3212 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-uBCM7S/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0213 04:26:51.321542 3213 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0213 04:26:51.324631 3216 process.cpp:2781] Returning '404 Not Found' for '/slave(1251)/api/v1' I0213 04:26:51.336292 3199 master.cpp:1140] Master terminating I0213 04:26:51.336724 3202 hierarchical.cpp:1132] Removed all filters for agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 I0213 04:26:51.336753 3202 hierarchical.cpp:1008] Removed agent 2aaecfe9-c3b2-42f7-ad25-f230400a92ce-S0 [ OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v1 (776 ms) [----------] 54 tests from CSIVersion/StorageLocalResourceProviderTest (107301 ms total) [----------] Global test environment tear-down [==========] 2321 tests from 222 test cases ran. (1316562 ms total) [ PASSED ] 2320 tests. [ FAILED ] 1 test, listed below: [ FAILED ] OversubscriptionTest.FixedResourceEstimator 1 FAILED TEST YOU HAVE 34 DISABLED TESTS I0213 04:26:51.421592 3216 process.cpp:935] Stopped the socket accept loop Makefile:15957: recipe for target 'check-local' failed make[4]: *** [check-local] Error 1 make[4]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub/src' Makefile:15073: recipe for target 'check-am' failed make[3]: *** [check-am] Error 2 make[3]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub/src' Makefile:15077: recipe for target 'check' failed make[2]: *** [check] Error 2 make[2]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub/src' Makefile:791: recipe for target 'check-recursive' failed make[1]: *** [check-recursive] Error 1 make[1]: Leaving directory '/tmp/SRC/build/mesos-1.10.0/_build/sub' Makefile:997: recipe for target 'distcheck' failed make: *** [distcheck] Error 1 Untagged: mesos/mesos-build:ubuntu-16.04 Untagged: mesos/mesos-build@sha256:fa967cbcfb44f55708a3cbc87f245c6d29dd891464db558af56a03ee321526bb Deleted: sha256:e895c0531b9a9a288fabe479a49f7059aed83645351ac99ec2ea2616822c9f97 Deleted: sha256:09119b0b314a69ba6ec6251f2e89f4199fe1e874c84f9abf07dcbd23dbc3f1c1 Deleted: sha256:562fe6af5a3883058be9c784a839392215ed4185a21d21f1d99df0d17f3ae6e7 Deleted: sha256:0dcdfbe322a4f332f73ac70905d557300ec6dae3bd19586758772c750c7b4a19 Deleted: sha256:c66652d605f01094e2db53d62505dbd524e076d5aa69b89d5e620003803eb149 Deleted: sha256:a2cf79bfb9593c05fd7142ddb49afef77ea4ad5d2464e841f09fe62ffee396e0 Deleted: sha256:f7a904214b390f39d98573882f631dc908df8b2b540cf04e1062f8182c1efffd Deleted: sha256:ce1f6fcaa83dfce189d76e08f184085732eab4eeb2562d2399953958405c5bec Deleted: sha256:cce92fda689ab9033f0b8db214bc63edd1ae3e05831a0f3a9418976d7dc7ccdd Deleted: sha256:d22094bbd65447c59a42c580eaa3a44cee9cd855f00905f59409be21bcefc745 Deleted: sha256:b8976847450013f3eb5e9a81a5778f73ed7bef67e6393049712ef17102b4b7b7 Deleted: sha256:b8c891f0ffec910a12757d733b178e3f62d81dbbde2b31d3b754071c416108ed Full log: https://builds.apache.org/job/Mesos-Reviewbot-Linux/7191/console - Mesos Reviewbot On Feb. 13, 2020, 2:05 a.m., Benjamin Mahler wrote: > > ----------------------------------------------------------- > This is an automatically generated e-mail. To reply, visit: > https://reviews.apache.org/r/72124/ > ----------------------------------------------------------- > > (Updated Feb. 13, 2020, 2:05 a.m.) > > > Review request for mesos, Greg Mann and Joseph Wu. > > > Bugs: MESOS-10095 > https://issues.apache.org/jira/browse/MESOS-10095 > > > Repository: mesos > > > Description > ------- > > When draining an agent, it's hard to tell which tasks failed to > terminate from the logs. The master prints a count of the tasks > remaining (only as VLOG(1) however), but not the IDs. > > This patch adds logging to the initiation of the drain on both the > master and agent, that shows which tasks and operations are present. > This makes it possible to then see which ones did not transition to > a terminal state (with a bit of log analysis effort). > > > Diffs > ----- > > src/master/http.cpp eeaac88c893b43170e655f8bff1d57dd0f7bbfb2 > src/slave/slave.cpp cce275a504effae7a6b71dd333ce8a300d1ce5be > > > Diff: https://reviews.apache.org/r/72124/diff/1/ > > > Testing > ------- > > make check > > Examples: > > ``` > I0212 18:03:33.488853 14728 http.cpp:4102] Transitioning agent > e1120790-a1cf-488d-8024-29cbaf1f63c4-S0 to the DRAINING state; agent has > (pending tasks, tasks, operations) == ({ }, { > e1120790-a1cf-488d-8024-29cbaf1f63c4-0000: { > a3bcc29d-3f7c-4454-8363-4a5cccc39370 } }, { }) > > I0212 18:03:32.496709 14720 slave.cpp:1097] Initiating drain with DrainConfig > {"mark_gone":false}; agent has (pending tasks, queued tasks, launched tasks, > operations) == ({ }, { }, { 968682eb-95c3-4d1e-a2b6-d04cb1a16a94-0000: { > 2d3e2ab5-b6ed-4a87-b390-9f88dda18b7a } }, { }) > ``` > > > Thanks, > > Benjamin Mahler > >
