OSv crash on pthread_start

[Deepak Krishnan]

Hi,

Running OSv with some Linux binaries and had a crash that I couldn't completely understand:

(gdb) where
#0  processor::cli_hlt () at arch/x64/processor.hh:248
#1  0x0000000040208fe6 in arch::halt_no_interrupts () at arch/x64/arch.hh:48
#2  0x0000000040487679 in osv::halt () at arch/x64/power.cc:26
#3  0x000000004021f9e9 in abort (fmt=0x40989a90 "Assertion failed: %s (%s: %s: %d)\n") at runtime.cc:132
#4  0x000000004021fa24 in __assert_fail (expr=0x409d5613 "sched::preemptable()", file=0x409d5603 "arch/x64/mmu.cc", line=37, func=0x409d5840 <page_fault::__func__> "page_fault") at runtime.cc:139
#5  0x0000000040476cea in page_fault (ef=0xffff8000089c5068) at arch/x64/mmu.cc:37
#6  <signal handler called>
#7  thread_main () at arch/x64/entry.S:113

It looks like what is happening is OSv thread #36 is executing a pthread_create -> pthread_run sequence, and the pthread run function is causing a page_fault in thread_main(). Since the threads start with preemption disabled, we are tripping on the assert there.

36 (0xffff800005cc5040) /usr/local/nu cpu0 queued     osv::rcu_lock_type::unlock() at include/osv/rcu.hh:179 vruntime  2.45014e+16
  37 (0xffff8000089c0040) >/usr/local/n cpu0 running    ?? at arch/x64/entry.S:112 vruntime -8.38882e+14

(gdb) osv thread 37
(gdb) where
#0  sched::thread::switch_to (this=0xffff8000089c0040) at arch/x64/arch-switch.hh:108
#1  0x00000000405b9e4c in sched::cpu::reschedule_from_interrupt (this=0xffff80000001f040, called_from_yield=false, preempt_after=...) at core/sched.cc:339
#2  0x00000000405b9728 in sched::cpu::schedule () at core/sched.cc:228
#3  0x000000004024cc8e in sched::preempt_enable () at include/osv/sched.hh:1017
#4  0x0000000040256c62 in osv::rcu_lock_type::unlock () at include/osv/rcu.hh:179
#5  0x000000004025776d in std::lock_guard<osv::rcu_lock_type>::~lock_guard (this=0x2000006ffaa8, __in_chrg=<optimized out>) at /misc/cross/el7.5-x86_64/gcc-7.3.0/x86_64-redhat-linux/include/c++/7.3.0/bits/std_mutex.h:168
#6  0x000000004025725c in lock_guard_for_with_lock<osv::rcu_lock_type>::~lock_guard_for_with_lock (this=0x2000006ffaa8, __in_chrg=<optimized out>) at include/osv/mutex.h:88
#7  0x00000000405bd16c in sched::thread::wake (this=0xffff8000089c0040) at core/sched.cc:1164
#8  0x00000000405bcd8f in sched::thread::start (this=0xffff8000089c0040) at core/sched.cc:1079

gdb) osv thread 37
(gdb) where
#0  thread_main () at arch/x64/entry.S:112

