2090184 – Latency tools: Cyclictest test fails on the expected runtime flag "-D"

Bug 2090184 - Latency tools: Cyclictest test fails on the expected runtime flag "-D"

Summary: Latency tools: Cyclictest test fails on the expected runtime flag "-D"

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	OpenShift Container Platform
Classification:	Red Hat
Component:	Performance Addon Operator
Sub Component:
Version:	4.11
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	low
Target Milestone:	---
Target Release:	4.11.0
Assignee:	Martin Sivák
QA Contact:	Gowrishankar Rajaiyan
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2022-05-25 10:32 UTC by Shereen Haj Makhoul
Modified:	2022-08-10 12:17 UTC (History)
CC List:	0 users
Fixed In Version:
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:	2022-08-10 12:16:31 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)

Links
System	ID	Private	Priority	Status	Summary	Last Updated
Github	openshift cluster-node-tuning-operator pull 366	0	None	open	Bug 2090184: e2e: performanceprofile: latency tests fixes	2022-05-25 10:33:58 UTC
Red Hat Product Errata	RHBA-2022:5869	0	None	None	None	2022-08-10 12:17:00 UTC

Description Shereen Haj Makhoul 2022-05-25 10:32:04 UTC

Description of problem:
Recently cyclictest runner started to use "--duration" as the runtime flag for the tool command instead of "-D". The test that checks valid values of cyclictest tool fails on the expected flag, it still expects "-D" while it finds "--duration" 

Version-Release number of selected component (if applicable):


How reproducible:
always

Steps to Reproduce:
1.run the latency testing suite with cnf-tests image that contains the fix
2.
3.

Actual results:

[2022-05-24T16:48:08.876Z] Test latency measurement tools tests 

[2022-05-24T16:48:08.876Z]   [test_id:42115] Cyclictest - Verify that the tool is working properly with valid environment variables values

[2022-05-24T16:48:08.876Z]   /home/jenkins/workspace/CNF/cnf-compute-4.9-shajmakh-temp/performance-addon-operators/functests/5_latency_testing/latency_testing.go:144

[2022-05-24T16:48:08.876Z] STEP: Run cyclictest test : 

[2022-05-24T16:48:08.876Z] LATENCY_TEST_DELAY = 0 

[2022-05-24T16:48:08.876Z] LATENCY_TEST_RUN = true 

[2022-05-24T16:48:08.876Z] LATENCY_TEST_RUNTIME = 5 

[2022-05-24T16:48:08.876Z] MAXIMUM_LATENCY = 20000 

[2022-05-24T16:48:08.876Z] LATENCY_TEST_CPUS = 2 

[2022-05-24T16:48:08.876Z] 

[2022-05-24T16:49:30.239Z] 

[2022-05-24T16:49:30.239Z] • Failure [80.117 seconds]

[2022-05-24T16:49:30.239Z] Test latency measurement tools tests

[2022-05-24T16:49:30.239Z] /home/jenkins/workspace/CNF/cnf-compute-4.9-shajmakh-temp/performance-addon-operators/functests/5_latency_testing/latency_testing.go:89

[2022-05-24T16:49:30.239Z]   [test_id:42115] Cyclictest - Verify that the tool is working properly with valid environment variables values [It]

[2022-05-24T16:49:30.239Z]   /home/jenkins/workspace/CNF/cnf-compute-4.9-shajmakh-temp/performance-addon-operators/functests/5_latency_testing/latency_testing.go:144

[2022-05-24T16:49:30.239Z] 

[2022-05-24T16:49:30.239Z]   The output of the executed tool is not as expected

[2022-05-24T16:49:30.239Z]   Expected

[2022-05-24T16:49:30.239Z]       <string>: Running Suite: Performance Addon Operator latency e2e tests

[2022-05-24T16:49:30.239Z]       ===========================================================

[2022-05-24T16:49:30.239Z]       Random Seed: 1653410888

[2022-05-24T16:49:30.239Z]       Will run 1 of 3 specs

[2022-05-24T16:49:30.239Z]       

[2022-05-24T16:49:30.239Z]       SLog file created at: 2022/05/24 16:48:13

[2022-05-24T16:49:30.239Z]       Running on machine: cyclictest-xrhkr

[2022-05-24T16:49:30.239Z]       Binary: Built with gc go1.17.5 for linux/amd64

[2022-05-24T16:49:30.239Z]       Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg

