Skip to content

DAOS-7203 control: Add histogram support to Prometheus exporter

Sign in for the full log view
GitHub Actions / Functional on EL 9 Test Results (old) failed Feb 21, 2024 in 0s

1 errors, 4 skipped, 130 pass in 1h 24m 30s

135 tests   130 ✅  1h 24m 30s ⏱️
 41 suites    4 💤
 41 files      0 ❌  1 🔥

Results for commit 427bb06.

Annotations

Check failure on line 0 in FTEST_control.TestWithTelemetryBasic

See this annotation in the file changed.

@github-actions github-actions / Functional on EL 9 Test Results (old)

1-./control/dmg_telemetry_basic.py:TestWithTelemetryBasic.test_telemetry_list;run-container-hosts-pool-server_config-engines-0-storage-0-test-timeouts-2f2e (FTEST_control.TestWithTelemetryBasic) with error

Functional on EL 9/control/dmg_telemetry_basic.py/results.xml [took 1m 30s]
Raw output
Symmetric difference found in telemetry metric names on wolf-102vm2 Symmetric difference found in telemetry metric names on wolf-102vm3 Runner error occurred: Timeout reached Original status: FAIL {'name': '1-./control/dmg_telemetry_basic.py:TestWithTelemetryBasic.test_telemetry_list;run-container-hosts-pool-server_config-engines-0-storage-0-test-timeouts-2f2e', 'logdir': '/var/tmp/ftest/avocado/job-results/job-2024-02-21T22.17-c82da4a/test-results/1-._control_dmg_telemetry_basic.py_TestWithTelemetryBasic.test_telemetry_list_run-container-hosts-pool-server_config-engines-0-storage-0-test-timeouts-2f2e', 'logfile': '/var/tmp/ftest/avocado/job-results/job-2024-02-21T22.17-c82da4a/test-results/1-._control_dmg_telemetry_basic.py_TestWithTelemetryBasic.test_telemetry_list_run-container-hosts-pool-server_config-engines-0-storage-0-test-timeouts-2f2e/debug.log', 'status': 'FAIL', 'running': False, 'paused': False, 'time_start': 1708553838.2285216, 'time_elapsed': 90.6360502243042, 'time_end': 1708553928.8645718, 'fail_reason': 'Symmetric difference found in telemetry metric names on wolf-102vm2\nSymmetric difference found in telemetry metric names on wolf-102vm3', 'fail_class': 'TestFail', 'traceback': 'Traceback (most recent call last):\n  File "/usr/local/lib/python3.9/site-packages/avocado/core/test.py", line 856, in _run_avocado\n    raise test_exception\n  File "/usr/local/lib/python3.9/site-packages/avocado/core/test.py", line 762, in _run_avocado\n    testMethod()\n  File "/usr/lib/daos/TESTING/ftest/control/dmg_telemetry_basic.py", line 84, in test_telemetry_list\n    self.verify_telemetry_list()\n  File "/usr/lib/daos/TESTING/ftest/util/telemetry_test_base.py", line 82, in verify_telemetry_list\n    self.fail("\\n".join(errors))\n  File "/usr/lib/daos/TESTING/ftest/util/apricot/apricot/test.py", line 1375, in fail\n    super().fail(message)\n  File "/usr/local/lib/python3.9/site-packages/avocado/core/test.py", line 953, in fail\n    raise exceptions.TestFail(message)\navocado.core.exceptions.TestFail: Symmetric difference found in telemetry metric names on wolf-102vm2\nSymmetric difference found in telemetry metric names on wolf-102vm3\n', 'timeout': 90, 'whiteboard': '', 'phase': 'FINISHED', 'class_name': 'TestWithTelemetryBasic', 'job_logdir': '/var/tmp/ftest/avocado/job-results/job-2024-02-21T22.17-c82da4a', 'job_unique_id': 'c82da4acb3acca51304e55064362ea821e368cd9', 'params': [('/run/hosts', 'test_servers', 'wolf-102vm[2-3]'), ('/run/hosts', 'test_clients', 'wolf-102vm4'), ('/run/timeouts', 'test_telemetry_list', 60), ('/run/timeouts', 'test_container_telemetry', 230), ('/run/server_config', 'name', 'daos_server'), ('/run/server_config', 'engines_per_host', 1), ('/run/server_config', 'system_ram_reserved', 1), ('/run/server_config/engines/0', 'targets', 4), ('/run/server_config/engines/0', 'nr_xs_helpers', 0), ('/run/server_config/engines/0/storage/0', 'class', 'ram'), ('/run/server_config/engines/0/storage/0', 'scm_mount', '/mnt/daos'), ('/run/pool', 'scm_size', '2G'), ('/run/pool', 'control_method', 'dmg'), ('/run/container', 'control_method', 'daos'), ('/run/test', 'container_qty', 5), ('/run/test', 'open_close_qty', 3)]}
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/avocado/core/test.py", line 856, in _run_avocado
    raise test_exception
  File "/usr/local/lib/python3.9/site-packages/avocado/core/test.py", line 762, in _run_avocado
    testMethod()
  File "/usr/lib/daos/TESTING/ftest/control/dmg_telemetry_basic.py", line 84, in test_telemetry_list
    self.verify_telemetry_list()
  File "/usr/lib/daos/TESTING/ftest/util/telemetry_test_base.py", line 82, in verify_telemetry_list
    self.fail("\n".join(errors))
  File "/usr/lib/daos/TESTING/ftest/util/apricot/apricot/test.py", line 1375, in fail
    super().fail(message)
  File "/usr/local/lib/python3.9/site-packages/avocado/core/test.py", line 953, in fail
    raise exceptions.TestFail(message)
