Skip to content

Conversation

@npitre
Copy link

@npitre npitre commented Aug 1, 2019

This is the workaround suggested by Andy Ross to fix #17851.

@andrewboie
Copy link
Contributor

Getting a failed assertion still in one test

[1/1] cd /home/buildslave/src/github.com/zephyrproject-rtos/zephyr/out-3nd-pass/m2gl025_miv/tests/cmsis_rtos_v2/portability.cmsis_rtos_v2 && /usr/bin/renode --disable-xwt --pid-file renode.pid -e '$bin=@/home/buildslave/src/github.com/zephyrproject-rtos/zephyr/out-3nd-pass/m2gl025_miv/tests/cmsis_rtos_v2/portability.cmsis_rtos_v2/zephyr/zephyr.elf; include @/home/buildslave/src/github.com/zephyrproject-rtos/zephyr/boards/riscv32/m2gl025_miv/support/m2gl025_miv.resc; s'
03:05:33.4192 [INFO] Including script: /home/buildslave/src/github.com/zephyrproject-rtos/zephyr/boards/riscv32/m2gl025_miv/support/m2gl025_miv.resc
03:05:33.4380 [INFO] System bus created.
03:05:34.3924 [DEBUG] Segment size automatically calculated to value 64KiB
03:05:34.3934 [DEBUG] Segment size automatically calculated to value 64KiB
03:05:34.3935 [DEBUG] Segment size automatically calculated to value 64KiB
03:05:34.3935 [DEBUG] Segment size automatically calculated to value 4MiB
03:05:34.6103 [WARNING] Writing to an output GPIO pin #0
03:05:34.6105 [WARNING] Writing to an output GPIO pin #1
03:05:34.6105 [WARNING] Writing to an output GPIO pin #2
03:05:35.0941 [DEBUG] sysbus: Loading ELF /home/buildslave/src/github.com/zephyrproject-rtos/zephyr/out-3nd-pass/m2gl025_miv/tests/cmsis_rtos_v2/portability.cmsis_rtos_v2/zephyr/zephyr.elf.
03:05:35.1045 [INFO] sysbus: Loading segment of 81000 bytes length at 0x80000000.
03:05:35.1175 [DEBUG] sysbus: Segment loaded.
03:05:35.1177 [INFO] sysbus: Loading segment of 1320 bytes length at 0x80013C68.
03:05:35.1179 [DEBUG] sysbus: Segment loaded.
03:05:35.1181 [INFO] sysbus: Loading segment of 25652 bytes length at 0x80040528.
03:05:35.1185 [DEBUG] sysbus: Segment loaded.
03:05:35.2035 [INFO] cpu: Setting PC value to 0x80000000.
03:05:35.2807 [INFO] Mi-V: Machine started.
03:05:35.3666 [WARNING] plic: Unhandled write to offset 0x200000, value 0x0.
03:05:35.3786 [WARNING] uart: Unhandled write to offset 0xC. Unhandled bits: [0] when writing value 0x1. Tags: BIT8 (0x1).
03:05:35.4040 [DEBUG] uart: [+0.72s host +0.2ms virt 0.2ms virt from start] ***** Booting Zephyr OS build zephyr-v1.14.0-2776-geb53f7ee9fa3 *****
03:05:35.4067 [DEBUG] uart: [+2.68ms host +0.1ms virt 0.3ms virt from start]   Running test suite test_cmsis_v2_apis
03:05:35.4077 [DEBUG] uart: [+1ms host +0s virt 0.3ms virt from start]   ===================================================================
03:05:35.4082 [DEBUG] uart: [+0.6ms host +0s virt 0.3ms virt from start]   starting test - test_kernel_apis
03:05:35.4180 [DEBUG] uart: [+9.77ms host +0.1ms virt 0.4ms virt from start]   PASS - test_kernel_apis
03:05:35.4189 [DEBUG] uart: [+0.95ms host +0s virt 0.4ms virt from start]   ===================================================================
03:05:35.4199 [DEBUG] uart: [+0.98ms host +0.1ms virt 0.5ms virt from start]   starting test - test_delay
03:05:35.4299 [DEBUG] uart: [+9.96ms host +0.5ms virt 1ms virt from start]   PASS - test_delay
03:05:35.4331 [DEBUG] uart: [+1.56ms host +0.1ms virt 1.1ms virt from start]   ===================================================================
03:05:35.4338 [DEBUG] uart: [+2.42ms host +0s virt 1.1ms virt from start]   starting test - test_thread_apis
03:05:35.4490 [DEBUG] uart: [+15.13ms host +1.1ms virt 2.2ms virt from start]   PASS - test_thread_apis
03:05:35.4498 [DEBUG] uart: [+0.92ms host +0s virt 2.2ms virt from start]   ===================================================================
03:05:35.4508 [DEBUG] uart: [+0.97ms host +0.1ms virt 2.3ms virt from start]   starting test - test_thread_apis_dynamic
03:05:35.4579 [DEBUG] uart: [+6.98ms host +1.1ms virt 3.4ms virt from start]   PASS - test_thread_apis_dynamic
03:05:35.4592 [DEBUG] uart: [+1.41ms host +0.1ms virt 3.5ms virt from start]   ===================================================================
03:05:35.4597 [DEBUG] uart: [+0.53ms host +0s virt 3.5ms virt from start]   starting test - test_thread_prio
03:05:35.4656 [DEBUG] uart: [+5.78ms host +0.2ms virt 3.7ms virt from start]   PASS - test_thread_prio
03:05:35.4664 [DEBUG] uart: [+0.89ms host +0s virt 3.7ms virt from start]   ===================================================================
03:05:35.4675 [DEBUG] uart: [+1.06ms host +0.1ms virt 3.8ms virt from start]   starting test - test_thread_prio_dynamic
03:05:35.4701 [DEBUG] uart: [+2.58ms host +0.2ms virt 4ms virt from start]   PASS - test_thread_prio_dynamic
03:05:35.4735 [DEBUG] uart: [+3.35ms host +0s virt 4ms virt from start]   ===================================================================
03:05:35.4744 [DEBUG] uart: [+0.99ms host +0.1ms virt 4.1ms virt from start]   starting test - test_timer
03:05:35.4811 [DEBUG] uart: [+6.58ms host +1ms virt 5.1ms virt from start]   oneshot_callback (Timer 1) = 1
03:05:35.4944 [DEBUG] uart: [+13.41ms host +2.2ms virt 7.3ms virt from start]   periodic_callback (Timer 2) = 1
03:05:35.4968 [DEBUG] uart: [+2.39ms host +0.4ms virt 7.7ms virt from start]   periodic_callback (Timer 2) = 2
03:05:35.4994 [DEBUG] uart: [+2.57ms host +0.5ms virt 8.2ms virt from start]   periodic_callback (Timer 2) = 3
03:05:35.5042 [DEBUG] uart: [+4.85ms host +0.5ms virt 8.7ms virt from start]   periodic_callback (Timer 2) = 4
03:05:35.5070 [DEBUG] uart: [+2.78ms host +0.5ms virt 9.2ms virt from start]   periodic_callback (Timer 2) = 5
03:05:35.5094 [DEBUG] uart: [+2.42ms host +0.5ms virt 9.7ms virt from start]   periodic_callback (Timer 2) = 6
03:05:35.5133 [DEBUG] uart: [+3.86ms host +0.1ms virt 9.8ms virt from start]   PASS - test_timer
03:05:35.5146 [DEBUG] uart: [+1.26ms host +0.1ms virt 9.9ms virt from start]   ===================================================================
03:05:35.5149 [DEBUG] uart: [+0.4ms host +0s virt 9.9ms virt from start]   starting test - test_mutex
03:05:35.5252 [DEBUG] uart: [+10.16ms host +1.1ms virt 11ms virt from start]   PASS - test_mutex
03:05:35.5266 [DEBUG] uart: [+1.51ms host +0.1ms virt 11.1ms virt from start]   ===================================================================
03:05:35.5272 [DEBUG] uart: [+0.62ms host +0s virt 11.1ms virt from start]   starting test - test_mutex_lock_timeout
03:05:35.5354 [DEBUG] uart: [+8.17ms host +0.3ms virt 11.4ms virt from start]   PASS - test_mutex_lock_timeout
03:05:35.5368 [DEBUG] uart: [+1.32ms host +0.1ms virt 11.5ms virt from start]   ===================================================================
03:05:35.5372 [DEBUG] uart: [+0.48ms host +0s virt 11.5ms virt from start]   starting test - test_semaphore
03:05:35.5401 [DEBUG] uart: [+2.87ms host +0.1ms virt 11.6ms virt from start]   ASSERTION FAIL [thread->base.pended_on] @ ZEPHYR_BASE/kernel/sched.c:390
03:05:35.5406 [DEBUG] uart: [+0.52ms host +0s virt 11.6ms virt from start]   @ ZEPHYR_BASE/lib/os/assert.c:39:
03:05:35.5438 [DEBUG] uart: [+3.21ms host +0.1ms virt 11.7ms virt from start]   FATAL: >>> ZEPHYR FATAL ERROR 4: Kernel panic
03:05:35.5450 [DEBUG] uart: [+1.22ms host +0s virt 11.7ms virt from start]   FATAL: Current thread: 0x80040c9c (Mutex_check)
03:05:35.5453 [DEBUG] uart: [+0.38ms host +0s virt 11.7ms virt from start]   FATAL: Halting system
03:05:35.5471 [DEBUG] uart: [+1.67ms host +0.1ms virt 11.8ms virt from start]   ASSERTION FAIL [z_spin_lock_valid(l)] @ ../../../../../include/spinlock.h:78
03:05:35.5474 [DEBUG] uart: [+0.35ms host +0s virt 11.8ms virt from start]   Recursive spinlock
03:05:35.5480 [DEBUG] uart: [+0.58ms host +0s virt 11.8ms virt from start]   @ ZEPHYR_BASE/lib/os/assert.c:39:
03:05:35.5486 [DEBUG] uart: [+0.63ms host +0s virt 11.8ms virt from start]   FATAL: >>> ZEPHYR FATAL ERROR 4: Kernel panic
03:05:35.5522 [DEBUG] uart: [+3.54ms host +0.1ms virt 11.9ms virt from start]   FATAL: Current thread: 0x80040c9c (Mutex_check)
03:05:35.5526 [DEBUG] uart: [+0.37ms host +0s virt 11.9ms virt from start]   FATAL: Halting system

