You are viewing a plain text version of this content. The canonical link for it is here.
Posted to reviews@mesos.apache.org by Andrei Sekretenko <as...@mesosphere.io> on 2019/07/18 16:05:22 UTC

Review Request 71117: WIP: debug egg build at ASF CI.

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

Review request for mesos.


Repository: mesos


Description
-------

WIP: debug egg build at ASF CI.


Diffs
-----

  src/python/native_common/ext_modules.py.in 38e6717ec3b7bb09cfbb9b2fa25f173a17d78f51 


Diff: https://reviews.apache.org/r/71117/diff/1/


Testing
-------


Thanks,

Andrei Sekretenko


Re: Review Request 71117: WIP: debug egg build at ASF CI.

Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71117/#review216735
-----------------------------------------------------------



Bad review!

Reviews applied: []

Error:
No reviewers specified. Please find a reviewer by asking on JIRA or the mailing list.

- Mesos Reviewbot


On July 18, 2019, 4:05 p.m., Andrei Sekretenko wrote:
> 
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71117/
> -----------------------------------------------------------
> 
> (Updated July 18, 2019, 4:05 p.m.)
> 
> 
> Review request for mesos.
> 
> 
> Repository: mesos
> 
> 
> Description
> -------
> 
> WIP: debug egg build at ASF CI.
> 
> 
> Diffs
> -----
> 
>   src/python/native_common/ext_modules.py.in 38e6717ec3b7bb09cfbb9b2fa25f173a17d78f51 
> 
> 
> Diff: https://reviews.apache.org/r/71117/diff/1/
> 
> 
> Testing
> -------
> 
> 
> Thanks,
> 
> Andrei Sekretenko
> 
>


Re: Review Request 71117: WIP: debug egg build at ASF CI.

Posted by Mesos Reviewbot <re...@mesos.apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/71117/#review216778
-----------------------------------------------------------



Bad patch!

Reviews applied: [71082, 71083, 71084, 71117]

Failed command: ['bash', '-c', "set -o pipefail; export OS='ubuntu:14.04' BUILDTOOL='autotools' COMPILER='gcc' CONFIGURATION='--verbose --disable-libtool-wrappers --disable-parallel-test-execution' ENVIRONMENT='GLOG_v=1 MESOS_VERBOSE=1'; ./support/docker-build.sh 2>&1 | tee build_71117"]

Error:
...<truncated>...
28] Forwarding operation status update OPERATION_FINISHED (Status UUID: 9e7f2d99-9f38-4565-8826-eab1f6444544) for operation UUID a5092426-4112-4cd2-9da2-ddbe5cc6a3f2 on agent a8984a0f-0964-496e-ba85-7a2b162cff20-S0
I0719 22:01:33.376742 18713 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 9a711384-d30a-4367-9795-47b2c9af974c) for stream 44be547e-5ee3-44da-a9d1-a2842dedbe8b
I0719 22:01:33.376812 18713 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 9a711384-d30a-4367-9795-47b2c9af974c) for operation UUID 44be547e-5ee3-44da-a9d1-a2842dedbe8b on agent a8984a0f-0964-496e-ba85-7a2b162cff20-S0
I0719 22:01:33.377233 18702 http_connection.hpp:131] Sending 2 call to http://172.17.0.7:38344/slave(1212)/api/v1/resource_provider
I0719 22:01:33.378469 18711 process.cpp:3671] Handling HTTP event for process 'slave(1212)' with path: '/slave(1212)/api/v1/resource_provider'
I0719 22:01:33.417438 18718 http.cpp:1115] HTTP POST for /slave(1212)/api/v1/resource_provider from 172.17.0.7:49872
I0719 22:01:33.418421 18708 slave.cpp:8416] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: a5092426-4112-4cd2-9da2-ddbe5cc6a3f2) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0719 22:01:33.418640 18708 slave.cpp:8869] Updating the state of operation with no ID (uuid: a5092426-4112-4cd2-9da2-ddbe5cc6a3f2) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0719 22:01:33.418694 18708 slave.cpp:8623] Forwarding status update of operation with no ID (operation_uuid: a5092426-4112-4cd2-9da2-ddbe5cc6a3f2) for an operator API call
I0719 22:01:33.419113 18717 master.cpp:12259] Updating the state of operation '' (uuid: a5092426-4112-4cd2-9da2-ddbe5cc6a3f2) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0719 22:01:33.419734 18720 slave.cpp:4345] Ignoring new checkpointed resources and operations identical to the current version
I0719 22:01:33.421262 18705 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0719 22:01:33.469010 18713 status_update_manager_process.hpp:490] Cleaning up operation status update stream 44be547e-5ee3-44da-a9d1-a2842dedbe8b
I0719 22:01:33.469609 18713 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 9e7f2d99-9f38-4565-8826-eab1f6444544) for stream a5092426-4112-4cd2-9da2-ddbe5cc6a3f2
I0719 22:01:33.469791 18713 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 9e7f2d99-9f38-4565-8826-eab1f6444544) for operation UUID a5092426-4112-4cd2-9da2-ddbe5cc6a3f2 on agent a8984a0f-0964-496e-ba85-7a2b162cff20-S0
I0719 22:01:33.625609 18713 status_update_manager_process.hpp:490] Cleaning up operation status update stream a5092426-4112-4cd2-9da2-ddbe5cc6a3f2
I0719 22:01:33.765697 18707 master.cpp:1410] Framework a8984a0f-0964-496e-ba85-7a2b162cff20-0000 (default) at scheduler-bf31c494-650a-4b0d-adca-4840ffa8a8c6@172.17.0.7:38344 disconnected
I0719 22:01:33.765755 18707 master.cpp:3360] Deactivating framework a8984a0f-0964-496e-ba85-7a2b162cff20-0000 (default) at scheduler-bf31c494-650a-4b0d-adca-4840ffa8a8c6@172.17.0.7:38344
I0719 22:01:33.766218 18716 hierarchical.cpp:475] Deactivated framework a8984a0f-0964-496e-ba85-7a2b162cff20-0000
I0719 22:01:33.766842 18707 master.cpp:12712] Removing offer a8984a0f-0964-496e-ba85-7a2b162cff20-O6
I0719 22:01:33.766922 18707 master.cpp:3337] Disconnecting framework a8984a0f-0964-496e-ba85-7a2b162cff20-0000 (default) at scheduler-bf31c494-650a-4b0d-adca-4840ffa8a8c6@172.17.0.7:38344
I0719 22:01:33.766978 18707 master.cpp:1425] Giving framework a8984a0f-0964-496e-ba85-7a2b162cff20-0000 (default) at scheduler-bf31c494-650a-4b0d-adca-4840ffa8a8c6@172.17.0.7:38344 0ns to failover
I0719 22:01:33.767412 18701 slave.cpp:924] Agent terminating
I0719 22:01:33.767810 18716 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_qZlQBu/2GB-7e97af06-8add-47ba-acae-f44a90bb1277,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v0_qZlQBu/2GB-7e97af06-8add-47ba-acae-f44a90bb1277,test)]:2048, allocated: {}) on agent a8984a0f-0964-496e-ba85-7a2b162cff20-S0 from framework a8984a0f-0964-496e-ba85-7a2b162cff20-0000
I0719 22:01:33.768510 18701 manager.cpp:163] Terminating resource provider 76fedacb-37a4-4c02-b496-2273defed930
I0719 22:01:33.768615 18705 master.cpp:10212] Framework failover timeout, removing framework a8984a0f-0964-496e-ba85-7a2b162cff20-0000 (default) at scheduler-bf31c494-650a-4b0d-adca-4840ffa8a8c6@172.17.0.7:38344
I0719 22:01:33.768671 18705 master.cpp:11211] Removing framework a8984a0f-0964-496e-ba85-7a2b162cff20-0000 (default) at scheduler-bf31c494-650a-4b0d-adca-4840ffa8a8c6@172.17.0.7:38344
I0719 22:01:33.769428 18708 hierarchical.cpp:1432] Allocation paused
I0719 22:01:33.769526 18705 master.cpp:1295] Agent a8984a0f-0964-496e-ba85-7a2b162cff20-S0 at slave(1212)@172.17.0.7:38344 (9601971be91b) disconnected
I0719 22:01:33.769572 18705 master.cpp:3397] Disconnecting agent a8984a0f-0964-496e-ba85-7a2b162cff20-S0 at slave(1212)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:33.769716 18705 master.cpp:3416] Deactivating agent a8984a0f-0964-496e-ba85-7a2b162cff20-S0 at slave(1212)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:33.770063 18708 hierarchical.cpp:417] Removed framework a8984a0f-0964-496e-ba85-7a2b162cff20-0000
I0719 22:01:33.770189 18708 hierarchical.cpp:1442] Allocation resumed
E0719 22:01:33.770284 18705 http_connection.hpp:452] End-Of-File received
I0719 22:01:33.770292 18708 hierarchical.cpp:799] Agent a8984a0f-0964-496e-ba85-7a2b162cff20-S0 deactivated
I0719 22:01:33.771095 18705 http_connection.hpp:217] Re-detecting endpoint
I0719 22:01:33.772017 18705 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0719 22:01:33.772105 18705 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0719 22:01:33.772156 18716 provider.cpp:471] Disconnected from resource provider manager
I0719 22:01:33.772212 18705 http_connection.hpp:227] New endpoint detected at http://172.17.0.7:38344/slave(1212)/api/v1/resource_provider
I0719 22:01:33.772361 18719 status_update_manager_process.hpp:379] Pausing operation status update manager
I0719 22:01:33.774494 18703 containerizer.cpp:2598] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0719 22:01:33.774600 18703 containerizer.cpp:3300] 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
I0719 22:01:33.775346 18703 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0719 22:01:33.776556 18712 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.7:38344/slave(1212)/api/v1/resource_provider
I0719 22:01:33.777374 18716 provider.cpp:459] Connected to resource provider manager
I0719 22:01:33.777985 18702 hierarchical.cpp:1508] Performed allocation for 1 agents in 188830ns
I0719 22:01:33.778364 18715 http_connection.hpp:131] Sending 1 call to http://172.17.0.7:38344/slave(1212)/api/v1/resource_provider
E0719 22:01:33.779086 18715 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Cannot process 'SUBSCRIBE' call as the driver is in state SUBSCRIBING
I0719 22:01:33.779309 18725 process.cpp:2781] Returning '404 Not Found' for '/slave(1212)/api/v1/resource_provider'
E0719 22:01:33.781049 18705 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0719 22:01:33.829025 18723 hierarchical.cpp:1508] Performed allocation for 1 agents in 189848ns
I0719 22:01:33.879745 18722 containerizer.cpp:3139] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0719 22:01:33.881016 18721 hierarchical.cpp:1508] Performed allocation for 1 agents in 239818ns
I0719 22:01:33.881935 18702 provisioner.cpp:611] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0719 22:01:33.885947 18713 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'
I0719 22:01:33.886252 18707 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-R86bba/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0719 22:01:33.886651 18717 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0719 22:01:33.891208 18725 process.cpp:2781] Returning '404 Not Found' for '/slave(1212)/api/v1'
I0719 22:01:33.905169 18700 master.cpp:1135] Master terminating
I0719 22:01:33.905970 18710 hierarchical.cpp:775] Removed all filters for agent a8984a0f-0964-496e-ba85-7a2b162cff20-S0
I0719 22:01:33.906006 18710 hierarchical.cpp:650] Removed agent a8984a0f-0964-496e-ba85-7a2b162cff20-S0
[       OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v0 (3063 ms)
[ RUN      ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1
I0719 22:01:33.926652 18700 cluster.cpp:177] Creating default 'local' authorizer
I0719 22:01:33.933557 18703 master.cpp:440] Master 5ed0af46-de03-4271-afc4-0960944d4b2f (9601971be91b) started on 172.17.0.7:38344
I0719 22:01:33.933606 18703 master.cpp:443] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/274TrA/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_alloca
 table_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/mesos/mesos-1.9.0/_inst/share/mesos/webui" --work_dir="/tmp/274TrA/master" --zk_session_timeout="10secs"
