spinlock: already released

[jessicah]

PANIC: release_spinlock: lock 0xffffffff82181dc0 was already released

Welcome to Kernel Debugging Land...
Thread 17361 "sh" running on CPU 3
stack trace for thread 17361 "sh"
    kernel stack: 0xffffffff8045a000 to 0xffffffff8045f000
      user stack: 0x00007f9fb85e6000 to 0x00007f9fb95e6000
frame                       caller             <image>:function + offset
 0 ffffffff8045e828 (+  24) ffffffff8014658c   <kernel_x86_64> arch_debug_call_with_fault_handler + 0x16
 1 ffffffff8045e840 (+  80) ffffffff800af958   <kernel_x86_64> debug_call_with_fault_handler + 0x78
 2 ffffffff8045e890 (+  96) ffffffff800b0fc3   <kernel_x86_64> kernel_debugger_loop(char const*, char const*, __va_list_tag*, int) + 0xf3
 3 ffffffff8045e8f0 (+  80) ffffffff800b135e   <kernel_x86_64> kernel_debugger_internal(char const*, char const*, __va_list_tag*, int) + 0x6e
 4 ffffffff8045e940 (+ 240) ffffffff800b16b7   <kernel_x86_64> panic + 0xb7
 5 ffffffff8045ea30 (+  64) ffffffff8005853c   <kernel_x86_64> ConditionVariable::_Notify(bool, int) + 0x4c
 6 ffffffff8045ea70 (+  64) ffffffff80060bbe   <kernel_x86_64> notify_loading_app(int, bool) + 0x7e
 7 ffffffff8045eab0 (+1136) ffffffff80061d4c   <kernel_x86_64> _user_image_relocated + 0x6c
 8 ffffffff8045ef20 (+  16) ffffffff8014807f   <kernel_x86_64> x86_64_syscall_entry + 0xfb
user iframe at 0xffffffff8045ef30 (end = 0xffffffff8045eff8)
 rax 0x5e                  rbx 0x8                   rcx 0x15c914596a1
 rdx 0x15c9145ba00         rsi 0x2e8998              rdi 0x4f93b
 rbp 0x7f9fb95e53c0         r8 0x0                    r9 0x61677e7aa0
 r10 0x15c914602a4         r11 0x202                 r12 0x339def5010
 r13 0x8                   r14 0x339def5010          r15 0x7f9fb95e5370
 rip 0x15c914596a1         rsp 0x7f9fb95e5348     rflags 0x202
 vector: 0x63, error code: 0x0
 9 ffffffff8045ef30 (+140326129394832) 0000015c914596a1   </boot/system/runtime_loader@0x0000015c91446000> <unknown> + 0x136a1
10 00007f9fb95e53c0 (+ 144) 0000015c9144e6b8   </boot/system/runtime_loader@0x0000015c91446000> <unknown> + 0x86b8
11 00007f9fb95e5450 (+  48) 0000015c91455ad3   </boot/system/runtime_loader@0x0000015c91446000> <unknown> + 0xfad3
12 00007f9fb95e5480 (+   0) 00007f8b45bef258   <commpage> commpage_thread_exit + 0x00

Info:

kernel build: Apr  4 2023 16:01:41 (gcc11 11.2.0), debug level 2
revision: hrev56861+23+dirty

cpu count: 4
  [1] active time: 1011640836, interrupt time:   63259112, irq time:    8649041
  [2] active time: 1047747605, interrupt time:   59357059, irq time:    1512024
  [3] active time: 1015245578, interrupt time:   53642851, irq time:       2753
  [4] active time: 1047966973, interrupt time:   80990409, irq time:   22425808
pages:		601083 (3141394 max)
sems:		1059 (65536 max)
ports:		147 (4096 max)
threads:	140 (4096 max)
teams:		27 (2048 max)

Thread:

THREAD: 0xffffffffa5061dc0
id:                 17361 (0x43d1)
serial_number:      17361
name:               "sh"
hash_next:          0xffffffff82f89840
team_next:          0x0000000000000000
priority:           10 (I/O: -1)
state:              running
cpu:                0xffffffff801bc880 (3)
sig_pending:        0x8000000000000000 (blocked: 0x0, before sigsuspend(): 0x0)
in_kernel:          1
fault_handler:      0x0000000000000000
team:               0xffffffffc0d53210, "sh"
  exit.sem:         71450
  exit.status:      0x0 (No error)
  exit.waiters:
kernel_stack_area:  1153208
kernel_stack_base:  0xffffffff8045a000
user_stack_area:    1153209
user_stack_base:    0x00007f9fb85e6000
user_local_storage: 0x00007f9fb95e6000
user_thread:        0x00007ffe0ee4f000
kernel_errno:       0x0 (No error)
kernel_time:        8769
user_time:          6728
flags:              0x101
architecture dependant section:
	rsp: 0xffffffff8045e658
	syscall_rsp: 0xffffffff8045f000
	user_rsp: 0x00007f9fb95e5348
	fpu_state at 0xffffffffa5062100
scheduler data:
	priority_penalty:	4
	additional_penalty:	2 (40130)
	effective_priority:	4
	time_used:		0 us (quantum: 1666 us)
	stolen_time:		0 us
	quantum_start:		4222922297 us
	needed_load:		99%
	went_sleep:		4222913982
	went_sleep_active:	1047952504
	core:			3

Team:

TEAM: 0xffffffffc0d53210
id:               17361 (0x43d1)
serial_number:    15264
name:             'sh'
args:             '/bin/sh -e -c 
LIBRARY_PATH="$LIBRARY_PATH:/Development/haiku/g'
hash_next:        0x0000000000000000
parent:           0xffffffff9fab3208 (id = 9753)
children:         0x0000000000000000
num_threads:      1
state:            0
flags:            0x0
io_context:       0xffffffffc7d82880
address_space:    0xffffffffa4f35788
user data:        0x00007ffe0ee4f000 (area 1153207)
free user thread: 0x0000000000000000
main_thread:      0xffffffffa5061dc0
thread_list:      0xffffffffa5061dc0
group_id:         9753
session_id:       420

Also noted a huge number of runtime_loader: /Development/haiku/generated/cross-tools-x86_64/lib/bfd-plugins/libdep.a: Incorrect ELF header in the syslog as well, not sure if that might be related? Happened whilst building Haiku with -j4.

[waddlesplash]

There appears to be a race in the team creation, not in the ConditionVariable code: if we return from team creation, destroying the ConditionVariable, before the notify thread finishes, then the notify thread will do a spin-unlock on a destroyed variable.

[waddlesplash]

Based on my analysis, this should be fixed by hrev56910. If it recurs, please re-open.