D02: assertion '!have_spinlock()'

[jforissier]

I get assertion failures with af8149d on D02 Aarch32. CFG_TEE_CORE_LOG_LEVEL=2. Not reproducible with -O0, always fail on !have_spinlock() but with various stack traces.

root@deb-est:~# xtest 1005
Test ID: 1005
E/TC:00 have_spinlock:41 locked_count=5a5a5a5a
E/TC:00 assertion '!have_spinlock()' failed at core/arch/arm/include/kernel/spinlock.h:25 <assert_have_no_spinlock>
E/TC:00 Panic at core/kernel/assert.c:28 <_assert_break>
E/TC:00 Call stack:
E/TC:00  0x50405949 print_kernel_stack at optee_os/core/arch/arm/kernel/unwind_arm32.c:465
E/TC:00  0x5040b649 __do_panic at optee_os/core/kernel/panic.c:30
E/TC:00  0x5040ad13 _assert_break at optee_os/core/kernel/assert.c:28
E/TC:00  0x50403823 thread_set_exceptions at optee_os/core/arch/arm/kernel/thread.c:235
E/TC:00  0x50409223 tee_entry_std at optee_os/core/arch/arm/tee/entry_std.c:536
E/TC:00  0x504045a7 __thread_std_smc_entry at optee_os/core/arch/arm/kernel/thread.c:591
E/TC:00  0x504034c0 thread_std_smc_entry at optee_os/core/arch/arm/kernel/thread_a32.S:361

Looks like memory corruption, judging by the value of locked_count in have_spinlock().

diff --git a/core/arch/arm/kernel/spin_lock_debug.c b/core/arch/arm/kernel/spin_lock_debug.c
index f76729a9..1b87b0af 100644
--- a/core/arch/arm/kernel/spin_lock_debug.c
+++ b/core/arch/arm/kernel/spin_lock_debug.c
@@ -37,6 +37,8 @@ bool have_spinlock(void)
        }
 
        l = thread_get_core_local();
+       if (l->locked_count)
+               EMSG("locked_count=%x", l->locked_count);
 
        return !!l->locked_count;
 }

[lorc]

Looks like a protective pattern after free(). I think this issue is related to #2414

[jenswi-linaro]

%grep 5a5a5a5a **/*.c
core/lib/libtomcrypt/src/ciphers/aes_tab.c:    0x1b1b1b1bUL, 0x6e6e6e6eUL, 0x5a5a5a5aUL, 0xa0a0a0a0UL,
core/lib/libtomcrypt/src/ciphers/aes_tab.c:    0x78787878UL, 0xcdcdcdcdUL, 0x5a5a5a5aUL, 0xf4f4f4f4UL,

Strange coincidence

[jenswi-linaro]

Agree with the relation to #2414

[jforissier]

@jenswi-linaro not the AES stuff apparently, I've changed the values in the static tables and the lock count is still overwritten by the same 5a5a5a5a pattern. In fact the tables are not used because CFG_CRYPTO_WITH_CE=y.

[jforissier]

Weird. I can reproduce the crash only if CPU#3 or CPU#11 are enabled (D02 has a total of 16 Cortex-A57 cores). With any of them enabled, xtest 1005 asserts. With both disabled (echo 0 >/sys/devices/system/cpu/cpu$i/online), the test runs fine.

[lorc]

I'm not quite remember... Does xtest 1005 issue parallel calls?

[jforissier]

Re-opening because #2440 is not a fix for this.

[github-actions]

This issue has been marked as a stale issue because it has been open (more than) 30 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 5 days. Note, that you can always re-open a closed issue at any time.