I0719 22:01:33.934187 18703 master.cpp:492] Master only allowing authenticated frameworks to register
I0719 22:01:33.934208 18703 master.cpp:498] Master only allowing authenticated agents to register
I0719 22:01:33.934222 18703 master.cpp:504] Master only allowing authenticated HTTP frameworks to register
I0719 22:01:33.934237 18703 credentials.hpp:37] Loading credentials for authentication from '/tmp/274TrA/credentials'
I0719 22:01:33.934772 18703 master.cpp:548] Using default 'crammd5' authenticator
I0719 22:01:33.935132 18703 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0719 22:01:33.935513 18703 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0719 22:01:33.935843 18703 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0719 22:01:33.936134 18703 master.cpp:629] Authorization enabled
I0719 22:01:33.936748 18716 hierarchical.cpp:241] Initialized hierarchical allocator process
I0719 22:01:33.936786 18721 whitelist_watcher.cpp:77] No whitelist given
I0719 22:01:33.940779 18715 master.cpp:2168] Elected as the leading master!
I0719 22:01:33.940819 18715 master.cpp:1664] Recovering from registrar
I0719 22:01:33.941054 18706 registrar.cpp:339] Recovering registrar
I0719 22:01:33.942276 18706 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns
I0719 22:01:33.942514 18706 registrar.cpp:487] Applied 1 operations in 62990ns; attempting to update the registry
I0719 22:01:33.943555 18706 registrar.cpp:544] Successfully updated the registry in 0ns
I0719 22:01:33.943856 18706 registrar.cpp:416] Successfully recovered registrar
I0719 22:01:33.944664 18711 master.cpp:1817] Recovered 0 agents from the registry (143B); allowing 10mins for agents to reregister
I0719 22:01:33.944733 18723 hierarchical.cpp:280] Skipping recovery of hierarchical allocator: nothing to recover
W0719 22:01:33.954041 18700 process.cpp:2877] Attempted to spawn already running process files@172.17.0.7:38344
I0719 22:01:33.956151 18700 containerizer.cpp:317] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0719 22:01:33.957010 18700 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0719 22:01:33.957058 18700 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0719 22:01:33.957274 18700 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0719 22:01:33.957340 18700 provisioner.cpp:300] Using default backend 'copy'
I0719 22:01:33.961372 18700 cluster.cpp:518] Creating default 'local' authorizer
I0719 22:01:33.965124 18708 slave.cpp:267] Mesos agent started on (1213)@172.17.0.7:38344
I0719 22:01:33.965155 18708 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/274TrA/DGc60p/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/274TrA/DGc60p/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/274TrA/DGc60p/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/274TrA/DGc60p/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/274TrA/DGc60p/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/274TrA/DGc60p/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.9.0/_build/src" --logbufsecs="0" --
 logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --network_cni_root_dir_persist="false" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resource_provider_config_dir="/tmp/274TrA/resource_provider_configs" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_9iyN6c" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsW
 ithResourceProviderResources_v1_l25vc0" --zk_session_timeout="10secs"