Nicolas Pitre added 3 commits August 1, 2019 11:32
This is the workaround suggested by Andy Ross to fix zephyrproject-rtos#17851.

Signed-off-by: Nicolas Pitre <[email protected]>
Commit  33c64c2 ("tests/cmsis_rtos_v1: Correct timing assumptions")
introduced a stricter criteria where time spent has to match the clock
within 1% discrepancy. It is zassert_true(diff < max && diff > min)
meaning _less than_ 1%.

The test uses a 1-second delay. When SYS_CLOCK_TICKS_PER_SEC=100 that
means a single tick discrepancy would overflow the test.

Let's be inclusive and allow up to 1% instead. That allows for this
test to pass on m2gl025_miv when using 100 ticks per sec.

Signed-off-by: Nicolas Pitre <[email protected]>
Commit ee4c23c ("CMSIS v2: Work around time unit confusion")
enforced CONFIG_SYS_CLOCK_TICKS_PER_SEC=1000 on this test, but the
m2gl025_miv platform has some issues with it. Let's exclude it for now.

Signed-off-by: Nicolas Pitre <[email protected]>
@npitre npitre requested a review from nashif as a code owner August 1, 2019 19:05
@zephyrbot zephyrbot added the area: Tests Issues related to a particular existing or missing test label Aug 1, 2019
@npitre
Copy link
Author

npitre commented Aug 2, 2019 via email

@andrewboie andrewboie added the Hotfix Fix for issues blocking development, i.e. upstream CI issues, tests failing in upstream CI , etc. label Aug 2, 2019
@andrewboie andrewboie requested review from carlescufi and galak August 2, 2019 00:45
@andrewboie andrewboie added the priority: high High impact/importance bug label Aug 2, 2019
@carlescufi carlescufi merged commit 7deca2e into zephyrproject-rtos:master Aug 2, 2019
@npitre npitre deleted the fix_17851 branch August 8, 2019 22:29
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

area: Boards area: Tests Issues related to a particular existing or missing test Hotfix Fix for issues blocking development, i.e. upstream CI issues, tests failing in upstream CI , etc. priority: high High impact/importance bug

Projects

None yet

Development

Successfully merging this pull request may close these issues.

riscv/m2gl025: timer tests broken

4 participants