I do get the reasoning behind threads starting with preemption disabled (https://github.com/cloudius-systems/osv/commit/695375f65303e13df1b9de798577ee9a4f8f9892),  but what is being observed here is indeed a valid scenario that needs to be handled? If not, please do share any pointers to correct my understanding.

Thanks
Deepak

[Nadav Har'El]

On Mon, Jan 11, 2021 at 9:37 AM Deepak Krishnan <deep...@gmail.com> wrote:

Hi,

Running OSv with some Linux binaries and had a crash that I couldn't completely understand:

(gdb) where
#0  processor::cli_hlt () at arch/x64/processor.hh:248
#1  0x0000000040208fe6 in arch::halt_no_interrupts () at arch/x64/arch.hh:48
#2  0x0000000040487679 in osv::halt () at arch/x64/power.cc:26
#3  0x000000004021f9e9 in abort (fmt=0x40989a90 "Assertion failed: %s (%s: %s: %d)\n") at runtime.cc:132
#4  0x000000004021fa24 in __assert_fail (expr=0x409d5613 "sched::preemptable()", file=0x409d5603 "arch/x64/mmu.cc", line=37, func=0x409d5840 <page_fault::__func__> "page_fault") at runtime.cc:139
#5  0x0000000040476cea in page_fault (ef=0xffff8000089c5068) at arch/x64/mmu.cc:37
#6  <signal handler called>
#7  thread_main () at arch/x64/entry.S:113

It looks like what is happening is OSv thread #36 is executing a pthread_create -> pthread_run sequence, and the pthread run function is causing a page_fault in thread_main(). Since the threads start with preemption disabled, we are tripping on the assert there.

Right.

36 (0xffff800005cc5040) /usr/local/nu cpu0 queued     osv::rcu_lock_type::unlock() at include/osv/rcu.hh:179 vruntime  2.45014e+16
  37 (0xffff8000089c0040) >/usr/local/n cpu0 running    ?? at arch/x64/entry.S:112 vruntime -8.38882e+14

(gdb) osv thread 37
(gdb) where
#0  sched::thread::switch_to (this=0xffff8000089c0040) at arch/x64/arch-switch.hh:108
#1  0x00000000405b9e4c in sched::cpu::reschedule_from_interrupt (this=0xffff80000001f040, called_from_yield=false, preempt_after=...) at core/sched.cc:339
#2  0x00000000405b9728 in sched::cpu::schedule () at core/sched.cc:228
#3  0x000000004024cc8e in sched::preempt_enable () at include/osv/sched.hh:1017
#4  0x0000000040256c62 in osv::rcu_lock_type::unlock () at include/osv/rcu.hh:179
#5  0x000000004025776d in std::lock_guard<osv::rcu_lock_type>::~lock_guard (this=0x2000006ffaa8, __in_chrg=<optimized out>) at /misc/cross/el7.5-x86_64/gcc-7.3.0/x86_64-redhat-linux/include/c++/7.3.0/bits/std_mutex.h:168
#6  0x000000004025725c in lock_guard_for_with_lock<osv::rcu_lock_type>::~lock_guard_for_with_lock (this=0x2000006ffaa8, __in_chrg=<optimized out>) at include/osv/mutex.h:88
#7  0x00000000405bd16c in sched::thread::wake (this=0xffff8000089c0040) at core/sched.cc:1164
#8  0x00000000405bcd8f in sched::thread::start (this=0xffff8000089c0040) at core/sched.cc:1079

gdb) osv thread 37
(gdb) where
#0  thread_main () at arch/x64/entry.S:112

I'm not sure we're seeing here the *same* thread. Maybe you're starting two threads at the same time?

I do get the reasoning behind threads starting with preemption disabled (https://github.com/cloudius-systems/osv/commit/695375f65303e13df1b9de798577ee9a4f8f9892),  but what is being observed here is indeed a valid scenario that needs to be handled? If not, please do share any pointers to correct my understanding.

Interesting. Theoretically, there is no reason why we didn't reach preempt_enable() and enabled preemption. If we didn't, there is one possible explanation: The thread's stack was allocated with mmap() without pre-population (MAP_STACK or MAP_POPULATE), so when the thread began to execute it had to page-fault its own stack, which failed.

I'll try to prepare a test and a patch for this issue - if I can reproduce it (the patch itself should be trivial).

Stay tuned.

 

Thanks
Deepak

--
You received this message because you are subscribed to the Google Groups "OSv Development" group.
To unsubscribe from this group and stop receiving emails from it, send an email to osv-dev+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/osv-dev/4b814e35-7384-4123-ac42-7523e292b29bn%40googlegroups.com.

[Deepak Krishnan]

You are right, I missed clarifying that before - in my case thread #36 and thread #37 are not the same thread.  

I do get the reasoning behind threads starting with preemption disabled (https://github.com/cloudius-systems/osv/commit/695375f65303e13df1b9de798577ee9a4f8f9892),  but what is being observed here is indeed a valid scenario that needs to be handled? If not, please do share any pointers to correct my understanding.

Interesting. Theoretically, there is no reason why we didn't reach preempt_enable() and enabled preemption. If we didn't, there is one possible explanation: The thread's stack was allocated with mmap() without pre-population (MAP_STACK or MAP_POPULATE), so when the thread began to execute it had to page-fault its own stack, which failed.

I'll try to prepare a test and a patch for this issue - if I can reproduce it (the patch itself should be trivial).

Stay tuned.

Thank you. I'll watch for your updates.

[Nadav Har'El]

I just sent a patch titled "[PATCH] pthread_create() - prefault top of stack" - can you please test it with your application?

The patch is just one line of code - with a lot of additional tests, comments, etc. :-)

Unfortunately, this is not a 100% foolproof solution, as explained in https://github.com/cloudius-systems/osv/issues/143 - if a thread's stack is not pre-allocated, we can always have random (but relatively rare) crashes when internal OSv code which has preemption disabled needs to use the stack and crosses over to a previously unused stack page that needs to be paged in. This should be rare, but can happen. Waldek did submit a 100% (?) solution once, but I don't remember what became of it :-( If you can modify your application, a good workaround is when you use mmap() to allocate thread stacks, use the MAP_STACK option. This option is a no-op on Linux, but does the same as MAP_POPULATE on OSv so works around these bugs.

 

Thanks
Deepak

--
You received this message because you are subscribed to the Google Groups "OSv Development" group.
To unsubscribe from this group and stop receiving emails from it, send an email to osv-dev+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/osv-dev/4b814e35-7384-4123-ac42-7523e292b29bn%40googlegroups.com.

--
You received this message because you are subscribed to the Google Groups "OSv Development" group.
To unsubscribe from this group and stop receiving emails from it, send an email to osv-dev+u...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/osv-dev/dd8bc7c0-7606-4d70-bd36-893d4a934258n%40googlegroups.com.

[Waldek Kozaczuk]

On Monday, January 11, 2021 at 5:26:51 AM UTC-5 Nadav Har'El wrote:

On Mon, Jan 11, 2021 at 11:43 AM Deepak Krishnan <deep...@gmail.com> wrote:

On Monday, 11 January, 2021 at 1:47:22 pm UTC+5:30 Nadav Har'El wrote:

Interesting. Theoretically, there is no reason why we didn't reach preempt_enable() and enabled preemption. If we didn't, there is one possible explanation: The thread's stack was allocated with mmap() without pre-population (MAP_STACK or MAP_POPULATE), so when the thread began to execute it had to page-fault its own stack, which failed.

I'll try to prepare a test and a patch for this issue - if I can reproduce it (the patch itself should be trivial).

Stay tuned.

Thank you. I'll watch for your updates.

I just sent a patch titled "[PATCH] pthread_create() - prefault top of stack" - can you please test it with your application?

The patch is just one line of code - with a lot of additional tests, comments, etc. :-)

Unfortunately, this is not a 100% foolproof solution, as explained in https://github.com/cloudius-systems/osv/issues/143 - if a thread's stack is not pre-allocated, we can always have random (but relatively rare) crashes when internal OSv code which has preemption disabled needs to use the stack and crosses over to a previously unused stack page that needs to be paged in. This should be rare, but can happen. Waldek did submit a 100% (?) solution once, but I don't remember what became of it :-( If you can modify your application, a good workaround is when you use mmap() to allocate thread stacks, use the MAP_STACK option. This option is a no-op on Linux, but does the same as MAP_POPULATE on OSv so works around these bugs.

If you have some time to review it I can find this patch, if necessary adjust it to apply to the latest source version and re-send it to the list :-)

[Deepak Krishnan]

On Monday, 11 January, 2021 at 3:56:51 pm UTC+5:30 Nadav Har'El wrote:

On Mon, Jan 11, 2021 at 11:43 AM Deepak Krishnan <deep...@gmail.com> wrote:

On Monday, 11 January, 2021 at 1:47:22 pm UTC+5:30 Nadav Har'El wrote:

Interesting. Theoretically, there is no reason why we didn't reach preempt_enable() and enabled preemption. If we didn't, there is one possible explanation: The thread's stack was allocated with mmap() without pre-population (MAP_STACK or MAP_POPULATE), so when the thread began to execute it had to page-fault its own stack, which failed.

I'll try to prepare a test and a patch for this issue - if I can reproduce it (the patch itself should be trivial).

Stay tuned.

Thank you. I'll watch for your updates.

I just sent a patch titled "[PATCH] pthread_create() - prefault top of stack" - can you please test it with your application?

Can confirm the patch fixes the crash with my application. :)

The patch is just one line of code - with a lot of additional tests, comments, etc. :-)

Unfortunately, this is not a 100% foolproof solution, as explained in https://github.com/cloudius-systems/osv/issues/143 - if a thread's stack is not pre-allocated, we can always have random (but relatively rare) crashes when internal OSv code which has preemption disabled needs to use the stack and crosses over to a previously unused stack page that needs to be paged in. This should be rare, but can happen. Waldek did submit a 100% (?) solution once, but I don't remember what became of it :-( If you can modify your application, a good workaround is when you use mmap() to allocate thread stacks, use the MAP_STACK option. This option is a no-op on Linux, but does the same as MAP_POPULATE on OSv so works around these bugs.

Indeed, the application was not using MAP_STACK/MAP_POPULATE in my case. I can modify it to use MAP_STACK - that being a no-op in Linux helps  :)  Thank you.