I0719 22:01:33.965746 18708 credentials.hpp:86] Loading credential for authentication from '/tmp/274TrA/DGc60p/credential'
I0719 22:01:33.965973 18708 slave.cpp:300] Agent using credential for: test-principal
I0719 22:01:33.966001 18708 credentials.hpp:37] Loading credentials for authentication from '/tmp/274TrA/DGc60p/http_credentials'
I0719 22:01:33.966246 18708 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0719 22:01:33.966737 18708 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor'
I0719 22:01:33.969238 18708 slave.cpp:615] 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"}]
I0719 22:01:33.969597 18708 slave.cpp:623] Agent attributes: [  ]
I0719 22:01:33.969622 18708 slave.cpp:632] Agent hostname: 9601971be91b
I0719 22:01:33.969913 18702 status_update_manager_process.hpp:379] Pausing operation status update manager
I0719 22:01:33.969956 18703 task_status_update_manager.cpp:181] Pausing sending task status updates
I0719 22:01:33.971340 18701 process.cpp:3671] Handling HTTP event for process 'test-disk-profile-server' with path: '/test-disk-profile-server/profiles'
I0719 22:01:33.972751 18714 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_l25vc0/meta'
I0719 22:01:33.973116 18707 slave.cpp:7443] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_l25vc0/meta', beginning agent recovery
I0719 22:01:33.974030 18723 task_status_update_manager.cpp:207] Recovering task status update manager
I0719 22:01:33.974655 18704 containerizer.cpp:819] Recovering Mesos containers
I0719 22:01:33.975229 18704 containerizer.cpp:1145] Recovering isolators
I0719 22:01:33.976832 18711 containerizer.cpp:1184] Recovering provisioner
I0719 22:01:33.977793 18708 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles
I0719 22:01:33.978145 18719 provisioner.cpp:500] Provisioner recovery complete
I0719 22:01:33.979575 18715 composing.cpp:339] Finished recovering all containerizers
I0719 22:01:33.980101 18713 slave.cpp:7907] Recovering executors
I0719 22:01:33.980267 18713 slave.cpp:8060] Finished recovery
I0719 22:01:33.981405 18714 task_status_update_manager.cpp:181] Pausing sending task status updates
I0719 22:01:33.981458 18717 status_update_manager_process.hpp:379] Pausing operation status update manager
I0719 22:01:33.981461 18713 slave.cpp:1350] New master detected at master@172.17.0.7:38344
I0719 22:01:33.981643 18713 slave.cpp:1415] Detecting new master
I0719 22:01:33.981959 18703 slave.cpp:1442] Authenticating with master master@172.17.0.7:38344
I0719 22:01:33.982136 18703 slave.cpp:1451] Using default CRAM-MD5 authenticatee
I0719 22:01:33.982620 18706 authenticatee.cpp:121] Creating new client SASL connection
I0719 22:01:33.983148 18711 master.cpp:10605] Authenticating slave(1213)@172.17.0.7:38344
I0719 22:01:33.983363 18708 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2064)@172.17.0.7:38344
I0719 22:01:33.984004 18712 authenticator.cpp:98] Creating new server SASL connection
I0719 22:01:33.984467 18710 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0719 22:01:33.984534 18710 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0719 22:01:33.984784 18716 authenticator.cpp:204] Received SASL authentication start
I0719 22:01:33.984908 18716 authenticator.cpp:326] Authentication requires more steps
I0719 22:01:33.985162 18719 authenticatee.cpp:259] Received SASL authentication step
I0719 22:01:33.985450 18721 authenticator.cpp:232] Received SASL authentication step
I0719 22:01:33.985517 18721 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9601971be91b' server FQDN: '9601971be91b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0719 22:01:33.985548 18721 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0719 22:01:33.985618 18721 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0719 22:01:33.985678 18721 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9601971be91b' server FQDN: '9601971be91b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0719 22:01:33.985723 18721 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0719 22:01:33.985747 18721 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0719 22:01:33.985780 18721 authenticator.cpp:318] Authentication success
I0719 22:01:33.986012 18702 authenticatee.cpp:299] Authentication success
I0719 22:01:33.986222 18720 master.cpp:10637] Successfully authenticated principal 'test-principal' at slave(1213)@172.17.0.7:38344
I0719 22:01:33.986232 18723 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2064)@172.17.0.7:38344
I0719 22:01:33.986639 18705 slave.cpp:1542] Successfully authenticated with master master@172.17.0.7:38344
I0719 22:01:33.987231 18705 slave.cpp:1992] Will retry registration in 17.939312ms if necessary
I0719 22:01:33.987542 18718 master.cpp:7113] Received register agent message from slave(1213)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:33.988101 18718 master.cpp:4229] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I0719 22:01:33.988999 18717 master.cpp:7180] Authorized registration of agent at slave(1213)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:33.989132 18717 master.cpp:7292] Registering agent at slave(1213)@172.17.0.7:38344 (9601971be91b) with id 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:33.990041 18704 registrar.cpp:487] Applied 1 operations in 263915ns; attempting to update the registry
I0719 22:01:33.991034 18704 registrar.cpp:544] Successfully updated the registry in 0ns
I0719 22:01:33.991322 18708 master.cpp:7340] Admitted agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:33.992483 18708 master.cpp:7385] Registered agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0719 22:01:33.992789 18710 slave.cpp:1575] Registered with master master@172.17.0.7:38344; given agent ID 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:33.992789 18716 hierarchical.cpp:617] Added agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 (9601971be91b) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I0719 22:01:33.992995 18721 task_status_update_manager.cpp:188] Resuming sending task status updates
I0719 22:01:33.993381 18716 hierarchical.cpp:1508] Performed allocation for 1 agents in 293342ns
I0719 22:01:33.993559 18710 slave.cpp:1610] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_l25vc0/meta/slaves/5ed0af46-de03-4271-afc4-0960944d4b2f-S0/slave.info'
I0719 22:01:33.993649 18720 status_update_manager_process.hpp:385] Resuming operation status update manager
I0719 22:01:33.995178 18710 slave.cpp:1662] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"XtVlFD6ZSLe2AbldFFLSlQ=="},"slave_id":{"value":"5ed0af46-de03-4271-afc4-0960944d4b2f-S0"},"update_oversubscribed_resources":false}
I0719 22:01:33.996441 18705 master.cpp:8484] Ignoring update on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b) as it reports no changes
I0719 22:01:34.003137 18712 process.cpp:3671] Handling HTTP event for process 'slave(1213)' with path: '/slave(1213)/api/v1'
I0719 22:01:34.004462 18722 http.cpp:1115] HTTP POST for /slave(1213)/api/v1 from 172.17.0.7:49914
I0719 22:01:34.005095 18722 http.cpp:2133] Processing GET_CONTAINERS call
I0719 22:01:34.012202 18706 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0719 22:01:34.015040 18721 process.cpp:3671] Handling HTTP event for process 'slave(1213)' with path: '/slave(1213)/api/v1'
I0719 22:01:34.016067 18710 http.cpp:1115] HTTP POST for /slave(1213)/api/v1 from 172.17.0.7:49916
I0719 22:01:34.016878 18710 http.cpp:2593] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0719 22:01:34.018294 18724 http.cpp:2697] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_l25vc0/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0719 22:01:34.019280 18718 containerizer.cpp:1380] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0719 22:01:34.021351 18718 containerizer.cpp:1552] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_9iyN6c/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config'
I0719 22:01:34.021427 18718 containerizer.cpp:3300] 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
I0719 22:01:34.025943 18704 containerizer.cpp:2078] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/mesos/mesos-1.9.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN","--available_capacity=2GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.9.0/_build/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_l25vc0/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-sYHy6f/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperat
 ionsWithResourceProviderResources_v1_l25vc0/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="86" --pipe_write="87" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_9iyN6c/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"'