[2022-05-24T16:49:30.239Z]       I0524 16:48:13.656687       1 node.go:39] Environment information: /proc/cmdline: BOOT_IMAGE=(hd0,gpt3)/ostree/rhcos-f68a7677295251cc4d1f4edf557735b65cc9cbbceb2540325c3e248f961e327f/vmlinuz-4.18.0-305.45.1.rt7.117.el8_4.x86_64 random.trust_cpu=on console=tty0 console=ttyS0,115200n8 ostree=/ostree/boot.1/rhcos/f68a7677295251cc4d1f4edf557735b65cc9cbbceb2540325c3e248f961e327f/0 ignition.platform.id=openstack root=UUID=f7105efa-704c-41ac-88f5-336bbe01091a rw rootflags=prjquota skew_tick=1 nohz=on rcu_nocbs=1-3 tuned.non_isolcpus=00000ff1 intel_pstate=disable nosoftlockup tsc=nowatchdog intel_iommu=on iommu=pt isolcpus=managed_irq,1-3 systemd.cpu_affinity=0,4,5,6,7,8,9,10,11 default_hugepagesz=1G hugepagesz=2M hugepages=128 nmi_watchdog=0 audit=0 mce=off processor.max_cstate=1 idle=poll intel_idle.max_cstate=0

[2022-05-24T16:49:30.239Z]       I0524 16:48:13.656957       1 node.go:46] Environment information: kernel version 4.18.0-305.45.1.rt7.117.el8_4.x86_64

[2022-05-24T16:49:30.239Z]       I0524 16:48:13.656997       1 main.go:52] running the cyclictest command with arguments [--duration 5 --priority 95 --threads 2 --affinity 1-2 --histogram 30 --interval 1000 --mlockall --quiet]

[2022-05-24T16:49:30.239Z]       I0524 16:48:18.721232       1 main.go:58] succeeded to run the cyclictest command: # /dev/cpu_dma_latency set to 0us

[2022-05-24T16:49:30.239Z]       # Histogram

[2022-05-24T16:49:30.239Z]       000000 000000	000000

[2022-05-24T16:49:30.239Z]       000001 000000	000000

[2022-05-24T16:49:30.239Z]       000002 000000	000000

[2022-05-24T16:49:30.239Z]       000003 002627	002761

[2022-05-24T16:49:30.239Z]       000004 001457	001575

[2022-05-24T16:49:30.239Z]       000005 000461	000372

[2022-05-24T16:49:30.239Z]       000006 000223	000159

[2022-05-24T16:49:30.239Z]       000007 000120	000064

[2022-05-24T16:49:30.239Z]       000008 000067	000037

[2022-05-24T16:49:30.239Z]       000009 000026	000019

[2022-05-24T16:49:30.239Z]       000010 000007	000012

[2022-05-24T16:49:30.239Z]       000011 000007	000000

[2022-05-24T16:49:30.239Z]       000012 000005	000001

[2022-05-24T16:49:30.239Z]       000013 000000	000000

[2022-05-24T16:49:30.239Z]       000014 000000	000000

[2022-05-24T16:49:30.239Z]       000015 000000	000000

[2022-05-24T16:49:30.239Z]       000016 000000	000000

[2022-05-24T16:49:30.239Z]       000017 000000	000000

[2022-05-24T16:49:30.239Z]       000018 000000	000000

[2022-05-24T16:49:30.239Z]       000019 000000	000000

[2022-05-24T16:49:30.239Z]       000020 000000	000000

[2022-05-24T16:49:30.239Z]       000021 000000	000000

[2022-05-24T16:49:30.239Z]       000022 000000	000000

[2022-05-24T16:49:30.239Z]       000023 000000	000000

[2022-05-24T16:49:30.239Z]       000024 000000	000000

[2022-05-24T16:49:30.239Z]       000025 000000	000000

[2022-05-24T16:49:30.239Z]       000026 000000	000000

[2022-05-24T16:49:30.239Z]       000027 000000	000000

[2022-05-24T16:49:30.239Z]       000028 000000	000000

[2022-05-24T16:49:30.239Z]       000029 000000	000000

[2022-05-24T16:49:30.239Z]       # Total: 000005000 000005000

[2022-05-24T16:49:30.239Z]       # Min Latencies: 00003 00003

[2022-05-24T16:49:30.239Z]       # Avg Latencies: 00003 00003

[2022-05-24T16:49:30.239Z]       # Max Latencies: 00012 00012

[2022-05-24T16:49:30.239Z]       # Histogram Overflows: 00000 00000

[2022-05-24T16:49:30.239Z]       # Histogram Overflow at cycle number:

