ehl_crb: tests/kernel/context fails sporadically

[jenmwms]

Describe the bug
This issue is observed on ehl_crb, but does not appear on other boards/HW. In tests/kernel/context the test case test_kernel_cpu_idle_atomic fails ~20% of the time (@chen-png can also help describe) .

The assert fails due to an "off-by-one" scenario. This happens sometimes on these very sensitive timing tests and different HW, in this case EHL CRB.

To Reproduce
Steps to reproduce the behavior:

1. west build -b ehl_crb -p auto tests/kernel/context/
2. copy binary to USB/PXE boot media
3. boot
4. See error

Expected behavior
All test cases pass.

Impact
Unexpected behavior is very sporadic (<20%)

Logs and console output

Booting Zephyr OS build v2.5.0-rc3-122-gfe7c2efca800  ***
Running test suite context
===================================================================
START - test_kernel_interrupts
PASS - test_kernel_interrupts
===================================================================
START - test_kernel_ctx_thread
Testing k_current_get() from an ISR and thread
Testing k_is_in_isr() from an ISR
Testing k_is_in_isr() from a preemptible thread
PASS - test_kernel_ctx_thread
===================================================================
START - test_busy_wait
Thread busy waiting for 20000 usecs
Thread busy waiting completed
Thread busy waiting for 20000 usecs (irqs locked)
Thread busy waiting completed (irqs locked)
PASS - test_busy_wait
===================================================================
START - test_k_sleep
thread sleeping for 50 milliseconds
thread back from sleep
Testing k_thread_create() without cancellation
thread (q order: 2, t/o: 500) is running
got thread (q order: 2, t/o: 500) as expected
thread (q order: 3, t/o: 750) is running
got thread (q order: 3, t/o: 750) as expected
thread (q order: 0, t/o: 1000) is running
got thread (q order: 0, t/o: 1000) as expected
thread (q order: 6, t/o: 1250) is running
got thread (q order: 6, t/o: 1250) as expected
thread (q order: 1, t/o: 1500) is running
got thread (q order: 1, t/o: 1500) as expected
thread (q order: 4, t/o: 1750) is running
got thread (q order: 4, t/o: 1750) as expected
thread (q order: 5, t/o: 2000) is running
got thread (q order: 5, t/o: 2000) as expected
Testing k_thread_create() with cancellations
cancelling [q order: 0, t/o: 1000, t/o order: 0]
thread (q order: 3, t/o: 750) is running
got (q order: 3, t/o: 750, t/o order 1) as expected
thread (q order: 0, t/o: 1000) is running
got (q order: 0, t/o: 1000, t/o order 2) as expected
cancelling [q order: 3, t/o: 750, t/o order: 3]
cancelling [q order: 4, t/o: 1750, t/o order: 4]
thread (q order: 4, t/o: 1750) is running
got (q order: 4, t/o: 1750, t/o order 5) as expected
cancelling [q order: 6, t/o: 1250, t/o order: 6]
PASS - test_k_sleep
===================================================================
START - test_kernel_cpu_idle_atomic
Assertion failed at WEST_TOPDIR/zephyr/tests/kernel/context/src/main.c:352: _test_kernel_cpu_idle: (tms2 < tms is true)
Bad ms value computed,got 5477 which is less than 5478
FAIL - test_kernel_cpu_idle_atomic
===================================================================
START - test_kernel_cpu_idle
PASS - test_kernel_cpu_idle
===================================================================
START - test_k_yield
PASS - test_k_yield
===================================================================
START - test_kernel_thread
PASS - test_kernel_thread
===================================================================
START - test_kernel_timer_interrupts
PASS - test_kernel_timer_interrupts
===================================================================
Test suite context failed.
===================================================================
PROJECT EXECUTION FAILED

Environment (please complete the following information):

• OS: Linux
• Toolchain: zephyr-sdk-0.12.2
• Commit SHA: 2.5 Release bump (fe7c2ef)

Note: Originally observed by @chen-png and I helped capture it here.

[jenmwms]

@chen-png How many times did you need to run the test to expose the issue? Reportedly 20% occurrence, but I could not reproduce in at least 10 trials. Do I need a larger sample?

[jenmwms]

^^ tested with same configurations (OS, Toolchain, Commit SHA). Also tested at least 10 times on later in the tree for #32557 (unrelated?)

[chen-png]

@jenmwms I ran this test at the eighth times, it reproduced this issue, this is really a low probability issue.

DEBUG - DEVICE: *** Booting Zephyr OS build v2.5.0-rc3-122-gfe7c2efca800 ***
DEBUG - DEVICE: Running test suite context
DEBUG - DEVICE: ===================================================================
DEBUG - DEVICE: START - test_kernel_interrupts
DEBUG - DEVICE: PASS - test_kernel_interrupts
....
DEBUG - DEVICE: ===================================================================
DEBUG - DEVICE: START - test_kernel_cpu_idle_atomic
DEBUG - DEVICE: PASS - test_kernel_cpu_idle_atomic
DEBUG - DEVICE: ===================================================================
DEBUG - DEVICE: START - test_kernel_cpu_idle
DEBUG - DEVICE:
DEBUG - DEVICE: Assertion failed at WEST_TOPDIR/zephyr/tests/kernel/context/src/main.c:352: _test_kernel_cpu_idle: (tms2 < tms is true)
DEBUG - DEVICE: Bad ms value computed,got 5495 which is less than 5496
DEBUG - DEVICE:
DEBUG - DEVICE: FAIL - test_kernel_cpu_idle
DEBUG - DEVICE: ===================================================================
DEBUG - DEVICE: START - test_k_yield
DEBUG - DEVICE: PASS - test_k_yield
DEBUG - DEVICE: ===================================================================
DEBUG - DEVICE: START - test_kernel_thread
DEBUG - DEVICE: PASS - test_kernel_thread
DEBUG - DEVICE: ===================================================================
DEBUG - DEVICE: START - test_kernel_timer_interrupts
DEBUG - DEVICE: PASS - test_kernel_timer_interrupts
DEBUG - DEVICE: ===================================================================
DEBUG - DEVICE: Test suite context failed.
DEBUG - DEVICE: ===================================================================
DEBUG - DEVICE: PROJECT EXECUTION FAILED
DEBUG - run status: ehl_crb/tests/kernel/context/kernel.common failed
INFO - 1/1 ehl_crb tests/kernel/context/kernel.common FAILED Failed (device 33.058s)

[jenmwms]

@chen-png mentioned this is not reproduceable most recently. Appears to be resolved.