I0719 22:01:34.037245 18704 launcher.cpp:145] Forked child with pid '32680' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0719 22:01:34.038605 18704 containerizer.cpp:3300] 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
I0719 22:01:34.041265 18710 containerizer.cpp:3300] 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
I0719 22:01:34.041862 18705 fetcher.cpp:369] Starting to fetch URIs for container: org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE, directory: /tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_l25vc0/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0719 22:01:34.043443 18724 containerizer.cpp:3300] 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
I0719 22:01:34.047636 18711 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'
I0719 22:01:34.047978 18711 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-sYHy6f/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0719 22:01:34.228680 18702 hierarchical.cpp:1508] Performed allocation for 1 agents in 274350ns
I0719 22:01:34.280599 18713 hierarchical.cpp:1508] Performed allocation for 1 agents in 186528ns
I0719 22:01:34.332165 18714 hierarchical.cpp:1508] Performed allocation for 1 agents in 162637ns
I0719 22:01:34.383783 18708 hierarchical.cpp:1508] Performed allocation for 1 agents in 220569ns
I0719 22:01:34.435299 18715 hierarchical.cpp:1508] Performed allocation for 1 agents in 174531ns
I0719 22:01:34.486610 18703 hierarchical.cpp:1508] Performed allocation for 1 agents in 188870ns
I0719 22:01:34.496007 18718 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-sYHy6f/endpoint.sock' with CSI v1
I0719 22:01:34.521908 32684 test_csi_plugin.cpp:909] ProbeRequest '{}'
I0719 22:01:34.524791 18712 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0719 22:01:34.528537 32685 test_csi_plugin.cpp:895] GetPluginCapabilitiesRequest '{}'
I0719 22:01:34.529526 18701 process.cpp:3671] Handling HTTP event for process 'slave(1213)' with path: '/slave(1213)/api/v1'
I0719 22:01:34.530997 18703 http.cpp:1115] HTTP POST for /slave(1213)/api/v1 from 172.17.0.7:49918
I0719 22:01:34.531823 18703 http.cpp:2811] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0719 22:01:34.533191 32684 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0719 22:01:34.533362 32685 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}'
I0719 22:01:34.535621 18716 v1_volume_manager.cpp:648] NODE_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"}
I0719 22:01:34.536285 18716 v1_volume_manager.cpp:648] CONTROLLER_SERVICE loaded: {"name":".","vendorVersion":"1.9.0"}
I0719 22:01:34.537983 18710 hierarchical.cpp:1508] Performed allocation for 1 agents in 224791ns
I0719 22:01:34.538811 32686 test_csi_plugin.cpp:1105] ControllerGetCapabilitiesRequest '{}'
I0719 22:01:34.542310 32685 test_csi_plugin.cpp:1241] NodeGetCapabilitiesRequest '{}'
I0719 22:01:34.545459 32685 test_csi_plugin.cpp:1255] NodeGetInfoRequest '{}'
I0719 22:01:34.547850 18719 provider.cpp:659] Finished recovery for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test'
I0719 22:01:34.547994 18709 status_update_manager_process.hpp:379] Pausing operation status update manager
I0719 22:01:34.548403 18721 http_connection.hpp:227] New endpoint detected at http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:34.551667 18701 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:34.552407 18717 provider.cpp:459] Connected to resource provider manager
I0719 22:01:34.552999 18714 http_connection.hpp:131] Sending 1 call to http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:34.554090 18706 process.cpp:3671] Handling HTTP event for process 'slave(1213)' with path: '/slave(1213)/api/v1/resource_provider'
I0719 22:01:34.555799 18708 http.cpp:1115] HTTP POST for /slave(1213)/api/v1/resource_provider from 172.17.0.7:49922
I0719 22:01:34.556618 18719 manager.cpp:807] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.9.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN","--available_capacity=2GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.9.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"}},"type":"org.apache.mesos.rp.local.storage"}
I0719 22:01:34.589629 18710 hierarchical.cpp:1508] Performed allocation for 1 agents in 262435ns
I0719 22:01:34.632411 18723 slave.cpp:8416] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"623a1c06-3f05-4f48-b557-d3e78541eac4"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.9.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN","--available_capacity=2GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.9.0/_build/src/test-csi-plugin"},"resources":[{"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}],"services":["CONTROLLER_SERVICE","NODE_SERVICE"]}],"name":"local","type":"org.apache.mesos.csi.test"}},"type":"org.apache.mesos.rp.local.storage"}'
I0719 22:01:34.634662 18707 provider.cpp:481] Received SUBSCRIBED event
I0719 22:01:34.634724 18707 provider.cpp:1255] Subscribed with ID 623a1c06-3f05-4f48-b557-d3e78541eac4
I0719 22:01:34.636085 18709 status_update_manager_process.hpp:314] Recovering operation status update manager
I0719 22:01:34.641562 18719 hierarchical.cpp:1508] Performed allocation for 1 agents in 195957ns
I0719 22:01:34.692725 18716 hierarchical.cpp:1508] Performed allocation for 1 agents in 182999ns
I0719 22:01:34.744391 18715 hierarchical.cpp:1508] Performed allocation for 1 agents in 170456ns
I0719 22:01:34.748579 32685 test_csi_plugin.cpp:1050] ListVolumesRequest '{}'
I0719 22:01:34.751931 18724 provider.cpp:2145] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:34.752255 18724 provider.cpp:745] Resource provider 623a1c06-3f05-4f48-b557-d3e78541eac4 is in READY state
I0719 22:01:34.752355 18714 status_update_manager_process.hpp:385] Resuming operation status update manager
I0719 22:01:34.752380 18704 http_connection.hpp:131] Sending 3 call to http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:34.753312 18712 provider.cpp:1181] Updating profiles { test } for resource provider 623a1c06-3f05-4f48-b557-d3e78541eac4
I0719 22:01:34.754057 18721 process.cpp:3671] Handling HTTP event for process 'slave(1213)' with path: '/slave(1213)/api/v1/resource_provider'
I0719 22:01:34.756505 18703 http.cpp:1115] HTTP POST for /slave(1213)/api/v1/resource_provider from 172.17.0.7:49920
I0719 22:01:34.757196 18714 manager.cpp:1039] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 623a1c06-3f05-4f48-b557-d3e78541eac4
I0719 22:01:34.757536 18724 slave.cpp:8416] Handling resource provider message 'UPDATE_STATE: 623a1c06-3f05-4f48-b557-d3e78541eac4 {}'
I0719 22:01:34.757665 18724 slave.cpp:8536] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0719 22:01:34.758378 32685 test_csi_plugin.cpp:1078] GetCapacityRequest '{"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0719 22:01:34.760083 18709 hierarchical.cpp:753] Grew agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 by {} (total), {  } (used)
I0719 22:01:34.760723 18709 hierarchical.cpp:710] Agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 (9601971be91b) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
W0719 22:01:34.762585 18700 process.cpp:2877] Attempted to spawn already running process version@172.17.0.7:38344
I0719 22:01:34.764168 18708 provider.cpp:933] Removing '{}' and adding 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' to the total resources
I0719 22:01:34.764639 18700 sched.cpp:239] Version: 1.9.0
I0719 22:01:34.765702 18703 sched.cpp:343] New master detected at master@172.17.0.7:38344
I0719 22:01:34.765884 18703 sched.cpp:408] Authenticating with master master@172.17.0.7:38344
I0719 22:01:34.765918 18703 sched.cpp:415] Using default CRAM-MD5 authenticatee
I0719 22:01:34.766484 18705 authenticatee.cpp:121] Creating new client SASL connection
I0719 22:01:34.766974 18714 hierarchical.cpp:1508] Performed allocation for 1 agents in 249887ns
I0719 22:01:34.767196 18724 master.cpp:10605] Authenticating scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:34.767482 18706 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2065)@172.17.0.7:38344
I0719 22:01:34.767993 18707 authenticator.cpp:98] Creating new server SASL connection
I0719 22:01:34.768366 18716 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0719 22:01:34.768414 18716 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0719 22:01:34.768651 18720 authenticator.cpp:204] Received SASL authentication start
I0719 22:01:34.768762 18720 authenticator.cpp:326] Authentication requires more steps
I0719 22:01:34.768939 18720 authenticatee.cpp:259] Received SASL authentication step
I0719 22:01:34.769121 18720 authenticator.cpp:232] Received SASL authentication step
I0719 22:01:34.769172 18720 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9601971be91b' server FQDN: '9601971be91b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0719 22:01:34.769196 18720 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0719 22:01:34.769264 18720 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0719 22:01:34.769328 18720 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9601971be91b' server FQDN: '9601971be91b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0719 22:01:34.769366 18720 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0719 22:01:34.769392 18720 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0719 22:01:34.769430 18720 authenticator.cpp:318] Authentication success
I0719 22:01:34.769667 18712 authenticatee.cpp:299] Authentication success
I0719 22:01:34.769767 18709 master.cpp:10637] Successfully authenticated principal 'test-principal' at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:34.769832 18710 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2065)@172.17.0.7:38344
I0719 22:01:34.770409 18721 sched.cpp:520] Successfully authenticated with master master@172.17.0.7:38344
I0719 22:01:34.770450 18721 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.7:38344
I0719 22:01:34.770691 18721 sched.cpp:870] Will retry registration in 1.251290511secs if necessary
I0719 22:01:34.771023 18722 master.cpp:2908] Received SUBSCRIBE call for framework 'default' at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:34.771086 18722 master.cpp:2240] Authorizing framework principal 'test-principal' to receive offers for roles '{ storage/default-role }'
I0719 22:01:34.771977 18701 master.cpp:2995] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0719 22:01:34.775692 18701 master.cpp:10835] Adding framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344 with roles {  } suppressed
I0719 22:01:34.776584 18703 sched.cpp:751] Framework registered with 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:34.776707 18703 sched.cpp:770] Scheduler::registered took 62495ns
I0719 22:01:34.776942 18705 hierarchical.cpp:368] Added framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:34.778736 18705 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.53436ms
I0719 22:01:34.779412 18711 master.cpp:10420] Sending offers [ 5ed0af46-de03-4271-afc4-0960944d4b2f-O0 ] to framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:34.780426 18714 sched.cpp:934] Scheduler::resourceOffers took 198604ns
I0719 22:01:34.781042 18714 master.cpp:6249] Processing DECLINE call for offers: [ 5ed0af46-de03-4271-afc4-0960944d4b2f-O0 ] for framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344 with 5 seconds filter
I0719 22:01:34.781998 18714 master.cpp:12712] Removing offer 5ed0af46-de03-4271-afc4-0960944d4b2f-O0
I0719 22:01:34.783149 18706 hierarchical.cpp:1218] Recovered cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 from framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:34.783272 18706 hierarchical.cpp:1264] Framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 filtered agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for 5secs
I0719 22:01:34.880573 18708 provider.cpp:2145] Sending UPDATE_STATE call with resources 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' and 0 operations to agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:34.881373 18707 http_connection.hpp:131] Sending 3 call to http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:34.883177 18719 process.cpp:3671] Handling HTTP event for process 'slave(1213)' with path: '/slave(1213)/api/v1/resource_provider'
I0719 22:01:34.922583 18712 http.cpp:1115] HTTP POST for /slave(1213)/api/v1/resource_provider from 172.17.0.7:49920
I0719 22:01:34.923491 18718 manager.cpp:1039] Received UPDATE_STATE call with resources '[{"disk":{"source":{"profile":"test","type":"RAW","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"623a1c06-3f05-4f48-b557-d3e78541eac4"},"reservations":[{"role":"storage","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]' and 0 operations from resource provider 623a1c06-3f05-4f48-b557-d3e78541eac4
I0719 22:01:34.924235 18721 slave.cpp:8416] Handling resource provider message 'UPDATE_STATE: 623a1c06-3f05-4f48-b557-d3e78541eac4 disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048'
I0719 22:01:34.924433 18721 slave.cpp:8536] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048
I0719 22:01:34.927860 18704 hierarchical.cpp:710] Agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 (9601971be91b) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048
I0719 22:01:34.930158 18704 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.931364ms
I0719 22:01:34.930948 18705 master.cpp:10420] Sending offers [ 5ed0af46-de03-4271-afc4-0960944d4b2f-O1 ] to framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:34.931771 18711 sched.cpp:934] Scheduler::resourceOffers took 139569ns
I0719 22:01:34.937520 18706 master.cpp:12712] Removing offer 5ed0af46-de03-4271-afc4-0960944d4b2f-O1
I0719 22:01:34.937593 18715 hierarchical.cpp:1508] Performed allocation for 1 agents in 366403ns
I0719 22:01:34.938107 18706 master.cpp:4766] Processing ACCEPT call for offers: [ 5ed0af46-de03-4271-afc4-0960944d4b2f-O1 ] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b) for framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:34.938284 18706 master.cpp:4139] Authorizing principal 'test-principal' to create a MOUNT disk from 'disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048'
I0719 22:01:34.939877 18709 master.cpp:6041] Processing CREATE_DISK operation with source disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048 from framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344 to agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:34.940766 18709 master.cpp:12603] Sending operation '' (uuid: e6dc5ce5-e860-43ff-9da2-4386b3fe958d) to agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:34.941246 18710 hierarchical.cpp:1432] Allocation paused
I0719 22:01:34.941726 18702 slave.cpp:4345] Ignoring new checkpointed resources and operations identical to the current version
I0719 22:01:34.943233 18710 hierarchical.cpp:1218] Recovered ports(allocated: storage/default-role):[31000-32000]; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048, allocated: disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048) on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 from framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:34.943403 18710 hierarchical.cpp:1264] Framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 filtered agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for 5secs
I0719 22:01:34.943833 18710 hierarchical.cpp:1442] Allocation resumed
I0719 22:01:34.945243 18704 provider.cpp:481] Received APPLY_OPERATION event
I0719 22:01:34.945319 18704 provider.cpp:1295] Received CREATE_DISK operation '' (uuid: e6dc5ce5-e860-43ff-9da2-4386b3fe958d)
I0719 22:01:34.989830 18711 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:34.990008 18711 hierarchical.cpp:1508] Performed allocation for 1 agents in 760515ns
I0719 22:01:35.041604 18724 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.041790 18724 hierarchical.cpp:1508] Performed allocation for 1 agents in 746049ns
I0719 22:01:35.049273 18707 v1_volume_manager.cpp:292] Creating volume with name 'e6dc5ce5-e860-43ff-9da2-4386b3fe958d'
I0719 22:01:35.053393 32685 test_csi_plugin.cpp:922] CreateVolumeRequest '{"name":"e6dc5ce5-e860-43ff-9da2-4386b3fe958d","capacityRange":{"requiredBytes":"2147483648","limitBytes":"2147483648"},"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}'
I0719 22:01:35.093312 18709 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.093487 18709 hierarchical.cpp:1508] Performed allocation for 1 agents in 709613ns
I0719 22:01:35.145092 18713 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.145277 18713 hierarchical.cpp:1508] Performed allocation for 1 agents in 680996ns
I0719 22:01:35.196854 18712 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.197059 18712 hierarchical.cpp:1508] Performed allocation for 1 agents in 732204ns
I0719 22:01:35.248394 18710 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.248543 18710 hierarchical.cpp:1508] Performed allocation for 1 agents in 607422ns
I0719 22:01:35.299760 18721 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.299893 18721 hierarchical.cpp:1508] Performed allocation for 1 agents in 542381ns
I0719 22:01:35.351891 18701 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.352078 18701 hierarchical.cpp:1508] Performed allocation for 1 agents in 802928ns
I0719 22:01:35.403760 18722 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.403982 18722 hierarchical.cpp:1508] Performed allocation for 1 agents in 848734ns
I0719 22:01:35.455458 18705 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.455632 18705 hierarchical.cpp:1508] Performed allocation for 1 agents in 703070ns
I0719 22:01:35.507439 18714 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.507619 18714 hierarchical.cpp:1508] Performed allocation for 1 agents in 717244ns
I0719 22:01:35.559244 18704 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.559432 18704 hierarchical.cpp:1508] Performed allocation for 1 agents in 743656ns
I0719 22:01:35.611085 18708 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.611268 18708 hierarchical.cpp:1508] Performed allocation for 1 agents in 788831ns
I0719 22:01:35.662895 18715 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.663084 18715 hierarchical.cpp:1508] Performed allocation for 1 agents in 762122ns
I0719 22:01:35.714666 18706 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.714840 18706 hierarchical.cpp:1508] Performed allocation for 1 agents in 703873ns
I0719 22:01:35.766566 18720 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.766911 18720 hierarchical.cpp:1508] Performed allocation for 1 agents in 911776ns
I0719 22:01:35.818259 18723 provider.cpp:1597] Applying conversion from 'disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048' to 'disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048' for operation (uuid: e6dc5ce5-e860-43ff-9da2-4386b3fe958d)
I0719 22:01:35.818527 18709 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.818714 18709 hierarchical.cpp:1508] Performed allocation for 1 agents in 736676ns
I0719 22:01:35.870128 18713 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.870292 18713 hierarchical.cpp:1508] Performed allocation for 1 agents in 656531ns
I0719 22:01:35.904942 18712 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 3fa0dbf5-385b-494e-b0a8-c6fe541ef667) for operation UUID e6dc5ce5-e860-43ff-9da2-4386b3fe958d of framework '5ed0af46-de03-4271-afc4-0960944d4b2f-0000' on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:35.905056 18712 status_update_manager_process.hpp:414] Creating operation status update stream e6dc5ce5-e860-43ff-9da2-4386b3fe958d checkpoint=true
I0719 22:01:35.905730 18712 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 3fa0dbf5-385b-494e-b0a8-c6fe541ef667) for operation UUID e6dc5ce5-e860-43ff-9da2-4386b3fe958d of framework '5ed0af46-de03-4271-afc4-0960944d4b2f-0000' on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:35.921829 18718 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.922003 18718 hierarchical.cpp:1508] Performed allocation for 1 agents in 702221ns
I0719 22:01:35.955041 18712 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 3fa0dbf5-385b-494e-b0a8-c6fe541ef667) for operation UUID e6dc5ce5-e860-43ff-9da2-4386b3fe958d of framework '5ed0af46-de03-4271-afc4-0960944d4b2f-0000' on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:35.956492 18703 http_connection.hpp:131] Sending 2 call to http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:35.958333 18717 process.cpp:3671] Handling HTTP event for process 'slave(1213)' with path: '/slave(1213)/api/v1/resource_provider'
I0719 22:01:35.973428 18711 hierarchical.cpp:2358] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for role storage/default-role of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:35.973618 18711 hierarchical.cpp:1508] Performed allocation for 1 agents in 758933ns
I0719 22:01:35.998311 18715 http.cpp:1115] HTTP POST for /slave(1213)/api/v1/resource_provider from 172.17.0.7:49920
I0719 22:01:35.999969 18716 slave.cpp:8416] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: e6dc5ce5-e860-43ff-9da2-4386b3fe958d) for framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0719 22:01:36.000293 18716 slave.cpp:8869] Updating the state of operation with no ID (uuid: e6dc5ce5-e860-43ff-9da2-4386b3fe958d) for framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0719 22:01:36.001107 18716 slave.cpp:8623] Forwarding status update of operation with no ID (operation_uuid: e6dc5ce5-e860-43ff-9da2-4386b3fe958d) for framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:36.001744 18709 master.cpp:12259] Updating the state of operation '' (uuid: e6dc5ce5-e860-43ff-9da2-4386b3fe958d) for framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0719 22:01:36.003549 18723 slave.cpp:4345] Ignoring new checkpointed resources and operations identical to the current version
I0719 22:01:36.004899 18713 hierarchical.cpp:956] Updated allocation of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 from disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:2048 to disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048
I0719 22:01:36.005906 18705 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0719 22:01:36.006134 18711 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 3fa0dbf5-385b-494e-b0a8-c6fe541ef667) for stream e6dc5ce5-e860-43ff-9da2-4386b3fe958d
I0719 22:01:36.006127 18713 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048, allocated: {}) on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 from framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:36.006289 18711 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 3fa0dbf5-385b-494e-b0a8-c6fe541ef667) for operation UUID e6dc5ce5-e860-43ff-9da2-4386b3fe958d of framework '5ed0af46-de03-4271-afc4-0960944d4b2f-0000' on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.026224 18724 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.774104ms
I0719 22:01:36.027279 18704 master.cpp:10420] Sending offers [ 5ed0af46-de03-4271-afc4-0960944d4b2f-O2 ] to framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:36.028410 18708 sched.cpp:934] Scheduler::resourceOffers took 183419ns
I0719 22:01:36.035383 18709 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0719 22:01:36.038614 18722 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.7:49966
I0719 22:01:36.039026 18722 http.cpp:263] Processing call RESERVE_RESOURCES
I0719 22:01:36.040386 18722 master.cpp:3851] Authorizing principal 'test-principal' to reserve resources 'disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048'
I0719 22:01:36.043134 18705 master.cpp:12712] Removing offer 5ed0af46-de03-4271-afc4-0960944d4b2f-O2
I0719 22:01:36.043323 18704 sched.cpp:960] Rescinded offer 5ed0af46-de03-4271-afc4-0960944d4b2f-O2
I0719 22:01:36.043455 18704 sched.cpp:971] Scheduler::offerRescinded took 42357ns
I0719 22:01:36.044512 18724 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048, allocated: {}) on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 from framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:36.044667 18724 hierarchical.cpp:1264] Framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 filtered agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for 5secs
I0719 22:01:36.047978 18708 master.cpp:12603] Sending operation '' (uuid: 2a803457-b208-45b8-9d25-10ae68e09275) to agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:36.048600 18720 slave.cpp:4345] Ignoring new checkpointed resources and operations identical to the current version
I0719 22:01:36.052767 18701 provider.cpp:481] Received APPLY_OPERATION event
I0719 22:01:36.052837 18701 provider.cpp:1295] Received RESERVE operation '' (uuid: 2a803457-b208-45b8-9d25-10ae68e09275)
I0719 22:01:36.063585 18711 status_update_manager_process.hpp:490] Cleaning up operation status update stream e6dc5ce5-e860-43ff-9da2-4386b3fe958d
I0719 22:01:36.173516 18703 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: c941167a-b62a-4382-9c2c-c5c2db223627) for operation UUID 2a803457-b208-45b8-9d25-10ae68e09275 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.173614 18703 status_update_manager_process.hpp:414] Creating operation status update stream 2a803457-b208-45b8-9d25-10ae68e09275 checkpoint=true
I0719 22:01:36.174077 18703 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: c941167a-b62a-4382-9c2c-c5c2db223627) for operation UUID 2a803457-b208-45b8-9d25-10ae68e09275 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.248775 18703 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: c941167a-b62a-4382-9c2c-c5c2db223627) for operation UUID 2a803457-b208-45b8-9d25-10ae68e09275 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.267065 18722 http_connection.hpp:131] Sending 2 call to http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:36.268532 18704 process.cpp:3671] Handling HTTP event for process 'slave(1213)' with path: '/slave(1213)/api/v1/resource_provider'
I0719 22:01:36.272711 18724 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.809811ms
I0719 22:01:36.273960 18715 master.cpp:10420] Sending offers [ 5ed0af46-de03-4271-afc4-0960944d4b2f-O3 ] to framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:36.274863 18706 sched.cpp:934] Scheduler::resourceOffers took 107881ns
I0719 22:01:36.279415 18720 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0719 22:01:36.282043 18709 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.7:49968
I0719 22:01:36.282467 18709 http.cpp:263] Processing call CREATE_VOLUMES
I0719 22:01:36.283737 18709 master.cpp:3978] Authorizing principal 'test-principal' to create volumes '[{"disk":{"persistence":{"id":"1ae747a9-482b-40a1-9996-e78702b4437b","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"},"volume":{"container_path":"volume","mode":"RW"}},"name":"disk","provider_id":{"value":"623a1c06-3f05-4f48-b557-d3e78541eac4"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0719 22:01:36.287256 18717 master.cpp:12712] Removing offer 5ed0af46-de03-4271-afc4-0960944d4b2f-O3
I0719 22:01:36.287521 18701 sched.cpp:960] Rescinded offer 5ed0af46-de03-4271-afc4-0960944d4b2f-O3
I0719 22:01:36.287667 18701 sched.cpp:971] Scheduler::offerRescinded took 41895ns
I0719 22:01:36.288545 18703 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048, allocated: {}) on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 from framework 5ed0af46-de03-42
 71-afc4-0960944d4b2f-0000
