[regression] Deskbar locks on boot

[korli]

hrev50229 x86 and x86_64. VirtualBox 5.0.18.

KERN: USER: User command requested kernel debugger.
KERN: Welcome to Kernel Debugging Land...
KERN: Thread 688 "kernel_debugger" running on CPU 1
KERN: kdebug> bt[1D[1D[1D[1Dteamsteam                   id  parent              name
KERN: 0xffffffff820bf000      1  0x0000000000000000  kernel_team
KERN: 0xffffffff820be600    199  0xffffffff820bf000  launch_daemon
KERN: 0xffffffff820ba000    202  0xffffffff820be600  app_server
KERN: 0xffffffff820b8200    205  0xffffffff820be600  net_server
KERN: 0xffffffff820b7800    206  0xffffffff820be600  debug_server
KERN: 0xffffffff820b6e00    207  0xffffffff820be600  mount_server
KERN: 0xffffffff820b6400    208  0xffffffff820be600  package_daemon
KERN: 0xffffffff820b5000    209  0xffffffff820be600  power_daemon
KERN: 0xffffffff820b4600    210  0xffffffff820be600  registrar
KERN: 0xffffffff820b5a00    211  0xffffffff820be600  syslog_daemon
KERN: 0xffffffff820b2800    242  0xffffffff820be600  launch_daemon
KERN: 0xffffffff820b0a00    252  0xffffffff820ba000  input_server
KERN: 0xffffffff89fbf008    263  0xffffffff820be600  media_server
KERN: 0xffffffff89fbbe08    282  0xffffffff820be600  notification_server
KERN: 0xffffffff89fbaa08    290  0xffffffff820b8200  sshd
KERN: 0xffffffff89fba008    292  0xffffffff89fbf008  media_addon_server
KERN: 0xffffffff89fbb408    299  0xffffffff820b2800  Tracker
KERN: 0xffffffff89fbd208    314  0xffffffff820b2800  Deskbar
KERN: 0xffffffff89fb9608    377  0xffffffff89fbb408  Terminal
KERN: 0xffffffff89fb8c08    382  0xffffffff89fb9608  bash
KERN: 0xffffffff89fb7808    688  0xffffffff89fb8c08  kernel_debugger
KERN: kdebug> threads 314thread                 id  state     wait for  object              cpu pri  stack              team  name
KERN: 0xffffffff89fecba0    314  waiting   cvar      0xffffffff89f4c688    -  10  0xffffffff81410000  314  Deskbar
KERN: 0xffffffff89fe94a0    337  zzz                                       -   5  0xffffffff86662000  314  Expando Window Watcher
KERN: 0xffffffff89fea520    340  waiting   cvar      0xffffffff8a04a888    -  15  0xffffffff86671000  314  w>Twitcher
KERN: 0xffffffff89fe8f20    341  waiting   cvar      0xffffffff8a01e1b0    -  15  0xffffffff86676000  314  w>Deskbar
KERN: 0xffffffff89fe4220    358  waiting   cvar      0xffffffff8a0fb088    -  20  0xffffffff866f1000  314  _BMediaRoster_
KERN: kdebug> bt 358[Kstack trace for thread 358 "_BMediaRoster_"
KERN:     kernel stack: 0xffffffff866f1000 to 0xffffffff866f6000
KERN:       user stack: 0x00007f65f4ba0000 to 0x00007f65f4be0000
KERN: frame                       caller             <image>:function + offset
KERN:  0 ffffffff866f5d00 (+ 112) ffffffff8009001c   <kernel_x86_64> reschedule(int) + 0xa64
KERN:  1 ffffffff866f5d70 (+  32) ffffffff80090a5e   <kernel_x86_64> scheduler_reschedule + 0x6c
KERN:  2 ffffffff866f5d90 (+  80) ffffffff80081757   <kernel_x86_64> thread_block_with_timeout + 0x186
KERN:  3 ffffffff866f5de0 (+  64) ffffffff800529ed   <kernel_x86_64> ConditionVariableEntry::Wait(unsigned int, long) + 0xc3
KERN:  4 ffffffff866f5e20 (+ 160) ffffffff8006810e   <kernel_x86_64> _get_port_message_info_etc + 0xfb
KERN:  5 ffffffff866f5ec0 (+  48) ffffffff800682da   <kernel_x86_64> port_buffer_size_etc + 0x1b
KERN:  6 ffffffff866f5ef0 (+  48) ffffffff8006936c   <kernel_x86_64> _user_port_buffer_size_etc + 0x75
KERN:  7 ffffffff866f5f20 (+  24) ffffffff80135125   <kernel_x86_64> x86_64_syscall_entry + 0xfb
KERN: user iframe at 0xffffffff866f5f38 (end = 0xffffffff866f6000)
KERN:  rax 0xd8                  rbx 0x1f5f1a19f40         rcx 0x59337edd1c
KERN:  rdx 0x7fffffffffffffff    rsi 0x8                   rdi 0xca
KERN:  rbp 0x7f65f4bdfa70         r8 0x7fffffffffffffff     r9 0xb
KERN:  r10 0x59337edd29          r11 0x3202                r12 0x1f5f1a19f40
KERN:  r13 0x7fffffffffffffff    r14 0x7f65f4bdfabc        r15 0x7f65f4bdfb08
KERN:  rip 0x59337edd1c          rsp 0x7f65f4bdfa68     rflags 0x3202
KERN:  vector: 0x63, error code: 0x0
KERN:  8 ffffffff866f5f38 (+140077914037048) 00000059337edd1c   <libroot.so> _kern_port_buffer_size_etc + 0x0c
KERN:  9 00007f65f4bdfa70 (+  48) 0000009852cece06   <libbe.so> BLooper::ReadRawFromPort(int*, long) + 0x26
KERN: 10 00007f65f4bdfaa0 (+  48) 0000009852cece8c   <libbe.so> BLooper::ReadMessageFromPort(long) + 0x1a
KERN: 11 00007f65f4bdfad0 (+  16) 0000009852cececf   <libbe.so> BLooper::MessageFromPort(long) + 0x09
KERN: 12 00007f65f4bdfae0 (+  96) 0000009852cee1de   <libbe.so> BLooper::task_looper() + 0x6a
KERN: 13 00007f65f4bdfb40 (+  32) 0000009852cecd1b   <libbe.so> BLooper::_task0_(void*) + 0x21
KERN: 14 00007f65f4bdfb60 (+  32) 00000059337ecbbc   <libroot.so> _thread_do_exit_work (nearest) + 0x70
KERN: 15 00007f65f4bdfb80 (+   0) 00007fdbece1c260   <commpage> commpage_thread_exit + 0x00
KERN: kdebug> bt 341stack trace for thread 341 "w>Deskbar"
KERN:     kernel stack: 0xffffffff86676000 to 0xffffffff8667b000
KERN:       user stack: 0x00007f28ec420000 to 0x00007f28ec460000
KERN: frame                       caller             <image>:function + offset
KERN:  0 ffffffff8667acc0 (+ 112) ffffffff8009001c   <kernel_x86_64> reschedule(int) + 0xa64
KERN:  1 ffffffff8667ad30 (+  32) ffffffff80090a5e   <kernel_x86_64> scheduler_reschedule + 0x6c
KERN:  2 ffffffff8667ad50 (+  80) ffffffff80081757   <kernel_x86_64> thread_block_with_timeout + 0x186
KERN:  3 ffffffff8667ada0 (+  64) ffffffff800529ed   <kernel_x86_64> CoKERN: nditionVariableEntry::Wait(unsigned int, long) + 0xc3
KERN:  4 ffffffff8667ade0 (+ 208) ffffffff80068983   <kernel_x86_64> writev_port_etc + 0x141
KERN:  5 ffffffff8667aeb0 (+ 112) ffffffff800695c9   <kernel_x86_64> _user_write_port_etc + 0xcd
KERN:  6 ffffffff8667af20 (+  24) ffffffff80135125   <kernel_x86_64> x86_64_syscall_entry + 0xfb
KERN: user iframe at 0xffffffff8667af38 (end = 0xffffffff8667b000)
KERN:  rax 0xdc                  rbx 0x6de4                rcx 0x59337edd5c
KERN:  rdx 0x7f28ec45ea80        rsi 0x601                 rdi 0xa8
KERN:  rbp 0x7f28ec45e9b0         r8 0x8                    r9 0xe4e1c0
KERN:  r10 0xc                   r11 0x3206                r12 0xa8
KERN:  r13 0x7f28ec45ea80        r14 0x7f28ec45ea70        r15 0x601
KERN:  rip 0x59337edd5c          rsp 0x7f28ec45e9a8     rflags 0x3206
KERN:  vector: 0x63, error code: 0x0
KERN:  7 ffffffff8667af38 (+139815779449464) 00000059337edd5c   <libroot.so> _kern_write_port_etc + 0x0c
KERN:  8 00007f28ec45e9b0 (+  96) 000001443e9711f5   <libmedia.so> BPrivate::media::dataexchange::QueryPort(int, int, BPrivate::media::request_data*, unsigned long, BPrivate::media::reply_data*, unsigned long) + 0x36
KERN:  9 00007f28ec45ea10 (+ 176) 000001443e95eb09   <libmedia.so> BMediaRoster::GetParameterWebFor(media_node const&, BParameterWeb**) + 0x127
KERN: 10 00007f28ec45eac0 (+ 128) 000001ac5ac416f0   <_APP_> MixerControl::Connect(int, float*, char const**) + 0xc6
KERN: 11 00007f28ec45eb40 (+ 128) 000001ac5ac40290   <_APP_> MediaReplicant::Pulse() + 0x3e
KERN: 12 00007f28ec45ebc0 (+  32) 0000009852d924fa   <libbe.so> BView::_Pulse() + 0x24
KERN: 13 00007f28ec45ebe0 (+  32) 0000009852d9250e   <libbe.so> BView::_Pulse() + 0x38
KERN: 14 00007f28ec45ec00 (+  32) 0000009852d9250e   <libbe.so> BView::_Pulse() + 0x38
KERN: 15 00007f28ec45ec20 (+  32) 0000009852d9250e   <libbe.so> BView::_Pulse() + 0x38
KERN: 16 00007f28ec45ec40 (+  32) 0000009852d9250e   <libbe.so> BView::_Pulse() + 0x38
KERN: 17 00007f28ec45ec60 (+ 800) 0000009852da6eef   <libbe.so> BWindow::DispatchMessage(BMessage*, BHandler*) + 0xed3
KERN: 18 00007f28ec45ef80 (+ 160) 0000009852da1297   <libbe.so> BWindow::task_looper() + 0x267
KERN: 19 00007f28ec45f020 (+  32) 0000009852cecd1b   <libbe.so> BLooper::_task0_(void*) + 0x21
KERN: 20 00007f28ec45f040 (+  32) 00000059337ecbbc   <libroot.so> _thread_do_exit_work (nearest) + 0x70
KERN: 21 00007f28ec45f060 (+   0) 00007fdbece1c260   <commpage> commpage_thread_exit + 0x00
KERN: kdebug> cont

[Barrett]

Very thanks for remembering me the kernel debugger exists :-), I also recalled there's a bonefish article.

[Barrett]

So, in the end the only solution I found is the same as the commit I reverted a long time ago. On boot certain threads are in a unconsistent state, and only by checking for negative waitUntil solve the issue here. As already stated, reintroducing this cause other problems, such as locking under heavy load. I think it's the case this issue is discussed openly, or I guess due to time I'm not willing to put more than the previously mentioned fix...

[axeld]

The usual order of actions is to fully understand the problem first, and then fix it. Allowing hacks like this seriously degrades the code quality over time, and makes it pretty much unmaintainable.

[Barrett]

I think a way or another, we need something like that. Events in the past (frequent in late situations) should be ideally processed differently than the others and we should expect a "non-linear" scenario. The problems is how to do it correctly, and what factors we have to take into account. How we can allow "flushing" of late events without mining the need to have balanced port reads/events.

[Barrett]

The issue should be resolved now.