[2022-05-24T16:49:30.239Z]       # Thread 0:

[2022-05-24T16:49:30.239Z]       # Thread 1:

[2022-05-24T16:49:30.239Z]       

[2022-05-24T16:49:30.239Z]       

[2022-05-24T16:49:30.239Z]       ------------------------------

[2022-05-24T16:49:30.239Z]       • [SLOW TEST:71.666 seconds]

[2022-05-24T16:49:30.239Z]       [performance] Latency Test

[2022-05-24T16:49:30.239Z]       /home/jenkins/workspace/CNF/cnf-compute-4.9-shajmakh-temp/performance-addon-operators/functests/4_latency/latency.go:61

[2022-05-24T16:49:30.239Z]         with the cyclictest image

[2022-05-24T16:49:30.239Z]         /home/jenkins/workspace/CNF/cnf-compute-4.9-shajmakh-temp/performance-addon-operators/functests/4_latency/latency.go:184

[2022-05-24T16:49:30.239Z]           should succeed

[2022-05-24T16:49:30.239Z]           /home/jenkins/workspace/CNF/cnf-compute-4.9-shajmakh-temp/performance-addon-operators/functests/4_latency/latency.go:196

[2022-05-24T16:49:30.239Z]       ------------------------------

[2022-05-24T16:49:30.239Z]       S

[2022-05-24T16:49:30.239Z]       JUnit report was created: /home/jenkins/workspace/CNF/cnf-compute-4.9-shajmakh-temp/performance-addon-operators/functests/5_latency_testing/unit_report_latency.xml

[2022-05-24T16:49:30.239Z]       

[2022-05-24T16:49:30.239Z]       Ran 1 of 3 Specs in 77.684 seconds

[2022-05-24T16:49:30.239Z]       SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 2 Skipped

[2022-05-24T16:49:30.239Z]       PASS

[2022-05-24T16:49:30.239Z]       

[2022-05-24T16:49:30.239Z]   to match regular expression

[2022-05-24T16:49:30.239Z]       <string>: running the cyclictest command with arguments .*-D 5

Expected results:
the test should not fail.

Additional info:
this bug is caused by this patch modification: https://github.com/openshift-kni/cnf-features-deploy/pull/1021

Comment 2 Shereen Haj Makhoul 2022-07-29 05:10:07 UTC

Verification:

cnf-tests image:registry-proxy.engineering.redhat.com/rh-osbs/openshift4-cnf-tests:v4.11.0-51

Steps:
podman run  -v $KUBECONFIG:/root/kubeconfig:Z -e KUBECONFIG=/root/kubeconfig -e IMAGE_REGISTRY=registry-proxy.engineering.redhat.com/rh-osbs/ -e CNF_TESTS_IMAGE=openshift4-cnf-tests:v4.11.0-51 -e PERF_TEST_PROFILE=performance -e ROLE_WORKER_CNF=worker-cnf -e LATENCY_TEST_RUN=true -e LATENCY_TEST_RUNTIME=30 -e LATENCY_TEST_CPUS=4 -e DISCOVERY_MODE=true registry-proxy.engineering.redhat.com/rh-osbs/openshift4-cnf-tests:v4.11.0-51 usr/bin/test-run.sh -ginkgo.focus="\[performance\]\ Latency\ Test" -ginkgo.v


output:

oslat:
 1 main.go:58] Running the oslat command with arguments [--duration 30 --rtprio 1 --cpu-list 2-4 --cpu-main-thread 1]
I0729 04:59:49.336537       1 main.go:64] Succeeded to run the oslat command: oslat V 2.30

cyclictest:
 1 main.go:63] running the cyclictest command with arguments [--duration 30 --priority 95 --threads 3 --affinity 2-4 --histogram 30 --interval 1000 --mlockall --mainaffinity 1 --quiet]
I0729 05:01:25.863385       1 main.go:69] succeeded to run the cyclictest command: # /dev/cpu_dma_latency set to 0us

hwlatdetec:
 1 main.go:50] running the hwlatdetect command with arguments [/usr/bin/hwlatdetect --threshold 20 --hardlimit 1000 --duration 30 --window 10000000us --width 950000us]
I0729 05:03:03.092100       1 main.go:56] succeeded to run the hwlatdetect command: hwlatdetect:  test duration 30 seconds

the --duration flag is now updated.
verified.

Comment 5 errata-xmlrpc 2022-08-10 12:16:31 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (OpenShift Container Platform 4.11 low-latency extras update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2022:5869

Note You need to log in before you can comment on or make changes to this bug.