I0719 22:01:36.288733 18703 hierarchical.cpp:1264] Framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 filtered agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for 5secs
I0719 22:01:36.292371 18722 master.cpp:12603] Sending operation '' (uuid: 69125b38-49b3-467c-97ce-bf66b1cf92c7) to agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:36.293067 18705 slave.cpp:4345] Ignoring new checkpointed resources and operations identical to the current version
I0719 22:01:36.296447 18720 provider.cpp:481] Received APPLY_OPERATION event
I0719 22:01:36.296511 18720 provider.cpp:1295] Received CREATE operation '' (uuid: 69125b38-49b3-467c-97ce-bf66b1cf92c7)
I0719 22:01:36.297089 18710 master.cpp:6442] Processing REVIVE call for framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:36.297719 18709 hierarchical.cpp:1365] Unsuppressed offers for roles { storage/default-role } of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:36.297770 18709 hierarchical.cpp:1387] Revived roles { storage/default-role } of framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:36.299901 18709 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.874638ms
I0719 22:01:36.300477 18709 hierarchical.cpp:1508] Performed allocation for 1 agents in 294152ns
I0719 22:01:36.300851 18712 master.cpp:10420] Sending offers [ 5ed0af46-de03-4271-afc4-0960944d4b2f-O4 ] to framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:36.301661 18711 sched.cpp:934] Scheduler::resourceOffers took 100333ns
I0719 22:01:36.305723 18704 http.cpp:1115] HTTP POST for /slave(1213)/api/v1/resource_provider from 172.17.0.7:49920
I0719 22:01:36.306854 18724 slave.cpp:8416] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 2a803457-b208-45b8-9d25-10ae68e09275) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0719 22:01:36.307044 18724 slave.cpp:8869] Updating the state of operation with no ID (uuid: 2a803457-b208-45b8-9d25-10ae68e09275) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0719 22:01:36.307097 18724 slave.cpp:8623] Forwarding status update of operation with no ID (operation_uuid: 2a803457-b208-45b8-9d25-10ae68e09275) for an operator API call
I0719 22:01:36.307560 18705 master.cpp:12259] Updating the state of operation '' (uuid: 2a803457-b208-45b8-9d25-10ae68e09275) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0719 22:01:36.308192 18706 slave.cpp:4345] Ignoring new checkpointed resources and operations identical to the current version
I0719 22:01:36.401384 18712 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: dc4a89b9-de81-4d10-9892-fc3b830f0179) for operation UUID 69125b38-49b3-467c-97ce-bf66b1cf92c7 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.401492 18712 status_update_manager_process.hpp:414] Creating operation status update stream 69125b38-49b3-467c-97ce-bf66b1cf92c7 checkpoint=true
I0719 22:01:36.401600 18720 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0719 22:01:36.401975 18712 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: dc4a89b9-de81-4d10-9892-fc3b830f0179) for operation UUID 69125b38-49b3-467c-97ce-bf66b1cf92c7 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.468051 18712 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: dc4a89b9-de81-4d10-9892-fc3b830f0179) for operation UUID 69125b38-49b3-467c-97ce-bf66b1cf92c7 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.468634 18712 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: c941167a-b62a-4382-9c2c-c5c2db223627) for stream 2a803457-b208-45b8-9d25-10ae68e09275
I0719 22:01:36.468752 18712 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: c941167a-b62a-4382-9c2c-c5c2db223627) for operation UUID 2a803457-b208-45b8-9d25-10ae68e09275 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.469236 18701 http_connection.hpp:131] Sending 2 call to http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:36.470374 18714 process.cpp:3671] Handling HTTP event for process 'slave(1213)' with path: '/slave(1213)/api/v1/resource_provider'
I0719 22:01:36.509860 18705 http.cpp:1115] HTTP POST for /slave(1213)/api/v1/resource_provider from 172.17.0.7:49920
I0719 22:01:36.511144 18706 slave.cpp:8416] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 69125b38-49b3-467c-97ce-bf66b1cf92c7) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0719 22:01:36.511406 18706 slave.cpp:8869] Updating the state of operation with no ID (uuid: 69125b38-49b3-467c-97ce-bf66b1cf92c7) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0719 22:01:36.511492 18706 slave.cpp:8623] Forwarding status update of operation with no ID (operation_uuid: 69125b38-49b3-467c-97ce-bf66b1cf92c7) for an operator API call
I0719 22:01:36.512135 18716 master.cpp:12259] Updating the state of operation '' (uuid: 69125b38-49b3-467c-97ce-bf66b1cf92c7) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0719 22:01:36.513015 18702 slave.cpp:4345] Ignoring new checkpointed resources and operations identical to the current version
I0719 22:01:36.516314 18717 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0719 22:01:36.534795 18712 status_update_manager_process.hpp:490] Cleaning up operation status update stream 2a803457-b208-45b8-9d25-10ae68e09275
I0719 22:01:36.535094 18712 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: dc4a89b9-de81-4d10-9892-fc3b830f0179) for stream 69125b38-49b3-467c-97ce-bf66b1cf92c7
I0719 22:01:36.535193 18712 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: dc4a89b9-de81-4d10-9892-fc3b830f0179) for operation UUID 69125b38-49b3-467c-97ce-bf66b1cf92c7 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.618539 18712 status_update_manager_process.hpp:490] Cleaning up operation status update stream 69125b38-49b3-467c-97ce-bf66b1cf92c7
I0719 22:01:36.690809 18715 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0719 22:01:36.692827 18708 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.7:49970
I0719 22:01:36.693105 18708 http.cpp:263] Processing call DESTROY_VOLUMES
I0719 22:01:36.694104 18708 master.cpp:4023] Authorizing principal 'test-principal' to destroy volumes '[{"disk":{"persistence":{"id":"1ae747a9-482b-40a1-9996-e78702b4437b","principal":"test-principal"},"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"},"volume":{"container_path":"volume","mode":"RW"}},"name":"disk","provider_id":{"value":"623a1c06-3f05-4f48-b557-d3e78541eac4"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0719 22:01:36.696732 18718 master.cpp:12712] Removing offer 5ed0af46-de03-4271-afc4-0960944d4b2f-O4
I0719 22:01:36.696988 18710 sched.cpp:960] Rescinded offer 5ed0af46-de03-4271-afc4-0960944d4b2f-O4
I0719 22:01:36.697120 18710 sched.cpp:971] Scheduler::offerRescinded took 40163ns
I0719 22:01:36.698706 18709 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test),1ae747a9-482b-40a1-9996-e78702b4437b:volume]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test),1ae747a9-482b-40a1-9996-e78702b4437b:volume]:2048, allocat
 ed: {}) on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 from framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:36.698920 18709 hierarchical.cpp:1264] Framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 filtered agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for 5secs
