See <https://builds.apache.org/job/Mesos-Buildbot-ARM/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--disable-java%20--disable-python%20--disable-parallel-test-execution,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1%20%20MESOS_TEST_AWAIT_TIMEOUT=60secs%20JOBS=16%20GTEST_FILTER=-DiskQuotaTest.SlaveRecovery,label_exp=arm1/1770/display/redirect?page=changes>
Changes: [gregorywmann] Added implementation of the CSI server. ------------------------------------------ [...truncated 48.20 MB...] 3: I0811 06:16:43.709452 18355 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I0811 06:16:43.709838 18355 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I0811 06:16:43.710148 18355 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I0811 06:16:43.710445 18355 master.cpp:632] Authorization enabled 3: I0811 06:16:43.711086 18373 hierarchical.cpp:634] Initialized hierarchical allocator process 3: I0811 06:16:43.711133 18433 whitelist_watcher.cpp:77] No whitelist given 3: I0811 06:16:43.718201 18391 master.cpp:2165] Elected as the leading master! 3: I0811 06:16:43.718262 18391 master.cpp:1661] Recovering from registrar 3: I0811 06:16:43.718539 18428 registrar.cpp:339] Recovering registrar 3: I0811 06:16:43.719846 18428 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns 3: I0811 06:16:43.720111 18428 registrar.cpp:487] Applied 1 operations in 105523ns; attempting to update the registry 3: I0811 06:16:43.721319 18428 registrar.cpp:544] Successfully updated the registry in 0ns 3: I0811 06:16:43.721562 18428 registrar.cpp:416] Successfully recovered registrar 3: I0811 06:16:43.722474 18399 hierarchical.cpp:673] Skipping recovery of hierarchical allocator: nothing to recover 3: I0811 06:16:43.722436 18414 master.cpp:1814] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister 3: W0811 06:16:43.735239 18345 process.cpp:2877] Attempted to spawn already running process [email protected]:40445 3: I0811 06:16:43.738287 18345 containerizer.cpp:317] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: W0811 06:16:43.739519 18345 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges 3: W0811 06:16:43.739588 18345 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W0811 06:16:43.739660 18345 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I0811 06:16:43.739748 18345 provisioner.cpp:294] Using default backend 'copy' 3: I0811 06:16:43.744582 18345 cluster.cpp:533] Creating default 'local' authorizer 3: I0811 06:16:43.749078 18405 slave.cpp:279] Mesos agent started on (1244)@172.17.0.2:40445 3: I0811 06:16:43.749150 18405 slave.cpp:280] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/VH1BMl/hdWcMF/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/VH1BMl/hdWcMF/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/VH1BMl/hdWcMF/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/VH1BMl/hdWcMF/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="/tmp/VH1BMl/hdWcMF/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/VH1BMl/hdWcMF/http_credentials" --http_executor_domain_sockets="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/tmp/SRC/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/VH1BMl/resource_provider_configs" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_xkle0O" --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_Update_v1_DKWDeY" --zk_session_timeout="10secs" 3: I0811 06:16:43.750058 18405 credentials.hpp:73] Loading credential for authentication from '/tmp/VH1BMl/hdWcMF/credential' 3: I0811 06:16:43.750329 18405 slave.cpp:312] Agent using credential for: test-principal 3: I0811 06:16:43.750380 18405 credentials.hpp:37] Loading credentials for authentication from '/tmp/VH1BMl/hdWcMF/http_credentials' 3: I0811 06:16:43.750711 18405 http.cpp:1296] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I0811 06:16:43.751323 18405 disk_profile_adaptor.cpp:82] Creating disk profile adaptor module 'org_apache_mesos_UriDiskProfileAdaptor' 3: I0811 06:16:43.751628 18390 hierarchical.cpp:1920] Performed allocation for 0 agents in 168735ns 3: I0811 06:16:43.754223 18385 uri_disk_profile_adaptor.cpp:305] Updated disk profile mapping to 1 active profiles 3: I0811 06:16:43.754606 18405 slave.cpp:627] 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"}] 3: I0811 06:16:43.754981 18405 slave.cpp:635] Agent attributes: [ ] 3: I0811 06:16:43.755020 18405 slave.cpp:644] Agent hostname: f0be561f1acb 3: I0811 06:16:43.755309 18361 status_update_manager_process.hpp:379] Pausing operation status update manager 3: I0811 06:16:43.755353 18398 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I0811 06:16:43.758991 18383 state.cpp:68] Recovering state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_DKWDeY/meta' 3: I0811 06:16:43.759344 18378 slave.cpp:7723] Finished recovering checkpointed state from '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_DKWDeY/meta', beginning agent recovery 3: I0811 06:16:43.760392 18371 task_status_update_manager.cpp:207] Recovering task status update manager 3: I0811 06:16:43.761127 18351 containerizer.cpp:822] Recovering Mesos containers 3: I0811 06:16:43.761747 18351 containerizer.cpp:1162] Recovering isolators 3: I0811 06:16:43.763296 18349 containerizer.cpp:1201] Recovering provisioner 3: I0811 06:16:43.764430 18384 provisioner.cpp:518] Provisioner recovery complete 3: I0811 06:16:43.765662 18379 composing.cpp:343] Finished recovering all containerizers 3: I0811 06:16:43.766191 18370 slave.cpp:8205] Recovering executors 3: I0811 06:16:43.766384 18370 slave.cpp:8358] Finished recovery 3: I0811 06:16:43.768069 18400 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I0811 06:16:43.768113 18397 status_update_manager_process.hpp:379] Pausing operation status update manager 3: I0811 06:16:43.768142 18370 slave.cpp:1471] New master detected at [email protected]:40445 3: I0811 06:16:43.768329 18370 slave.cpp:1536] Detecting new master 3: I0811 06:16:43.770723 18373 slave.cpp:1563] Authenticating with master [email protected]:40445 3: I0811 06:16:43.770856 18373 slave.cpp:1572] Using default CRAM-MD5 authenticatee 3: I0811 06:16:43.771303 18408 authenticatee.cpp:121] Creating new client SASL connection 3: I0811 06:16:43.771894 18365 master.cpp:9667] Authenticating slave(1244)@172.17.0.2:40445 3: I0811 06:16:43.772140 18418 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2104)@172.17.0.2:40445 3: I0811 06:16:43.772641 18391 authenticator.cpp:98] Creating new server SASL connection 3: I0811 06:16:43.773032 18375 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I0811 06:16:43.773103 18375 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I0811 06:16:43.773334 18359 authenticator.cpp:204] Received SASL authentication start 3: I0811 06:16:43.773480 18359 authenticator.cpp:326] Authentication requires more steps 3: I0811 06:16:43.773682 18386 authenticatee.cpp:259] Received SASL authentication step 3: I0811 06:16:43.773931 18429 authenticator.cpp:232] Received SASL authentication step 3: I0811 06:16:43.774030 18429 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'f0be561f1acb' server FQDN: 'f0be561f1acb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I0811 06:16:43.774080 18429 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I0811 06:16:43.774176 18429 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I0811 06:16:43.774256 18429 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'f0be561f1acb' server FQDN: 'f0be561f1acb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I0811 06:16:43.774303 18429 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I0811 06:16:43.774338 18429 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I0811 06:16:43.774386 18429 authenticator.cpp:318] Authentication success 3: I0811 06:16:43.774538 18401 authenticatee.cpp:299] Authentication success 3: I0811 06:16:43.774730 18350 master.cpp:9699] Successfully authenticated principal 'test-principal' at slave(1244)@172.17.0.2:40445 3: I0811 06:16:43.774847 18403 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2104)@172.17.0.2:40445 3: I0811 06:16:43.775207 18427 slave.cpp:1663] Successfully authenticated with master [email protected]:40445 3: I0811 06:16:43.776098 18427 slave.cpp:2113] Will retry registration in 8.1243ms if necessary 3: I0811 06:16:43.776414 18358 master.cpp:6162] Received register agent message from slave(1244)@172.17.0.2:40445 (f0be561f1acb) 3: I0811 06:16:43.777276 18358 master.cpp:3693] Authorizing principal 'test-principal' to perform action REGISTER_AGENT on ANY object 3: I0811 06:16:43.778205 18366 master.cpp:6229] Authorized registration of agent at slave(1244)@172.17.0.2:40445 (f0be561f1acb) 3: I0811 06:16:43.778380 18366 master.cpp:6341] Registering agent at slave(1244)@172.17.0.2:40445 (f0be561f1acb) with id 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 3: I0811 06:16:43.779490 18395 registrar.cpp:487] Applied 1 operations in 503124ns; attempting to update the registry 3: I0811 06:16:43.780390 18395 registrar.cpp:544] Successfully updated the registry in 803072ns 3: I0811 06:16:43.780670 18369 master.cpp:6389] Admitted agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 at slave(1244)@172.17.0.2:40445 (f0be561f1acb) 3: I0811 06:16:43.782035 18430 slave.cpp:1696] Registered with master [email protected]:40445; given agent ID 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 3: I0811 06:16:43.781870 18369 master.cpp:6434] Registered agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 at slave(1244)@172.17.0.2:40445 (f0be561f1acb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] 3: I0811 06:16:43.782261 18424 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I0811 06:16:43.782333 18432 hierarchical.cpp:1026] Added agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 (f0be561f1acb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {}) 3: I0811 06:16:43.782860 18432 hierarchical.cpp:1920] Performed allocation for 1 agents in 232666ns 3: I0811 06:16:43.782954 18430 slave.cpp:1731] Checkpointing SlaveInfo to '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_DKWDeY/meta/slaves/93c82f39-0e6c-4883-83bd-18375ed475b4-S0/slave.info' 3: I0811 06:16:43.783102 18441 status_update_manager_process.hpp:385] Resuming operation status update manager 3: I0811 06:16:43.785138 18430 slave.cpp:1783] Forwarding agent update {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"MWXpEFWVTPK97FdajEJI7w=="},"slave_id":{"value":"93c82f39-0e6c-4883-83bd-18375ed475b4-S0"},"update_oversubscribed_resources":false} 3: I0811 06:16:43.786993 18363 master.cpp:7575] Ignoring update on agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 at slave(1244)@172.17.0.2:40445 (f0be561f1acb) as it reports no changes 3: I0811 06:16:43.792114 18385 process.cpp:3671] Handling HTTP event for process 'slave(1244)' with path: '/slave(1244)/api/v1' 3: I0811 06:16:43.793678 18405 http.cpp:1436] HTTP POST for /slave(1244)/api/v1 from 172.17.0.2:40876 3: I0811 06:16:43.794512 18405 http.cpp:2828] Processing GET_CONTAINERS call 3: I0811 06:16:43.803270 18423 hierarchical.cpp:1920] Performed allocation for 1 agents in 241116ns 3: I0811 06:16:43.804204 18351 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' 3: I0811 06:16:43.807531 18382 process.cpp:3671] Handling HTTP event for process 'slave(1244)' with path: '/slave(1244)/api/v1' 3: I0811 06:16:43.808750 18393 http.cpp:1436] HTTP POST for /slave(1244)/api/v1 from 172.17.0.2:40878 3: I0811 06:16:43.809937 18393 http.cpp:3289] Processing LAUNCH_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' 3: I0811 06:16:43.811554 18393 http.cpp:3399] Creating sandbox '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_DKWDeY/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' 3: I0811 06:16:43.812655 18407 containerizer.cpp:1397] Starting container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE 3: I0811 06:16:43.814011 18407 containerizer.cpp:3406] 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 535808ns 3: I0811 06:16:43.815709 18407 containerizer.cpp:1576] Checkpointed ContainerConfig at '/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_xkle0O/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE/config' 3: I0811 06:16:43.815799 18407 containerizer.cpp:3406] 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 1.792256ms 3: I0811 06:16:43.821393 18373 containerizer.cpp:2102] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["/tmp/SRC/build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TfGHr7","--available_capacity=0B","--volumes=","--forward=unix:///tmp/VH1BMl/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/build/src/test-csi-plugin"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_DKWDeY/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-jKUmij/endpoint.sock"}]},"task_environment":{},"working_directory":"/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_DKWDeY/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE"}" --pipe_read="51" --pipe_write="56" --runtime_directory="/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_xkle0O/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE" --unshare_namespace_mnt="false"' 3: I0811 06:16:43.840898 18373 launcher.cpp:145] Forked child with pid '55218' for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' 3: I0811 06:16:43.843055 18373 containerizer.cpp:3406] 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 27.241984ms 3: I0811 06:16:43.846273 18373 containerizer.cpp:3406] 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 3.224832ms 3: I0811 06:16:43.846809 18414 fetcher.cpp:369] Starting to fetch URIs for container: org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE, directory: /tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_DKWDeY/containers/org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE 3: I0811 06:16:43.848855 18399 containerizer.cpp:3406] 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 2.575104ms 3: I0811 06:16:43.854099 18394 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' 3: I0811 06:16:43.854508 18387 service_manager.cpp:775] Connecting to endpoint 'unix:///tmp/mesos-csi-jKUmij/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE 3: I0811 06:16:43.855507 18366 hierarchical.cpp:1920] Performed allocation for 1 agents in 567435ns 3: I0811 06:16:43.907143 18424 hierarchical.cpp:1920] Performed allocation for 1 agents in 286247ns 3: I0811 06:16:43.959105 18354 hierarchical.cpp:1920] Performed allocation for 1 agents in 376420ns 3: I0811 06:16:44.011179 18422 hierarchical.cpp:1920] Performed allocation for 1 agents in 218615ns 3: I0811 06:16:44.062808 18398 hierarchical.cpp:1920] Performed allocation for 1 agents in 368940ns 3: I0811 06:16:44.115061 18405 hierarchical.cpp:1920] Performed allocation for 1 agents in 305648ns 3: I0811 06:16:44.166797 18413 hierarchical.cpp:1920] Performed allocation for 1 agents in 483402ns 3: I0811 06:16:44.218591 18396 hierarchical.cpp:1920] Performed allocation for 1 agents in 377760ns 3: I0811 06:16:44.270433 18415 hierarchical.cpp:1920] Performed allocation for 1 agents in 229816ns 3: I0811 06:16:44.321565 18426 hierarchical.cpp:1920] Performed allocation for 1 agents in 246606ns 3: I0811 06:16:44.372869 18397 hierarchical.cpp:1920] Performed allocation for 1 agents in 308648ns 3: I0811 06:16:44.424319 18407 hierarchical.cpp:1920] Performed allocation for 1 agents in 300658ns 3: I0811 06:16:44.475420 18386 hierarchical.cpp:1920] Performed allocation for 1 agents in 269747ns 3: I0811 06:16:44.526907 18373 hierarchical.cpp:1920] Performed allocation for 1 agents in 194245ns 3: I0811 06:16:44.578088 18427 hierarchical.cpp:1920] Performed allocation for 1 agents in 437052ns 3: I0811 06:16:44.629561 18440 hierarchical.cpp:1920] Performed allocation for 1 agents in 268967ns 3: I0811 06:16:44.680814 18424 hierarchical.cpp:1920] Performed allocation for 1 agents in 316018ns 3: I0811 06:16:44.709053 18402 service_manager.cpp:617] Probing endpoint 'unix:///tmp/mesos-csi-jKUmij/endpoint.sock' with CSI v1 3: I0811 06:16:44.712697 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/Probe call 3: I0811 06:16:44.718644 18363 container_daemon.cpp:171] Waiting for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' 3: I0811 06:16:44.722977 18361 process.cpp:3671] Handling HTTP event for process 'slave(1244)' with path: '/slave(1244)/api/v1' 3: I0811 06:16:44.723716 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginCapabilities call 3: I0811 06:16:44.724696 18356 http.cpp:1436] HTTP POST for /slave(1244)/api/v1 from 172.17.0.2:40880 3: I0811 06:16:44.725643 18356 http.cpp:3513] Processing WAIT_CONTAINER call for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' 3: I0811 06:16:44.731207 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call 3: I0811 06:16:44.731951 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Identity/GetPluginInfo call 3: I0811 06:16:44.732390 18425 hierarchical.cpp:1920] Performed allocation for 1 agents in 241607ns 3: I0811 06:16:44.734632 18423 v1_volume_manager.cpp:674] NODE_SERVICE loaded: {} 3: I0811 06:16:44.735496 18423 v1_volume_manager.cpp:674] CONTROLLER_SERVICE loaded: {} 3: I0811 06:16:44.739377 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ControllerGetCapabilities call 3: I0811 06:16:44.745877 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetCapabilities call 3: I0811 06:16:44.752156 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Node/NodeGetInfo call 3: I0811 06:16:44.756187 18347 provider.cpp:676] Recovered resources '{}' and 0 operations for resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test' 3: I0811 06:16:44.756399 18431 status_update_manager_process.hpp:379] Pausing operation status update manager 3: I0811 06:16:44.757177 18355 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:40445/slave(1244)/api/v1/resource_provider 3: I0811 06:16:44.761250 18365 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:40445/slave(1244)/api/v1/resource_provider 3: I0811 06:16:44.762374 18350 provider.cpp:476] Connected to resource provider manager 3: I0811 06:16:44.763437 18388 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:40445/slave(1244)/api/v1/resource_provider 3: I0811 06:16:44.765513 18399 process.cpp:3671] Handling HTTP event for process 'slave(1244)' with path: '/slave(1244)/api/v1/resource_provider' 3: I0811 06:16:44.767894 18419 http.cpp:1436] HTTP POST for /slave(1244)/api/v1/resource_provider from 172.17.0.2:40882 3: I0811 06:16:44.769114 18394 manager.cpp:779] Subscribing resource provider {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TfGHr7","--available_capacity=0B","--volumes=","--forward=unix:///tmp/VH1BMl/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/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":15.0},"type":"org.apache.mesos.rp.local.storage"} 3: I0811 06:16:44.775444 18369 slave.cpp:8714] Handling resource provider message 'SUBSCRIBE: {"default_reservations":[{"role":"storage","type":"DYNAMIC"}],"id":{"value":"436ec82b-e2ea-4773-9bf8-74a6992d3d8d"},"name":"test","storage":{"plugin":{"containers":[{"command":{"arguments":["/tmp/SRC/build/src/test-csi-plugin","--api_version=v1","--work_dir=/tmp/CSIVersion_StorageLocalResourceProviderTest_Update_v1_TfGHr7","--available_capacity=0B","--volumes=","--forward=unix:///tmp/VH1BMl/mock_csi.sock","--create_parameters=","--volume_metadata="],"shell":false,"value":"/tmp/SRC/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":15.0},"type":"org.apache.mesos.rp.local.storage"}' 3: I0811 06:16:44.777796 18354 provider.cpp:498] Received SUBSCRIBED event 3: I0811 06:16:44.777858 18354 provider.cpp:1309] Subscribed with ID 436ec82b-e2ea-4773-9bf8-74a6992d3d8d 3: I0811 06:16:44.779244 18409 status_update_manager_process.hpp:314] Recovering operation status update manager 3: I0811 06:16:44.783557 18420 hierarchical.cpp:1920] Performed allocation for 1 agents in 262776ns 3: I0811 06:16:44.785766 18363 provider.cpp:790] Reconciling storage pools and volumes 3: I0811 06:16:44.789708 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call 3: I0811 06:16:44.794158 18389 provider.cpp:2217] Sending UPDATE_STATE call with resources '{}' and 0 operations to agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 3: I0811 06:16:44.794636 18378 http_connection.hpp:131] Sending UPDATE_STATE call to http://172.17.0.2:40445/slave(1244)/api/v1/resource_provider 3: I0811 06:16:44.794808 18389 provider.cpp:748] Resource provider 436ec82b-e2ea-4773-9bf8-74a6992d3d8d is in READY state 3: I0811 06:16:44.794876 18381 status_update_manager_process.hpp:385] Resuming operation status update manager 3: I0811 06:16:44.795994 18437 provider.cpp:1235] Updating profiles { test } for resource provider 436ec82b-e2ea-4773-9bf8-74a6992d3d8d 3: I0811 06:16:44.796141 18425 process.cpp:3671] Handling HTTP event for process 'slave(1244)' with path: '/slave(1244)/api/v1/resource_provider' 3: I0811 06:16:44.797646 18436 provider.cpp:790] Reconciling storage pools and volumes 3: I0811 06:16:44.798350 18416 http.cpp:1436] HTTP POST for /slave(1244)/api/v1/resource_provider from 172.17.0.2:40884 3: I0811 06:16:44.799234 18393 manager.cpp:1011] Received UPDATE_STATE call with resources '[]' and 0 operations from resource provider 436ec82b-e2ea-4773-9bf8-74a6992d3d8d 3: I0811 06:16:44.799532 18431 slave.cpp:8714] Handling resource provider message 'UPDATE_STATE: 436ec82b-e2ea-4773-9bf8-74a6992d3d8d {}' 3: I0811 06:16:44.799680 18431 slave.cpp:8834] Forwarding new total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] 3: I0811 06:16:44.801689 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call 3: I0811 06:16:44.802675 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call 3: I0811 06:16:44.802871 18408 hierarchical.cpp:1177] Grew agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 by {} (total), { } (used) 3: I0811 06:16:44.803676 18408 hierarchical.cpp:1134] Agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 (f0be561f1acb) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] 3: I0811 06:16:44.811870 18403 hierarchical.cpp:1920] Performed allocation for 1 agents in 489823ns 3: I0811 06:16:44.812084 18394 provider.cpp:790] Reconciling storage pools and volumes 3: I0811 06:16:44.815752 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/ListVolumes call 3: I0811 06:16:44.816392 55222 test_csi_plugin.cpp:1915] Forwarding /csi.v1.Controller/GetCapacity call 3: I0811 06:16:44.826699 18363 slave.cpp:1000] Agent terminating 3: I0811 06:16:44.828065 18363 manager.cpp:127] Terminating resource provider 436ec82b-e2ea-4773-9bf8-74a6992d3d8d 3: I0811 06:16:44.828691 18356 master.cpp:1292] Agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 at slave(1244)@172.17.0.2:40445 (f0be561f1acb) disconnected 3: I0811 06:16:44.828752 18356 master.cpp:3361] Disconnecting agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 at slave(1244)@172.17.0.2:40445 (f0be561f1acb) 3: I0811 06:16:44.828891 18356 master.cpp:3380] Deactivating agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 at slave(1244)@172.17.0.2:40445 (f0be561f1acb) 3: I0811 06:16:44.829119 18378 hierarchical.cpp:1223] Agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 deactivated 3: E0811 06:16:44.829300 18405 http_connection.hpp:449] End-Of-File received 3: I0811 06:16:44.830032 18405 http_connection.hpp:217] Re-detecting endpoint 3: I0811 06:16:44.830705 18405 http_connection.hpp:338] Ignoring disconnection attempt from stale connection 3: I0811 06:16:44.830809 18405 http_connection.hpp:338] Ignoring disconnection attempt from stale connection 3: I0811 06:16:44.830895 18351 provider.cpp:488] Disconnected from resource provider manager 3: I0811 06:16:44.830965 18405 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:40445/slave(1244)/api/v1/resource_provider 3: I0811 06:16:44.831104 18406 status_update_manager_process.hpp:379] Pausing operation status update manager 3: I0811 06:16:44.833004 18379 containerizer.cpp:2708] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE in RUNNING state 3: I0811 06:16:44.833108 18379 containerizer.cpp:3406] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE from RUNNING to DESTROYING after 15.984267008secs 3: I0811 06:16:44.833835 18379 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE 3: I0811 06:16:44.835217 18431 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:40445/slave(1244)/api/v1/resource_provider 3: I0811 06:16:44.836175 18347 provider.cpp:476] Connected to resource provider manager 3: I0811 06:16:44.837085 18418 http_connection.hpp:131] Sending SUBSCRIBE call to http://172.17.0.2:40445/slave(1244)/api/v1/resource_provider 3: I0811 06:16:44.838229 18442 process.cpp:2781] Returning '404 Not Found' for '/slave(1244)/api/v1/resource_provider' 3: E0811 06:16:44.839990 18391 provider.cpp:721] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' () 3: I0811 06:16:44.854913 18359 hierarchical.cpp:1920] Performed allocation for 1 agents in 177574ns 3: I0811 06:16:44.906844 18414 hierarchical.cpp:1920] Performed allocation for 1 agents in 230836ns 3: I0811 06:16:44.906869 18373 containerizer.cpp:3244] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE has exited 3: I0811 06:16:44.909373 18366 provisioner.cpp:652] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE 3: I0811 06:16:44.913182 18432 container_daemon.cpp:189] Invoking post-stop hook for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' 3: I0811 06:16:44.913513 18434 service_manager.cpp:795] Disconnected from endpoint 'unix:///tmp/mesos-csi-jKUmij/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE 3: I0811 06:16:44.913902 18369 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--CONTROLLER_SERVICE-NODE_SERVICE' 3: I0811 06:16:44.917022 18442 process.cpp:2781] Returning '404 Not Found' for '/slave(1244)/api/v1' 3: I0811 06:16:44.938818 18434 master.cpp:1140] Master terminating 3: I0811 06:16:44.939378 18430 hierarchical.cpp:1199] Removed all filters for agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 3: I0811 06:16:44.939424 18430 hierarchical.cpp:1075] Removed agent 93c82f39-0e6c-4883-83bd-18375ed475b4-S0 3: [ OK ] CSIVersion/StorageLocalResourceProviderTest.Update/v1 (1274 ms) 3: [----------] 54 tests from CSIVersion/StorageLocalResourceProviderTest (105424 ms total) 3: 3: [----------] Global test environment tear-down 3: [==========] 2273 tests from 216 test cases ran. (1058064 ms total) 3: [ PASSED ] 2272 tests. 3: [ FAILED ] 1 test, listed below: 3: [ FAILED ] SlaveTest.RunTaskGroupReferenceTypeSecret 3: 3: 1 FAILED TEST 3: YOU HAVE 34 DISABLED TESTS 3: 3: I0811 06:16:45.180691 18442 process.cpp:935] Stopped the socket accept loop 3/3 Test #3: MesosTests .......................***Failed 1061.11 sec 67% tests passed, 1 tests failed out of 3 Total Test time (real) = 1130.32 sec The following tests FAILED: 3 - MesosTests (Failed) Errors while running CTest CMakeFiles/check.dir/build.make:60: recipe for target 'CMakeFiles/check' failed make[3]: *** [CMakeFiles/check] Error 8 make[3]: Leaving directory '/tmp/SRC/build' CMakeFiles/Makefile2:255: recipe for target 'CMakeFiles/check.dir/all' failed make[2]: *** [CMakeFiles/check.dir/all] Error 2 make[2]: Leaving directory '/tmp/SRC/build' CMakeFiles/Makefile2:262: recipe for target 'CMakeFiles/check.dir/rule' failed make[1]: *** [CMakeFiles/check.dir/rule] Error 2 make[1]: Leaving directory '/tmp/SRC/build' Makefile:278: recipe for target 'check' failed make: *** [check] Error 2 real 82m35.451s user 0m17.646s sys 0m15.867s Build step 'Execute shell' marked build as failure Recording test results