avocado.core.exceptions.TestFail: Symmetric difference found in telemetry metric names on wolf-102vm2
Symmetric difference found in telemetry metric names on wolf-102vm3
22:17:18 INFO | *** SETUP running on <LinuxDistro: name=rocky, version=9, release=2, arch=x86_64> ***
22:17:18 INFO | Test.random seed = 4639991874015956795
22:17:18 DEBUG| Shared test directory: /mnt/share/tmp.HS7mih4z8F
22:17:18 DEBUG| Common test directory: /var/tmp/daos_testing/test_telemetry_list
22:17:18 DEBUG| PARAMS (key=fault_list, path=/run/faults/*, default=None) => None
22:17:18 DEBUG| PARAMS (key=start_agents_once, path=/run/setup/*, default=True) => True
22:17:18 DEBUG| PARAMS (key=start_servers_once, path=/run/setup/*, default=True) => True
22:17:18 DEBUG| PARAMS (key=server_manager_class, path=/run/setup/*, default=Systemctl) => 'Systemctl'
22:17:18 DEBUG| PARAMS (key=agent_manager_class, path=/run/setup/*, default=Systemctl) => 'Systemctl'
22:17:18 DEBUG| PARAMS (key=start_servers, path=/run/setup/*, default=True) => True
22:17:18 DEBUG| PARAMS (key=start_agents, path=/run/setup/*, default=True) => True
22:17:18 DEBUG| PARAMS (key=slurm_exclude_servers, path=/run/setup/*, default=False) => False
22:17:18 DEBUG| PARAMS (key=name, path=/server_config/, default=daos_server) => 'daos_server'
22:17:18 DEBUG| PARAMS (key=server_config_namespace, path=/run/setup/*, default=None) => None
22:17:18 DEBUG| PARAMS (key=manager_class, path=/, default=Orterun) => 'Orterun'
22:17:18 DEBUG| PARAMS (key=test_servers, path=/run/hosts/*, default=None) => 'wolf-102vm[2-3]'
22:17:18 DEBUG| PARAMS (key=server_partition, path=/run/hosts/*, default=None) => None
22:17:18 DEBUG| PARAMS (key=server_reservation, path=/run/hosts/*, default=None) => None
22:17:18 DEBUG| PARAMS (key=test_clients, path=/run/hosts/*, default=None) => 'wolf-102vm4'
22:17:18 DEBUG| PARAMS (key=client_partition, path=/run/hosts/*, default=None) => None
22:17:18 DEBUG| PARAMS (key=client_reservation, path=/run/hosts/*, default=None) => None
22:17:18 DEBUG| PARAMS (key=access_points_qty, path=/run/setup/*, default=1) => 1
22:17:18 DEBUG| PARAMS (key=access_points, path=/run/setup/*, default=wolf-102vm2) => <ClusterShell.NodeSet.NodeSet object at 0x7f62c2851610>
22:17:18 DEBUG| PARAMS (key=access_points_suffix, path=/run/setup/*, default=None) => None
22:17:18 DEBUG| Writing hostfile: /var/tmp/avocado_3pcbd8xr/avocado_job__gxsh1kc/1-._control_dmg_telemetry_basic.py_TestWithTelemetryBasic.test_telemetry_list_run-container-hosts-pool-server_config-engines-0-storage-0-test-timeouts-2f2e/hostfile_bt_dp1tr (hosts=wolf-102vm4, slots=1)
22:17:18 INFO | ----------------------------------------------------------------------------------------------------
22:17:18 INFO | --- HOST INFORMATION ---
22:17:18 INFO | servers:             wolf-102vm[2-3]
22:17:18 INFO | clients:             wolf-102vm4
22:17:18 INFO | server_partition:    None
22:17:18 INFO | client_partition:    None
22:17:18 INFO | server_reservation:  None
22:17:18 INFO | client_reservation:  None
22:17:18 INFO | access_points:       wolf-102vm2
22:17:18 INFO | ----------------------------------------------------------------------------------------------------
22:17:18 DEBUG| Common test directory (/var/tmp/daos_testing/test_telemetry_list) contents:
22:17:18 INFO | ----------------------------------------------------------------------------------------------------
22:17:18 INFO | Stopping any of the following commands left running on wolf-102vm[2-4]: orterun,mpirun
22:17:18 DEBUG| Searching for any processes on wolf-102vm[2-4] that match '(orterun|mpirun)'
22:17:18 DEBUG| Running on wolf-102vm[2-4] with a 60 second timeout: /usr/bin/pgrep --list-full '(orterun|mpirun)'
22:17:18 DEBUG|   wolf-102vm[2-4] (rc=1): <no output>
22:17:18 DEBUG| No processes found on wolf-102vm[2-4] that match '(orterun|mpirun)'
22:17:18 INFO | ----------------------------------------------------------------------------------------------------
22:17:18 INFO | Updating file permissions for /var/tmp/daos_testing for use with systemctl
22:17:19 INFO | Command: chmod a+rw /var/tmp/daos_testing
Results:
  wolf-102vm[2-4]: exit_status=0, interrupted=False:
22:17:19 INFO | ----------------------------------------------------------------------------------------------------
22:17:19 DEBUG| --- SETTING UP SERVER GROUPS: {'daos_server': {'hosts': <ClusterShell.NodeSet.NodeSet object at 0x7f62c8114c40>, 'access_points': <ClusterShell.NodeSet.NodeSet object at 0x7f62c2851640>, 'svr_config_file': None, 'dmg_config_file': None, 'svr_config_temp': None, 'dmg_config_temp': None}} ---
22:17:19 INFO | ----------------------------------------------------------------------------------------------------
22:17:19 INFO | --- CONFIGURING SERVER MANAGER ---
22:17:19 DEBUG| PARAMS (key=collect_log_timeout, path=/run/server_manager/*, default=120) => 120
22:17:19 DEBUG| PARAMS (key=storage_format_timeout, path=/run/server_manager/*, default=40) => 40
22:17:19 DEBUG| PARAMS (key=storage_prepare_timeout, path=/run/server_manager/*, default=40) => 40
22:17:19 DEBUG| PARAMS (key=storage_reset_timeout, path=/run/server_manager/*, default=120) => 120
22:17:19 DEBUG| PARAMS (key=env_vars, path=/run/client/*, default=[]) => []
22:17:19 DEBUG| PARAMS (key=env_vars, path=/run/systemctl/*, default=[]) => []
22:17:19 DEBUG| PARAMS (key=allow_proxy, path=/run/daos_server/*, default=False) => False
22:17:19 DEBUG| PARAMS (key=config, path=/run/daos_server/*, default=/etc/daos/daos_server.yml) => '/etc/daos/daos_server.yml'
22:17:19 DEBUG| PARAMS (key=debug, path=/run/daos_server/*, default=True) => True
22:17:19 DEBUG| PARAMS (key=json, path=/run/daos_server/*, default=False) => False
22:17:19 DEBUG| PARAMS (key=json_logs, path=/run/daos_server/*, default=False) => False
22:17:19 DEBUG| PARAMS (key=pattern_timeout, path=/run/daos_server/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=daos_server_sub_command, path=/run/daos_server/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=env_vars, path=/run/client/*, default=[]) => []
22:17:19 DEBUG| PARAMS (key=env_vars, path=/run/daos_server/*, default=[]) => []
22:17:19 DEBUG| PARAMS (key=firstcore, path=/run/daos_server/start/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=group, path=/run/daos_server/start/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=insecure, path=/run/daos_server/start/*, default=False) => False
22:17:19 DEBUG| PARAMS (key=modules, path=/run/daos_server/start/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=port, path=/run/daos_server/start/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=recreate, path=/run/daos_server/start/*, default=False) => False
22:17:19 DEBUG| PARAMS (key=sock_dir, path=/run/daos_server/start/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=storage, path=/run/daos_server/start/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=targets, path=/run/daos_server/start/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=xshelpernr, path=/run/daos_server/start/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=bdev_exclude, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=client_env_vars, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=control_log_file, path=/run/server_config/*, default=daos_control.log) => 'daos_control.log'
22:17:19 DEBUG|   Added the directory: control_log_file => /var/tmp/daos_testing/daos_control.log
22:17:19 DEBUG| PARAMS (key=control_log_mask, path=/run/server_config/*, default=DEBUG) => 'DEBUG'
22:17:19 DEBUG| PARAMS (key=core_dump_filter, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=crt_ctx_share_addr, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=crt_timeout, path=/run/server_config/*, default=10) => 10
22:17:19 DEBUG| PARAMS (key=disable_hugepages, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=disable_srx, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=disable_vfio, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=disable_vmd, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=enable_hotplug, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=engines_per_host, path=/run/server_config/*, default=0) => 1
22:17:19 DEBUG| PARAMS (key=fabric_auth_key, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=fault_cb, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=fault_path, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=group_name, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=helper_log_file, path=/run/server_config/*, default=daos_server_helper.log) => 'daos_server_helper.log'
22:17:19 DEBUG|   Added the directory: helper_log_file => /var/tmp/daos_testing/daos_server_helper.log
22:17:19 DEBUG| PARAMS (key=hyperthreads, path=/run/server_config/*, default=False) => False
22:17:19 DEBUG| PARAMS (key=nr_hugepages, path=/run/server_config/*, default=0) => 0
22:17:19 DEBUG| PARAMS (key=provider, path=/run/server_config/*, default=ofi+tcp;ofi_rxm) => 'ofi+tcp;ofi_rxm'
22:17:19 DEBUG| PARAMS (key=socket_dir, path=/run/server_config/*, default=/var/run/daos_server) => '/var/run/daos_server'
22:17:19 DEBUG| PARAMS (key=system_ram_reserved, path=/run/server_config/*, default=None) => 1
22:17:19 DEBUG| PARAMS (key=telemetry_port, path=/run/server_config/*, default=9191) => 9191
22:17:19 DEBUG| PARAMS (key=user_name, path=/run/server_config/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=access_points, path=/run/common_config/*, default=['localhost']) => ['localhost']
22:17:19 DEBUG| PARAMS (key=name, path=/run/common_config/*, default=daos_server) => 'daos_server'
22:17:19 DEBUG| PARAMS (key=port, path=/run/common_config/*, default=10001) => 10001
22:17:19 DEBUG| PARAMS (key=allow_insecure, path=/run/server_config/transport_config/*, default=False) => False
22:17:19 DEBUG| PARAMS (key=ca_cert, path=/run/server_config/transport_config/*, default=daosCA.crt) => 'daosCA.crt'
22:17:19 DEBUG|   Added the directory: ca_cert => /etc/daos/certs/daosCA.crt
22:17:19 DEBUG| PARAMS (key=cert, path=/run/server_config/transport_config/*, default=server.crt) => 'server.crt'
22:17:19 DEBUG|   Added the directory: cert => /etc/daos/certs/server.crt
22:17:19 DEBUG| PARAMS (key=client_cert_dir, path=/run/server_config/transport_config/*, default=clients) => 'clients'
22:17:19 DEBUG|   Added the directory: client_cert_dir => /etc/daos/certs/clients
22:17:19 DEBUG| PARAMS (key=key, path=/run/server_config/transport_config/*, default=server.key) => 'server.key'
22:17:19 DEBUG|   Added the directory: key => /etc/daos/certs/server.key
22:17:19 DEBUG| PARAMS (key=device, path=/run/server_config/control_metadata/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=path, path=/run/server_config/control_metadata/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=crt_ctx_share_addr, path=/run/server_config/engines/0/*, default=0) => 0
22:17:19 DEBUG| PARAMS (key=env_vars, path=/run/server_config/engines/0/*, default=['ABT_ENV_MAX_NUM_XSTREAMS=100', 'ABT_MAX_NUM_XSTREAMS=100', 'DAOS_MD_CAP=1024', 'DAOS_SCHED_WATCHDOG_ALL=1', 'DD_MASK=mgmt,io,md,epc,rebuild', 'D_LOG_FILE_APPEND_PID=1', 'COVFILE=/tmp/test.cov']) => ['ABT_ENV_MAX_NUM_XSTREAMS=100', 'ABT_MAX_NUM_XSTREAMS=100', 'DAOS_MD_CAP=1024', 'DAOS_SCHED_WATCHDOG_ALL=1', 'DD_MASK=mgmt,io,md,epc,rebuild', 'D_LOG_FILE_APPEND_PID=1', 'COVFILE=/tmp/test.cov']
22:17:19 DEBUG| PARAMS (key=fabric_iface, path=/run/server_config/engines/0/*, default=eth0) => 'eth0'
22:17:19 DEBUG| PARAMS (key=fabric_iface_port, path=/run/server_config/engines/0/*, default=31416) => 31416
22:17:19 DEBUG| PARAMS (key=first_core, path=/run/server_config/engines/0/*, default=0) => 0
22:17:19 DEBUG| PARAMS (key=log_file, path=/run/server_config/engines/0/*, default=daos_server.log) => 'daos_server.log'
22:17:19 DEBUG|   Added the directory: log_file => /var/tmp/daos_testing/daos_server.log
22:17:19 DEBUG| PARAMS (key=log_mask, path=/run/server_config/engines/0/*, default=INFO) => 'INFO'
22:17:19 DEBUG| PARAMS (key=nr_xs_helpers, path=/run/server_config/engines/0/*, default=4) => 0
22:17:19 DEBUG| PARAMS (key=pinned_numa_node, path=/run/server_config/engines/0/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=targets, path=/run/server_config/engines/0/*, default=8) => 4
22:17:19 DEBUG| Checking for storage tier in /run/server_config/engines/0/storage/0/* 
22:17:19 DEBUG| PARAMS (key=class, path=/run/server_config/engines/0/storage/0/*, default=None) => 'ram'
22:17:19 DEBUG| PARAMS (key=scm_list, path=/run/server_config/engines/0/storage/0/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=scm_mount, path=/run/server_config/engines/0/storage/0/*, default=None) => '/mnt/daos'
22:17:19 DEBUG| PARAMS (key=scm_size, path=/run/server_config/engines/0/storage/0/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=scm_hugepages_disabled, path=/run/server_config/engines/0/storage/0/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=bdev_list, path=/run/server_config/engines/0/storage/0/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=bdev_number, path=/run/server_config/engines/0/storage/0/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=bdev_size, path=/run/server_config/engines/0/storage/0/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=bdev_roles, path=/run/server_config/engines/0/storage/0/*, default=None) => None
22:17:19 DEBUG| Checking for storage tier in /run/server_config/engines/0/storage/1/* 
22:17:19 DEBUG| PARAMS (key=class, path=/run/server_config/engines/0/storage/1/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=_hostlist, path=/run/dmg/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=configpath, path=/run/dmg/*, default=/etc/daos/daos_control.yml) => '/etc/daos/daos_control.yml'
22:17:19 DEBUG| PARAMS (key=debug, path=/run/dmg/*, default=True) => True
22:17:19 DEBUG| PARAMS (key=hostfile, path=/run/dmg/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=insecure, path=/run/dmg/*, default=False) => False
22:17:19 DEBUG| PARAMS (key=json, path=/run/dmg/*, default=False) => False
22:17:19 DEBUG| PARAMS (key=pattern_timeout, path=/run/dmg/*, default=10) => 10
22:17:19 DEBUG| PARAMS (key=dmg_sub_command, path=/run/dmg/*, default=None) => None
22:17:19 DEBUG| PARAMS (key=env_vars, path=/run/client/*, default=[]) => []
22:17:19 DEBUG| PARAMS (key=env_vars, path=/run/dmg/*, default=[]) => []
22:17:19 DEBUG| PARAMS (key=hostlist, path=/run/dmg/*, default=localhost) => 'localhost'
22:17:19 DEBUG| PARAMS (key=name, path=/run/dmg/*, default=daos_server) => 'daos_server'
22:17:19 DEBUG| PARAMS (key=port, path=/run/dmg/*, default=10001) => 10001
22:17:19 DEBUG| PARAMS (key=allow_insecure, path=/run/dmg/transport_config/*, default=False) => False
22:17:19 DEBUG| PARAMS (key=ca_cert, path=/run/dmg/transport_config/*, default=daosCA.crt) => 'daosCA.crt'
22:17:19 DEBUG|   Added the directory: ca_cert => /etc/daos/certs/daosCA.crt
22:17:19 DEBUG| PARAMS (key=cert, path=/run/dmg/transport_config/*, default=admin.crt) => 'admin.crt'
22:17:19 DEBUG|   Added the directory: cert => /etc/daos/certs/admin.crt
22:17:19 DEBUG| PARAMS (key=key, path=/run/dmg/transport_config/*, default=admin.key) => 'admin.key'
22:17:19 DEBUG|   Added the directory: key => /etc/daos/certs/admin.key
22:17:19 DEBUG| Updated param access_points => ['wolf-102vm2']
22:17:19 INFO | ----------------------------------------------------------------------------------------------------
22:17:19 INFO | --- VERIFYING STATES OF 1 SERVERS GROUP ---
22:17:19 DEBUG| Copying certificates for dmg:
22:17:19 DEBUG|   /var/tmp/daos_testing/daosCA/certs/daosCA.crt -> /etc/daos/certs/daosCA.crt
22:17:20 DEBUG|   /var/tmp/daos_testing/daosCA/certs/admin.crt -> /etc/daos/certs/admin.crt
22:17:21 DEBUG|   /var/tmp/daos_testing/daosCA/certs/admin.key -> /etc/daos/certs/admin.key
22:17:21 DEBUG| Copied certificates for dmg (in /etc/daos/certs):
22:17:22 DEBUG|   wolf-102vm1: total 40
22:17:22 DEBUG|   wolf-102vm1: drwxr-xr-x 3 root        root        4096 Feb 21 21:45 .
22:17:22 DEBUG|   wolf-102vm1: drwxr-xr-x 3 root        root        4096 Feb 21 22:15 ..
22:17:22 DEBUG|   wolf-102vm1: -rw-r--r-- 1 jenkins     jenkins     5561 Feb 21 22:17 admin.crt
22:17:22 DEBUG|   wolf-102vm1: -r-------- 1 jenkins     jenkins     2484 Feb 21 22:17 admin.key
22:17:22 DEBUG|   wolf-102vm1: -rw-r--r-- 1 daos_agent  daos_agent  5561 Feb 21 22:14 agent.crt
22:17:22 DEBUG|   wolf-102vm1: -r-------- 1 daos_agent  daos_agent  2484 Feb 21 22:14 agent.key
22:17:22 DEBUG|   wolf-102vm1: drwx------ 2 daos_server daos_server 4096 Feb 21 21:28 clients
22:17:22 DEBUG|   wolf-102vm1: -rw-r--r-- 1 jenkins     jenkins     1476 Feb 21 22:17 daosCA.crt
22:17:22 DEBUG| Updated param dmg.yaml.hostlist => ['wolf-102vm2', 'wolf-102vm3']
22:17:22 DEBUG| Updated param ranks => None
22:17:22 DEBUG| Updated param verbose => True
22:17:22 INFO | Writing yaml configuration file /var/tmp/daos_testing/test_telemetry_list/test_daos_server_dmg.yaml
22:17:22 INFO | Copying /var/tmp/daos_testing/test_telemetry_list/test_daos_server_dmg.yaml yaml configuration file to /etc/daos/daos_control.yml on wolf-102vm1
22:17:22 INFO | Command environment vars:
  {}
22:17:22 INFO | Running '/usr/bin/dmg -o /etc/daos/daos_control.yml -d -j system query --verbose'
22:17:22 DEBUG| [stderr] DEBUG 22:17:22.914972 main.go:209: debug output enabled
22:17:22 DEBUG| [stderr] DEBUG 22:17:22.915651 main.go:241: control config loaded from /etc/daos/daos_control.yml
22:17:22 DEBUG| [stderr] DEBUG 22:17:22.938143 system.go:279: DAOS system query request: *mgmt.SystemQueryReq (sys:"daos_server-2.5.100"  state_mask:65535)
22:17:22 DEBUG| [stderr] DEBUG 22:17:22.941134 rpc.go:278: request hosts: [wolf-102vm2:10001 wolf-102vm3:10001]
22:17:22 DEBUG| [stderr] DEBUG 22:17:22.946246 response.go:168: wolf-102vm2:10001: err: client: code = 506 description = "the server at wolf-102vm2:10001 refused the connection"
22:17:22 DEBUG| [stderr] DEBUG 22:17:22.946565 response.go:168: wolf-102vm2:10001: err: client: code = 506 description = "the server at wolf-102vm2:10001 refused the connection"
22:17:22 DEBUG| [stdout] {
22:17:22 DEBUG| [stderr] ERROR: dmg: system query failed: client: code = 506 description = "the server at wolf-102vm2:10001 refused the connection": unable to contact the DAOS Management Service
22:17:22 DEBUG| [stdout]   "response": null,
22:17:22 DEBUG| [stdout]   "error": "system query failed: client: code = 506 description = \"the server at wolf-102vm2:10001 refused the connection\": unable to contact the DAOS Management Service",
22:17:22 DEBUG| [stdout]   "status": -1025
22:17:22 DEBUG| [stdout] }
22:17:22 INFO | Command '/usr/bin/dmg -o /etc/daos/daos_control.yml -d -j system query --verbose' finished with 1 after 0.07490086555480957s
22:17:22 INFO | Error occurred running '/usr/bin/dmg -o /etc/daos/daos_control.yml -d -j system query --verbose': Command '/usr/bin/dmg -o /etc/daos/daos_control.yml -d -j system query --verbose' failed.
stdout: b'{\n  "response": null,\n  "error": "system query failed: client: code = 506 description = \\"the server at wolf-102vm2:10001 refused the connection\\": unable to contact the DAOS Management Service",\n  "status": -1025\n}\n'
stderr: b'DEBUG 22:17:22.914972 main.go:209: debug output enabled\nDEBUG 22:17:22.915651 main.go:241: control config loaded from /etc/daos/daos_control.yml\nDEBUG 22:17:22.938143 system.go:279: DAOS system query request: *mgmt.SystemQueryReq (sys:"daos_server-2.5.100"  state_mask:65535)\nDEBUG 22:17:22.941134 rpc.go:278: request hosts: [wolf-102vm2:10001 wolf-102vm3:10001]\nDEBUG 22:17:22.946246 response.go:168: wolf-102vm2:10001: err: client: code = 506 description = "the server at wolf-102vm2:10001 refused the connection"\nDEBUG 22:17:22.946565 response.go:168: wolf-102vm2:10001: err: client: code = 506 description = "the server at wolf-102vm2:10001 refused the connection"\nERROR: dmg: system query failed: client: code = 506 description = "the server at wolf-102vm2:10001 refused the connection": unable to contact the DAOS Management Service\n'
additional_info: None
22:17:22 INFO | <SERVER> Assigning expected server states: {}
22:17:22 INFO | <SERVER> Verifying server states: group=daos_server, hosts=wolf-102vm[2-3]
22:17:22 INFO |   Unable to obtain current server state.  Undefined expected server states due to a failure starting the server.
22:17:22 INFO | ----------------------------------------------------------------------------------------------------
22:17:22 INFO | --- STOPPING SERVERS ---
22:17:22 INFO | Stopping 1 group(s) of servers
22:17:22 INFO | <SERVER> Stopping server systemd command
22:17:23 INFO | Command: sudo -n systemctl stop daos_server.service
Results:
  wolf-102vm[2-3]: exit_status=0, interrupted=False:
22:17:23 INFO | Command: sudo -n systemctl disable daos_server.service
Results:
  wolf-102vm[2-3]: exit_status=0, interrupted=False:
22:17:23 INFO | Command: sudo -n systemctl stop daos_server.service
Results:
  wolf-102vm[2-3]: exit_status=0, interrupted=False:
22:17:24 INFO | Command: sudo -n systemctl disable daos_server.service
Results:
  wolf-102vm[2-3]: exit_status=0, interrupted=False:
22:17:24 DEBUG| Searching for any processes on wolf-102vm[2-3] that match '(daos_server|daos_engine)'
22:17:24 DEBUG| Running on wolf-102vm[2-3] with a 60 second timeout: /usr/bin/pgrep --list-full '(daos_server|daos_engine)'
22:17:24 DEBUG|   wolf-102vm[2-3] (rc=1): <no output>
22:17:24 DEBUG| No processes found on wolf-102vm[2-3] that match '(daos_server|daos_engine)'
22:17:24 INFO | No remote '(daos_server|daos_engine)' processes killed on wolf-102vm[2-3] (none found), done.
22:17:24 INFO | ----------------------------------------------------------------------------------------------------
22:17:24 INFO | --- STARTING SERVERS ---
22:17:24 INFO | Starting server: group=daos_server, hosts=wolf-102vm[2-3], config=/etc/daos/daos_server.yml
22:17:24 INFO | <SERVER> Preparing to start daos_server on wolf-102vm[2-3] with systemd
22:17:24 INFO | Writing yaml configuration file /var/tmp/daos_testing/test_telemetry_list/test_daos_server_server.yaml
22:17:24 INFO | Copying /var/tmp/daos_testing/test_telemetry_list/test_daos_server_server.yaml yaml configuration file to /etc/daos/daos_server.yml on wolf-102vm[2-3]
22:17:26 DEBUG| Updating pattern timeout based upon server config
22:17:26 DEBUG|   Detected bdev_list entries: []
22:17:26 DEBUG| Updated param DaosServerCommand.pattern_timeout => 40
22:17:26 DEBUG| Copying certificates for daos_server:
22:17:26 DEBUG|   /var/tmp/daos_testing/daosCA/certs/daosCA.crt -> /etc/daos/certs/daosCA.crt
22:17:28 DEBUG|   /var/tmp/daos_testing/daosCA/certs/server.crt -> /etc/daos/certs/server.crt
22:17:30 DEBUG|   /var/tmp/daos_testing/daosCA/certs/server.key -> /etc/daos/certs/server.key
22:17:32 DEBUG|   /var/tmp/daos_testing/daosCA/certs/agent.crt -> /etc/daos/certs/clients/agent.crt
22:17:34 DEBUG| Copied certificates for daos_server (in /etc/daos/certs, /etc/daos/certs/clients):
22:17:35 DEBUG|   wolf-102vm2: /etc/daos/certs:
22:17:35 DEBUG|   wolf-102vm2: total 28
22:17:35 DEBUG|   wolf-102vm2: drwxr-xr-x 3 root        root        4096 Feb 21 21:45 .
22:17:35 DEBUG|   wolf-102vm2: drwxr-xr-x 3 root        root        4096 Feb 21 22:17 ..
22:17:35 DEBUG|   wolf-102vm2: drwx------ 2 daos_server daos_server 4096 Feb 21 21:45 clients
22:17:35 DEBUG|   wolf-102vm2: -rw-r--r-- 1 daos_server daos_server 1476 Feb 21 22:17 daosCA.crt
22:17:35 DEBUG|   wolf-102vm2: -rw-r--r-- 1 daos_server daos_server 5609 Feb 21 22:17 server.crt
22:17:35 DEBUG|   wolf-102vm2: -r-------- 1 daos_server daos_server 2484 Feb 21 22:17 server.key
22:17:35 DEBUG|   wolf-102vm2: 
22:17:35 DEBUG|   wolf-102vm2: /etc/daos/certs/clients:
22:17:35 DEBUG|   wolf-102vm2: total 16
22:17:35 DEBUG|   wolf-102vm2: drwx------ 2 daos_server daos_server 4096 Feb 21 21:45 .
22:17:35 DEBUG|   wolf-102vm2: drwxr-xr-x 3 root        root        4096 Feb 21 21:45 ..
22:17:35 DEBUG|   wolf-102vm2: -rw-r--r-- 1 daos_server daos_server 5561 Feb 21 22:17 agent.crt
22:17:35 DEBUG|   wolf-102vm3: /etc/daos/certs:
22:17:35 DEBUG|   wolf-102vm3: total 40
22:17:35 DEBUG|   wolf-102vm3: drwxr-xr-x 3 root        root        4096 Feb 21 21:49 .
22:17:35 DEBUG|   wolf-102vm3: drwxr-xr-x 3 root        root        4096 Feb 21 22:17 ..
22:17:35 DEBUG|   wolf-102vm3: -rw-r--r-- 1 daos_agent  daos_agent  5561 Feb 21 21:49 agent.crt
22:17:35 DEBUG|   wolf-102vm3: -r-------- 1 daos_agent  daos_agent  2484 Feb 21 21:49 agent.key
22:17:35 DEBUG|   wolf-102vm3: drwx------ 2 daos_server daos_server 4096 Feb 21 21:45 clients
22:17:35 DEBUG|   wolf-102vm3: -rw-r--r-- 1 daos_server daos_server 1476 Feb 21 22:17 daosCA.crt
22:17:35 DEBUG|   wolf-102vm3: -rw-r--r-- 1 daos_server daos_server 5609 Feb 21 22:17 server.crt
22:17:35 DEBUG|   wolf-102vm3: -r-------- 1 daos_server daos_server 2484 Feb 21 22:17 server.key
22:17:35 DEBUG|   wolf-102vm3: 
22:17:35 DEBUG|   wolf-102vm3: /etc/daos/certs/clients:
22:17:35 DEBUG|   wolf-102vm3: total 16
22:17:35 DEBUG|   wolf-102vm3: drwx------ 2 daos_server daos_server 4096 Feb 21 21:45 .
22:17:35 DEBUG|   wolf-102vm3: drwxr-xr-x 3 root        root        4096 Feb 21 21:49 ..
22:17:35 DEBUG|   wolf-102vm3: -rw-r--r-- 1 daos_server daos_server 5561 Feb 21 22:17 agent.crt
22:17:35 DEBUG| Copying certificates for dmg:
22:17:35 DEBUG|   /var/tmp/daos_testing/daosCA/certs/daosCA.crt -> /etc/daos/certs/daosCA.crt
22:17:36 DEBUG|   /var/tmp/daos_testing/daosCA/certs/admin.crt -> /etc/daos/certs/admin.crt
22:17:36 DEBUG|   /var/tmp/daos_testing/daosCA/certs/admin.key -> /etc/daos/certs/admin.key
22:17:37 DEBUG| Copied certificates for dmg (in /etc/daos/certs):
22:17:38 DEBUG|   wolf-102vm1: total 40
22:17:38 DEBUG|   wolf-102vm1: drwxr-xr-x 3 root        root        4096 Feb 21 21:45 .
22:17:38 DEBUG|   wolf-102vm1: drwxr-xr-x 3 root        root        4096 Feb 21 22:17 ..
22:17:38 DEBUG|   wolf-102vm1: -rw-r--r-- 1 jenkins     jenkins     5561 Feb 21 22:17 admin.crt
22:17:38 DEBUG|   wolf-102vm1: -r-------- 1 jenkins     jenkins     2484 Feb 21 22:17 admin.key
22:17:38 DEBUG|   wolf-102vm1: -rw-r--r-- 1 daos_agent  daos_agent  5561 Feb 21 22:14 agent.crt
22:17:38 DEBUG|   wolf-102vm1: -r-------- 1 daos_agent  daos_agent  2484 Feb 21 22:14 agent.key
22:17:38 DEBUG|   wolf-102vm1: drwx------ 2 daos_server daos_server 4096 Feb 21 21:28 clients
22:17:38 DEBUG|   wolf-102vm1: -rw-r--r-- 1 jenkins     jenkins     1476 Feb 21 22:17 daosCA.crt
22:17:38 DEBUG| Updated param dmg.yaml.hostlist => ['wolf-102vm2', 'wolf-102vm3']
22:17:38 INFO | Command: sudo -n systemctl stop daos_server.service
Results:
  wolf-102vm[2-3]: exit_status=0, interrupted=False:
22:17:38 INFO | Command: sudo -n systemctl disable daos_server.service
Results:
  wolf-102vm[2-3]: exit_status=0, interrupted=False:
22:17:38 DEBUG| Searching for any processes on wolf-102vm[2-3] that match '(daos_server|daos_engine)'
22:17:38 DEBUG| Running on wolf-102vm[2-3] with a 60 second timeout: /usr/bin/pgrep --list-full '(daos_server|daos_engine)'
22:17:39 DEBUG|   wolf-102vm[2-3] (rc=1): <no output>
22:17:39 DEBUG| No processes found on wolf-102vm[2-3] that match '(daos_server|daos_engine)'
22:17:39 INFO | No remote '(daos_server|daos_engine)' processes killed on wolf-102vm[2-3] (none found), done.
22:17:39 INFO | Cleaning up the /mnt/daos scm mount.
22:17:39 DEBUG| Checking for the existence of the /mnt/daos mount point
22:17:39 DEBUG| Running on wolf-102vm[2-3] with a 120 second timeout: test -d /mnt/daos
22:17:39 DEBUG|   wolf-102vm[2-3] (rc=0): <no output>
22:17:39 DEBUG| Removing the /mnt/daos superblocks
22:17:39 DEBUG| Running on wolf-102vm[2-3] with a 120 second timeout: sudo rm -fr /mnt/daos/*
22:17:39 DEBUG|   wolf-102vm[2-3] (rc=0): <no output>
22:17:39 DEBUG| Rem…18:16 DEBUG| [stdout]         "description": "Total rejected requests",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "counter",
22:18:16 DEBUG| [stdout]         "name": "engine_sched_total_time",
22:18:16 DEBUG| [stdout]         "description": "Total running time",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "engine_sched_wait_queue",
22:18:16 DEBUG| [stdout]         "description": "Wait queue length",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "engine_servicing_at",
22:18:16 DEBUG| [stdout]         "description": "Timestamp when the engine became ready",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "engine_started_at",
22:18:16 DEBUG| [stdout]         "description": "Timestamp of last engine startup",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "summary",
22:18:16 DEBUG| [stdout]         "name": "go_gc_duration_seconds",
22:18:16 DEBUG| [stdout]         "description": "A summary of the pause duration of garbage collection cycles.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_goroutines",
22:18:16 DEBUG| [stdout]         "description": "Number of goroutines that currently exist.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_info",
22:18:16 DEBUG| [stdout]         "description": "Information about the Go environment.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_alloc_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of bytes allocated and still in use.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "counter",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_alloc_bytes_total",
22:18:16 DEBUG| [stdout]         "description": "Total number of bytes allocated, even if freed.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_buck_hash_sys_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of bytes used by the profiling bucket hash table.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "counter",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_frees_total",
22:18:16 DEBUG| [stdout]         "description": "Total number of frees.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_gc_sys_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of bytes used for garbage collection system metadata.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_heap_alloc_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of heap bytes allocated and still in use.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_heap_idle_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of heap bytes waiting to be used.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_heap_inuse_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of heap bytes that are in use.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_heap_objects",
22:18:16 DEBUG| [stdout]         "description": "Number of allocated objects.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_heap_released_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of heap bytes released to OS.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_heap_sys_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of heap bytes obtained from system.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_last_gc_time_seconds",
22:18:16 DEBUG| [stdout]         "description": "Number of seconds since 1970 of last garbage collection.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "counter",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_lookups_total",
22:18:16 DEBUG| [stdout]         "description": "Total number of pointer lookups.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "counter",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_mallocs_total",
22:18:16 DEBUG| [stdout]         "description": "Total number of mallocs.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_mcache_inuse_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of bytes in use by mcache structures.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_mcache_sys_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of bytes used for mcache structures obtained from system.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_mspan_inuse_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of bytes in use by mspan structures.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_mspan_sys_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of bytes used for mspan structures obtained from system.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_next_gc_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of heap bytes when next garbage collection will take place.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_other_sys_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of bytes used for other system allocations.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_stack_inuse_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of bytes in use by the stack allocator.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_
22:18:16 DEBUG| [stdout] stack_sys_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of bytes obtained from system for stack allocator.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_memstats_sys_bytes",
22:18:16 DEBUG| [stdout]         "description": "Number of bytes obtained from system.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "go_threads",
22:18:16 DEBUG| [stdout]         "description": "Number of OS threads created.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "counter",
22:18:16 DEBUG| [stdout]         "name": "process_cpu_seconds_total",
22:18:16 DEBUG| [stdout]         "description": "Total user and system CPU time spent in seconds.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "process_max_fds",
22:18:16 DEBUG| [stdout]         "description": "Maximum number of open file descriptors.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "process_open_fds",
22:18:16 DEBUG| [stdout]         "description": "Number of open file descriptors.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "process_resident_memory_bytes",
22:18:16 DEBUG| [stdout]         "description": "Resident memory size in bytes.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "process_start_time_seconds",
22:18:16 DEBUG| [stdout]         "description": "Start time of the process since unix epoch in seconds.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "process_virtual_memory_bytes",
22:18:16 DEBUG| [stdout]         "description": "Virtual memory size in bytes.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       },
22:18:16 DEBUG| [stdout]       {
22:18:16 DEBUG| [stdout]         "type": "gauge",
22:18:16 DEBUG| [stdout]         "name": "process_virtual_memory_max_bytes",
22:18:16 DEBUG| [stdout]         "description": "Maximum amount of virtual memory available in bytes.",
22:18:16 DEBUG| [stdout]         "metrics": null
22:18:16 DEBUG| [stdout]       }
22:18:16 DEBUG| [stdout]     ]
22:18:16 DEBUG| [stdout]   },
22:18:16 DEBUG| [stdout]   "error": null,
22:18:16 DEBUG| [stdout]   "status": 0
22:18:16 DEBUG| [stdout] }
22:18:16 INFO | Command '/usr/bin/dmg -o /etc/daos/daos_control.yml -d -j telemetry metrics list --host-list=wolf-102vm3' finished with 0 after 1.5344679355621338s
22:18:16 INFO | Detected 2/2 telemetry metrics list hosts
22:18:16 INFO |   Difference between expected and actual: set()
22:18:16 INFO |   Symmetric difference between expected and actual: set()
22:18:16 INFO |   wolf-102vm2: detected 383/324 telemetry metric names
22:18:16 INFO |     wolf-102vm2: difference between expected and actual: set()
22:18:16 INFO |     wolf-102vm2: symmetric difference between expected and actual: {'engine_io_ops_key_query_latency_samples', 'engine_io_ops_compound_active_samples', 'engine_io_latency_vos_fetch_samples', 'engine_io_latency_bio_update_samples', 'engine_io_ops_key2anchor_active_samples', 'engine_dmabuff_wal_waiters_samples', 'engine_io_ops_dkey_enum_active_samples', 'engine_io_ops_dkey_punch_active_samples', 'engine_dmabuff_wal_qd_samples', 'engine_io_ops_tgt_akey_punch_latency_samples', 'engine_sched_cycle_duration_samples', 'engine_io_latency_vos_update_samples', 'engine_io_ops_akey_enum_active_samples', 'engine_io_ops_recx_enum_latency_samples', 'engine_io_ops_obj_punch_active_samples', 'engine_io_ops_dkey_punch_latency_samples', 'engine_net_swim_delay_samples', 'engine_io_ops_obj_punch_latency_samples', 'engine_io_ops_obj_enum_latency_samples', 'engine_io_ops_tgt_dkey_punch_active_samples', 'engine_io_ops_tgt_dkey_punch_latency_samples', 'engine_io_ops_tgt_update_active_samples', 'engine_io_ops_fetch_active_samples', 'engine_io_ops_ec_agg_active_samples', 'engine_io_latency_bulk_update_samples', 'engine_io_ops_key2anchor_latency_samples', 'engine_io_ops_tgt_akey_punch_active_samples', 'engine_io_ops_ec_rep_latency_samples', 'engine_io_latency_update_samples', 'engine_io_dtx_committable_samples', 'engine_io_ops_recx_enum_active_samples', 'engine_io_ops_migrate_latency_samples', 'engine_io_ops_migrate_active_samples', 'engine_io_latency_fetch_samples', 'engine_io_ops_obj_sync_active_samples', 'engine_io_ops_obj_coll_query_latency_samples', 'engine_io_ops_obj_enum_active_samples', 'engine_io_ops_key_query_active_samples', 'engine_io_dtx_committed_samples', 'engine_io_ops_dkey_enum_latency_samples', 'engine_io_ops_ec_agg_latency_samples', 'engine_io_ops_update_active_samples', 'engine_io_ops_akey_punch_latency_samples', 'engine_sched_cycle_size_samples', 'engine_io_latency_bulk_fetch_samples', 'engine_io_latency_bio_fetch_samples', 'engine_io_ops_akey_punch_active_samples', 'engine_io_ops_akey_enum_latency_samples', 'engine_io_ops_obj_sync_latency_samples', 'engine_io_ops_obj_coll_punch_active_samples', 'engine_io_ops_tgt_punch_latency_samples', 'engine_dmabuff_wal_sz_samples', 'engine_io_ops_ec_rep_active_samples', 'engine_io_ops_tgt_punch_active_samples', 'engine_io_ops_obj_coll_query_active_samples', 'engine_io_latency_tgt_update_samples', 'engine_io_ops_compound_latency_samples', 'engine_dmabuff_grab_retries_samples', 'engine_io_ops_obj_coll_punch_latency_samples'}
22:18:16 INFO |   wolf-102vm3: detected 383/324 telemetry metric names
22:18:16 INFO |     wolf-102vm3: difference between expected and actual: set()
22:18:16 INFO |     wolf-102vm3: symmetric difference between expected and actual: {'engine_io_ops_key_query_latency_samples', 'engine_io_ops_compound_active_samples', 'engine_io_latency_vos_fetch_samples', 'engine_io_latency_bio_update_samples', 'engine_io_ops_key2anchor_active_samples', 'engine_dmabuff_wal_waiters_samples', 'engine_io_ops_dkey_enum_active_samples', 'engine_io_ops_dkey_punch_active_samples', 'engine_dmabuff_wal_qd_samples', 'engine_io_ops_tgt_akey_punch_latency_samples', 'engine_sched_cycle_duration_samples', 'engine_io_latency_vos_update_samples', 'engine_io_ops_akey_enum_active_samples', 'engine_io_ops_recx_enum_latency_samples', 'engine_io_ops_obj_punch_active_samples', 'engine_io_ops_dkey_punch_latency_samples', 'engine_net_swim_delay_samples', 'engine_io_ops_obj_punch_latency_samples', 'engine_io_ops_obj_enum_latency_samples', 'engine_io_ops_tgt_dkey_punch_active_samples', 'engine_io_ops_tgt_dkey_punch_latency_samples', 'engine_io_ops_tgt_update_active_samples', 'engine_io_ops_fetch_active_samples', 'engine_io_ops_ec_agg_active_samples', 'engine_io_latency_bulk_update_samples', 'engine_io_ops_key2anchor_latency_samples', 'engine_io_ops_tgt_akey_punch_active_samples', 'engine_io_ops_ec_rep_latency_samples', 'engine_io_latency_update_samples', 'engine_io_dtx_committable_samples', 'engine_io_ops_recx_enum_active_samples', 'engine_io_ops_migrate_latency_samples', 'engine_io_ops_migrate_active_samples', 'engine_io_latency_fetch_samples', 'engine_io_ops_obj_sync_active_samples', 'engine_io_ops_obj_coll_query_latency_samples', 'engine_io_ops_obj_enum_active_samples', 'engine_io_ops_key_query_active_samples', 'engine_io_dtx_committed_samples', 'engine_io_ops_dkey_enum_latency_samples', 'engine_io_ops_ec_agg_latency_samples', 'engine_io_ops_update_active_samples', 'engine_io_ops_akey_punch_latency_samples', 'engine_sched_cycle_size_samples', 'engine_io_latency_bulk_fetch_samples', 'engine_io_latency_bio_fetch_samples', 'engine_io_ops_akey_punch_active_samples', 'engine_io_ops_akey_enum_latency_samples', 'engine_io_ops_obj_sync_latency_samples', 'engine_io_ops_obj_coll_punch_active_samples', 'engine_io_ops_tgt_punch_latency_samples', 'engine_dmabuff_wal_sz_samples', 'engine_io_ops_ec_rep_active_samples', 'engine_io_ops_tgt_punch_active_samples', 'engine_io_ops_obj_coll_query_active_samples', 'engine_io_latency_tgt_update_samples', 'engine_io_ops_compound_latency_samples', 'engine_dmabuff_grab_retries_samples', 'engine_io_ops_obj_coll_punch_latency_samples'}
22:18:16 INFO | Test has failed, dumping ULT stacks
22:18:16 INFO | Dumping ULT stacks of engines on wolf-102vm[2-3]
22:18:47 INFO | Command: rc=0; if /usr/bin/pgrep --list-full daos_engine; then rc=1; sudo pkill --signal USR2 daos_engine; sleep 30; fi; exit $rc
Results:
  wolf-102vm3: exit_status=1, interrupted=False:    35546 /usr/bin/daos_engine -t 4 -x 0 -g daos_server -d /var/run/daos_server -T 1 -I 0 -r 0 -H 0 -s /mnt/daos
  wolf-102vm2: exit_status=1, interrupted=False:    80231 /usr/bin/daos_engine -t 4 -x 0 -g daos_server -d /var/run/daos_server -T 1 -I 0 -r 0 -H 0 -s /mnt/daos

22:18:47 ERROR| 
22:18:47 ERROR| Reproduced traceback from: /usr/local/lib/python3.9/site-packages/avocado/core/test.py:767
22:18:47 ERROR| Traceback (most recent call last):
22:18:47 ERROR|   File "/usr/lib/daos/TESTING/ftest/control/dmg_telemetry_basic.py", line 84, in test_telemetry_list
22:18:47 ERROR|     self.verify_telemetry_list()
22:18:47 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/telemetry_test_base.py", line 82, in verify_telemetry_list
22:18:47 ERROR|     self.fail("\n".join(errors))
22:18:47 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/apricot/apricot/test.py", line 1375, in fail
22:18:47 ERROR|     super().fail(message)
22:18:47 ERROR|   File "/usr/local/lib/python3.9/site-packages/avocado/core/test.py", line 953, in fail
22:18:47 ERROR|     raise exceptions.TestFail(message)
22:18:47 ERROR| avocado.core.exceptions.TestFail: Symmetric difference found in telemetry metric names on wolf-102vm2
22:18:47 ERROR| Symmetric difference found in telemetry metric names on wolf-102vm3
22:18:47 ERROR| 
22:18:47 DEBUG| Local variables:
22:18:47 DEBUG|  -> self <class 'dmg_telemetry_basic.TestWithTelemetryBasic'>: 1-./control/dmg_telemetry_basic.py:TestWithTelemetryBasic.test_telemetry_list;run-container-hosts-pool-server_config-engines-0-storage-0-test-timeouts-2f2e
22:18:47 INFO | ====================================================================================================
22:18:47 INFO | *** TEARDOWN called after test completion: elapsed time: 89.11373281478882 seconds ***
22:18:47 INFO | Amount of time left in test timeout: 0.8862671852111816 seconds
22:18:47 DEBUG| no pre-teardown steps defined
22:18:47 INFO | ----------------------------------------------------------------------------------------------------
22:18:47 INFO | --- STOPPING AGENTS ---
22:18:47 INFO | ----------------------------------------------------------------------------------------------------
22:18:47 INFO | --- VERIFYING STATES OF 1 AGENTS GROUP ---
22:18:47 INFO | Command: systemctl is-active daos_agent.service
Results:
  wolf-102vm[1,4]: exit_status=0, interrupted=False:    active

22:18:47 INFO | <AGENT> Verifying agent states: group=daos_server, hosts=wolf-102vm[1,4]
22:18:47 INFO |   Rank  Host             UUID                                  Expected State          Current State   Result
22:18:47 INFO |   ----  ---------------  ------------------------------------  ----------------------  --------------  ------
22:18:47 INFO |   0     wolf-102vm1      -                                     active                  active          PASS
22:18:47 INFO |   1     wolf-102vm4      -                                     active                  active          PASS
22:18:47 INFO | Agents are configured to run across multiple test variants, not stopping
22:18:47 INFO | ----------------------------------------------------------------------------------------------------
22:18:47 INFO | --- STOPPING SERVERS ---
22:18:47 INFO | ----------------------------------------------------------------------------------------------------
22:18:47 INFO | --- VERIFYING STATES OF 1 SERVERS GROUP ---
22:18:47 DEBUG| Updated param ranks => None
22:18:47 DEBUG| Updated param verbose => True
22:18:47 INFO | Command environment vars:
  {}
22:18:47 INFO | Running '/usr/bin/dmg -o /etc/daos/daos_control.yml -d -j system query --verbose'
22:18:47 DEBUG| [stderr] DEBUG 22:18:47.703828 main.go:209: debug output enabled
22:18:47 DEBUG| [stderr] DEBUG 22:18:47.704388 main.go:241: control config loaded from /etc/daos/daos_control.yml
22:18:47 DEBUG| [stderr] DEBUG 22:18:47.726782 system.go:279: DAOS system query request: *mgmt.SystemQueryReq (sys:"daos_server-2.5.100"  state_mask:65535)
22:18:47 DEBUG| [stderr] DEBUG 22:18:47.727999 rpc.go:278: request hosts: [wolf-102vm2:10001 wolf-102vm3:10001]
22:18:47 DEBUG| [stderr] DEBUG 22:18:47.863246 response.go:168: wolf-102vm2:10001: *mgmt.SystemQueryResp@6 joined:0-1 
22:18:47 DEBUG| [stdout] {
22:18:47 DEBUG| [stdout]   "response": {
22:18:47 DEBUG| [stdout]     "members": [
22:18:47 DEBUG| [stdout]       {
22:18:47 DEBUG| [stdout]         "addr": "10.8.2.161:10001",
22:18:47 DEBUG| [stdout]         "state": "joined",
22:18:47 DEBUG| [stdout]         "fault_domain": "/wolf-102vm2.wolf.hpdd.intel.com",
22:18:47 DEBUG| [stdout]         "rank": 0,
22:18:47 DEBUG| [stdout]         "incarnation": 1585514796750209024,
22:18:47 DEBUG| [stdout]         "uuid": "fb6249d7-1ad2-4d28-95d5-9a49732c352e",
22:18:47 DEBUG| [stdout]         "fabric_uri": "ofi+tcp;ofi_rxm://10.8.2.161:31416",
22:18:47 DEBUG| [stdout]         "fabric_contexts": 6,
22:18:47 DEBUG| [stdout]         "info": "",
22:18:47 DEBUG| [stdout]         "last_update": "2024-02-21T22:17:56.982333828Z"
22:18:47 DEBUG| [stdout]       },
22:18:47 DEBUG| [stdout]       {
22:18:47 DEBUG| [stdout]         "addr": "10.8.2.162:10001",
22:18:47 DEBUG| [stdout]         "state": "joined",
22:18:47 DEBUG| [stdout]         "fault_domain": "/wolf-102vm3.wolf.hpdd.intel.com",
22:18:47 DEBUG| [stdout]         "rank": 1,
22:18:47 DEBUG| [stdout]         "incarnation": 1585514796786909184,
22:18:47 DEBUG| [stdout]         "uuid": "ee8bfd59-5bab-46f2-b33f-d79a0386b40d",
22:18:47 DEBUG| [stdout]         "fabric_uri": "ofi+tcp;ofi_rxm://10.8.2.162:31416",
22:18:47 DEBUG| [stdout]         "fabric_contexts": 6,
22:18:47 DEBUG| [stdout]         "info": "",
22:18:47 DEBUG| [stdout]         "last_update": "2024-02-21T22:17:58.231426985Z"
22:18:47 DEBUG| [stdout]       }
22:18:47 DEBUG| [stdout]     ]
22:18:47 DEBUG| [stdout]   },
22:18:47 DEBUG| [stdout]   "error": null,
22:18:47 DEBUG| [stdout]   "status": 0
22:18:47 DEBUG| [stdout] }
22:18:48 ERROR| 
22:18:48 ERROR| Reproduced traceback from: /usr/local/lib/python3.9/site-packages/avocado/core/test.py:793
22:18:48 ERROR| Traceback (most recent call last):
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/apricot/apricot/test.py", line 1414, in tearDown
22:18:48 ERROR|     self._teardown_errors.extend(self.stop_servers())
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/apricot/apricot/test.py", line 1599, in stop_servers
22:18:48 ERROR|     status = self.check_running("servers", self.server_managers)
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/apricot/apricot/test.py", line 1300, in check_running
22:18:48 ERROR|     manager_status = manager.verify_expected_states(set_expected)
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/command_utils.py", line 1373, in verify_expected_states
22:18:48 ERROR|     current_states = self.get_current_state()
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/server_utils.py", line 896, in get_current_state
22:18:48 ERROR|     query_data = self.dmg.system_query()
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/dmg_utils.py", line 1076, in system_query
22:18:48 ERROR|     return self._get_json_result(
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/command_utils.py", line 704, in _get_json_result
22:18:48 ERROR|     self._get_result(sub_command_list, raise_exception=raise_exception, **kwargs)
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/command_utils.py", line 677, in _get_result
22:18:48 ERROR|     return self.run(raise_exception)
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/command_utils.py", line 992, in run
22:18:48 ERROR|     return super().run(raise_exception)
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/command_utils.py", line 617, in run
22:18:48 ERROR|     super().run(raise_exception)
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/command_utils.py", line 205, in run
22:18:48 ERROR|     return self._run_process(raise_exception)
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/command_utils.py", line 231, in _run_process
22:18:48 ERROR|     self.result = run_command(
22:18:48 ERROR|   File "/usr/lib/daos/TESTING/ftest/util/general_utils.py", line 260, in run_command
22:18:48 ERROR|     return process.run(**kwargs)
22:18:48 ERROR|   File "/usr/local/lib/python3.9/site-packages/avocado/utils/process.py", line 1034, in run
22:18:48 ERROR|     cmd_result = sp.run(timeout=timeout)
22:18:48 ERROR|   File "/usr/local/lib/python3.9/site-packages/avocado/utils/process.py", line 908, in run
22:18:48 ERROR|     self.wait(timeout, sig)
22:18:48 ERROR|   File "/usr/local/lib/python3.9/site-packages/avocado/utils/process.py", line 822, in wait
22:18:48 ERROR|     rc = self._popen.wait()
22:18:48 ERROR|   File "/usr/lib64/python3.9/subprocess.py", line 1189, in wait
22:18:48 ERROR|     return self._wait(timeout=timeout)
22:18:48 ERROR|   File "/usr/lib64/python3.9/subprocess.py", line 1917, in _wait
22:18:48 ERROR|     (pid, sts) = self._try_wait(0)
22:18:48 ERROR|   File "/usr/lib64/python3.9/subprocess.py", line 1875, in _try_wait
22:18:48 ERROR|     (pid, sts) = os.waitpid(self.pid, wait_flags)
22:18:48 ERROR|   File "/usr/local/lib/python3.9/site-packages/avocado/plugins/runner.py", line 77, in sigterm_handler
22:18:48 ERROR|     raise RuntimeError("Test interrupted by SIGTERM")
22:18:48 ERROR| RuntimeError: Test interrupted by SIGTERM
22:18:48 ERROR| 
22:18:48 DEBUG| DATA (filename=output.expected) => NOT FOUND (data sources: variant, test, file)
22:18:48 DEBUG| DATA (filename=stdout.expected) => NOT FOUND (data sources: variant, test, file)
22:18:48 DEBUG| DATA (filename=stderr.expected) => NOT FOUND (data sources: variant, test, file)
22:18:48 ERROR| FAIL 1-./control/dmg_telemetry_basic.py:TestWithTelemetryBasic.test_telemetry_list;run-container-hosts-pool-server_config-engines-0-storage-0-test-timeouts-2f2e -> TestFail: Symmetric difference found in telemetry metric names on wolf-102vm2
Symmetric difference found in telemetry metric names on wolf-102vm3
22:18:48 INFO | 

Runner error occurred: Timeout reached
Original status: FAIL
{'name': '1-./control/dmg_telemetry_basic.py:TestWithTelemetryBasic.test_telemetry_list;run-container-hosts-pool-server_config-engines-0-storage-0-test-timeouts-2f2e', 'logdir': '/var/tmp/ftest/avocado/job-results/job-2024-02-21T22.17-c82da4a/test-results/1-._control_dmg_telemetry_basic.py_TestWithTelemetryBasic.test_telemetry_list_run-container-hosts-pool-server_config-engines-0-storage-0-test-timeouts-2f2e', 'logfile': '/var/tmp/ftest/avocado/job-results/job-2024-02-21T22.17-c82da4a/test-results/1-._control_dmg_telemetry_basic.py_TestWithTelemetryBasic.test_telemetry_list_run-container-hosts-pool-server_config-engines-0-storage-0-test-timeouts-2f2e/debug.log', 'status': 'FAIL', 'running': False, 'paused': False, 'time_start': 1708553838.2285216, 'time_elapsed': 90.6360502243042, 'time_end': 1708553928.8645718, 'fail_reason': 'Symmetric difference found in telemetry metric names on wolf-102vm2\nSymmetric difference found in telemetry metric names on wolf-102vm3', 'fail_class': 'TestFail', 'traceback': 'Traceback (most recent call last):\n  File "/usr/local/lib/python3.9/site-packages/avocado/core/test.py", line 856, in _run_avocado\n    raise test_exception\n  File "/usr/local/lib/python3.9/site-packages/avocado/core/test.py", line 762, in _run_avocado\n    testMethod()\n  File "/usr/lib/daos/TESTING/ftest/control/dmg_telemetry_basic.py", line 84, in test_telemetry_list\n    self.verify_telemetry_list()\n  File "/usr/lib/daos/TESTING/ftest/util/telemetry_test_base.py", line 82, in verify_telemetry_list\n    self.fail("\\n".join(errors))\n  File "/usr/lib/daos/TESTING/ftest/util/apricot/apricot/test.py", line 1375, in fail\n    super().fail(message)\n  File "/usr/local/lib/python3.9/site-packages/avocado/core/test.py", line 953, in fail\n    raise exceptions.TestFail(message)\navocado.core.exceptions.TestFail: Symmetric difference found in telemetry metric names on wolf-102vm2\nSymmetric difference found in telemetry metric names on wolf-102vm3\n', 'timeout': 90, 'whiteboard': '', 'phase': 'FINISHED', 'class_name': 'TestWithTelemetryBasic', 'job_logdir': '/var/tmp/ftest/avocado/job-results/job-2024-02-21T22.17-c82da4a', 'job_unique_id': 'c82da4acb3acca51304e55064362ea821e368cd9', 'params': [('/run/hosts', 'test_servers', 'wolf-102vm[2-3]'), ('/run/hosts', 'test_clients', 'wolf-102vm4'), ('/run/timeouts', 'test_telemetry_list', 60), ('/run/timeouts', 'test_container_telemetry', 230), ('/run/server_config', 'name', 'daos_server'), ('/run/server_config', 'engines_per_host', 1), ('/run/server_config', 'system_ram_reserved', 1), ('/run/server_config/engines/0', 'targets', 4), ('/run/server_config/engines/0', 'nr_xs_helpers', 0), ('/run/server_config/engines/0/storage/0', 'class', 'ram'), ('/run/server_config/engines/0/storage/0', 'scm_mount', '/mnt/daos'), ('/run/pool', 'scm_size', '2G'), ('/run/pool', 'control_method', 'dmg'), ('/run/container', 'control_method', 'daos'), ('/run/test', 'container_qty', 5), ('/run/test', 'open_close_qty', 3)]}