I0719 22:01:36.704183 18711 master.cpp:12603] Sending operation '' (uuid: 765233f4-acf0-4e9c-9f29-a8619cd52729) to agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:36.705130 18714 slave.cpp:4345] Ignoring new checkpointed resources and operations identical to the current version
I0719 22:01:36.709856 18716 provider.cpp:481] Received APPLY_OPERATION event
I0719 22:01:36.709904 18716 provider.cpp:1295] Received DESTROY operation '' (uuid: 765233f4-acf0-4e9c-9f29-a8619cd52729)
I0719 22:01:36.711057 18706 hierarchical.cpp:1508] Performed allocation for 1 agents in 2.055726ms
I0719 22:01:36.711906 18708 master.cpp:10420] Sending offers [ 5ed0af46-de03-4271-afc4-0960944d4b2f-O5 ] to framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:36.712677 18719 sched.cpp:934] Scheduler::resourceOffers took 100903ns
I0719 22:01:36.803978 18721 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 61d36a04-85f6-4d28-9a2d-c246ea225701) for operation UUID 765233f4-acf0-4e9c-9f29-a8619cd52729 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.804052 18721 status_update_manager_process.hpp:414] Creating operation status update stream 765233f4-acf0-4e9c-9f29-a8619cd52729 checkpoint=true
I0719 22:01:36.804414 18721 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 61d36a04-85f6-4d28-9a2d-c246ea225701) for operation UUID 765233f4-acf0-4e9c-9f29-a8619cd52729 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.870728 18721 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 61d36a04-85f6-4d28-9a2d-c246ea225701) for operation UUID 765233f4-acf0-4e9c-9f29-a8619cd52729 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.871528 18718 http_connection.hpp:131] Sending 2 call to http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:36.873071 18701 process.cpp:3671] Handling HTTP event for process 'slave(1213)' with path: '/slave(1213)/api/v1/resource_provider'
I0719 22:01:36.878098 18714 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1'
I0719 22:01:36.881207 18707 http.cpp:1115] HTTP POST for /master/api/v1 from 172.17.0.7:49972
I0719 22:01:36.881705 18707 http.cpp:263] Processing call UNRESERVE_RESOURCES
I0719 22:01:36.882831 18707 master.cpp:3915] Authorizing principal 'test-principal' to unreserve resources '[{"disk":{"source":{"id":"/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d","mount":{"root":"./csi/org.apache.mesos.csi.test/local/mounts"},"profile":"test","type":"MOUNT","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"623a1c06-3f05-4f48-b557-d3e78541eac4"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/default-role","type":"DYNAMIC"}],"scalar":{"value":2048.0},"type":"SCALAR"}]'
I0719 22:01:36.885655 18723 master.cpp:12712] Removing offer 5ed0af46-de03-4271-afc4-0960944d4b2f-O5
I0719 22:01:36.885875 18708 sched.cpp:960] Rescinded offer 5ed0af46-de03-4271-afc4-0960944d4b2f-O5
I0719 22:01:36.885996 18708 sched.cpp:971] Scheduler::offerRescinded took 39136ns
I0719 22:01:36.886862 18706 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/default-role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048, allocated: {}) on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 from framework 5ed0af46-de03-42
 71-afc4-0960944d4b2f-0000
