search

zephyrproject-rtos / zephyr

Primary Git Repository for the Zephyr Project. Zephyr is a new generation, scalable, optimized, secure RTOS for multiple hardware architectures.
https://docs.zephyrproject.org
Apache License 2.0
10.82k stars 6.59k forks source link

up_squared: tests/lib/c_lib/thrd - slow execution #69608

Closed mdubielx closed 4 months ago

mdubielx commented 8 months ago

list of failing c_lib tests:

tests/lib/c_lib/thrd/libraries.libc.c11_threads.minimal 
tests/lib/c_lib/thrd/libraries.libc.c11_threads.picolibc 
tests/lib/c_lib/thrd/libraries.libc.c11_threads.picolibc.module
tests/lib/c_lib/thrd/libraries.libc.c11_threads.picolibc.notls 
tests/lib/c_lib/thrd/libraries.libc.c11_threads.newlib 
tests/lib/c_lib/thrd/libraries.libc.c11_threads.newlib_nano

To Reproduce twister --device-testing --hardware-map up2.map -T tests/lib/c_lib/thrd/ -vv

Logs and console output
too many tests fail, here is an example output:
Thu, 29 Feb 2024 04:46:10 GMT
Downloading NBP file...
Thu, 29 Feb 2024 04:46:10 GMT
Succeed to download NBP file.
Thu, 29 Feb 2024 04:46:10 GMT
*** Zephyr EFI Loader ***
Thu, 29 Feb 2024 04:46:10 GMT
RSDP found at 0x79c39000
Thu, 29 Feb 2024 04:46:10 GMT
Zeroing 12292096 bytes of memory at 0x140000
Thu, 29 Feb 2024 04:46:10 GMT
Zeroing 960 bytes of memory at 0xf1fc40
Thu, 29 Feb 2024 04:46:10 GMT
Copying 32768 data bytes to 0x1000 from image offset 
Thu, 29 Feb 2024 04:46:10 GMT
Copying 262144 data bytes to 0x100000 from image offset 32768
Thu, 29 Feb 2024 04:46:10 GMT
Copying 2255936 data bytes to 0xcf9000 from image offset 294912
Thu, 29 Feb 2024 04:46:10 GMT
Jumping to Entry Point: 0x1137 (48 31 c0 48 31 d2 48)
Thu, 29 Feb 2024 04:46:10 GMT
***** delaying boot 500ms (per build configuration) *****
Thu, 29 Feb 2024 04:46:10 GMT
*** Booting Zephyr OS build v3.6.0-250-gbb27f0578b56 (delayed boot 500ms) ***
Thu, 29 Feb 2024 04:46:10 GMT
Running TESTSUITE libc_cnd
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_cnd_broadcast_wait
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_cnd_broadcast_wait in 0.101 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_cnd_errors
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_cnd_errors in 0.001 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_cnd_init_destroy
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_cnd_init_destroy in 0.001 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_cnd_signal_timedwait
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_cnd_signal_timedwait in 0.051 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_cnd_signal_wait
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_cnd_signal_wait in 0.051 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_cnd_timedwait_timeout
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_cnd_timedwait_timeout in 0.201 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
TESTSUITE libc_cnd succeeded
Thu, 29 Feb 2024 04:46:10 GMT
Running TESTSUITE libc_mtx
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_mtx_destroy
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_mtx_destroy in 0.001 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_mtx_init
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_mtx_init in 0.001 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_mtx_lock
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_mtx_lock in 0.001 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_mtx_timedlock
Thu, 29 Feb 2024 04:46:10 GMT
Expecting timedlock with timeout of 200 ms to fail
Thu, 29 Feb 2024 04:46:10 GMT
Expecting timedlock with timeout of 200 ms to succeed after 100ms
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_mtx_timedlock in 0.312 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_mtx_trylock
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_mtx_trylock in 0.001 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_mtx_unlock
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_mtx_unlock in 0.001 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
TESTSUITE libc_mtx succeeded
Thu, 29 Feb 2024 04:46:10 GMT
Running TESTSUITE libc_once
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_call_once
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_call_once in 0.001 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
TESTSUITE libc_once succeeded
Thu, 29 Feb 2024 04:46:10 GMT
Running TESTSUITE libc_thrd
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_thrd_create_join
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_thrd_create_join in 0.001 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_thrd_current_equal
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_thrd_current_equal in 0.001 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_thrd_detach
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_thrd_detach in 0.101 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_thrd_exit
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_thrd_exit in 0.001 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_thrd_reuse
Thu, 29 Feb 2024 04:46:10 GMT
PASS - test_thrd_reuse in 0.002 seconds
Thu, 29 Feb 2024 04:46:10 GMT
===================================================================
Thu, 29 Feb 2024 04:46:10 GMT
START - test_thrd_sleep
Thu, 29 Feb 2024 04:46:10 GMT
sleeping 0 ms
Thu, 29 Feb 2024 04:46:10 GMT
sleeping 100 ms
Thu, 29 Feb 2024 04:46:10 GMT

