tests/posix/common fails randomly on all platforms

[nniranjhana]

The pthread_execution test fails with an Assertion Error when trying to set or use attributes before they are initialized.

Arch: ARM, xtensa
Platforms: arduino2:arm, sam_e70_xplained:arm, frdm_k64f:arm, nrf52840_pca10056:arm, nrf52_pca10040:arm, emsk7d_v22:arc, esp32:xtensa

Error log on console:

 ***** Booting Zephyr OS 1.13.99 (delayed boot 1000ms) *****
 Running test suite posix_apis
 ===================================================================
 starting test - test_posix_pthread_execution
 
     Assertion failed at ../zephyr/tests/posix/common/src/pthread.c:253: test_posix_pthread_execution: (ret not equal to EINVAL)
 uninitialized attr set!
 FAIL - test_posix_pthread_execution
 ===================================================================
 starting test - test_posix_pthread_termination
 Thread 0 starting with a priority of 4
 Cancelling thread 0
 Thread 1 starting with a priority of 3
 Cancelling thread 1
 Thread 1 could not be cancelled
 Thread 2 starting with a priority of 2
 Cancelling thread 2
 Thread 3 starting with a priority of 1
 Cancelling thread 3
 Thread 3 could not be cancelled
 PASS - test_posix_pthread_termination
 ===================================================================
 starting test - test_posix_multiple_threads_single_key
 
 Different threads set different values to same key:
 thread 0: set value = 1073436044 and retrieved value = 1073436044
 thread 1: set value = 1073436300 and retrieved value = 1073436300
 
 PASS - test_posix_multiple_threads_single_key
 ===================================================================
 starting test - test_posix_single_thread_multiple_keys
 
 Single thread associates its value with different keys:
 key 0: set value = 1073435788 and retrieved value = 1073435788
 key 1: set value = 1073435788 and retrieved value = 1073435788
 
 PASS - test_posix_single_thread_multiple_keys
 ===================================================================
 starting test - test_posix_clock
 POSIX clock APIs
 POSIX clock APIs test done
 PASS - test_posix_clock
 ===================================================================
 starting test - test_posix_semaphore
 PASS - test_posix_semaphore
 ===================================================================
 starting test - test_posix_normal_mutex
 mutex lock is taken
 PASS - test_posix_normal_mutex
 ===================================================================
 starting test - test_posix_recursive_mutex
 recrusive mutex lock is taken
 PASS - test_posix_recursive_mutex
 ===================================================================
 starting test - test_posix_mqueue
 PASS - test_posix_mqueue
 ===================================================================
 starting test - test_posix_realtime
 POSIX clock set APIs
 POSIX clock set APIs test done
 PASS - test_posix_realtime
 ===================================================================
 starting test - test_posix_timer
 POSIX timer test
 Timer fires every 0 secs and  100000000 nsecs
 Time remaining to fire 0 secs and  890000000 nsecs
 Handler Signal value :20 for 1 times
 Handler Signal value :20 for 2 times
 Handler Signal value :20 for 3 times
 Handler Signal value :20 for 4 times
 Handler Signal value :20 for 5 times
 Handler Signal value :20 for 6 times
 Handler Signal value :20 for 7 times
 Handler Signal value :20 for 8 times
 Handler Signal value :20 for 9 times
 Handler Signal value :20 for 10 times
 Handler Signal value :20 for 11 times
 Handler Signal value :20 for 12 times
 PASS - test_posix_timer
 ===================================================================
 starting test - test_posix_rw_lock
 
 main acquire WR lock and 3 threads acquire RD lock
 Thread 2 scheduling policy = 1 & priority 3 started
 Not able to get RD lock on trying, try again
 Thread 1 scheduling policy = 1 & priority 2 started
 Not able to get RD lock on Parent thread releasing WR lock
 Thread 2 got RD lock
 trying, try again
 Thread 1 got RD lock
 Thread 0 scheduling policy = 1 & priority 1 started
 Thread 0 got RD lock
 Parent thread acquiring WR lock again
 Thread 2 releasing RD lock
 Thread 2 acquiring WR lock
 Thread 1 releasing RD lock
 Thread 1 acquiring WR lock
 Thread 0 releasing RD lock
 Parent thread acquired WR lock again
 Thread 0 acquiring WR lock
 Parent thread releasing WR lock again
 
 3 threads acquire WR lock
 Main thread acquiring RD lock
 Thread 2 acquired WR lock
 Thread 2 releasing WR lock
 Main thread acquired RD lock
 Main thread releasing RD lock
 Thread 1 acquired WR lock
 Thread 1 releasing WR lock
 Thread 0 acquired WR lock
 Thread 0 releasing WR lock
 PASS - test_posix_rw_lock
 ===================================================================
 ===================================================================

 PROJECT EXECUTION FAILED

[nniranjhana]

Reported by @aescolar from valgrind:

Randomly, the test crashes with an assert. The cause would seem to be the one detected by valgrind (see log below)