I0719 22:01:36.887032 18706 hierarchical.cpp:1264] Framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 filtered agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 for 5secs
I0719 22:01:36.890017 18719 master.cpp:12603] Sending operation '' (uuid: 3a3f3c62-d43e-4667-b067-4a39a0335f2a) to agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:36.890815 18718 slave.cpp:4345] Ignoring new checkpointed resources and operations identical to the current version
I0719 22:01:36.894433 18722 provider.cpp:481] Received APPLY_OPERATION event
I0719 22:01:36.894510 18722 provider.cpp:1295] Received UNRESERVE operation '' (uuid: 3a3f3c62-d43e-4667-b067-4a39a0335f2a)
I0719 22:01:36.898365 18704 hierarchical.cpp:1508] Performed allocation for 1 agents in 1.824806ms
I0719 22:01:36.899401 18715 master.cpp:10420] Sending offers [ 5ed0af46-de03-4271-afc4-0960944d4b2f-O6 ] to framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:36.900398 18707 sched.cpp:934] Scheduler::resourceOffers took 116715ns
I0719 22:01:36.913314 18716 http.cpp:1115] HTTP POST for /slave(1213)/api/v1/resource_provider from 172.17.0.7:49920
I0719 22:01:36.914288 18710 slave.cpp:8416] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 765233f4-acf0-4e9c-9f29-a8619cd52729) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0719 22:01:36.914472 18710 slave.cpp:8869] Updating the state of operation with no ID (uuid: 765233f4-acf0-4e9c-9f29-a8619cd52729) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0719 22:01:36.914535 18710 slave.cpp:8623] Forwarding status update of operation with no ID (operation_uuid: 765233f4-acf0-4e9c-9f29-a8619cd52729) for an operator API call
I0719 22:01:36.914947 18709 master.cpp:12259] Updating the state of operation '' (uuid: 765233f4-acf0-4e9c-9f29-a8619cd52729) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0719 22:01:36.915552 18703 slave.cpp:4345] Ignoring new checkpointed resources and operations identical to the current version
I0719 22:01:36.988556 18707 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 4e959317-5a1c-4533-833c-1a20277c2c66) for operation UUID 3a3f3c62-d43e-4667-b067-4a39a0335f2a on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:36.988628 18707 status_update_manager_process.hpp:414] Creating operation status update stream 3a3f3c62-d43e-4667-b067-4a39a0335f2a checkpoint=true
I0719 22:01:36.988665 18722 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0719 22:01:36.988999 18707 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 4e959317-5a1c-4533-833c-1a20277c2c66) for operation UUID 3a3f3c62-d43e-4667-b067-4a39a0335f2a on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:37.055459 18707 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 4e959317-5a1c-4533-833c-1a20277c2c66) for operation UUID 3a3f3c62-d43e-4667-b067-4a39a0335f2a on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:37.056001 18707 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 61d36a04-85f6-4d28-9a2d-c246ea225701) for stream 765233f4-acf0-4e9c-9f29-a8619cd52729
I0719 22:01:37.056118 18707 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 61d36a04-85f6-4d28-9a2d-c246ea225701) for operation UUID 765233f4-acf0-4e9c-9f29-a8619cd52729 on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:37.056758 18702 http_connection.hpp:131] Sending 2 call to http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:37.058419 18706 process.cpp:3671] Handling HTTP event for process 'slave(1213)' with path: '/slave(1213)/api/v1/resource_provider'
I0719 22:01:37.097765 18720 http.cpp:1115] HTTP POST for /slave(1213)/api/v1/resource_provider from 172.17.0.7:49920
I0719 22:01:37.098951 18703 slave.cpp:8416] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 3a3f3c62-d43e-4667-b067-4a39a0335f2a) for framework  (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0719 22:01:37.099174 18703 slave.cpp:8869] Updating the state of operation with no ID (uuid: 3a3f3c62-d43e-4667-b067-4a39a0335f2a) for an operation API call (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0719 22:01:37.099241 18703 slave.cpp:8623] Forwarding status update of operation with no ID (operation_uuid: 3a3f3c62-d43e-4667-b067-4a39a0335f2a) for an operator API call
I0719 22:01:37.099674 18717 master.cpp:12259] Updating the state of operation '' (uuid: 3a3f3c62-d43e-4667-b067-4a39a0335f2a) for an operator API call (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0719 22:01:37.100823 18714 slave.cpp:4345] Ignoring new checkpointed resources and operations identical to the current version
I0719 22:01:37.103377 18723 provider.cpp:481] Received ACKNOWLEDGE_OPERATION_STATUS event
I0719 22:01:37.123769 18707 status_update_manager_process.hpp:490] Cleaning up operation status update stream 765233f4-acf0-4e9c-9f29-a8619cd52729
I0719 22:01:37.124094 18707 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 4e959317-5a1c-4533-833c-1a20277c2c66) for stream 3a3f3c62-d43e-4667-b067-4a39a0335f2a
I0719 22:01:37.124191 18707 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 4e959317-5a1c-4533-833c-1a20277c2c66) for operation UUID 3a3f3c62-d43e-4667-b067-4a39a0335f2a on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:37.207399 18707 status_update_manager_process.hpp:490] Cleaning up operation status update stream 3a3f3c62-d43e-4667-b067-4a39a0335f2a
I0719 22:01:37.310763 18721 master.cpp:1410] Framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344 disconnected
I0719 22:01:37.310809 18721 master.cpp:3360] Deactivating framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:37.311230 18718 hierarchical.cpp:475] Deactivated framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:37.311868 18724 slave.cpp:924] Agent terminating
I0719 22:01:37.312402 18721 master.cpp:12712] Removing offer 5ed0af46-de03-4271-afc4-0960944d4b2f-O6
I0719 22:01:37.312549 18721 master.cpp:3337] Disconnecting framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:37.312664 18721 master.cpp:1425] Giving framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344 0ns to failover
I0719 22:01:37.312983 18724 manager.cpp:163] Terminating resource provider 623a1c06-3f05-4f48-b557-d3e78541eac4
I0719 22:01:37.313789 18716 master.cpp:1295] Agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b) disconnected
I0719 22:01:37.313870 18716 master.cpp:3397] Disconnecting agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:37.313977 18716 master.cpp:3416] Deactivating agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 at slave(1213)@172.17.0.7:38344 (9601971be91b)
I0719 22:01:37.314026 18718 hierarchical.cpp:1218] Recovered disk(allocated: storage/default-role)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048; cpus(allocated: storage/default-role):2; mem(allocated: storage/default-role):1024; disk(allocated: storage/default-role):1024; ports(allocated: storage/default-role):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_OperatorOperationsWithResourceProviderResources_v1_nX3fiN/2GB-e6dc5ce5-e860-43ff-9da2-4386b3fe958d,test)]:2048, allocated: {}) on agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 from framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:37.314345 18718 hierarchical.cpp:799] Agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0 deactivated
I0719 22:01:37.314394 18716 master.cpp:10212] Framework failover timeout, removing framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
I0719 22:01:37.314442 18716 master.cpp:11211] Removing framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000 (default) at scheduler-cb41ac60-69c2-49a2-ad26-90a38b4098e2@172.17.0.7:38344
E0719 22:01:37.314777 18709 http_connection.hpp:452] End-Of-File received
I0719 22:01:37.314980 18703 hierarchical.cpp:1432] Allocation paused
I0719 22:01:37.315549 18709 http_connection.hpp:217] Re-detecting endpoint
I0719 22:01:37.315783 18703 hierarchical.cpp:417] Removed framework 5ed0af46-de03-4271-afc4-0960944d4b2f-0000
I0719 22:01:37.315867 18703 hierarchical.cpp:1442] Allocation resumed
I0719 22:01:37.316210 18709 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0719 22:01:37.316292 18709 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0719 22:01:37.316368 18705 provider.cpp:471] Disconnected from resource provider manager
I0719 22:01:37.316444 18709 http_connection.hpp:227] New endpoint detected at http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:37.316593 18721 status_update_manager_process.hpp:379] Pausing operation status update manager
I0719 22:01:37.318425 18713 containerizer.cpp:2598] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state
I0719 22:01:37.318471 18713 containerizer.cpp:3300] 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
I0719 22:01:37.319041 18713 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0719 22:01:37.321338 18715 hierarchical.cpp:1508] Performed allocation for 1 agents in 282818ns
I0719 22:01:37.321861 18703 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:37.322875 18705 provider.cpp:459] Connected to resource provider manager
I0719 22:01:37.323881 18708 http_connection.hpp:131] Sending 1 call to http://172.17.0.7:38344/slave(1213)/api/v1/resource_provider
I0719 22:01:37.324868 18725 process.cpp:2781] Returning '404 Not Found' for '/slave(1213)/api/v1/resource_provider'
E0719 22:01:37.326406 18709 provider.cpp:702] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0719 22:01:37.372601 18719 hierarchical.cpp:1508] Performed allocation for 1 agents in 232928ns
I0719 22:01:37.424068 18704 containerizer.cpp:3139] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited
I0719 22:01:37.424326 18715 hierarchical.cpp:1508] Performed allocation for 1 agents in 194359ns
I0719 22:01:37.426175 18704 provisioner.cpp:611] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0719 22:01:37.430821 18714 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'
I0719 22:01:37.431147 18716 service_manager.cpp:723] Disconnected from endpoint 'unix:///tmp/mesos-csi-sYHy6f/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE
I0719 22:01:37.431481 18701 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE'
I0719 22:01:37.436162 18725 process.cpp:2781] Returning '404 Not Found' for '/slave(1213)/api/v1'
I0719 22:01:37.449147 18700 master.cpp:1135] Master terminating
I0719 22:01:37.449965 18712 hierarchical.cpp:775] Removed all filters for agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
I0719 22:01:37.450001 18712 hierarchical.cpp:650] Removed agent 5ed0af46-de03-4271-afc4-0960944d4b2f-S0
[       OK ] CSIVersion/StorageLocalResourceProviderTest.OperatorOperationsWithResourceProviderResources/v1 (3540 ms)
[----------] 50 tests from CSIVersion/StorageLocalResourceProviderTest (117973 ms total)