Environment:

OS: Linux Toolchain: zephyr-sdk-0.16.5 v3.6.0-250-gbb27f0578b56

github-actions[bot] commented 8 months ago

Hi @mdubielx! We appreciate you submitting your first issue for our open-source project. 🌟

Even though I'm a bot, I can assure you that the whole community is genuinely grateful for your time and effort. 🤖💙

najumon1980 commented 8 months ago

Could you please verify with following PR: https://github.com/zephyrproject-rtos/zephyr/pull/69705

KamilxPaszkiet commented 7 months ago

Could you please verify with following PR: #69705

I checked your PR. Unfortunately we still have a timeout. I run tests together with timestamps and you can see that the "sleeping xxx ms" stage lasts a very long time. Maybe this will make debugging easier.

2024-03-13 09:21:23,413 - DEBUG - DEVICE: *** Booting Zephyr OS build v3.6.0-676-gaa87ed5d8a71 ***
2024-03-13 09:21:23,425 - DEBUG - DEVICE: Running TESTSUITE libc_cnd
2024-03-13 09:21:23,432 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:23,435 - DEBUG - DEVICE: START - test_cnd_broadcast_wait
2024-03-13 09:21:23,540 - DEBUG - DEVICE: PASS - test_cnd_broadcast_wait in 0.101 seconds
2024-03-13 09:21:23,547 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:23,549 - DEBUG - DEVICE: START - test_cnd_errors
2024-03-13 09:21:23,553 - DEBUG - DEVICE: PASS - test_cnd_errors in 0.001 seconds
2024-03-13 09:21:23,560 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:23,563 - DEBUG - DEVICE: START - test_cnd_init_destroy
2024-03-13 09:21:23,568 - DEBUG - DEVICE: PASS - test_cnd_init_destroy in 0.001 seconds
2024-03-13 09:21:23,575 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:23,578 - DEBUG - DEVICE: START - test_cnd_signal_timedwait
2024-03-13 09:21:23,633 - DEBUG - DEVICE: PASS - test_cnd_signal_timedwait in 0.051 seconds
2024-03-13 09:21:23,640 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:23,643 - DEBUG - DEVICE: START - test_cnd_signal_wait
2024-03-13 09:21:23,697 - DEBUG - DEVICE: PASS - test_cnd_signal_wait in 0.051 seconds
2024-03-13 09:21:23,704 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:23,708 - DEBUG - DEVICE: START - test_cnd_timedwait_timeout
2024-03-13 09:21:23,913 - DEBUG - DEVICE: PASS - test_cnd_timedwait_timeout in 0.201 seconds2024-03-13 09:21:23,920 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:23,923 - DEBUG - DEVICE: TESTSUITE libc_cnd succeeded
2024-03-13 09:21:23,925 - DEBUG - DEVICE: Running TESTSUITE libc_mtx
2024-03-13 09:21:23,932 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:23,934 - DEBUG - DEVICE: START - test_mtx_destroy
2024-03-13 09:21:23,939 - DEBUG - DEVICE: PASS - test_mtx_destroy in 0.001 seconds
2024-03-13 09:21:23,945 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:23,948 - DEBUG - DEVICE: START - test_mtx_init
2024-03-13 09:21:23,952 - DEBUG - DEVICE: PASS - test_mtx_init in 0.001 seconds
2024-03-13 09:21:23,958 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:23,960 - DEBUG - DEVICE: START - test_mtx_lock
2024-03-13 09:21:23,964 - DEBUG - DEVICE: PASS - test_mtx_lock in 0.001 seconds
2024-03-13 09:21:23,971 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:23,974 - DEBUG - DEVICE: START - test_mtx_timedlock
2024-03-13 09:21:23,979 - DEBUG - DEVICE: Expecting timedlock with timeout of 200 ms to fail2024-03-13 09:21:24,184 - DEBUG - DEVICE: Expecting timedlock with timeout of 200 ms to succeed after 100ms
2024-03-13 09:21:24,289 - DEBUG - DEVICE: PASS - test_mtx_timedlock in 0.311 seconds
2024-03-13 09:21:24,296 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:24,298 - DEBUG - DEVICE: START - test_mtx_trylock
2024-03-13 09:21:24,302 - DEBUG - DEVICE: PASS - test_mtx_trylock in 0.001 seconds
2024-03-13 09:21:24,309 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:24,311 - DEBUG - DEVICE: START - test_mtx_unlock
2024-03-13 09:21:24,316 - DEBUG - DEVICE: PASS - test_mtx_unlock in 0.001 seconds
2024-03-13 09:21:24,322 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:24,325 - DEBUG - DEVICE: TESTSUITE libc_mtx succeeded
2024-03-13 09:21:24,328 - DEBUG - DEVICE: Running TESTSUITE libc_once
2024-03-13 09:21:24,335 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:24,337 - DEBUG - DEVICE: START - test_call_once
2024-03-13 09:21:24,341 - DEBUG - DEVICE: PASS - test_call_once in 0.001 seconds
2024-03-13 09:21:24,348 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:24,351 - DEBUG - DEVICE: TESTSUITE libc_once succeeded
2024-03-13 09:21:24,354 - DEBUG - DEVICE: Running TESTSUITE libc_thrd
2024-03-13 09:21:24,360 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:24,363 - DEBUG - DEVICE: START - test_thrd_create_join
2024-03-13 09:21:24,368 - DEBUG - DEVICE: PASS - test_thrd_create_join in 0.001 seconds
2024-03-13 09:21:24,375 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:24,378 - DEBUG - DEVICE: START - test_thrd_current_equal
2024-03-13 09:21:24,383 - DEBUG - DEVICE: PASS - test_thrd_current_equal in 0.001 seconds
2024-03-13 09:21:24,390 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:24,392 - DEBUG - DEVICE: START - test_thrd_detach
2024-03-13 09:21:24,496 - DEBUG - DEVICE: PASS - test_thrd_detach in 0.101 seconds
2024-03-13 09:21:24,503 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:24,505 - DEBUG - DEVICE: START - test_thrd_exit
2024-03-13 09:21:24,509 - DEBUG - DEVICE: PASS - test_thrd_exit in 0.001 seconds
2024-03-13 09:21:24,516 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:24,518 - DEBUG - DEVICE: START - test_thrd_reuse
2024-03-13 09:21:24,525 - DEBUG - DEVICE: PASS - test_thrd_reuse in 0.003 seconds
2024-03-13 09:21:24,531 - DEBUG - DEVICE: ===================================================================
2024-03-13 09:21:24,534 - DEBUG - DEVICE: START - test_thrd_sleep
2024-03-13 09:21:24,535 - DEBUG - DEVICE: sleeping 0 ms
2024-03-13 09:21:24,537 - DEBUG - DEVICE: sleeping 100 ms
2024-03-13 09:21:40,371 - DEBUG - DEVICE: sleeping 200 ms
2024-03-13 09:21:56,304 - DEBUG - DEVICE: sleeping 400 ms
2024-03-13 09:22:00,878 - DEBUG - Timed out while monitoring serial output on up_square
github-actions[bot] commented 5 months ago

