----------------------------------------------------------- This is an automatically generated e-mail. To reply, visit: https://reviews.apache.org/r/71455/#review217663 -----------------------------------------------------------
Bad patch! Reviews applied: [71454, 71455] 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_71455"] Error: ...<truncated>... pp:891] Removed agent 7a25d834-f5dd-4508-937d-291d4f68748e-S0 [ OK ] CSIVersion/StorageLocalResourceProviderTest.CreateDestroyDiskWithRecovery/v0 (3938 ms) [ RUN ] CSIVersion/StorageLocalResourceProviderTest.CreateDestroyDiskWithRecovery/v1 I0909 19:07:05.873780 18915 cluster.cpp:177] Creating default 'local' authorizer I0909 19:07:05.878141 18934 master.cpp:440] Master a0055024-74a2-47f4-8a64-e7876b603597 (2e411cc79614) started on 172.17.0.2:33926 I0909 19:07:05.878180 18934 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/5qNuFe/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.10.0/_inst/share/mesos/webui" --work_dir="/tmp/5qNuFe/master" --zk_session_timeout="10secs" I0909 19:07:05.878645 18934 master.cpp:492] Master only allowing authenticated frameworks to register I0909 19:07:05.878664 18934 master.cpp:498] Master only allowing authenticated agents to register I0909 19:07:05.878674 18934 master.cpp:504] Master only allowing authenticated HTTP frameworks to register I0909 19:07:05.878685 18934 credentials.hpp:37] Loading credentials for authentication from '/tmp/5qNuFe/credentials' I0909 19:07:05.879004 18934 master.cpp:548] Using default 'crammd5' authenticator I0909 19:07:05.879210 18934 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0909 19:07:05.879443 18934 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0909 19:07:05.879627 18934 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0909 19:07:05.879798 18934 master.cpp:629] Authorization enabled I0909 19:07:05.880210 18925 hierarchical.cpp:474] Initialized hierarchical allocator process I0909 19:07:05.880225 18929 whitelist_watcher.cpp:77] No whitelist given I0909 19:07:05.883572 18930 master.cpp:2169] Elected as the leading master! I0909 19:07:05.883613 18930 master.cpp:1665] Recovering from registrar I0909 19:07:05.883797 18935 registrar.cpp:339] Recovering registrar I0909 19:07:05.884609 18935 registrar.cpp:383] Successfully fetched the registry (0B) in 756224ns I0909 19:07:05.884752 18935 registrar.cpp:487] Applied 1 operations in 41971ns; attempting to update the registry I0909 19:07:05.885488 18935 registrar.cpp:544] Successfully updated the registry in 660992ns I0909 19:07:05.885628 18935 registrar.cpp:416] Successfully recovered registrar I0909 19:07:05.886270 18928 master.cpp:1818] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister I0909 19:07:05.886293 18916 hierarchical.cpp:513] Skipping recovery of hierarchical allocator: nothing to recover W0909 19:07:05.892613 18915 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:33926 I0909 19:07:05.894309 18915 containerizer.cpp:318] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } W0909 19:07:05.895031 18915 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges W0909 19:07:05.895066 18915 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges W0909 19:07:05.895200 18915 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges I0909 19:07:05.895244 18915 provisioner.cpp:300] Using default backend 'copy' I0909 19:07:05.897827 18915 cluster.cpp:524] Creating default 'local' authorizer I0909 19:07:05.900156 18925 slave.cpp:267] Mesos agent started on (1189)@172.17.0.2:33926 I0909 19:07:05.900185 18925 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/5qNuFe/bov1nx/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/5qNuFe/bov1nx/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/5qNuFe/bov1nx/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/5qNuFe/bov1nx/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/5qNuFe/bov1nx/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/5qNuFe/bov1nx/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.10.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/5qNuFe/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_CreateDestroyDiskWithRecovery_v1_Dq4bHs" --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_Create DestroyDiskWithRecovery_v1_XQun0n" --zk_session_timeout="10secs" I0909 19:07:05.900718 18925 credentials.hpp:86] Loading credential for authentication from '/tmp/5qNuFe/bov1nx/credential' I0909 19:07:05.900899 18925 slave.cpp:300] Agent using credential for: test-principal I0909 19:07:05.900925 18925 credentials.hpp:37] Loading credentials for authentication from '/tmp/5qNuFe/bov1nx/http_credentials' I0909 19:07:05.901144 18925 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0909 19:07:05.901515 18925 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor' I0909 19:07:05.903128 18936 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles I0909 19:07:05.903141 18925 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"}] I0909 19:07:05.903357 18925 slave.cpp:623] Agent attributes: [ ] I0909 19:07:05.903373 18925 slave.cpp:632] Agent hostname: 2e411cc79614 I0909 19:07:05.903556 18938 status_update_manager_process.hpp:379] Pausing operation status update manager I0909 19:07:05.903591 18926 task_status_update_manager.cpp:181] Pausing sending task status updates I0909 19:07:05.905311 18931 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/meta' I0909 19:07:05.905580 18918 slave.cpp:7491] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/meta', beginning agent recovery I0909 19:07:05.906206 18933 task_status_update_manager.cpp:207] Recovering task status update manager I0909 19:07:05.906769 18924 containerizer.cpp:821] Recovering Mesos containers I0909 19:07:05.907213 18924 containerizer.cpp:1161] Recovering isolators I0909 19:07:05.907963 18939 containerizer.cpp:1200] Recovering provisioner I0909 19:07:05.908823 18926 provisioner.cpp:500] Provisioner recovery complete I0909 19:07:05.909544 18933 composing.cpp:339] Finished recovering all containerizers I0909 19:07:05.909834 18922 slave.cpp:7972] Recovering executors I0909 19:07:05.909948 18922 slave.cpp:8125] Finished recovery I0909 19:07:05.910794 18934 task_status_update_manager.cpp:181] Pausing sending task status updates I0909 19:07:05.910817 18920 status_update_manager_process.hpp:379] Pausing operation status update manager I0909 19:07:05.910861 18928 slave.cpp:1351] New master detected at master@172.17.0.2:33926 I0909 19:07:05.911025 18928 slave.cpp:1416] Detecting new master I0909 19:07:05.914403 18921 slave.cpp:1443] Authenticating with master master@172.17.0.2:33926 I0909 19:07:05.914496 18921 slave.cpp:1452] Using default CRAM-MD5 authenticatee I0909 19:07:05.914825 18924 authenticatee.cpp:121] Creating new client SASL connection I0909 19:07:05.915235 18919 master.cpp:10574] Authenticating slave(1189)@172.17.0.2:33926 I0909 19:07:05.915419 18936 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2014)@172.17.0.2:33926 I0909 19:07:05.915735 18938 authenticator.cpp:98] Creating new server SASL connection I0909 19:07:05.916033 18932 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0909 19:07:05.916067 18932 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0909 19:07:05.916183 18932 authenticator.cpp:204] Received SASL authentication start I0909 19:07:05.916256 18932 authenticator.cpp:326] Authentication requires more steps I0909 19:07:05.916385 18925 authenticatee.cpp:259] Received SASL authentication step I0909 19:07:05.916534 18937 authenticator.cpp:232] Received SASL authentication step I0909 19:07:05.916574 18937 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e411cc79614' server FQDN: '2e411cc79614' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0909 19:07:05.916589 18937 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0909 19:07:05.916635 18937 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0909 19:07:05.916661 18937 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e411cc79614' server FQDN: '2e411cc79614' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0909 19:07:05.916676 18937 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0909 19:07:05.916693 18937 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0909 19:07:05.916712 18937 authenticator.cpp:318] Authentication success I0909 19:07:05.916805 18917 authenticatee.cpp:299] Authentication success I0909 19:07:05.916937 18918 master.cpp:10606] Successfully authenticated principal 'test-principal' at slave(1189)@172.17.0.2:33926 I0909 19:07:05.917003 18933 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2014)@172.17.0.2:33926 I0909 19:07:05.917220 18931 slave.cpp:1543] Successfully authenticated with master master@172.17.0.2:33926 I0909 19:07:05.917593 18931 slave.cpp:1993] Will retry registration in 10.873206ms if necessary I0909 19:07:05.917788 18923 master.cpp:7069] Received register agent message from slave(1189)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:05.918081 18923 master.cpp:4189] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal' I0909 19:07:05.918808 18920 master.cpp:7136] Authorized registration of agent at slave(1189)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:05.918925 18920 master.cpp:7248] Registering agent at slave(1189)@172.17.0.2:33926 (2e411cc79614) with id a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:05.919674 18930 registrar.cpp:487] Applied 1 operations in 264534ns; attempting to update the registry I0909 19:07:05.920500 18930 registrar.cpp:544] Successfully updated the registry in 730112ns I0909 19:07:05.920696 18936 master.cpp:7296] Admitted agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1189)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:05.921512 18936 master.cpp:7341] Registered agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1189)@172.17.0.2:33926 (2e411cc79614) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0909 19:07:05.921681 18932 hierarchical.cpp:854] Added agent a0055024-74a2-47f4-8a64-e7876b603597-S0 (2e411cc79614) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {}) I0909 19:07:05.921742 18926 slave.cpp:1576] Registered with master master@172.17.0.2:33926; given agent ID a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:05.921860 18935 task_status_update_manager.cpp:188] Resuming sending task status updates I0909 19:07:05.922181 18926 slave.cpp:1611] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/meta/slaves/a0055024-74a2-47f4-8a64-e7876b603597-S0/slave.info' I0909 19:07:05.922235 18932 hierarchical.cpp:1726] Performed allocation for 1 agents in 155171ns I0909 19:07:05.922247 18929 status_update_manager_process.hpp:385] Resuming operation status update manager W0909 19:07:05.922678 18915 process.cpp:2877] Attempted to spawn already running process version@172.17.0.2:33926 I0909 19:07:05.923346 18926 slave.cpp:1663] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"txeCZF6hRt+nS06GZAsFag=="},"slave_id":{"value":"a0055024-74a2-47f4-8a64-e7876b603597-S0"},"update_oversubscribed_resources":false} I0909 19:07:05.923979 18915 sched.cpp:239] Version: 1.10.0 I0909 19:07:05.924063 18920 master.cpp:8460] Ignoring update on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1189)@172.17.0.2:33926 (2e411cc79614) as it reports no changes I0909 19:07:05.924746 18927 sched.cpp:343] New master detected at master@172.17.0.2:33926 I0909 19:07:05.924860 18927 sched.cpp:408] Authenticating with master master@172.17.0.2:33926 I0909 19:07:05.924885 18927 sched.cpp:415] Using default CRAM-MD5 authenticatee I0909 19:07:05.925227 18917 authenticatee.cpp:121] Creating new client SASL connection I0909 19:07:05.925608 18917 master.cpp:10574] Authenticating scheduler-345c4018-e916-4fc0-9e4f-f427b22ba1a0@172.17.0.2:33926 I0909 19:07:05.925762 18922 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2015)@172.17.0.2:33926 I0909 19:07:05.926007 18916 authenticator.cpp:98] Creating new server SASL connection I0909 19:07:05.926218 18926 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0909 19:07:05.926249 18926 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0909 19:07:05.926388 18931 authenticator.cpp:204] Received SASL authentication start I0909 19:07:05.926463 18931 authenticator.cpp:326] Authentication requires more steps I0909 19:07:05.926579 18931 authenticatee.cpp:259] Received SASL authentication step I0909 19:07:05.926721 18939 authenticator.cpp:232] Received SASL authentication step I0909 19:07:05.926775 18939 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e411cc79614' server FQDN: '2e411cc79614' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0909 19:07:05.926807 18939 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0909 19:07:05.926867 18939 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0909 19:07:05.926916 18939 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e411cc79614' server FQDN: '2e411cc79614' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0909 19:07:05.926945 18939 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0909 19:07:05.926965 18939 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0909 19:07:05.926995 18939 authenticator.cpp:318] Authentication success I0909 19:07:05.927095 18920 authenticatee.cpp:299] Authentication success I0909 19:07:05.927233 18919 master.cpp:10606] Successfully authenticated principal 'test-principal' at scheduler-345c4018-e916-4fc0-9e4f-f427b22ba1a0@172.17.0.2:33926 I0909 19:07:05.927296 18930 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2015)@172.17.0.2:33926 I0909 19:07:05.927529 18938 sched.cpp:520] Successfully authenticated with master master@172.17.0.2:33926 I0909 19:07:05.927561 18938 sched.cpp:835] Sending SUBSCRIBE call to master@172.17.0.2:33926 I0909 19:07:05.927727 18938 sched.cpp:870] Will retry registration in 73.980971ms if necessary I0909 19:07:05.927939 18927 master.cpp:2909] Received SUBSCRIBE call for framework 'default' at scheduler-345c4018-e916-4fc0-9e4f-f427b22ba1a0@172.17.0.2:33926 I0909 19:07:05.927983 18927 master.cpp:2241] Authorizing framework principal 'test-principal' to receive offers for roles '{ storage/role }' I0909 19:07:05.928568 18935 master.cpp:2996] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] I0909 19:07:05.929306 18922 process.cpp:3671] Handling HTTP event for process 'slave(1189)' with path: '/slave(1189)/api/v1' I0909 19:07:05.930300 18935 master.cpp:10804] Adding framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (default) at scheduler-345c4018-e916-4fc0-9e4f-f427b22ba1a0@172.17.0.2:33926 with roles { } suppressed I0909 19:07:05.930497 18931 http.cpp:1115] HTTP POST for /slave(1189)/api/v1 from 172.17.0.2:58812 I0909 19:07:05.930898 18919 sched.cpp:751] Framework registered with a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:05.930963 18919 sched.cpp:770] Scheduler::registered took 33515ns I0909 19:07:05.931057 18931 http.cpp:2146] Processing GET_CONTAINERS call I0909 19:07:05.931425 18934 hierarchical.cpp:605] Added framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:05.932732 18934 hierarchical.cpp:1726] Performed allocation for 1 agents in 1.028828ms I0909 19:07:05.933519 18937 master.cpp:10389] Sending offers [ a0055024-74a2-47f4-8a64-e7876b603597-O0 ] to framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (default) at scheduler-345c4018-e916-4fc0-9e4f-f427b22ba1a0@172.17.0.2:33926 I0909 19:07:05.934496 18932 sched.cpp:934] Scheduler::resourceOffers took 241310ns I0909 19:07:05.934926 18916 master.cpp:6213] Processing DECLINE call for offers: [ a0055024-74a2-47f4-8a64-e7876b603597-O0 ] for framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (default) at scheduler-345c4018-e916-4fc0-9e4f-f427b22ba1a0@172.17.0.2:33926 with 3.1536e+07 seconds filter I0909 19:07:05.935536 18916 master.cpp:12684] Removing offer a0055024-74a2-47f4-8a64-e7876b603597-O0 I0909 19:07:05.936424 18921 hierarchical.cpp:1451] Recovered ports(allocated: storage/role):[31000-32000]; cpus(allocated: storage/role):2; mem(allocated: storage/role):1024; disk(allocated: storage/role):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], offered or allocated: {}) on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 from framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:05.936501 18921 hierarchical.cpp:1498] Framework a0055024-74a2-47f4-8a64-e7876b603597-0000 filtered agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for 365days I0909 19:07:05.938206 18920 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:05.941009 18918 process.cpp:3671] Handling HTTP event for process 'slave(1189)' with path: '/slave(1189)/api/v1' I0909 19:07:05.941998 18934 http.cpp:1115] HTTP POST for /slave(1189)/api/v1 from 172.17.0.2:58814 I0909 19:07:05.942785 18934 http.cpp:2606] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:05.943997 18917 http.cpp:2710] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:05.944758 18932 containerizer.cpp:1396] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0909 19:07:05.945670 18932 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from STARTING to PROVISIONING after 333056ns I0909 19:07:05.946362 18932 containerizer.cpp:1574] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_Dq4bHs/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config' I0909 19:07:05.946427 18932 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PROVISIONING to PREPARING after 759040ns I0909 19:07:05.949815 18924 containerizer.cpp:2100] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj","--available_capacity=4GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.0/_build/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/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-zSYBuQ/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/containe rs/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="70" --pipe_write="71" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_Dq4bHs/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"' I0909 19:07:05.958425 18924 launcher.cpp:145] Forked child with pid '32535' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:05.959498 18924 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PREPARING to ISOLATING after 13.058048ms I0909 19:07:05.961236 18924 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from ISOLATING to FETCHING after 1.730816ms I0909 19:07:05.961634 18937 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_CreateDestroyDiskWithRecovery_v1_XQun0n/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0909 19:07:05.963075 18923 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from FETCHING to RUNNING after 1.723136ms I0909 19:07:05.966171 18929 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' I0909 19:07:05.966377 18929 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-zSYBuQ/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0909 19:07:05.984421 18918 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:05.984577 18918 hierarchical.cpp:1726] Performed allocation for 1 agents in 717319ns I0909 19:07:06.036156 18936 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.036361 18936 hierarchical.cpp:1726] Performed allocation for 1 agents in 850284ns I0909 19:07:06.087462 18919 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.087579 18919 hierarchical.cpp:1726] Performed allocation for 1 agents in 414849ns I0909 19:07:06.138866 18925 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.138989 18925 hierarchical.cpp:1726] Performed allocation for 1 agents in 453352ns I0909 19:07:06.190510 18930 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.190762 18930 hierarchical.cpp:1726] Performed allocation for 1 agents in 867024ns I0909 19:07:06.242045 18935 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.242230 18935 hierarchical.cpp:1726] Performed allocation for 1 agents in 699275ns I0909 19:07:06.293604 18926 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.293771 18926 hierarchical.cpp:1726] Performed allocation for 1 agents in 662176ns I0909 19:07:06.345839 18918 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.346071 18918 hierarchical.cpp:1726] Performed allocation for 1 agents in 765127ns I0909 19:07:06.398123 18936 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.398272 18936 hierarchical.cpp:1726] Performed allocation for 1 agents in 572579ns I0909 19:07:06.420945 18923 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-zSYBuQ/endpoint.sock' with CSI v1 I0909 19:07:06.437110 32539 test_csi_plugin.cpp:909] ProbeRequest '{}' I0909 19:07:06.439581 18933 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:06.442983 32540 test_csi_plugin.cpp:895] GetPluginCapabilitiesRequest '{}' I0909 19:07:06.443653 18939 process.cpp:3671] Handling HTTP event for process 'slave(1189)' with path: '/slave(1189)/api/v1' I0909 19:07:06.445255 18924 http.cpp:1115] HTTP POST for /slave(1189)/api/v1 from 172.17.0.2:58816 I0909 19:07:06.445854 18924 http.cpp:2824] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:06.448236 32539 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}' I0909 19:07:06.448650 32540 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}' I0909 19:07:06.450371 18929 v1_volume_manager.cpp:649] NODE_SERVICE loaded: {"name":".","vendorVersion":"1.10.0"} I0909 19:07:06.450498 18925 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.450697 18925 hierarchical.cpp:1726] Performed allocation for 1 agents in 755023ns I0909 19:07:06.450968 18929 v1_volume_manager.cpp:649] CONTROLLER_SERVICE loaded: {"name":".","vendorVersion":"1.10.0"} I0909 19:07:06.453346 32541 test_csi_plugin.cpp:1105] ControllerGetCapabilitiesRequest '{}' I0909 19:07:06.456851 32539 test_csi_plugin.cpp:1241] NodeGetCapabilitiesRequest '{}' I0909 19:07:06.460170 32539 test_csi_plugin.cpp:1255] NodeGetInfoRequest '{}' I0909 19:07:06.462043 18932 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test' I0909 19:07:06.462218 18938 status_update_manager_process.hpp:379] Pausing operation status update manager I0909 19:07:06.462736 18921 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:33926/slave(1189)/api/v1/resource_provider I0909 19:07:06.465873 18931 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:33926/slave(1189)/api/v1/resource_provider I0909 19:07:06.466647 18937 provider.cpp:476] Connected to resource provider manager I0909 19:07:06.467572 18922 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:33926/slave(1189)/api/v1/resource_provider I0909 19:07:06.469251 18916 process.cpp:3671] Handling HTTP event for process 'slave(1189)' with path: '/slave(1189)/api/v1/resource_provider' I0909 19:07:06.471408 18920 http.cpp:1115] HTTP POST for /slave(1189)/api/v1/resource_provider from 172.17.0.2:58820 I0909 19:07:06.472208 18921 manager.cpp:813] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj","--available_capacity=4GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.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"},"reconciliation_interval_seconds":0.0},"type":"org.apache.mesos.rp.local.storage"} I0909 19:07:06.502790 18930 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.502996 18930 hierarchical.cpp:1726] Performed allocation for 1 agents in 820435ns I0909 19:07:06.505410 18935 slave.cpp:8481] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"ed026377-7715-4186-9441-147807a7ac94"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj","--available_capacity=4GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.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"},"reconciliation_interval_seconds":0.0},"type":"org.apache.mesos.rp.local.storage"}' I0909 19:07:06.507511 18923 provider.cpp:498] Received SUBSCRIBED event I0909 19:07:06.507570 18923 provider.cpp:1309] Subscribed with ID ed026377-7715-4186-9441-147807a7ac94 I0909 19:07:06.508555 18932 status_update_manager_process.hpp:314] Recovering operation status update manager I0909 19:07:06.554672 18929 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.554844 18929 hierarchical.cpp:1726] Performed allocation for 1 agents in 610424ns I0909 19:07:06.571805 18920 provider.cpp:790] Reconciling storage pools and volumes I0909 19:07:06.574759 32539 test_csi_plugin.cpp:1050] ListVolumesRequest '{}' I0909 19:07:06.576972 18937 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:06.577327 18937 provider.cpp:748] Resource provider ed026377-7715-4186-9441-147807a7ac94 is in READY state I0909 19:07:06.577296 18917 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.2:33926/slave(1189)/api/v1/resource_provider I0909 19:07:06.577370 18922 status_update_manager_process.hpp:385] Resuming operation status update manager I0909 19:07:06.578049 18924 provider.cpp:1235] Updating profiles { test } for resource provider ed026377-7715-4186-9441-147807a7ac94 I0909 19:07:06.578774 18919 process.cpp:3671] Handling HTTP event for process 'slave(1189)' with path: '/slave(1189)/api/v1/resource_provider' I0909 19:07:06.579282 18934 provider.cpp:790] Reconciling storage pools and volumes I0909 19:07:06.580572 18922 http.cpp:1115] HTTP POST for /slave(1189)/api/v1/resource_provider from 172.17.0.2:58818 I0909 19:07:06.581096 18937 manager.cpp:1045] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider ed026377-7715-4186-9441-147807a7ac94 I0909 19:07:06.581311 18933 slave.cpp:8481] Handling resource provider message 'UPDATE_STATE: ed026377-7715-4186-9441-147807a7ac94 {}' I0909 19:07:06.581421 18933 slave.cpp:8601] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0909 19:07:06.581629 32541 test_csi_plugin.cpp:1050] ListVolumesRequest '{}' I0909 19:07:06.582355 32541 test_csi_plugin.cpp:1078] GetCapacityRequest '{"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}' I0909 19:07:06.583148 18921 hierarchical.cpp:992] Grew agent a0055024-74a2-47f4-8a64-e7876b603597-S0 by {} (total), { } (used) I0909 19:07:06.583575 18921 hierarchical.cpp:950] Agent a0055024-74a2-47f4-8a64-e7876b603597-S0 (2e411cc79614) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0909 19:07:06.586309 18935 provider.cpp:808] Removing '{}' and adding 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096' to the total resources I0909 19:07:06.606627 18934 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.606758 18934 hierarchical.cpp:1726] Performed allocation for 1 agents in 583417ns I0909 19:07:06.630515 18935 provider.cpp:2217] Sending UPDATE_STATE call with resources 'disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096' and 0 operations to agent a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:06.630972 18922 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.2:33926/slave(1189)/api/v1/resource_provider I0909 19:07:06.632127 18917 process.cpp:3671] Handling HTTP event for process 'slave(1189)' with path: '/slave(1189)/api/v1/resource_provider' I0909 19:07:06.658741 18923 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.658897 18923 hierarchical.cpp:1726] Performed allocation for 1 agents in 601894ns I0909 19:07:06.672034 18929 http.cpp:1115] HTTP POST for /slave(1189)/api/v1/resource_provider from 172.17.0.2:58818 I0909 19:07:06.673113 18920 manager.cpp:1045] Received UPDATE_STATE call with resources '[{"disk":{"source":{"profile":"test","type":"RAW","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"ed026377-7715-4186-9441-147807a7ac94"},"reservations":[{"role":"storage","type":"DYNAMIC"}],"scalar":{"value":4096.0},"type":"SCALAR"}]' and 0 operations from resource provider ed026377-7715-4186-9441-147807a7ac94 I0909 19:07:06.673921 18927 slave.cpp:8481] Handling resource provider message 'UPDATE_STATE: ed026377-7715-4186-9441-147807a7ac94 disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096' I0909 19:07:06.674191 18927 slave.cpp:8601] 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)]:4096 I0909 19:07:06.678014 18925 hierarchical.cpp:950] Agent a0055024-74a2-47f4-8a64-e7876b603597-S0 (2e411cc79614) 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)]:4096 I0909 19:07:06.680271 18925 hierarchical.cpp:1726] Performed allocation for 1 agents in 1.932477ms I0909 19:07:06.681764 18916 master.cpp:10389] Sending offers [ a0055024-74a2-47f4-8a64-e7876b603597-O1 ] to framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (default) at scheduler-345c4018-e916-4fc0-9e4f-f427b22ba1a0@172.17.0.2:33926 I0909 19:07:06.683367 18936 sched.cpp:934] Scheduler::resourceOffers took 286762ns I0909 19:07:06.685968 18917 master.cpp:4719] Processing ACCEPT call for offers: [ a0055024-74a2-47f4-8a64-e7876b603597-O1 ] on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1189)@172.17.0.2:33926 (2e411cc79614) for framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (default) at scheduler-345c4018-e916-4fc0-9e4f-f427b22ba1a0@172.17.0.2:33926 I0909 19:07:06.686221 18917 master.cpp:3811] Authorizing principal 'test-principal' to reserve resources 'disk(allocated: storage/role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096' I0909 19:07:06.686573 18917 master.cpp:4099] Authorizing principal 'test-principal' to create a MOUNT disk from 'disk(allocated: storage/role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096' I0909 19:07:06.688413 18920 master.cpp:12684] Removing offer a0055024-74a2-47f4-8a64-e7876b603597-O1 I0909 19:07:06.689227 18920 master.cpp:5105] Applying RESERVE operation for resources [{"allocation_info":{"role":"storage/role"},"disk":{"source":{"profile":"test","type":"RAW","vendor":"org.apache.mesos.csi.test.local"}},"name":"disk","provider_id":{"value":"ed026377-7715-4186-9441-147807a7ac94"},"reservations":[{"role":"storage","type":"DYNAMIC"},{"principal":"test-principal","role":"storage/role","type":"DYNAMIC"}],"scalar":{"value":4096.0},"type":"SCALAR"}] from framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (default) at scheduler-345c4018-e916-4fc0-9e4f-f427b22ba1a0@172.17.0.2:33926 to agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1189)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:06.690518 18920 master.cpp:12557] Sending operation '' (uuid: 7740940e-c924-4f22-85e0-525f71eb74a5) to agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1189)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:06.691150 18920 master.cpp:6005] Processing CREATE_DISK operation with source disk(allocated: storage/role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096 from framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (default) at scheduler-345c4018-e916-4fc0-9e4f-f427b22ba1a0@172.17.0.2:33926 to agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1189)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:06.691316 18919 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version I0909 19:07:06.691890 18920 master.cpp:12557] Sending operation '' (uuid: e4120ec4-776e-4cf0-a712-4c7de2b31062) to agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1189)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:06.692586 18931 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version I0909 19:07:06.695240 18933 provider.cpp:498] Received APPLY_OPERATION event I0909 19:07:06.695287 18933 provider.cpp:1351] Received RESERVE operation '' (uuid: 7740940e-c924-4f22-85e0-525f71eb74a5) I0909 19:07:06.695807 18918 hierarchical.cpp:1193] Updated allocation of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 from ports(allocated: storage/role):[31000-32000]; disk(allocated: storage/role)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096; cpus(allocated: storage/role):2; mem(allocated: storage/role):1024; disk(allocated: storage/role):1024 to ports(allocated: storage/role):[31000-32000]; disk(allocated: storage/role):1024; cpus(allocated: storage/role):2; mem(allocated: storage/role):1024; disk(allocated: storage/role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096 I0909 19:07:06.696038 18918 hierarchical.cpp:1650] Allocation paused I0909 19:07:06.697476 18918 hierarchical.cpp:1451] Recovered ports(allocated: storage/role):[31000-32000]; disk(allocated: storage/role):1024; cpus(allocated: storage/role):2; mem(allocated: storage/role):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096, offered or allocated: disk(allocated: storage/role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096) on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 from framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.697608 18918 hierarchical.cpp:1498] Framework a0055024-74a2-47f4-8a64-e7876b603597-0000 filtered agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for 5secs I0909 19:07:06.697953 18918 hierarchical.cpp:1660] Allocation resumed I0909 19:07:06.710937 18932 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.711099 18932 hierarchical.cpp:1726] Performed allocation for 1 agents in 654073ns I0909 19:07:06.762265 18921 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.762411 18921 hierarchical.cpp:1726] Performed allocation for 1 agents in 432516ns I0909 19:07:06.782212 18927 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: 6dd039be-52d1-40bb-9216-c1dcf943d0f7) for operation UUID 7740940e-c924-4f22-85e0-525f71eb74a5 of framework 'a0055024-74a2-47f4-8a64-e7876b603597-0000' on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:06.782295 18927 status_update_manager_process.hpp:414] Creating operation status update stream 7740940e-c924-4f22-85e0-525f71eb74a5 checkpoint=true I0909 19:07:06.782514 18933 provider.cpp:498] Received APPLY_OPERATION event I0909 19:07:06.782558 18933 provider.cpp:1351] Received CREATE_DISK operation '' (uuid: e4120ec4-776e-4cf0-a712-4c7de2b31062) I0909 19:07:06.782781 18927 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: 6dd039be-52d1-40bb-9216-c1dcf943d0f7) for operation UUID 7740940e-c924-4f22-85e0-525f71eb74a5 of framework 'a0055024-74a2-47f4-8a64-e7876b603597-0000' on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:06.813769 18919 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.813988 18919 hierarchical.cpp:1726] Performed allocation for 1 agents in 670968ns I0909 19:07:06.865532 18930 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.865720 18930 hierarchical.cpp:1726] Performed allocation for 1 agents in 640282ns I0909 19:07:06.874460 18927 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: 6dd039be-52d1-40bb-9216-c1dcf943d0f7) for operation UUID 7740940e-c924-4f22-85e0-525f71eb74a5 of framework 'a0055024-74a2-47f4-8a64-e7876b603597-0000' on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:06.891793 18931 v1_volume_manager.cpp:293] Creating volume with name 'e4120ec4-776e-4cf0-a712-4c7de2b31062' I0909 19:07:06.893280 18935 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:33926/slave(1189)/api/v1/resource_provider I0909 19:07:06.894968 18938 process.cpp:3671] Handling HTTP event for process 'slave(1189)' with path: '/slave(1189)/api/v1/resource_provider' I0909 19:07:06.895165 32541 test_csi_plugin.cpp:922] CreateVolumeRequest '{"name":"e4120ec4-776e-4cf0-a712-4c7de2b31062","capacityRange":{"requiredBytes":"4294967296","limitBytes":"4294967296"},"volumeCapabilities":[{"mount":{},"accessMode":{"mode":"SINGLE_NODE_WRITER"}}]}' I0909 19:07:06.917711 18934 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.917923 18934 hierarchical.cpp:1726] Performed allocation for 1 agents in 819150ns I0909 19:07:06.932610 18921 http.cpp:1115] HTTP POST for /slave(1189)/api/v1/resource_provider from 172.17.0.2:58818 I0909 19:07:06.934427 18920 slave.cpp:8481] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 7740940e-c924-4f22-85e0-525f71eb74a5) for framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0909 19:07:06.934711 18920 slave.cpp:8934] Updating the state of operation with no ID (uuid: 7740940e-c924-4f22-85e0-525f71eb74a5) for framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0909 19:07:06.934810 18920 slave.cpp:8688] Forwarding status update of operation with no ID (operation_uuid: 7740940e-c924-4f22-85e0-525f71eb74a5) for framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.935370 18927 master.cpp:12213] Updating the state of operation '' (uuid: 7740940e-c924-4f22-85e0-525f71eb74a5) for framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0909 19:07:06.936185 18933 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version I0909 19:07:06.938401 18917 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event I0909 19:07:06.938678 18939 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 6dd039be-52d1-40bb-9216-c1dcf943d0f7) for stream 7740940e-c924-4f22-85e0-525f71eb74a5 I0909 19:07:06.938799 18939 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: 6dd039be-52d1-40bb-9216-c1dcf943d0f7) for operation UUID 7740940e-c924-4f22-85e0-525f71eb74a5 of framework 'a0055024-74a2-47f4-8a64-e7876b603597-0000' on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:06.970144 18918 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:06.970378 18918 hierarchical.cpp:1726] Performed allocation for 1 agents in 782600ns I0909 19:07:07.002058 18932 provider.cpp:1653] Applying conversion from 'disk(allocated: storage/role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096' to 'disk(allocated: storage/role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj/4GB-e4120ec4-776e-4cf0-a712-4c7de2b31062,test)]:4096' for operation (uuid: e4120ec4-776e-4cf0-a712-4c7de2b31062) I0909 19:07:07.021880 18929 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.022049 18929 hierarchical.cpp:1726] Performed allocation for 1 agents in 587821ns I0909 19:07:07.023916 18939 status_update_manager_process.hpp:490] Cleaning up operation status update stream 7740940e-c924-4f22-85e0-525f71eb74a5 I0909 19:07:07.060554 18919 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: a9c27fc1-2a7d-4e3a-b646-675add64a33f) for operation UUID e4120ec4-776e-4cf0-a712-4c7de2b31062 of framework 'a0055024-74a2-47f4-8a64-e7876b603597-0000' on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:07.060672 18919 status_update_manager_process.hpp:414] Creating operation status update stream e4120ec4-776e-4cf0-a712-4c7de2b31062 checkpoint=true I0909 19:07:07.061365 18919 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: a9c27fc1-2a7d-4e3a-b646-675add64a33f) for operation UUID e4120ec4-776e-4cf0-a712-4c7de2b31062 of framework 'a0055024-74a2-47f4-8a64-e7876b603597-0000' on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:07.073479 18920 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.073617 18920 hierarchical.cpp:1726] Performed allocation for 1 agents in 490121ns I0909 19:07:07.124944 18930 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.125123 18930 hierarchical.cpp:1726] Performed allocation for 1 agents in 608775ns I0909 19:07:07.152719 18919 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: a9c27fc1-2a7d-4e3a-b646-675add64a33f) for operation UUID e4120ec4-776e-4cf0-a712-4c7de2b31062 of framework 'a0055024-74a2-47f4-8a64-e7876b603597-0000' on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:07.171169 18931 http_connection.hpp:131] Sending UPDATE_OPERATION_STATUS call to http://172.17.0.2:33926/slave(1189)/api/v1/resource_provider I0909 19:07:07.172982 18916 process.cpp:3671] Handling HTTP event for process 'slave(1189)' with path: '/slave(1189)/api/v1/resource_provider' I0909 19:07:07.176882 18925 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.177112 18925 hierarchical.cpp:1726] Performed allocation for 1 agents in 936565ns I0909 19:07:07.212819 18924 http.cpp:1115] HTTP POST for /slave(1189)/api/v1/resource_provider from 172.17.0.2:58818 I0909 19:07:07.214370 18917 slave.cpp:8481] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: e4120ec4-776e-4cf0-a712-4c7de2b31062) for framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)' I0909 19:07:07.214669 18917 slave.cpp:8934] Updating the state of operation with no ID (uuid: e4120ec4-776e-4cf0-a712-4c7de2b31062) for framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED) I0909 19:07:07.215373 18917 slave.cpp:8688] Forwarding status update of operation with no ID (operation_uuid: e4120ec4-776e-4cf0-a712-4c7de2b31062) for framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.215948 18926 master.cpp:12213] Updating the state of operation '' (uuid: e4120ec4-776e-4cf0-a712-4c7de2b31062) for framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED) I0909 19:07:07.217346 18921 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version I0909 19:07:07.218266 18939 hierarchical.cpp:1193] Updated allocation of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 from disk(allocated: storage/role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096 to disk(allocated: storage/role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj/4GB-e4120ec4-776e-4cf0-a712-4c7de2b31062,test)]:4096 I0909 19:07:07.219190 18916 provider.cpp:498] Received ACKNOWLEDGE_OPERATION_STATUS event I0909 19:07:07.219173 18939 hierarchical.cpp:1451] Recovered disk(allocated: storage/role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj/4GB-e4120ec4-776e-4cf0-a712-4c7de2b31062,test)]:4096 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj/4GB-e4120ec4-776e-4cf0-a712-4c7de2b31062,test)]:4096, offered or allocated: {}) on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 from framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.219424 18928 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: a9c27fc1-2a7d-4e3a-b646-675add64a33f) for stream e4120ec4-776e-4cf0-a712-4c7de2b31062 I0909 19:07:07.219539 18928 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: a9c27fc1-2a7d-4e3a-b646-675add64a33f) for operation UUID e4120ec4-776e-4cf0-a712-4c7de2b31062 of framework 'a0055024-74a2-47f4-8a64-e7876b603597-0000' on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 I0909 19:07:07.228991 18935 hierarchical.cpp:1726] Performed allocation for 1 agents in 1.173699ms I0909 19:07:07.229723 18937 master.cpp:10389] Sending offers [ a0055024-74a2-47f4-8a64-e7876b603597-O2 ] to framework a0055024-74a2-47f4-8a64-e7876b603597-0000 (default) at scheduler-345c4018-e916-4fc0-9e4f-f427b22ba1a0@172.17.0.2:33926 I0909 19:07:07.230551 18938 sched.cpp:934] Scheduler::resourceOffers took 137392ns I0909 19:07:07.231565 18917 slave.cpp:924] Agent terminating I0909 19:07:07.232520 18917 manager.cpp:163] Terminating resource provider ed026377-7715-4186-9441-147807a7ac94 I0909 19:07:07.233088 18936 master.cpp:1296] Agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1189)@172.17.0.2:33926 (2e411cc79614) disconnected I0909 19:07:07.233144 18936 master.cpp:3391] Disconnecting agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1189)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:07.233244 18936 master.cpp:3410] Deactivating agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1189)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:07.233566 18916 hierarchical.cpp:1038] Agent a0055024-74a2-47f4-8a64-e7876b603597-S0 deactivated I0909 19:07:07.233798 18925 sched.cpp:960] Rescinded offer a0055024-74a2-47f4-8a64-e7876b603597-O2 I0909 19:07:07.233950 18925 sched.cpp:971] Scheduler::offerRescinded took 54931ns E0909 19:07:07.234266 18937 http_connection.hpp:452] End-Of-File received I0909 19:07:07.234793 18936 master.cpp:12684] Removing offer a0055024-74a2-47f4-8a64-e7876b603597-O2 I0909 19:07:07.235013 18937 http_connection.hpp:217] Re-detecting endpoint I0909 19:07:07.235638 18937 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0909 19:07:07.235743 18937 http_connection.hpp:338] Ignoring disconnection attempt from stale connection I0909 19:07:07.235812 18921 provider.cpp:488] Disconnected from resource provider manager I0909 19:07:07.235882 18937 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:33926/slave(1189)/api/v1/resource_provider I0909 19:07:07.237021 18932 hierarchical.cpp:1451] Recovered ports(allocated: storage/role):[31000-32000]; disk(allocated: storage/role)(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj/4GB-e4120ec4-776e-4cf0-a712-4c7de2b31062,test)]:4096; cpus(allocated: storage/role):2; mem(allocated: storage/role):1024; disk(allocated: storage/role):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj/4GB-e4120ec4-776e-4cf0-a712-4c7de2b31062,test)]:4096, offered or allocated: {}) on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 from framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.239521 18916 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:33926/slave(1189)/api/v1/resource_provider W0909 19:07:07.240058 18915 process.cpp:2877] Attempted to spawn already running process files@172.17.0.2:33926 I0909 19:07:07.240101 18924 provider.cpp:476] Connected to resource provider manager I0909 19:07:07.240732 18938 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:33926/slave(1189)/api/v1/resource_provider I0909 19:07:07.241550 18940 process.cpp:2781] Returning '404 Not Found' for '/slave(1189)/api/v1/resource_provider' I0909 19:07:07.242015 18915 containerizer.cpp:318] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } W0909 19:07:07.242871 18915 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges W0909 19:07:07.242913 18915 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges E0909 19:07:07.242990 18917 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' () W0909 19:07:07.243089 18915 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges I0909 19:07:07.243144 18915 provisioner.cpp:300] Using default backend 'copy' I0909 19:07:07.246559 18915 cluster.cpp:524] Creating default 'local' authorizer I0909 19:07:07.249807 18932 slave.cpp:267] Mesos agent started on (1190)@172.17.0.2:33926 I0909 19:07:07.249846 18932 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/5qNuFe/bov1nx/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/5qNuFe/bov1nx/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/5qNuFe/bov1nx/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --docker_volume_chown="false" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/5qNuFe/bov1nx/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/5qNuFe/bov1nx/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/5qNuFe/bov1nx/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.10.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/5qNuFe/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_CreateDestroyDiskWithRecovery_v1_Dq4bHs" --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_Create DestroyDiskWithRecovery_v1_XQun0n" --zk_session_timeout="10secs" I0909 19:07:07.250598 18932 credentials.hpp:86] Loading credential for authentication from '/tmp/5qNuFe/bov1nx/credential' I0909 19:07:07.250903 18932 slave.cpp:300] Agent using credential for: test-principal I0909 19:07:07.250939 18932 credentials.hpp:37] Loading credentials for authentication from '/tmp/5qNuFe/bov1nx/http_credentials' I0909 19:07:07.251273 18932 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0909 19:07:07.251783 18932 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor' I0909 19:07:07.253569 18931 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles I0909 19:07:07.253896 18932 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"}] I0909 19:07:07.254195 18932 slave.cpp:623] Agent attributes: [ ] I0909 19:07:07.254216 18932 slave.cpp:632] Agent hostname: 2e411cc79614 I0909 19:07:07.254460 18933 status_update_manager_process.hpp:379] Pausing operation status update manager I0909 19:07:07.254482 18925 task_status_update_manager.cpp:181] Pausing sending task status updates I0909 19:07:07.256418 18936 state.cpp:67] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/meta' I0909 19:07:07.256518 18936 state.cpp:874] No committed checkpointed resources and operations found at '/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/meta/resources/resources_and_operations.state' I0909 19:07:07.256558 18936 state.cpp:880] No committed checkpointed resources found at '/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/meta/resources/resources.info' I0909 19:07:07.257719 18935 slave.cpp:7491] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/meta', beginning agent recovery I0909 19:07:07.259734 18923 task_status_update_manager.cpp:207] Recovering task status update manager I0909 19:07:07.260557 18927 containerizer.cpp:821] Recovering Mesos containers I0909 19:07:07.262630 18927 containerizer.cpp:1161] Recovering isolators I0909 19:07:07.263903 18934 containerizer.cpp:1200] Recovering provisioner I0909 19:07:07.264797 18921 provisioner.cpp:500] Provisioner recovery complete I0909 19:07:07.266510 18919 composing.cpp:339] Finished recovering all containerizers I0909 19:07:07.267029 18926 status_update_manager_process.hpp:314] Recovering operation status update manager I0909 19:07:07.267505 18936 slave.cpp:7972] Recovering executors I0909 19:07:07.267630 18936 slave.cpp:8125] Finished recovery I0909 19:07:07.268513 18918 task_status_update_manager.cpp:181] Pausing sending task status updates I0909 19:07:07.268539 18921 status_update_manager_process.hpp:379] Pausing operation status update manager I0909 19:07:07.268545 18916 slave.cpp:1351] New master detected at master@172.17.0.2:33926 I0909 19:07:07.268705 18916 slave.cpp:1416] Detecting new master I0909 19:07:07.269973 18935 slave.cpp:1443] Authenticating with master master@172.17.0.2:33926 I0909 19:07:07.270076 18935 slave.cpp:1452] Using default CRAM-MD5 authenticatee I0909 19:07:07.270442 18930 authenticatee.cpp:121] Creating new client SASL connection I0909 19:07:07.270845 18929 master.cpp:10574] Authenticating slave(1190)@172.17.0.2:33926 I0909 19:07:07.271030 18917 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2016)@172.17.0.2:33926 I0909 19:07:07.271344 18931 authenticator.cpp:98] Creating new server SASL connection I0909 19:07:07.271605 18938 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0909 19:07:07.271641 18938 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0909 19:07:07.271773 18937 authenticator.cpp:204] Received SASL authentication start I0909 19:07:07.271845 18937 authenticator.cpp:326] Authentication requires more steps I0909 19:07:07.271981 18920 authenticatee.cpp:259] Received SASL authentication step I0909 19:07:07.272147 18919 authenticator.cpp:232] Received SASL authentication step I0909 19:07:07.272186 18919 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e411cc79614' server FQDN: '2e411cc79614' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0909 19:07:07.272202 18919 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0909 19:07:07.272254 18919 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0909 19:07:07.272280 18919 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e411cc79614' server FQDN: '2e411cc79614' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0909 19:07:07.272295 18919 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0909 19:07:07.272305 18919 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0909 19:07:07.272321 18919 authenticator.cpp:318] Authentication success I0909 19:07:07.272426 18932 authenticatee.cpp:299] Authentication success I0909 19:07:07.272523 18933 master.cpp:10606] Successfully authenticated principal 'test-principal' at slave(1190)@172.17.0.2:33926 I0909 19:07:07.272557 18925 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2016)@172.17.0.2:33926 I0909 19:07:07.272799 18926 slave.cpp:1543] Successfully authenticated with master master@172.17.0.2:33926 I0909 19:07:07.273345 18926 slave.cpp:1993] Will retry registration in 17.200359ms if necessary I0909 19:07:07.273578 18918 master.cpp:7420] Received reregister agent message from agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1190)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:07.274019 18918 master.cpp:4189] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal' I0909 19:07:07.274778 18939 master.cpp:7512] Authorized re-registration of agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1190)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:07.274899 18939 master.cpp:7596] Agent is already marked as registered: a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1190)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:07.275199 18939 master.cpp:8007] Registry updated for slave a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1190)@172.17.0.2:33926(2e411cc79614) I0909 19:07:07.275710 18939 master.cpp:3440] Reactivating agent a0055024-74a2-47f4-8a64-e7876b603597-S0 at slave(1190)@172.17.0.2:33926 (2e411cc79614) I0909 19:07:07.275857 18929 slave.cpp:1700] Re-registered with master master@172.17.0.2:33926 I0909 19:07:07.275985 18931 task_status_update_manager.cpp:188] Resuming sending task status updates I0909 19:07:07.276016 18938 status_update_manager_process.hpp:385] Resuming operation status update manager I0909 19:07:07.276183 18929 slave.cpp:1746] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"WeKGH/nnQ8Kx+YRrDR2KtA=="},"slave_id":{"value":"a0055024-74a2-47f4-8a64-e7876b603597-S0"},"update_oversubscribed_resources":false} I0909 19:07:07.276727 18930 hierarchical.cpp:950] Agent a0055024-74a2-47f4-8a64-e7876b603597-S0 (2e411cc79614) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] I0909 19:07:07.276919 18930 hierarchical.cpp:1026] Agent a0055024-74a2-47f4-8a64-e7876b603597-S0 reactivated I0909 19:07:07.277448 18930 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.277596 18930 hierarchical.cpp:1726] Performed allocation for 1 agents in 538516ns I0909 19:07:07.280781 18925 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.280894 18925 hierarchical.cpp:1726] Performed allocation for 1 agents in 362034ns I0909 19:07:07.282040 18921 process.cpp:3671] Handling HTTP event for process 'slave(1190)' with path: '/slave(1190)/api/v1' I0909 19:07:07.283362 18938 http.cpp:1115] HTTP POST for /slave(1190)/api/v1 from 172.17.0.2:58826 I0909 19:07:07.283891 18938 http.cpp:2146] Processing GET_CONTAINERS call I0909 19:07:07.290014 18925 service_manager.cpp:300] Cleaning up plugin container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:07.292500 18935 process.cpp:3671] Handling HTTP event for process 'slave(1190)' with path: '/slave(1190)/api/v1' I0909 19:07:07.293468 18920 http.cpp:1115] HTTP POST for /slave(1190)/api/v1 from 172.17.0.2:58828 I0909 19:07:07.293889 18920 http.cpp:2995] Processing KILL_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:07.294770 18939 containerizer.cpp:3031] Sending Killed to container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state I0909 19:07:07.298002 18919 process.cpp:3671] Handling HTTP event for process 'slave(1190)' with path: '/slave(1190)/api/v1' I0909 19:07:07.298911 18931 http.cpp:1115] HTTP POST for /slave(1190)/api/v1 from 172.17.0.2:58830 I0909 19:07:07.299333 18931 http.cpp:2824] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:07.332365 18933 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.332511 18933 hierarchical.cpp:1726] Performed allocation for 1 agents in 632304ns I0909 19:07:07.354226 18928 status_update_manager_process.hpp:490] Cleaning up operation status update stream e4120ec4-776e-4cf0-a712-4c7de2b31062 I0909 19:07:07.358633 18934 containerizer.cpp:3161] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited I0909 19:07:07.358673 18934 containerizer.cpp:2620] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state I0909 19:07:07.358706 18934 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 97.06112ms I0909 19:07:07.358779 18925 containerizer.cpp:3161] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited I0909 19:07:07.358819 18925 containerizer.cpp:2620] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state I0909 19:07:07.358851 18925 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 1.395916032secs I0909 19:07:07.359128 18925 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0909 19:07:07.359128 18934 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE *** Aborted at 1568056027 (unix time) try "date -d @1568056027" if you are using GNU date *** I0909 19:07:07.365145 18927 provisioner.cpp:612] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE PC: @ 0x56495aca3aa8 __gnu_cxx::__atomic_add() *** SIGSEGV (@0x0) received by PID 18915 (TID 0x2af49df81700) from PID 0; stack trace: *** @ 0x2af5061938f7 (unknown) I0909 19:07:07.369997 18932 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' @ 0x2af506198249 JVM_handle_linux_signal @ 0x2af493e86330 (unknown) I0909 19:07:07.372951 18924 process.cpp:3671] Handling HTTP event for process 'slave(1190)' with path: '/slave(1190)/api/v1' @ 0x56495aca3aa8 __gnu_cxx::__atomic_add() I0909 19:07:07.373980 18927 http.cpp:1115] HTTP POST for /slave(1190)/api/v1 from 172.17.0.2:58832 I0909 19:07:07.374995 18927 http.cpp:2606] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' @ 0x56495aca3b66 __gnu_cxx::__atomic_add_dispatch() I0909 19:07:07.376058 18938 http.cpp:2710] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:07.376718 18933 containerizer.cpp:1396] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0909 19:07:07.377362 18933 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from STARTING to PROVISIONING after 243968ns I0909 19:07:07.378023 18933 containerizer.cpp:1574] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_Dq4bHs/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config' I0909 19:07:07.378075 18933 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PROVISIONING to PREPARING after 717056ns I0909 19:07:07.381013 18939 containerizer.cpp:2100] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj","--available_capacity=5GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.0/_build/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/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-F5mOQp/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_XQun0n/containe rs/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="22" --pipe_write="24" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_Dq4bHs/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"' @ 0x56495acaa8e7 std::_Sp_counted_base<>::_M_add_ref_copy() I0909 19:07:07.390264 18939 launcher.cpp:145] Forked child with pid '32546' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:07.391347 18939 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from PREPARING to ISOLATING after 13.263104ms I0909 19:07:07.391805 18920 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.392076 18920 hierarchical.cpp:1726] Performed allocation for 1 agents in 985475ns I0909 19:07:07.392997 18939 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from ISOLATING to FETCHING after 1.641984ms I0909 19:07:07.393358 18935 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_CreateDestroyDiskWithRecovery_v1_XQun0n/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE I0909 19:07:07.394634 18938 containerizer.cpp:3323] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from FETCHING to RUNNING after 1.52576ms I0909 19:07:07.397385 18936 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' I0909 19:07:07.397665 18932 service_manager.cpp:703] Connecting to endpoint 'unix:///tmp/mesos-csi-F5mOQp/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE @ 0x56495aca8901 std::__shared_count<>::__shared_count() @ 0x56495aca60a7 std::__shared_ptr<>::__shared_ptr() @ 0x56495aca60cd std::shared_ptr<>::shared_ptr() I0909 19:07:07.444525 18931 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.444757 18931 hierarchical.cpp:1726] Performed allocation for 1 agents in 966811ns @ 0x56495aca60f3 process::UPID::ID::ID() @ 0x56495aca6140 process::UPID::UPID() I0909 19:07:07.496099 18938 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.496282 18938 hierarchical.cpp:1726] Performed allocation for 1 agents in 731211ns @ 0x2af48ff64b74 process::UPID::UPID() @ 0x56495b274e8b process::PID<>::PID() @ 0x56495c810a67 process::Process<>::self() I0909 19:07:07.547629 18918 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.547801 18918 hierarchical.cpp:1726] Performed allocation for 1 agents in 726362ns I0909 19:07:07.598968 18919 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.599143 18919 hierarchical.cpp:1726] Performed allocation for 1 agents in 705536ns @ 0x2af48e11c98b process::dispatch<>() I0909 19:07:07.650477 18935 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.650646 18935 hierarchical.cpp:1726] Performed allocation for 1 agents in 722480ns @ 0x2af48e11c0a4 mesos::internal::PendingFutureTracker::track<>() @ 0x2af48e1b5fd7 mesos::internal::slave::LauncherTracker::destroy() @ 0x2af48df6f052 mesos::internal::slave::MesosContainerizerProcess::__destroy() I0909 19:07:07.702183 18922 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.702430 18922 hierarchical.cpp:1726] Performed allocation for 1 agents in 786333ns @ 0x2af48df6ec7e mesos::internal::slave::MesosContainerizerProcess::_destroy() @ 0x2af48df6d9df _ZZN5mesos8internal5slave25MesosContainerizerProcess7destroyERKNS_11ContainerIDERK6OptionINS_5slave20ContainerTerminationEEENKUlRKSt6vectorIN7process6FutureIS9_EESaISF_EEE_clESJ_ @ 0x2af48df8209e _ZN5cpp176invokeIZN5mesos8internal5slave25MesosContainerizerProcess7destroyERKNS1_11ContainerIDERK6OptionINS1_5slave20ContainerTerminationEEEUlRKSt6vectorIN7process6FutureISB_EESaISH_EEE_ISJ_EEEDTclcl7forwardIT_Efp_Espcl7forwardIT0_Efp0_EEEOSN_DpOSO_ @ 0x2af48df814fc _ZN6lambda8internal7PartialIZN5mesos8internal5slave25MesosContainerizerProcess7destroyERKNS2_11ContainerIDERK6OptionINS2_5slave20ContainerTerminationEEEUlRKSt6vectorIN7process6FutureISC_EESaISI_EEE_ISK_EE13invoke_expandISN_St5tupleIISK_EESQ_IIEEILm0EEEEDTcl6invokecl7forwardIT_Efp_Espcl6expandcl3getIXT2_EEcl7forwardIT0_Efp0_EEcl7forwardIT1_Efp2_EEEEOST_OSU_N5cpp1416integer_sequenceImIXspT2_EEEEOSV_ @ 0x2af48df80c9c _ZNO6lambda8internal7PartialIZN5mesos8internal5slave25MesosContainerizerProcess7destroyERKNS2_11ContainerIDERK6OptionINS2_5slave20ContainerTerminationEEEUlRKSt6vectorIN7process6FutureISC_EESaISI_EEE_ISK_EEclIIEEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImILm0EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOST_ @ 0x2af48df80307 _ZN5cpp176invokeIN6lambda8internal7PartialIZN5mesos8internal5slave25MesosContainerizerProcess7destroyERKNS4_11ContainerIDERK6OptionINS4_5slave20ContainerTerminationEEEUlRKSt6vectorIN7process6FutureISE_EESaISK_EEE_ISM_EEEIEEEDTclcl7forwardIT_Efp_Espcl7forwardIT0_Efp0_EEEOSR_DpOSS_ @ 0x2af48df7f926 _ZN6lambda8internal6InvokeIN7process6FutureI7NothingEEEclINS0_7PartialIZN5mesos8internal5slave25MesosContainerizerProcess7destroyERKNS9_11ContainerIDERK6OptionINS9_5slave20ContainerTerminationEEEUlRKSt6vectorINS3_ISJ_EESaISN_EEE_ISP_EEEIEEES5_OT_DpOT0_ @ 0x2af48df7ef50 _ZNO6lambda12CallableOnceIFN7process6FutureI7NothingEEvEE10CallableFnINS_8internal7PartialIZN5mesos8internal5slave25MesosContainerizerProcess7destroyERKNSA_11ContainerIDERK6OptionINSA_5slave20ContainerTerminationEEEUlRKSt6vectorINS2_ISK_EESaISO_EEE_ISQ_EEEEclEv I0909 19:07:07.754215 18932 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.754422 18932 hierarchical.cpp:1726] Performed allocation for 1 agents in 777021ns @ 0x56495b014c89 _ZNO6lambda12CallableOnceIFN7process6FutureI7NothingEEvEEclEv I0909 19:07:07.789433 18920 service_manager.cpp:545] Probing endpoint 'unix:///tmp/mesos-csi-F5mOQp/endpoint.sock' with CSI v1 @ 0x56495affc139 _ZZN7process8internal8DispatchINS_6FutureI7NothingEEEclIN6lambda12CallableOnceIFS4_vEEEEES4_RKNS_4UPIDEOT_ENKUlSt10unique_ptrINS_7PromiseIS3_EESt14default_deleteISI_EEOSA_PNS_11ProcessBaseEE_clESL_SM_SO_ I0909 19:07:07.804179 32550 test_csi_plugin.cpp:909] ProbeRequest '{}' I0909 19:07:07.805948 18938 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:07.806164 18935 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.806399 18935 hierarchical.cpp:1726] Performed allocation for 1 agents in 831866ns I0909 19:07:07.810322 32550 test_csi_plugin.cpp:895] GetPluginCapabilitiesRequest '{}' I0909 19:07:07.811241 18924 process.cpp:3671] Handling HTTP event for process 'slave(1190)' with path: '/slave(1190)/api/v1' I0909 19:07:07.813196 18924 http.cpp:1115] HTTP POST for /slave(1190)/api/v1 from 172.17.0.2:58842 I0909 19:07:07.813896 18924 http.cpp:2824] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' I0909 19:07:07.814548 32551 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}' I0909 19:07:07.814800 32550 test_csi_plugin.cpp:877] GetPluginInfoRequest '{}' I0909 19:07:07.816233 18934 v1_volume_manager.cpp:649] NODE_SERVICE loaded: {"name":".","vendorVersion":"1.10.0"} I0909 19:07:07.817123 18934 v1_volume_manager.cpp:649] CONTROLLER_SERVICE loaded: {"name":".","vendorVersion":"1.10.0"} I0909 19:07:07.819530 32551 test_csi_plugin.cpp:1105] ControllerGetCapabilitiesRequest '{}' I0909 19:07:07.823601 32552 test_csi_plugin.cpp:1241] NodeGetCapabilitiesRequest '{}' @ 0x56495b0cc543 _ZN5cpp176invokeIZN7process8internal8DispatchINS1_6FutureI7NothingEEEclIN6lambda12CallableOnceIFS6_vEEEEES6_RKNS1_4UPIDEOT_EUlSt10unique_ptrINS1_7PromiseIS5_EESt14default_deleteISK_EEOSC_PNS1_11ProcessBaseEE_JSN_SC_SQ_EEEDTclcl7forwardIT_Efp_Espcl7forwardIT0_Efp0_EEEOSS_DpOST_ I0909 19:07:07.828114 32551 test_csi_plugin.cpp:1255] NodeGetInfoRequest '{}' I0909 19:07:07.832068 18917 provider.cpp:676] Recovered resources 'disk(reservations: [(DYNAMIC,storage),(DYNAMIC,storage/role,test-principal)])[MOUNT(org.apache.mesos.csi.test.local,/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj/4GB-e4120ec4-776e-4cf0-a712-4c7de2b31062,test)]:4096' and 1 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test' I0909 19:07:07.832231 18938 status_update_manager_process.hpp:379] Pausing operation status update manager I0909 19:07:07.832589 18935 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:33926/slave(1190)/api/v1/resource_provider I0909 19:07:07.836984 18916 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:33926/slave(1190)/api/v1/resource_provider I0909 19:07:07.837895 18931 provider.cpp:476] Connected to resource provider manager I0909 19:07:07.838977 18939 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:33926/slave(1190)/api/v1/resource_provider I0909 19:07:07.840663 18928 process.cpp:3671] Handling HTTP event for process 'slave(1190)' with path: '/slave(1190)/api/v1/resource_provider' I0909 19:07:07.842993 18922 http.cpp:1115] HTTP POST for /slave(1190)/api/v1/resource_provider from 172.17.0.2:58846 @ 0x56495b0bbf9f _ZN6lambda8internal7PartialIZN7process8internal8DispatchINS2_6FutureI7NothingEEEclINS_12CallableOnceIFS7_vEEEEES7_RKNS2_4UPIDEOT_EUlSt10unique_ptrINS2_7PromiseIS6_EESt14default_deleteISK_EEOSC_PNS2_11ProcessBaseEE_JSN_SC_St12_PlaceholderILi1EEEE13invoke_expandISR_St5tupleIJSN_SC_ST_EESW_IJOSQ_EEJLm0ELm1ELm2EEEEDTcl6invokecl7forwardISG_Efp_Espcl6expandcl3getIXT2_EEcl7forwardIT0_Efp0_EEcl7forwardIT1_Efp2_EEEESH_OS10_N5cpp1416integer_sequenceImJXspT2_EEEEOS11_ I0909 19:07:07.843755 18935 manager.cpp:813] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"ed026377-7715-4186-9441-147807a7ac94"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj","--available_capacity=5GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.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"},"reconciliation_interval_seconds":0.0},"type":"org.apache.mesos.rp.local.storage"} I0909 19:07:07.844877 18934 slave.cpp:8481] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"ed026377-7715-4186-9441-147807a7ac94"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/mesos/mesos-1.10.0/_build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_CreateDestroyDiskWithRecovery_v1_dj5zjj","--available_capacity=5GB","--volumes=","","--create_parameters=","--volume_metadata="],"shell":false,"value":"/mesos/mesos-1.10.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"},"reconciliation_interval_seconds":0.0},"type":"org.apache.mesos.rp.local.storage"}' I0909 19:07:07.846794 18931 provider.cpp:498] Received SUBSCRIBED event I0909 19:07:07.846855 18931 provider.cpp:1309] Subscribed with ID ed026377-7715-4186-9441-147807a7ac94 I0909 19:07:07.847715 18929 status_update_manager_process.hpp:314] Recovering operation status update manager I0909 19:07:07.847784 18929 status_update_manager_process.hpp:443] Recovering operation status update stream e4120ec4-776e-4cf0-a712-4c7de2b31062 I0909 19:07:07.847975 18929 status_update_manager_process.hpp:684] Replaying operation status update stream e4120ec4-776e-4cf0-a712-4c7de2b31062 I0909 19:07:07.858436 18928 hierarchical.cpp:2581] Filtered offer with ports:[31000-32000]; cpus:2; mem:1024; disk:1024 on agent a0055024-74a2-47f4-8a64-e7876b603597-S0 for role storage/role of framework a0055024-74a2-47f4-8a64-e7876b603597-0000 I0909 19:07:07.858575 18928 hierarchical.cpp:1726] Performed allocation for 1 agents in 611695ns @ 0x56495b0a632d _ZNO6lambda8internal7PartialIZN7process8internal8DispatchINS2_6FutureI7NothingEEEclINS_12CallableOnceIFS7_vEEEEES7_RKNS2_4UPIDEOT_EUlSt10unique_ptrINS2_7PromiseIS6_EESt14default_deleteISK_EEOSC_PNS2_11ProcessBaseEE_JSN_SC_St12_PlaceholderILi1EEEEclIJSQ_EEEDTcl13invoke_expandcl4movedtdefpT1fEcl4movedtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1ELm2EEEE_Ecl16forward_as_tuplespcl7forwardIT_Efp_EEEEDpOSZ_ @ 0x56495b087f37 _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8internal8DispatchINS4_6FutureI7NothingEEEclINS1_12CallableOnceIFS9_vEEEEES9_RKNS4_4UPIDEOT_EUlSt10unique_ptrINS4_7PromiseIS8_EESt14default_deleteISM_EEOSE_PNS4_11ProcessBaseEE_JSP_SE_St12_PlaceholderILi1EEEEEJSS_EEEDTclcl7forwardIT_Efp_Espcl7forwardIT0_Efp0_EEEOSX_DpOSY_ make[4]: *** [check-local] Segmentation fault (core dumped) make[4]: Leaving directory `/mesos/mesos-1.10.0/_build/src' make[3]: *** [check-am] Error 2 make[3]: Leaving directory `/mesos/mesos-1.10.0/_build/src' make[2]: *** [check] Error 2 make[2]: Leaving directory `/mesos/mesos-1.10.0/_build/src' make[1]: *** [check-recursive] Error 1 make[1]: Leaving directory `/mesos/mesos-1.10.0/_build' make: *** [distcheck] Error 1 + docker rmi --force mesos-1568048394-9716 Untagged: mesos-1568048394-9716:latest Deleted: sha256:b9156edb1c23768ee7fbb6a1401a987d0864945322bf141b2d5d3a2dac2141ea Deleted: sha256:e308514f19ab92123fc9e305b42ccbd1e9124868975e62457d63d017d7e381b7 Deleted: sha256:45f97f6a3a4abb0138089779ca90233035ec592632dd08baeb31e4be78c79fbc Deleted: sha256:05ce3a6ec38780ab36e75b89d3fe837595f42261d26f7920d3faed6f33bbed75 Deleted: sha256:c1571b792300557bad6ffad0f71ba088184aa0ecfd6c959171d980b9472bf5fb Deleted: sha256:54ff58453d81b46b1f6a47c3c6efe999cdbf8c9968dbc236706b82b166e36e7e Deleted: sha256:79bf6270e7e43fbbf0876e9ce5d513b568cdab6a7bd946f24070f4d411af4b27 Deleted: sha256:da21f672edf59ed5b820e75dcee3943b07b809cda99eb982b4a84f8bb834115e Deleted: sha256:1ffd57f13c8fb779f531f6480add62a4b37fa4c84d98802471cfcd5173b6c714 Deleted: sha256:f8eb1b18ba8512f40adece462c5ba4c5b54754148838580327aa79e83e58c74f Deleted: sha256:c88855d13c9fcc7bfdfa460681848fde3055504c4c645c2a1933f14bc361a7e4 Deleted: sha256:e1434feb769f6aab1b9178b97b94ecd9eba1ca4b57a366c4abda619a16bb8ce5 Deleted: sha256:76c7cc4184af290ecb880cb73db4a53848c5d6a3abb9d6a63cd7569eefabc67b Deleted: sha256:a009e21feadba4557008b6075890320068a9a3f5771e37f64b3d3ce362e610db Deleted: sha256:35b5c5eb29abcac2c3e2519f55ab5d4514b125fbf389e3d4afdfe1808900129e Deleted: sha256:887bb2c460ac75c336ca618ce7829386ccb61539d6c31a029ebc4d1e825e0520 Deleted: sha256:913306a82ede0cfd950588bee142cc8aab99a46860a39ef82e4051b6db7fb227 Deleted: sha256:2585fc6a6042db51187adfbd58a36c0109a4923fe896282b8e1fcc3afb603747 Deleted: sha256:3223cf6cc6e97d780d4daad1cc52b7522b31298736666a11083b89a8f12a07c8 Deleted: sha256:33ed817c6a0a371727201ee6117c86fd73c5983ffe313c29bc871abe4b6750e5 Deleted: sha256:0012256120a3b4f067297c2aec9e5d0cd8e0e3535a8fd85530ab0e28c8ea4a2a Deleted: sha256:c3db6ed3723b0d64e565216c1680712f6800d73d910e3e0e719ee3055b3ab217 Deleted: sha256:6b270a6295dd0a2147009ae0e7c0ca4e9ca8889d82a6fbe1fbc26bbc5ccbefda Deleted: sha256:6a910d5ed96b086b041e285cea1026c2a27fe6136b9ed347e694d4fe5dd67357 Deleted: sha256:e9d0ca07e9a9b7f1f82ac580286ba2453cf73ea0a4e43857c85f31b174d8ecae Deleted: sha256:2c02d071d5b9f03c7ca4b8cf9e30008eed292f1996fbc7d9961f7aeda9cbef18 Deleted: sha256:d712727a0a73deb09ee7d32b3f68a29315ccf93222532e9f0045291e74c8c84b Deleted: sha256:4fe427b2ca35a4573bdd9833b4e14bed82a14959e9182e7df3c62f0e6d512ef7 Deleted: sha256:cb3831ab23b493137cc8efea4050447596a6c4aeae08d6e1a36eafb84ec2e874 Deleted: sha256:4bd2477eecc15809e709c88c8f466ce0554588153d73348b200fc786c6711c9a Full log: https://builds.apache.org/job/Mesos-Reviewbot-Linux/3596/console - Mesos Reviewbot On Sept. 9, 2019, 2:53 p.m., Andrei Budnik wrote: > > ----------------------------------------------------------- > This is an automatically generated e-mail. To reply, visit: > https://reviews.apache.org/r/71455/ > ----------------------------------------------------------- > > (Updated Sept. 9, 2019, 2:53 p.m.) > > > Review request for mesos, Gilbert Song, Joseph Wu, and Qian Zhang. > > > Bugs: MESOS-9843 > https://issues.apache.org/jira/browse/MESOS-9843 > > > Repository: mesos > > > Description > ------- > > This test starts an agent with the MockIsolator to intercept calls to > its `prepare` method, then it launches a task, which gets stuck. > We check that the /containerizer/debug endpoint returns a non-empty > list of pending futures including `MockIsolator::prepare`. After > setting the promise for the `prepare`, the task successfully starts > and we expect for the /containerizer/debug endpoint to return an > empty list of pending operations. > > > Diffs > ----- > > src/tests/slave_tests.cpp 02b65a925a52d09b0a9183d3288b9ab363b98bc5 > > > Diff: https://reviews.apache.org/r/71455/diff/1/ > > > Testing > ------- > > internal CI > > > Thanks, > > Andrei Budnik > >