[----------] Global test environment tear-down
[==========] 2285 tests from 217 test cases ran. (1311241 ms total)
[  PASSED  ] 2284 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] ExamplesTest.PythonFramework

 1 FAILED TEST
  YOU HAVE 31 DISABLED TESTS

I0719 22:01:37.596007 18725 process.cpp:935] Stopped the socket accept loop
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-1.9.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.9.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.9.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.9.0/_build'
make: *** [distcheck] Error 1
+ docker rmi --force mesos-1563566339-23078
Untagged: mesos-1563566339-23078:latest
Deleted: sha256:7cf20723fd7b598e7c8e5e332ec7b8aa144f84e3d2fb128d9bc467100bd43858
Deleted: sha256:c2a4bbba9947fe159229518400d43a7cd019fb5fa7d44dde78f56495a4b30a9e
Deleted: sha256:011cfc75c32138373d3ffd31ac2f8a4a91b05c04e4c8fc6743945ab5c3275075
Deleted: sha256:bbd72d809d4b72a7401d0397e097182a865b09dbf156f7876552cbebe330172d
Deleted: sha256:16cf5ad96769624ab70959028733a66c7f092488958973c269879dee828ca630
Deleted: sha256:669fc676e4d1698cb771a532b58112420ee9d20ca1ca27218f61e1faf2384461
Deleted: sha256:fbcd39663370ca99b103d7301d3fce9a73fbe07271b8d83cfb8a158c74e80e1e
Deleted: sha256:5ac3718438b7b07b4db62ade3378635fda5b542bc9eaa6e76c769f52facfa05c
Deleted: sha256:b96168273446e4207f6234c70d897f31fc5e1fe26164c47866ab6bf03ac48a99
Deleted: sha256:d472c3dd94ae853031a0104562f46b054a6e26581f00efca88cb9475d5bc2815
Deleted: sha256:2ac833889fae17a167ff21f65a5554e2a4ad2abb1858c5ff6bead23fb41edf42
Deleted: sha256:c82c1df1cbf115860a50eef3eaaffd042e5bf47fb64b18dca96691d78417b106
Deleted: sha256:1a2ee6537f6a2c529d549f44431e85649a5a1a406b869b17e842f882012fd0cc
Deleted: sha256:9d0577eb3e8388bd771c66f0e318162ba3c1f57e0cd8864928187483ddcac552
Deleted: sha256:3c5a953955c2652b19c3036c986b44e525c8274252823020ae5eee45c089c5d6
Deleted: sha256:483f57064598f14e03c711213779a154d99012aeca8022ab31949aaa977c6a83
Deleted: sha256:d3d60c62f2532d48f4a904c76d4e2435537716cb68eb9c84d79801f8b3b904b7
Deleted: sha256:f99b28318044c8dfdabf94753c964fc83d4e1b557d053d7f547b57d32c751662
Deleted: sha256:650b98d6f9731a34dde9819e7dd40319951adb1ff7f63851f61f7568112da548
Deleted: sha256:28523f42a97c87ca85dd148b5db8d80962abf6f1d1658f9eb36a7bb81f34297c
Deleted: sha256:f7686be7156534fd4a661a3275e6915aa8cc453b2930560a6b61ce13a628ee23
Deleted: sha256:796848a2a67e84bc1d55003154177d60cec4c7935ff5416aa164863631acd6fd
Deleted: sha256:923b994575f295f2bf5cc09cd4d30973984980ce0f1edabdfb2e1aa9bcb71788
Deleted: sha256:8a7d4cab23754d785ca9665344906676a69614fa9d1afe51bd4872ad0fad8df4
Deleted: sha256:c40b62eb85b9e176c38d2cabdcd4521747c1f93fbdae2808c6f9a41035236d40
Deleted: sha256:01d4ca28da2ba18ef6081f9b817ea5897319a0aa1857076891b1b7c36bd659a3
Deleted: sha256:9a84f68f171c1781c116b3372b68a8bf9cfece96d06bbe1a52afcab16fa250c0
Deleted: sha256:552873f4947637e3397a1d4eaf7960cef2e9f0b30f84a0ea20b0ea3b2c429b1c
Deleted: sha256:c3002b39d7783f14c3fb7b3b55f98f04e85afa2db30adbc53e815a00780ba76c
Deleted: sha256:7a1c85fbeb6c9f30ea1787d407d35fa1f6af05e9458a407aebe116c2b1aeea9f
Deleted: sha256:2c5e00d77a67934d5e39493477f262b878f127b9c01b491f06d8f06f78819578
Deleted: sha256:664a2bb343be8b1a691e0ce9c563ee654c30a1c694dc1b25ebb5467fa3d074fd
Deleted: sha256:4ac0c5a114c714b429ff471f5415974618e0b6fc743070d445cd0e2ac586cc7b
Deleted: sha256:5f200444c0009c41eb39bc1cf37a5b3c2e953478f2f373c5a1873dee820e0ced
Deleted: sha256:b057ab380990c219581e3b074919413ebe31079cbd0d615f63872c471b4dc633

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

- Mesos Reviewbot


On July 18, 2019, 9:05 a.m., Andrei Sekretenko wrote:
> 
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/71117/
> -----------------------------------------------------------
> 
> (Updated July 18, 2019, 9:05 a.m.)
> 
> 
> Review request for mesos and Andrei Sekretenko.
> 
> 
> Repository: mesos
> 
> 
> Description
> -------
> 
> WIP: debug egg build at ASF CI.
> 
> 
> Diffs
> -----
> 
>   src/python/native_common/ext_modules.py.in 38e6717ec3b7bb09cfbb9b2fa25f173a17d78f51 
> 
> 
> Diff: https://reviews.apache.org/r/71117/diff/2/
> 
> 
> Testing
> -------
> 
> 
> Thanks,
> 
> Andrei Sekretenko
> 
>