This issue has been marked as stale because it has been open (more than) 60 days with no activity. Remove the stale label or add a comment saying that you would like to have the label removed otherwise this issue will automatically be closed in 14 days. Note, that you can always re-open a closed issue at any time.

KamilxPaszkiet commented 5 months ago

Issue still reproduce

golowanow commented 5 months ago

An update after investigations on the same hw lab setup:

The tests were initially reported as failed running with default Twister timeout of 60 sec.

Extending the timeout e.g. to 120 sec. allows them to pass, so the question: is it normal behavior or a performance issue for this platform ?

DEBUG - DEVICE: *** Booting Zephyr OS build v3.6.0-5550-gedd0ed733969 (delayed boot 500ms) ***
...
INFO    - 13/18 up_squared                tests/lib/c_lib/thrd/libraries.libc.c11_threads.newlib_nano PASSED (device: up2, 101.273s)
INFO    - 14/18 up_squared                tests/lib/c_lib/thrd/libraries.libc.c11_threads.newlib PASSED (device: up2, 101.320s)
INFO    - 15/18 up_squared                tests/lib/c_lib/thrd/libraries.libc.c11_threads.picolibc.notls PASSED (device: up2, 101.339s)
INFO    - 16/18 up_squared                tests/lib/c_lib/thrd/libraries.libc.c11_threads.picolibc.module PASSED (device: up2, 101.301s)
INFO    - 17/18 up_squared                tests/lib/c_lib/thrd/libraries.libc.c11_threads.picolibc PASSED (device: up2, 101.445s)
INFO    - 18/18 up_squared                tests/lib/c_lib/thrd/libraries.libc.c11_threads.minimal PASSED (device: up2, 101.528s)