Steps to reproduce

On ae8649c

cmake ../tests/posix/common/ -DBOARD=native_posix -GNinja
ninja
valgrind zephyr/zephyr.exe

Log

***** Booting Zephyr OS v1.9.0-8074-gae8649c5ec *****
Running test suite posix_apis
===================================================================
starting test - test_posix_pthread_execution
==17094== Thread 2:
==17094== Conditional jump or move depends on uninitialised value(s)
==17094==    at 0x10D74C: zap_pthread_attr_setschedparam (pthread.c:89)
==17094==    by 0x10A97E: test_posix_pthread_execution (pthread.c:249)
==17094==    by 0x110800: run_test_functions (ztest.c:58)
==17094==    by 0x110800: test_cb (ztest.c:195)
==17094==    by 0x10C17E: _thread_entry (thread_entry.c:29)
==17094==    by 0x10CE61: posix_thread_starter (posix_core.c:301)
==17094==    by 0x495D3BC: start_thread (pthread_create.c:463)
==17094==    by 0x4A6EE15: clone (clone.S:108)
==17094== 
==17094== Conditional jump or move depends on uninitialised value(s)
==17094==    at 0x10DDE6: valid_posix_policy (pthread_sched.c:12)
==17094==    by 0x10DDE6: zap_sched_get_priority_min (pthread_sched.c:26)
==17094==    by 0x10D75E: is_posix_prio_valid (pthread.c:42)
==17094==    by 0x10D75E: zap_pthread_attr_setschedparam (pthread.c:90)
==17094==    by 0x10A97E: test_posix_pthread_execution (pthread.c:249)
==17094==    by 0x110800: run_test_functions (ztest.c:58)
==17094==    by 0x110800: test_cb (ztest.c:195)
==17094==    by 0x10C17E: _thread_entry (thread_entry.c:29)
==17094==    by 0x10CE61: posix_thread_starter (posix_core.c:301)
==17094==    by 0x495D3BC: start_thread (pthread_create.c:463)
==17094==    by 0x4A6EE15: clone (clone.S:108)
==17094== 
==17094== Conditional jump or move depends on uninitialised value(s)
==17094==    at 0x10DE07: valid_posix_policy (pthread_sched.c:12)
==17094==    by 0x10DE07: zap_sched_get_priority_max (pthread_sched.c:54)
==17094==    by 0x10D76E: is_posix_prio_valid (pthread.c:43)
==17094==    by 0x10D76E: zap_pthread_attr_setschedparam (pthread.c:90)
==17094==    by 0x10A97E: test_posix_pthread_execution (pthread.c:249)
==17094==    by 0x110800: run_test_functions (ztest.c:58)
==17094==    by 0x110800: test_cb (ztest.c:195)
==17094==    by 0x10C17E: _thread_entry (thread_entry.c:29)
==17094==    by 0x10CE61: posix_thread_starter (posix_core.c:301)
==17094==    by 0x495D3BC: start_thread (pthread_create.c:463)
==17094==    by 0x4A6EE15: clone (clone.S:108)
==17094== 

    Assertion failed at /home/alpi/aescolar-ot/tests/posix/common/src/pthread.c:250: test_posix_pthread_execution: (ret not equal to EINVAL)
uninitialized attr set!
FAIL - test_posix_pthread_execution
[...]

[aescolar]

How is fixing this one going? It is quite disruptive to have this test failing in CI at random so often as it does..

[pfalcon]

So, if it's random, them I'm updating the title. (Because I also have regular systematic failures on trying to refactor code - mostly due to fragile includes.)

[nashif]

this is coming from 11775b2, @nniranjhana this is a commit from you.

[nniranjhana]

Hi, yes in my commit, I had introduced negative tests which try to set or use attributes before they are initialized (they shouldn't be ideally), but since they are, the test is failing. So is testing this way wrong for some reason and I should remove these tests, or should I be looking into the implementation to fix this bug?

[nniranjhana]

@aescolar This does not seem to fail on all platforms, rather only platforms with ARM architecture and emsk (ARC) and esp32 (xtensa).
The failure seems consistent, not really random either.
I am not sure why the negative test should cause this issue, ideally we should not be able to use attributes before initializing them, but somehow this is not the case for the above mentioned platforms. Any idea?

@nashif What should be done in this case? Should I remove these tests, since a lot of PRs seem to have shippable failing because of this, or do I arch_exclude ARM until the implementation bug is resolved?

[aescolar]

rather only platforms with ARM

@nniranjhana This fails also on POSIX as shown above #10508 (comment)
And will fail in any platform when that area of the stack happens to not be zeroed'* during execution of that test.
'* or some data values which will lead to pthread_attr_setschedparam() not returning EINVAL.
Given that, in general, the content of a non initialized section of the stack should be assumed unknown (to contain any garbage values), you can also assume the test will fail at random, depending on that unknown content.

The trivial solution is to initialize attr to 0 in test_posix_pthread_execution()