NOTE: Each test's time includes its flash operation which takes about 35 sec. from the total ~101 sec.

Most of the test time is at test_thrd_sleep (>60 seconds)

An example test log with timestamps:

2024-06-07 06:46:38,120 - twister - DEBUG - Flash command:
...
2024-06-07 06:47:14,043 - twister - DEBUG - DEVICE: *** Booting Zephyr OS build v3.6.0-5550-gedd0ed733969 (delayed boot 500ms) ***
2024-06-07 06:47:14,043 - twister - DEBUG - DEVICE: Running TESTSUITE libc_cnd
2024-06-07 06:47:14,043 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,044 - twister - DEBUG - DEVICE: START - test_cnd_broadcast_wait
2024-06-07 06:47:14,190 - twister - DEBUG - DEVICE: PASS - test_cnd_broadcast_wait in 0.101 seconds
2024-06-07 06:47:14,191 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,191 - twister - DEBUG - DEVICE: START - test_cnd_errors
2024-06-07 06:47:14,191 - twister - DEBUG - DEVICE: PASS - test_cnd_errors in 0.001 seconds
2024-06-07 06:47:14,191 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,192 - twister - DEBUG - DEVICE: START - test_cnd_init_destroy
2024-06-07 06:47:14,192 - twister - DEBUG - DEVICE: PASS - test_cnd_init_destroy in 0.001 seconds
2024-06-07 06:47:14,192 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,193 - twister - DEBUG - DEVICE: START - test_cnd_signal_timedwait
2024-06-07 06:47:14,253 - twister - DEBUG - DEVICE: PASS - test_cnd_signal_timedwait in 0.051 seconds
2024-06-07 06:47:14,253 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,253 - twister - DEBUG - DEVICE: START - test_cnd_signal_wait
2024-06-07 06:47:14,317 - twister - DEBUG - DEVICE: PASS - test_cnd_signal_wait in 0.051 seconds
2024-06-07 06:47:14,317 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,317 - twister - DEBUG - DEVICE: START - test_cnd_timedwait_timeout
2024-06-07 06:47:14,557 - twister - DEBUG - DEVICE: PASS - test_cnd_timedwait_timeout in 0.201 seconds
2024-06-07 06:47:14,557 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,558 - twister - DEBUG - DEVICE: TESTSUITE libc_cnd succeeded
2024-06-07 06:47:14,558 - twister - DEBUG - DEVICE: Running TESTSUITE libc_mtx
2024-06-07 06:47:14,558 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,558 - twister - DEBUG - DEVICE: START - test_mtx_destroy
2024-06-07 06:47:14,559 - twister - DEBUG - DEVICE: PASS - test_mtx_destroy in 0.001 seconds
2024-06-07 06:47:14,559 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,559 - twister - DEBUG - DEVICE: START - test_mtx_init
2024-06-07 06:47:14,559 - twister - DEBUG - DEVICE: PASS - test_mtx_init in 0.001 seconds
2024-06-07 06:47:14,560 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,560 - twister - DEBUG - DEVICE: START - test_mtx_lock
2024-06-07 06:47:14,585 - twister - DEBUG - DEVICE: PASS - test_mtx_lock in 0.001 seconds
2024-06-07 06:47:14,585 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,586 - twister - DEBUG - DEVICE: START - test_mtx_timedlock
2024-06-07 06:47:14,586 - twister - DEBUG - DEVICE: Expecting timedlock with timeout of 200 ms to fail
2024-06-07 06:47:14,793 - twister - DEBUG - DEVICE: Expecting timedlock with timeout of 200 ms to succeed after 100ms
2024-06-07 06:47:14,930 - twister - DEBUG - DEVICE: PASS - test_mtx_timedlock in 0.312 seconds
2024-06-07 06:47:14,930 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,930 - twister - DEBUG - DEVICE: START - test_mtx_trylock
2024-06-07 06:47:14,931 - twister - DEBUG - DEVICE: PASS - test_mtx_trylock in 0.001 seconds
2024-06-07 06:47:14,931 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,931 - twister - DEBUG - DEVICE: START - test_mtx_unlock
2024-06-07 06:47:14,932 - twister - DEBUG - DEVICE: PASS - test_mtx_unlock in 0.001 seconds
2024-06-07 06:47:14,932 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,932 - twister - DEBUG - DEVICE: TESTSUITE libc_mtx succeeded
2024-06-07 06:47:14,932 - twister - DEBUG - DEVICE: Running TESTSUITE libc_once
2024-06-07 06:47:14,978 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,978 - twister - DEBUG - DEVICE: START - test_call_once
2024-06-07 06:47:14,978 - twister - DEBUG - DEVICE: PASS - test_call_once in 0.001 seconds
2024-06-07 06:47:14,979 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,979 - twister - DEBUG - DEVICE: TESTSUITE libc_once succeeded
2024-06-07 06:47:14,979 - twister - DEBUG - DEVICE: Running TESTSUITE libc_thrd
2024-06-07 06:47:14,980 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,980 - twister - DEBUG - DEVICE: START - test_thrd_create_join
2024-06-07 06:47:14,980 - twister - DEBUG - DEVICE: PASS - test_thrd_create_join in 0.001 seconds
2024-06-07 06:47:14,981 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:14,981 - twister - DEBUG - DEVICE: START - test_thrd_current_equal
2024-06-07 06:47:14,999 - twister - DEBUG - DEVICE: PASS - test_thrd_current_equal in 0.001 seconds
2024-06-07 06:47:15,000 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:15,000 - twister - DEBUG - DEVICE: START - test_thrd_detach
2024-06-07 06:47:15,151 - twister - DEBUG - DEVICE: PASS - test_thrd_detach in 0.101 seconds
2024-06-07 06:47:15,151 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:15,151 - twister - DEBUG - DEVICE: START - test_thrd_exit
2024-06-07 06:47:15,152 - twister - DEBUG - DEVICE: PASS - test_thrd_exit in 0.001 seconds
2024-06-07 06:47:15,152 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:15,152 - twister - DEBUG - DEVICE: START - test_thrd_reuse
2024-06-07 06:47:15,153 - twister - DEBUG - DEVICE: PASS - test_thrd_reuse in 0.003 seconds
2024-06-07 06:47:15,153 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:47:15,153 - twister - DEBUG - DEVICE: START - test_thrd_sleep
2024-06-07 06:47:15,153 - twister - DEBUG - DEVICE: sleeping 0 ms
2024-06-07 06:47:15,153 - twister - DEBUG - DEVICE: sleeping 100 ms
2024-06-07 06:47:36,184 - twister - DEBUG - DEVICE: sleeping 200 ms
2024-06-07 06:47:57,314 - twister - DEBUG - DEVICE: sleeping 400 ms
2024-06-07 06:48:18,693 - twister - DEBUG - DEVICE: PASS - test_thrd_sleep in 63.517 seconds
2024-06-07 06:48:18,693 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:48:18,694 - twister - DEBUG - DEVICE: START - test_thrd_yield
2024-06-07 06:48:18,694 - twister - DEBUG - DEVICE: PASS - test_thrd_yield in 0.001 seconds
2024-06-07 06:48:18,694 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:48:18,695 - twister - DEBUG - DEVICE: TESTSUITE libc_thrd succeeded
2024-06-07 06:48:18,695 - twister - DEBUG - DEVICE: Running TESTSUITE libc_tss
2024-06-07 06:48:18,695 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:48:18,695 - twister - DEBUG - DEVICE: START - test_tss_create_delete
2024-06-07 06:48:18,696 - twister - DEBUG - DEVICE: PASS - test_tss_create_delete in 0.001 seconds
2024-06-07 06:48:18,740 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:48:18,740 - twister - DEBUG - DEVICE: START - test_tss_get_set
2024-06-07 06:48:18,740 - twister - DEBUG - DEVICE: PASS - test_tss_get_set in 0.001 seconds
2024-06-07 06:48:18,741 - twister - DEBUG - DEVICE: ===================================================================
2024-06-07 06:48:18,741 - twister - DEBUG - DEVICE: TESTSUITE libc_tss succeeded
2024-06-07 06:48:18,741 - twister - DEBUG - DEVICE: 
2024-06-07 06:48:18,741 - twister - DEBUG - DEVICE: ------ TESTSUITE SUMMARY START ------
2024-06-07 06:48:18,741 - twister - DEBUG - DEVICE: 
2024-06-07 06:48:18,742 - twister - DEBUG - DEVICE: SUITE PASS - 100.00% [libc_cnd]: pass = 6, fail = 0, skip = 0, total = 6 duration = 0.406 seconds
2024-06-07 06:48:18,742 - twister - DEBUG - DEVICE: - PASS - [libc_cnd.test_cnd_broadcast_wait] duration = 0.101 seconds
2024-06-07 06:48:18,743 - twister - DEBUG - DEVICE: - PASS - [libc_cnd.test_cnd_errors] duration = 0.001 seconds
2024-06-07 06:48:18,788 - twister - DEBUG - DEVICE: - PASS - [libc_cnd.test_cnd_init_destroy] duration = 0.001 seconds
2024-06-07 06:48:18,789 - twister - DEBUG - DEVICE: - PASS - [libc_cnd.test_cnd_signal_timedwait] duration = 0.051 seconds
2024-06-07 06:48:18,789 - twister - DEBUG - DEVICE: - PASS - [libc_cnd.test_cnd_signal_wait] duration = 0.051 seconds
2024-06-07 06:48:18,789 - twister - DEBUG - DEVICE: - PASS - [libc_cnd.test_cnd_timedwait_timeout] duration = 0.201 seconds
2024-06-07 06:48:18,790 - twister - DEBUG - DEVICE: 
2024-06-07 06:48:18,790 - twister - DEBUG - DEVICE: SUITE PASS - 100.00% [libc_mtx]: pass = 6, fail = 0, skip = 0, total = 6 duration = 0.317 seconds
2024-06-07 06:48:18,790 - twister - DEBUG - DEVICE: - PASS - [libc_mtx.test_mtx_destroy] duration = 0.001 seconds
2024-06-07 06:48:18,791 - twister - DEBUG - DEVICE: - PASS - [libc_mtx.test_mtx_init] duration = 0.001 seconds
2024-06-07 06:48:18,836 - twister - DEBUG - DEVICE: - PASS - [libc_mtx.test_mtx_lock] duration = 0.001 seconds
2024-06-07 06:48:18,837 - twister - DEBUG - DEVICE: - PASS - [libc_mtx.test_mtx_timedlock] duration = 0.312 seconds
2024-06-07 06:48:18,837 - twister - DEBUG - DEVICE: - PASS - [libc_mtx.test_mtx_trylock] duration = 0.001 seconds
2024-06-07 06:48:18,838 - twister - DEBUG - DEVICE: - PASS - [libc_mtx.test_mtx_unlock] duration = 0.001 seconds
2024-06-07 06:48:18,838 - twister - DEBUG - DEVICE: 
2024-06-07 06:48:18,838 - twister - DEBUG - DEVICE: SUITE PASS - 100.00% [libc_once]: pass = 1, fail = 0, skip = 0, total = 1 duration = 0.001 seconds
2024-06-07 06:48:18,839 - twister - DEBUG - DEVICE: - PASS - [libc_once.test_call_once] duration = 0.001 seconds
2024-06-07 06:48:18,839 - twister - DEBUG - DEVICE: 
2024-06-07 06:48:18,884 - twister - DEBUG - DEVICE: SUITE PASS - 100.00% [libc_thrd]: pass = 7, fail = 0, skip = 0, total = 7 duration = 63.625 seconds
2024-06-07 06:48:18,885 - twister - DEBUG - DEVICE: - PASS - [libc_thrd.test_thrd_create_join] duration = 0.001 seconds
2024-06-07 06:48:18,885 - twister - DEBUG - DEVICE: - PASS - [libc_thrd.test_thrd_current_equal] duration = 0.001 seconds
2024-06-07 06:48:18,886 - twister - DEBUG - DEVICE: - PASS - [libc_thrd.test_thrd_detach] duration = 0.101 seconds
2024-06-07 06:48:18,886 - twister - DEBUG - DEVICE: - PASS - [libc_thrd.test_thrd_exit] duration = 0.001 seconds
2024-06-07 06:48:18,886 - twister - DEBUG - DEVICE: - PASS - [libc_thrd.test_thrd_reuse] duration = 0.003 seconds
2024-06-07 06:48:18,887 - twister - DEBUG - DEVICE: - PASS - [libc_thrd.test_thrd_sleep] duration = 63.517 seconds
2024-06-07 06:48:18,887 - twister - DEBUG - DEVICE: - PASS - [libc_thrd.test_thrd_yield] duration = 0.001 seconds
2024-06-07 06:48:18,887 - twister - DEBUG - DEVICE: 
2024-06-07 06:48:18,937 - twister - DEBUG - DEVICE: SUITE PASS - 100.00% [libc_tss]: pass = 2, fail = 0, skip = 0, total = 2 duration = 0.002 seconds
2024-06-07 06:48:18,937 - twister - DEBUG - DEVICE: - PASS - [libc_tss.test_tss_create_delete] duration = 0.001 seconds
2024-06-07 06:48:18,937 - twister - DEBUG - DEVICE: - PASS - [libc_tss.test_tss_get_set] duration = 0.001 seconds
2024-06-07 06:48:18,938 - twister - DEBUG - DEVICE: 
2024-06-07 06:48:18,938 - twister - DEBUG - DEVICE: ------ TESTSUITE SUMMARY END ------
===================================================================
2024-06-07 06:48:18,939 - twister - DEBUG - DEVICE: RunID: d247154e4e9cbac6e012f96a0726b762
2024-06-07 06:48:18,939 - twister - DEBUG - DEVICE: PROJECT EXECUTION SUCCESSFUL
2024-06-07 06:48:19,440 - twister - DEBUG - run status: up_squared/tests/lib/c_lib/thrd/libraries.libc.c11_threads.newlib passed
2024-06-07 06:48:19,442 - twister - INFO - 14/18 up_squared                tests/lib/c_lib/thrd/libraries.libc.c11_threads.newlib 
 PASSED (device: up2, 101.320s)