stdlib in a loop hangs #2451
Labels
triggers release
Major issue that when fixed, results in an "emergency" release
Comments
mfelsche
added
bug: 1 - needs investigation
triggers release
|
@SeanTAllen any success duplicating this issue? |
|
@winksaville I haven't had a chance to look into it yet. Hopefully soon... In relation to that, are there any specifics to reproducing beyond running In the meantime:
|
winksaville
added a commit
to winksaville/ponyc
that referenced
this issue
Dec 28, 2017
The targets can be used to test issue ponylang#2451 These use the sub-targets stdlib-debug, stdlib to compile stdlib either in debug or not. And stdlib-loop will execute stdlib in a forever while loop capturing the output to stdlib-xxxx.txt where xxx is the current date and time.
|
I've add PR #2456 which has just failed on my system running test-stdlib-debug. What specific information would you like to have, here are the backtraces for the 3 running threads: Curious, what additional information is available when running stdlib after being compiled with a debug build of ponyc? In the above I used the test-stdlib-debug target which passes the "-d" switch to ponyc when compiling. Be glad to test any prior build, could you please give me a specific commit. I'm guessing this commit which is the one prior to your #2386 commit, but want to make sure. |
|
@winksaville compiling Compiling I hope that the above was helpful (and not just more confusing). I'm sure there's a better way to explain things but I'm unable to manage such an explanation at the moment. In regards to what information to look at once you're in the debugger, it would be helpful to be able to see the following:
In regards to testing a prior build before the dynamic scheduler scaling changes, yes, that commit prior to #2386 being merged is a good one. Or you can pick one of the official release tags. Either one works. |
|
Makes perfect sense, now that you explain it, txs. I'll rerun the test with ponyc compiled with config=debug and as well as with a prior commit. |
|
whoops, wrong button, reopening. |
winksaville
added a commit
to winksaville/ponyc
that referenced
this issue
Dec 29, 2017
The targets can be used to test issue ponylang#2451 These use the sub-targets stdlib-debug, stdlib to compile stdlib either in debug or not. And stdlib-loop will execute stdlib in a forever while loop capturing the output to stdlib-xxxx.txt where xxx is the current date and time.
winksaville
added a commit
to winksaville/ponyc
that referenced
this issue
Dec 30, 2017
The targets can be used to test issue ponylang#2451 These use the sub-targets stdlib-debug, stdlib to compile stdlib either in debug or not. And stdlib-loop will execute stdlib in a forever while loop capturing the output to stdlib-xxxx.txt where xxx is the current date and time.
winksaville
added a commit
to winksaville/ponyc
that referenced
this issue
Dec 30, 2017
The targets can be used to test issue ponylang#2451 These use the sub-targets stdlib-debug, stdlib to compile stdlib either in debug or not. And stdlib-loop will execute stdlib in a forever while loop capturing the output to stdlib-xxxx.txt where xxx is the current date and time.
|
@dipinhora so I've run two branches in my repo. I built both the following, which builds "all" and then builds "stdlib": Finally I run test-long-term to start the forever loop I ran debug-2451-0.21.0 for about 16.5 hours starting yesterday afternoon and finishing this morning, there were no issues. If you wan't to see the 2.4G of uncompressed logs its here. This moring I ran debug-2451 which has you new scheduler stuff and it ran a couple minutes and then hung. Another words it fails quickly, its logs are here. The one thing that doesn't work is getting the queue size, it SIGSEGV's: So I'm doing something wrong. Actually, I'm probably doing lots of things wrong. Just let me know what you'd like me to do. |
|
Hi @winksaville. Thanks for taking the time to do all the legwork and for confirming that the issue didn't exist prior to the dynamic scheduler scaling code changes. I tried reproducing but my virtual machine doesn't seem to trigger the issue (or I just didn't wait long enough). I'll have to spin up an AWS instance at some point. The debug information you provided is very helpful and points to the fact that the last thread is not being woken properly. I'm not sure why that's the case, but the following diff should try and catch that scenario and try again automatically (until it is hopefully successful and cleanly shuts down): diff --git a/src/common/threads.h b/src/common/threads.h
index 6ed464f..06cb87c 100644
--- a/src/common/threads.h
+++ b/src/common/threads.h
@@ -59,6 +59,6 @@ pony_thread_id_t ponyint_thread_self();
void ponyint_thread_suspend(pony_signal_event_t signal);
-void ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal);
+int ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal);
#endif
diff --git a/src/libponyrt/platform/threads.c b/src/libponyrt/platform/threads.c
index 52e8a23..a9660a5 100644
--- a/src/libponyrt/platform/threads.c
+++ b/src/libponyrt/platform/threads.c
@@ -276,19 +276,18 @@ void ponyint_thread_suspend(pony_signal_event_t signal)
#endif
}
-void ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal)
+int ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal)
{
+ int ret;
#if defined(PLATFORM_IS_WINDOWS)
(void) thread;
- SetEvent(signal);
+ ret = SetEvent(signal);
#elif defined(USE_SCHEDULER_SCALING_PTHREADS)
(void) thread;
- int ret;
// signal condition variable
ret = pthread_cond_signal(signal);
- // TODO: What to do if `ret` is an unrecoverable error?
- (void) ret;
#else
- pthread_kill(thread, signal);
+ ret = pthread_kill(thread, signal);
#endif
+ return ret;
}
diff --git a/src/libponyrt/sched/scheduler.c b/src/libponyrt/sched/scheduler.c
index ab23773..d942c88 100644
--- a/src/libponyrt/sched/scheduler.c
+++ b/src/libponyrt/sched/scheduler.c
@@ -126,9 +126,16 @@ static void wake_suspended_threads()
{
// in case the count changed between the while check and now
if(get_active_scheduler_count() < scheduler_count)
+ {
// send signal to wake up next scheduler thread available
- ponyint_thread_wake(scheduler[get_active_scheduler_count()].tid,
- scheduler[get_active_scheduler_count()].sleep_object);
+ if(!ponyint_thread_wake(scheduler[get_active_scheduler_count()].tid,
+ scheduler[get_active_scheduler_count()].sleep_object))
+ // if there was an error waking the thread
+ // unlock the bool that controls modifying the active scheduler count
+ // variable.
+ atomic_store_explicit(&scheduler_count_changing, false,
+ memory_order_release);
+ }
else
// if there are no scheduler threads left to unlock
// unlock the bool that controls modifying the active scheduler count
@@ -800,8 +807,13 @@ void ponyint_sched_maybe_wakeup()
memory_order_acquire))
{
// send signal to wake up next scheduler thread available
- ponyint_thread_wake(scheduler[current_active_scheduler_count].tid,
- scheduler[current_active_scheduler_count].sleep_object);
+ if(!ponyint_thread_wake(scheduler[current_active_scheduler_count].tid,
+ scheduler[current_active_scheduler_count].sleep_object))
+ // if there was an error waking the thread
+ // unlock the bool that controls modifying the active scheduler count
+ // variable.
+ atomic_store_explicit(&scheduler_count_changing, false,
+ memory_order_release);
}
}
There's no guarantee that this fixes the issue, but I think it should help. I likely need to go through and add in error handling logic everywhere there's a syscall that can return an error code to catch other similar edge cases. It would be great if you're able to test with this diff applied to see if it helps any. Also, re: the segfault when trying to get the queue count, that was my fault. I told you to use the wrong function to print the size of the queue. You should be using |
|
Today, I've been trying to simpily stdlib, it now is down to the code below, the big thing was it doesn't require openssl 1.1.0. It failed once after 20minutes and has now just failed a second time but took 55minutes! So openssl 1.1.0 isn't directly the problem, but there is one other non-standard change and that's that my Arch Linux system runs llvm 5.0. This definitely has issues as the "normal tests" won't complete unless I remove a bunch of tests, see this. Anyway, I'll apply your patch and see what happens. |
|
@dipinhora, I applied your patch and stdlib still hung. But I think you have the logic backwards, your if statement is true on the "good" case i.e. when ponyint_thread_wake returns 0. I changed it to the opposite logic and also added a printf just to see what would happen: As you might expect ponyint_thread_wake always returned 0 and stdlib still hung. Below is the gdb output with the above patch: |
|
@winksaville Yes, I did have the logic backwards on the Still no clue why that last thread is not being woken if the signal is being successfully sent since signals are supposed to not get lost according to my understanding of things. I know you tested this once previously, but would you be able to test again with I'm likely not going to be able to spend time on AWS to reproduce this for at least a week (maybe longer) so I'm mainly going to be limited to some analysis of code and semantics and maybe a suggestion or two in the meantime. |
|
NP, I'll try it in the morning. |
|
Is there a document on the pony runtime, specifically the relationship between the threads, actors and message queues? Can I ignore GC when delving into these relationships? |
|
@dipinhora, stdlib hung within a few minutes when I built with Here is the gdb output, notice there were 4 threads still alive instead of the usual 3, but I've also see it with as many as 8 threads so I don't beleive it's related to use=scheduler_scaling_pthreads: |
SeanTAllen
pushed a commit
that referenced
this issue
Jan 3, 2018
The targets can be used to test issue #2451 These use the sub-targets stdlib-debug, stdlib to compile stdlib either in debug or not.
|
@winksaville, thanks for taking the time to test out the In order to In regards to your question about documentation of the runtime. I'm not sure specific documentation exists. There are a number of papers about pony, so it is possible one of them covers the runtime (but I haven't read the papers so I could be wrong). The following is a quick summary of my understanding of the relationship between the threads, actors, message queues and GC in the runtime. Please keep in mind that I've mainly learned things by randomly poking at things and looking at the source code and could very likely be misunderstanding things and providing you incorrect information. Additionally, I'm speaking in regards to the runtime as used by a compiled pony program. There are slight differences when the pony runtime is embedded as a C library (mainly around how the runtime gets started and not how it works internally) but I'm not versed in the nuances involved to speak to them.
To answer your question: Ummm... so... I kind of went on a bit of a tangent, but hopefully that was at least somewhat coherent and maybe even useful. 8*) |
|
First, txs so much for the explanation of the runtime, I'll have to study it more but it's a great start. I'll re- run the test to properly use the "use statement". I'll also make additional changes if the people would like me to, although I'd like to get openssl 1.1 support in ASAP, as I have to do alot of juggling to test drive n my Arch systems. But if will gladly do what's everyone desires. |
|
@winksaville Thank you again for being so very patient and helpful in regards to this while I've been unable to reproduce the issue on my end. I'm still hoping to try and reproduce on AWS at some point but I'm not sure when due to other more pressing concerns (work, etc). In regards to the openssl 1.1 support, I don't mean to cause additional delay on it. I was thinking of it from the perspective of if I had to use it and I'm 100% sure it would annoy me to have to remember to add in the extra argument for |
|
Here's the latest run which failed after 10secs, so very quickly: |
|
@dipinhora, one thing we could do is you could log into my computer and debug it. We could use tmux and I could watch over your shoulder and I'm sure I'd learn alot. |
|
So I've modified examples/ring and called it pony-ring. When it hangs the stack traces are similar to, but not exactly like, the one from stdlib above. I built pony-ring with the same ponyc compiler as I used for stdlib, you can look at the Makefile. It seems to fail maybe 50% of the time when running --ponynoblock with 1000 rings each with a 1000 Nodes and requesting 10 messages to be forwarded. When it works, as below, it takes about 1.5secs: When it hangs, none of the CPUs are doing much: And then in another terminal I run gdb: If I don't use --ponynoblock I've only seen it hang once but it takes variable length of time to finish and the long time between the "DONE" message and "Main._final" there is one CPU is running at 100%, the others are fairly idle. Below are a series of runs that completed successfully, notice how variable the time is: And here is the the one hang without --ponynoblock: Of course it never gets to _Main._final because it was hung and eventually the all the CPU's become idle, although for several minutes one CPU was at 100%. Here is the stack traces from gdb: Anyway, I hope this is the same problem as stdlib, as its obviously much simpler. |
|
Oh, here is the output from the hang without --ponynoblock after quiting gdb and then hitting Ctrl-C on the ./ring run. I think that "user 5m35.268s" represents the approx 5m33s of time it must have spent with the one CPU at 100%: |
|
@winksaville Thanks for your continued work on this and for your offer regarding the From what I can tell, there are at least two or three different issues based on the backtraces you've provided so far.
I've managed to reproduce the issue with the In the meantime, if you have time, it would be great if you could run your tests with the following two scenarios to help rule out some things (ideally both with
diff --git a/src/common/threads.h b/src/common/threads.h
index 6ed464f..06cb87c 100644
--- a/src/common/threads.h
+++ b/src/common/threads.h
@@ -59,6 +59,6 @@ pony_thread_id_t ponyint_thread_self();
void ponyint_thread_suspend(pony_signal_event_t signal);
-void ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal);
+int ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal);
#endif
diff --git a/src/libponyrt/platform/threads.c b/src/libponyrt/platform/threads.c
index 52e8a23..a9660a5 100644
--- a/src/libponyrt/platform/threads.c
+++ b/src/libponyrt/platform/threads.c
@@ -276,19 +276,18 @@ void ponyint_thread_suspend(pony_signal_event_t signal)
#endif
}
-void ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal)
+int ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal)
{
+ int ret;
#if defined(PLATFORM_IS_WINDOWS)
(void) thread;
- SetEvent(signal);
+ ret = SetEvent(signal);
#elif defined(USE_SCHEDULER_SCALING_PTHREADS)
(void) thread;
- int ret;
// signal condition variable
ret = pthread_cond_signal(signal);
- // TODO: What to do if `ret` is an unrecoverable error?
- (void) ret;
#else
- pthread_kill(thread, signal);
+ ret = pthread_kill(thread, signal);
#endif
+ return ret;
}
diff --git a/src/libponyrt/sched/scheduler.c b/src/libponyrt/sched/scheduler.c
index ab23773..fb366c2 100644
--- a/src/libponyrt/sched/scheduler.c
+++ b/src/libponyrt/sched/scheduler.c
@@ -122,19 +122,26 @@ static void wake_suspended_threads()
while (get_active_scheduler_count() < scheduler_count)
{
if(!atomic_exchange_explicit(&scheduler_count_changing, true,
- memory_order_acquire))
+ memory_order_seq_cst))
{
// in case the count changed between the while check and now
if(get_active_scheduler_count() < scheduler_count)
+ {
// send signal to wake up next scheduler thread available
- ponyint_thread_wake(scheduler[get_active_scheduler_count()].tid,
- scheduler[get_active_scheduler_count()].sleep_object);
+ if(ponyint_thread_wake(scheduler[get_active_scheduler_count()].tid,
+ scheduler[get_active_scheduler_count()].sleep_object))
+ // if there was an error waking the thread
+ // unlock the bool that controls modifying the active scheduler count
+ // variable.
+ atomic_store_explicit(&scheduler_count_changing, false,
+ memory_order_seq_cst);
+ }
else
// if there are no scheduler threads left to unlock
// unlock the bool that controls modifying the active scheduler count
// variable.
atomic_store_explicit(&scheduler_count_changing, false,
- memory_order_release);
+ memory_order_seq_cst);
}
}
}
@@ -407,6 +414,7 @@ static pony_actor_t* steal(scheduler_t* sched)
if (!block_sent)
{
uint32_t current_active_scheduler_count = get_active_scheduler_count();
+
if (steal_attempts < current_active_scheduler_count)
{
steal_attempts++;
@@ -421,7 +429,7 @@ static pony_actor_t* steal(scheduler_t* sched)
&& (current_active_scheduler_count > min_scheduler_count)
&& (!sched->terminate)
&& !atomic_exchange_explicit(&scheduler_count_changing, true,
- memory_order_acquire))
+ memory_order_seq_cst))
{
// let sched 0 know we're suspending
send_msg(sched->index, 0, SCHED_SUSPEND, 0);
@@ -439,7 +447,7 @@ static pony_actor_t* steal(scheduler_t* sched)
// unlock the bool that controls modifying the active scheduler count
// variable
atomic_store_explicit(&scheduler_count_changing, false,
- memory_order_release);
+ memory_order_seq_cst);
// sleep waiting for signal to wake up again
ponyint_thread_suspend(sched->sleep_object);
@@ -455,7 +463,7 @@ static pony_actor_t* steal(scheduler_t* sched)
// variable. this is because the signalling thread locks the control
// variable before signalling
atomic_store_explicit(&scheduler_count_changing, false,
- memory_order_release);
+ memory_order_seq_cst);
// dtrace resume notification
DTRACE1(THREAD_RESUME, (uintptr_t)sched);
@@ -797,11 +805,26 @@ void ponyint_sched_maybe_wakeup()
// if we have some schedulers that are sleeping, wake one up
if((current_active_scheduler_count < scheduler_count) &&
!atomic_exchange_explicit(&scheduler_count_changing, true,
- memory_order_acquire))
+ memory_order_seq_cst))
{
- // send signal to wake up next scheduler thread available
- ponyint_thread_wake(scheduler[current_active_scheduler_count].tid,
- scheduler[current_active_scheduler_count].sleep_object);
+ // in case the count changed between the while check and now
+ if(get_active_scheduler_count() < scheduler_count)
+ {
+ // send signal to wake up next scheduler thread available
+ if(ponyint_thread_wake(scheduler[get_active_scheduler_count()].tid,
+ scheduler[get_active_scheduler_count()].sleep_object))
+ // if there was an error waking the thread
+ // unlock the bool that controls modifying the active scheduler count
+ // variable.
+ atomic_store_explicit(&scheduler_count_changing, false,
+ memory_order_seq_cst);
+ }
+ else
+ // if there are no scheduler threads left to unlock
+ // unlock the bool that controls modifying the active scheduler count
+ // variable.
+ atomic_store_explicit(&scheduler_count_changing, false,
+ memory_order_seq_cst);
}
}
|
|
K, I'll give it a try in the AM. Its great you've reproduced the problem.
Did you reproduce it using stdlib or pony-ring or another program? How long
did it take to reproduce? Right now pony-ring with --ponynoblock is easiest
for me.
…On Fri, Jan 5, 2018, 9:34 PM Dipin Hora ***@***.***> wrote:
@winksaville <https://github.com/winksaville> Thanks for your continued
work on this and for your offer regarding the tmux session. The
bottleneck for both your suggestion and my testing on AWS is time on my
side. I am unable to dedicate enough time to properly debug this at the
moment (which my guess is at least a good few hours if not a day or two
worth of banging my head against it). Also, I'm not sure how much you'd
learn from watching me work. It's mostly a lot of "googling to figure out
how to use lldb properly, looking at source code, scratching my head as to
what could be happening, taking a semi-random guess, making a change,
compiling and rerunning to see if it worked or not" repeated over and over
and over again until I somehow get lucky. As @SeanTAllen
<https://github.com/seantallen> will confirm, I'm a database guy, not a
programmer. 8*P (sorry for the inside joke, couldn't help myself).
From what I can tell, there are at least two or three different issues
based on the backtraces you've provided so far.
- The first is where there's an out of order suspended thread (i.e. index
= 4 is suspended but index = 5 is not). This should not be possible
given how the scheduler_count_changing variable is supposed to gate
things.
- The second is where during shutdown, every thread but one is
successfully woken up and shuts down and index = 0 is stuck in
wake_suspended_threads because that last thread is still sleeping even
though it was sent a wake signal. I'm not sure why/how this is happening
but my suspicion is that this is the same root cause as the previous one.
- The third is where the no threads are suspended but there is still a
hang (your last backtrace). My guess is this happens because there's an
edge case around quiescence and thread waking/sleeping that I missed.
I've managed to reproduce the issue with the pthreads version of things
in my linux vm. I'll try and bang my head against it in order to figure out
where I went wrong.
In the meantime, if you have time, it would be great if you could run your
tests with the following two scenarios to help rule out some things
(ideally both with pthreads and signals):
- Run the programs with --ponyminthreads 9999 (this effectively
disabled dynamic scheduler scaling) to confirm that there isn't a larger
issue introduced accidentally (unless I screwed something up, this should
behave exactly the same as before the dynamic scheduler scaling logic was
merged)
- Run the programs with the following diff applied to rule out
atomics/memory order related issues:
diff --git a/src/common/threads.h b/src/common/threads.h
index 6ed464f..06cb87c 100644--- a/src/common/threads.h+++ b/src/common/threads.h@@ -59,6 +59,6 @@ pony_thread_id_t ponyint_thread_self();
void ponyint_thread_suspend(pony_signal_event_t signal);
-void ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal);+int ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal);
#endifdiff --git a/src/libponyrt/platform/threads.c b/src/libponyrt/platform/threads.c
index 52e8a23..a9660a5 100644--- a/src/libponyrt/platform/threads.c+++ b/src/libponyrt/platform/threads.c@@ -276,19 +276,18 @@ void ponyint_thread_suspend(pony_signal_event_t signal)
#endif
}
-void ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal)+int ponyint_thread_wake(pony_thread_id_t thread, pony_signal_event_t signal)
{+ int ret;
#if defined(PLATFORM_IS_WINDOWS)
(void) thread;- SetEvent(signal);+ ret = SetEvent(signal);
#elif defined(USE_SCHEDULER_SCALING_PTHREADS)
(void) thread;- int ret;
// signal condition variable
ret = pthread_cond_signal(signal);- // TODO: What to do if `ret` is an unrecoverable error?- (void) ret;
#else- pthread_kill(thread, signal);+ ret = pthread_kill(thread, signal);
#endif+ return ret;
}
diff --git a/src/libponyrt/sched/scheduler.c b/src/libponyrt/sched/scheduler.c
index ab23773..fb366c2 100644--- a/src/libponyrt/sched/scheduler.c+++ b/src/libponyrt/sched/scheduler.c@@ -122,19 +122,26 @@ static void wake_suspended_threads()
while (get_active_scheduler_count() < scheduler_count)
{
if(!atomic_exchange_explicit(&scheduler_count_changing, true,- memory_order_acquire))+ memory_order_seq_cst))
{
// in case the count changed between the while check and now
if(get_active_scheduler_count() < scheduler_count)+ {
// send signal to wake up next scheduler thread available
- ponyint_thread_wake(scheduler[get_active_scheduler_count()].tid,- scheduler[get_active_scheduler_count()].sleep_object);
+ if(ponyint_thread_wake(scheduler[get_active_scheduler_count()].tid,
+ scheduler[get_active_scheduler_count()].sleep_object))+ // if there was an error waking the thread+ // unlock the bool that controls modifying the active scheduler count+ // variable.+ atomic_store_explicit(&scheduler_count_changing, false,
+ memory_order_seq_cst);+ }
else
// if there are no scheduler threads left to unlock
// unlock the bool that controls modifying the active scheduler count
// variable.
atomic_store_explicit(&scheduler_count_changing, false,- memory_order_release);+ memory_order_seq_cst);
}
}
}@@ -407,6 +414,7 @@ static pony_actor_t* steal(scheduler_t* sched)
if (!block_sent)
{
uint32_t current_active_scheduler_count = get_active_scheduler_count();+
if (steal_attempts < current_active_scheduler_count)
{
steal_attempts++;@@ -421,7 +429,7 @@ static pony_actor_t* steal(scheduler_t* sched)
&& (current_active_scheduler_count > min_scheduler_count)
&& (!sched->terminate)
&& !atomic_exchange_explicit(&scheduler_count_changing, true,- memory_order_acquire))+ memory_order_seq_cst))
{
// let sched 0 know we're suspending
send_msg(sched->index, 0, SCHED_SUSPEND, 0);@@ -439,7 +447,7 @@ static pony_actor_t* steal(scheduler_t* sched)
// unlock the bool that controls modifying the active scheduler count
// variable
atomic_store_explicit(&scheduler_count_changing, false,- memory_order_release);+ memory_order_seq_cst);
// sleep waiting for signal to wake up again
ponyint_thread_suspend(sched->sleep_object);@@ -455,7 +463,7 @@ static pony_actor_t* steal(scheduler_t* sched)
// variable. this is because the signalling thread locks the control
// variable before signalling
atomic_store_explicit(&scheduler_count_changing, false,- memory_order_release);+ memory_order_seq_cst);
// dtrace resume notification
DTRACE1(THREAD_RESUME, (uintptr_t)sched);@@ -797,11 +805,26 @@ void ponyint_sched_maybe_wakeup()
// if we have some schedulers that are sleeping, wake one up
if((current_active_scheduler_count < scheduler_count) &&
!atomic_exchange_explicit(&scheduler_count_changing, true,- memory_order_acquire))+ memory_order_seq_cst))
{- // send signal to wake up next scheduler thread available
- ponyint_thread_wake(scheduler[current_active_scheduler_count].tid,- scheduler[current_active_scheduler_count].sleep_object);
+ // in case the count changed between the while check and now+ if(get_active_scheduler_count() < scheduler_count)+ {+ // send signal to wake up next scheduler thread available+ if(ponyint_thread_wake(scheduler[get_active_scheduler_count()].tid,
+ scheduler[get_active_scheduler_count()].sleep_object))+ // if there was an error waking the thread+ // unlock the bool that controls modifying the active scheduler count+ // variable.+ atomic_store_explicit(&scheduler_count_changing, false,
+ memory_order_seq_cst);+ }+ else+ // if there are no scheduler threads left to unlock
+ // unlock the bool that controls modifying the active scheduler count+ // variable.+ atomic_store_explicit(&scheduler_count_changing, false,
+ memory_order_seq_cst);
}
}
—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
<#2451 (comment)>,
or mute the thread
<https://github.com/notifications/unsubscribe-auth/AA-hHEpEH5L4YLS3i8OIxqMBp4Izku4eks5tHwXhgaJpZM4RM75f>
.
|
|
I reproduced using stdlib (mainly because I hadn't seen your pony-ring update at that time) with the following variant of your looping test (when compiling with No clue how long it took as I wasn't timing it and reproducing was more important but I don't think it took more than 5 - 10 mins most of the time. I ignored all standard output because my goal was to inspect the program state via lldb. Also, I made sure to add debug statements via standard error so they would show if they occurred (mainly for identifying edge cases/unexpected behavior that will become asserts). I checked to see if it was hung or not by polling ps ( Also, good news... I apparently don't know how to use pthreads condition variables correctly and that is why the |
dipinhora
added a commit
to dipinhora/ponyc
that referenced
this issue
Jan 6, 2018
Prior to this commit, the pthreads variant of the dynamic scheduler scaling functionality didn't use pthread condition variables correctly for the logic required. It relied on a single pthread condition variable for all threads to sleep against. Unfortunately, there's no way to wake up a specific thread when relying on pthread condition variables and the operating system is free to wake up any thread that is sleeping against a pthread condition variable. This resulted in out of order waking of sleeping threads which broke one of the invariants for how dynamic scheduler scaling is supposed to work. This commit fixes the code to create a separate pthread condition variable for each scheduler thread ensure that we can wake up a specific single thread at a time correctly. This commit also adds some error handling and asssertions to help catch any other logic error that might exist. Thanks to @winksaville for all his help in testing and debugging this. It likely wouldn't have been found/fixed so soon if it weren't for him. NOTE: While this fixes at least one of the causes of ponylang#2451, I don't believe it resolves the entire issue. Hopefully @winksaville is able to test and confirm if the issue still exists or not.
|
@winksaville I've opened up the PR (#2472) regarding the pthreads condition variable fix. It would be awesome if you're able to test it out. As an aside, to avoid any confusion regarding my "inside joke" from my comment last night, the inside joke was the comment about @SeanTAllen confirming that I'm a database guy. The rest of everything I wrote is actually my process and not a joke... 8*/ |
|
@winksaville the atomics patch to apply on top of the PR #2472 commit for testing: diff --git a/src/libponyrt/sched/scheduler.c b/src/libponyrt/sched/scheduler.c
index 6800ab7..f0bb952 100644
--- a/src/libponyrt/sched/scheduler.c
+++ b/src/libponyrt/sched/scheduler.c
@@ -118,7 +118,7 @@ static void wake_suspended_threads()
while (get_active_scheduler_count() < scheduler_count)
{
if(!atomic_exchange_explicit(&scheduler_count_changing, true,
- memory_order_acquire))
+ memory_order_seq_cst))
{
// in case the count changed between the while check and now
if(get_active_scheduler_count() < scheduler_count)
@@ -130,14 +130,14 @@ static void wake_suspended_threads()
// unlock the bool that controls modifying the active scheduler count
// variable.
atomic_store_explicit(&scheduler_count_changing, false,
- memory_order_release);
+ memory_order_seq_cst);
}
else
// if there are no scheduler threads left to unlock
// unlock the bool that controls modifying the active scheduler count
// variable.
atomic_store_explicit(&scheduler_count_changing, false,
- memory_order_release);
+ memory_order_seq_cst);
}
}
}
@@ -429,7 +429,7 @@ static pony_actor_t* steal(scheduler_t* sched)
&& (current_active_scheduler_count > min_scheduler_count)
&& (!sched->terminate)
&& !atomic_exchange_explicit(&scheduler_count_changing, true,
- memory_order_acquire))
+ memory_order_seq_cst))
{
// let sched 0 know we're suspending
send_msg(sched->index, 0, SCHED_SUSPEND, 0);
@@ -451,13 +451,13 @@ static pony_actor_t* steal(scheduler_t* sched)
// unlock the bool that controls modifying the active scheduler count
// variable
atomic_store_explicit(&scheduler_count_changing, false,
- memory_order_release);
+ memory_order_seq_cst);
// sleep waiting for signal to wake up again
ponyint_thread_suspend(sched->sleep_object);
bool scc = atomic_load_explicit(&scheduler_count_changing,
- memory_order_acquire);
+ memory_order_seq_cst);
// make sure scheduler_count_changing is true
pony_assert(scc);
@@ -478,7 +478,7 @@ static pony_actor_t* steal(scheduler_t* sched)
// variable before signalling
scc = false;
atomic_store_explicit(&scheduler_count_changing, scc,
- memory_order_release);
+ memory_order_seq_cst);
// dtrace resume notification
DTRACE1(THREAD_RESUME, (uintptr_t)sched);
@@ -814,7 +814,7 @@ void ponyint_sched_maybe_wakeup()
// if we have some schedulers that are sleeping, wake one up
if((current_active_scheduler_count < scheduler_count) &&
!atomic_exchange_explicit(&scheduler_count_changing, true,
- memory_order_acquire))
+ memory_order_seq_cst))
{
// in case the count changed between the while check and now
if(get_active_scheduler_count() < scheduler_count)
@@ -826,14 +826,14 @@ void ponyint_sched_maybe_wakeup()
// unlock the bool that controls modifying the active scheduler count
// variable.
atomic_store_explicit(&scheduler_count_changing, false,
- memory_order_release);
+ memory_order_seq_cst);
}
else
// if there are no scheduler threads left to unlock
// unlock the bool that controls modifying the active scheduler count
// variable.
atomic_store_explicit(&scheduler_count_changing, false,
- memory_order_release);
+ memory_order_seq_cst);
}
}
|
dipinhora
added a commit
to dipinhora/ponyc
that referenced
this issue
Jan 7, 2018
Prior to this commit, the pthreads variant of the dynamic scheduler scaling functionality didn't use pthread condition variables correctly for the logic required. It relied on a single pthread condition variable for all threads to sleep against. Unfortunately, there's no way to wake up a specific thread when relying on pthread condition variables and the operating system is free to wake up any thread that is sleeping against a pthread condition variable. This resulted in out of order waking of sleeping threads which broke one of the invariants for how dynamic scheduler scaling is supposed to work. This commit fixes the code to create a separate pthread condition variable for each scheduler thread ensure that we can wake up a specific single thread at a time correctly. This commit also adds some error handling and asssertions to help catch any other logic error that might exist. Thanks to @winksaville for all his help in testing and debugging this. It likely wouldn't have been found/fixed so soon if it weren't for him. NOTE: While this fixes at least one of the causes of ponylang#2451, I don't believe it resolves the entire issue. Hopefully @winksaville is able to test and confirm if the issue still exists or not.
|
@winksaville I've updated PR #2472 to fix some edge cases around quiescence. I think I might have done a force push out of habit so keep that in mind when you pull/merge. Given that I was able to reproduce the issue (at least for
Assuming the
|
|
@dipinhora, I ran pony-ring and it hung after about 20minutes, I then tried to replicate after rebuilding ponyc and ring again its run 2hrs without hanging. So I may have made a mistake the first run. In the second run I definitlely build ponyc with "make default_pic=true config=debug use=scheduler_scaling_pthreads" and ./ring was with run with the defaults in pony-ring's Makefile "./ring --ponynoblock --size 1000 --count 1000 --pass 10". I believe I did the same for the first run, but its possible I didn't. Anyway, the second run continues, and below is the output from gdb on the first run and here is the log file: |
|
@winksaville Thanks for the update. The hang/backtrace you're showing here looks like the original hang/backtrace from the It seems the PR has significantly improved things for at least the |
dipinhora
added a commit
to dipinhora/ponyc
that referenced
this issue
Jan 10, 2018
This effectively disables dynamic scheduler scaling by default. The main reason for this is issue ponylang#2451 which only surfaces when dynamic scheduler scaling is used. We can revert this and re-enable dynamic scheduler scaling by default once the issue is resolved.
dipinhora
added a commit
to dipinhora/ponyc
that referenced
this issue
Jan 10, 2018
Prior to this commit, the pthreads variant of the dynamic scheduler scaling functionality didn't use pthread condition variables correctly for the logic required. It relied on a single pthread condition variable for all threads to sleep against. Unfortunately, there's no way to wake up a specific thread when relying on pthread condition variables and the operating system is free to wake up any thread that is sleeping against a pthread condition variable. This resulted in out of order waking of sleeping threads which broke one of the invariants for how dynamic scheduler scaling is supposed to work. This commit fixes the code to create a separate pthread condition variable for each scheduler thread ensure that we can wake up a specific single thread at a time correctly. This commit also adds some error handling and asssertions to help catch any other logic error that might exist. Thanks to @winksaville for all his help in testing and debugging this. It likely wouldn't have been found/fixed so soon if it weren't for him. NOTE: While this fixes at least one of the causes of ponylang#2451, I don't believe it resolves the entire issue. Hopefully @winksaville is able to test and confirm if the issue still exists or not.
dipinhora
added a commit
to dipinhora/ponyc
that referenced
this issue
Jan 10, 2018
This effectively disables dynamic scheduler scaling by default. The main reason for this is issue ponylang#2451 which only surfaces when dynamic scheduler scaling is used. We can revert this and re-enable dynamic scheduler scaling by default once the issue is resolved.
SeanTAllen
pushed a commit
that referenced
this issue
Jan 10, 2018
Prior to this commit, the pthreads variant of the dynamic scheduler scaling functionality didn't use pthread condition variables correctly for the logic required. It relied on a single pthread condition variable for all threads to sleep against. Unfortunately, there's no way to wake up a specific thread when relying on pthread condition variables and the operating system is free to wake up any thread that is sleeping against a pthread condition variable. This resulted in out of order waking of sleeping threads which broke one of the invariants for how dynamic scheduler scaling is supposed to work. This commit fixes the code to create a separate pthread condition variable for each scheduler thread ensure that we can wake up a specific single thread at a time correctly. This commit also adds some error handling and asssertions to help catch any other logic error that might exist. Thanks to @winksaville for all his help in testing and debugging this. It likely wouldn't have been found/fixed so soon if it weren't for him. NOTE: While this fixes at least one of the causes of #2451, I don't believe it resolves the entire issue. Hopefully @winksaville is able to test and confirm if the issue still exists or not.
SeanTAllen
pushed a commit
that referenced
this issue
Jan 10, 2018
This effectively disables dynamic scheduler scaling by default. The main reason for this is issue #2451 which only surfaces when dynamic scheduler scaling is used. We can revert this and re-enable dynamic scheduler scaling by default once the issue is resolved.
dipinhora
added a commit
to dipinhora/ponyc
that referenced
this issue
Jan 10, 2018
Change dynamic scheduler scaling implementation in order to resolve the hangs encountered in ponylang#2451. The previous implementation assumed that signalling to wake a thread was a reliable operation. Apparently, that's not necessarily true (see https://en.wikipedia.org/wiki/Spurious_wakeup and https://askldjd.com/2010/04/24/the-lost-wakeup-problem/). Seeing as we couldn't find any other explanation for why the previous implementation was experiencing hangs, I've assumed it is either because of lost wake ups or spurious wake ups and redesigned the logic accordingly. Now, when a thread is about to suspend, it will decrement the `active_scheduler_count` and then suspend. When it wakes up, it will check to see if the `active_scheduler_count` is at least as big as its `index`. If the `active_scheduler_count` isn't big enough, the thread will suspend itself again immediately. If it is big enough, it will resume. Threads no longer modify `active_scheduler_count` when they wake up. `active_scheduler_count` must now be modified by the thread that is waking up another thread prior to sending the wake up notification. Additionally, since we're now assuming that wake up signals can be lost, we now send multiple wake up notifications just in case. While this is somewhat wasteful, it is better than being in a situation where some threads aren't woken up at all (i.e. a hang). This commit also includes a change inspired by ponylang#2474. Now, *all* scheduler threads can suspend as long as there is at least one noisy actor registered with the ASIO subsystem. If there are no noisy actors registered with the ASIO subsystem then scheduler 0 is not allowed to suspend itself.
dipinhora
added a commit
to dipinhora/ponyc
that referenced
this issue
Jan 14, 2018
Change dynamic scheduler scaling implementation in order to resolve the hangs encountered in ponylang#2451. The previous implementation assumed that signalling to wake a thread was a reliable operation. Apparently, that's not necessarily true (see https://en.wikipedia.org/wiki/Spurious_wakeup and https://askldjd.com/2010/04/24/the-lost-wakeup-problem/). Seeing as we couldn't find any other explanation for why the previous implementation was experiencing hangs, I've assumed it is either because of lost wake ups or spurious wake ups and redesigned the logic accordingly. Now, when a thread is about to suspend, it will decrement the `active_scheduler_count` and then suspend. When it wakes up, it will check to see if the `active_scheduler_count` is at least as big as its `index`. If the `active_scheduler_count` isn't big enough, the thread will suspend itself again immediately. If it is big enough, it will resume. Threads no longer modify `active_scheduler_count` when they wake up. `active_scheduler_count` must now be modified by the thread that is waking up another thread prior to sending the wake up notification. Additionally, since we're now assuming that wake up signals can be lost, we now send multiple wake up notifications just in case. While this is somewhat wasteful, it is better than being in a situation where some threads aren't woken up at all (i.e. a hang). This commit also includes a change inspired by ponylang#2474. Now, *all* scheduler threads can suspend as long as there is at least one noisy actor registered with the ASIO subsystem. If there are no noisy actors registered with the ASIO subsystem then scheduler 0 is not allowed to suspend itself.
dipinhora
added a commit
to dipinhora/ponyc
that referenced
this issue
Jan 19, 2018
Change dynamic scheduler scaling implementation in order to resolve the hangs encountered in ponylang#2451. The previous implementation assumed that signalling to wake a thread was a reliable operation. Apparently, that's not necessarily true (see https://en.wikipedia.org/wiki/Spurious_wakeup and https://askldjd.com/2010/04/24/the-lost-wakeup-problem/). Seeing as we couldn't find any other explanation for why the previous implementation was experiencing hangs, I've assumed it is either because of lost wake ups or spurious wake ups and redesigned the logic accordingly. Now, when a thread is about to suspend, it will decrement the `active_scheduler_count` and then suspend. When it wakes up, it will check to see if the `active_scheduler_count` is at least as big as its `index`. If the `active_scheduler_count` isn't big enough, the thread will suspend itself again immediately. If it is big enough, it will resume. Threads no longer modify `active_scheduler_count` when they wake up. `active_scheduler_count` must now be modified by the thread that is waking up another thread prior to sending the wake up notification. Additionally, since we're now assuming that wake up signals can be lost, we now send multiple wake up notifications just in case. While this is somewhat wasteful, it is better than being in a situation where some threads aren't woken up at all (i.e. a hang). Additionally, only use `scheduler_count_changing` for `signals` implementation of dynamic scheduler scaling. `pthreads` implementation now uses a mutex (`sched_mut`) in its place. We also now change logic to only unlock mutex in `pthreads` implementation once threads have been woken to avoid potential lost wake ups. This isn't an issue for the `signals` implementation and the unlocking of `scheduler_count_changing` can remain where it is prior to threads being woken up. This commit also splits out scheduler block/unblock message handling logic into their own functions (this is so that sched 0 can call those functions directly instead of sending messages to itself). This commit also includes a change inspired by ponylang#2474. Now, *all* scheduler threads can suspend as long as there is at least one noisy actor registered with the ASIO subsystem. If there are no noisy actors registered with the ASIO subsystem then scheduler 0 is not allowed to suspend itself because it is reponsible for quiescence detection. Lastly, this commit adds logic to allow a scheduler thread to suspend even if it has already sent a scheduler block message so that we can now suspend scheduler threads in most scenarios.
SeanTAllen
pushed a commit
that referenced
this issue
Jan 20, 2018
Change dynamic scheduler scaling implementation in order to resolve the hangs encountered in #2451. The previous implementation assumed that signalling to wake a thread was a reliable operation. Apparently, that's not necessarily true (see https://en.wikipedia.org/wiki/Spurious_wakeup and https://askldjd.com/2010/04/24/the-lost-wakeup-problem/). Seeing as we couldn't find any other explanation for why the previous implementation was experiencing hangs, I've assumed it is either because of lost wake ups or spurious wake ups and redesigned the logic accordingly. Now, when a thread is about to suspend, it will decrement the `active_scheduler_count` and then suspend. When it wakes up, it will check to see if the `active_scheduler_count` is at least as big as its `index`. If the `active_scheduler_count` isn't big enough, the thread will suspend itself again immediately. If it is big enough, it will resume. Threads no longer modify `active_scheduler_count` when they wake up. `active_scheduler_count` must now be modified by the thread that is waking up another thread prior to sending the wake up notification. Additionally, since we're now assuming that wake up signals can be lost, we now send multiple wake up notifications just in case. While this is somewhat wasteful, it is better than being in a situation where some threads aren't woken up at all (i.e. a hang). Additionally, only use `scheduler_count_changing` for `signals` implementation of dynamic scheduler scaling. `pthreads` implementation now uses a mutex (`sched_mut`) in its place. We also now change logic to only unlock mutex in `pthreads` implementation once threads have been woken to avoid potential lost wake ups. This isn't an issue for the `signals` implementation and the unlocking of `scheduler_count_changing` can remain where it is prior to threads being woken up. This commit also splits out scheduler block/unblock message handling logic into their own functions (this is so that sched 0 can call those functions directly instead of sending messages to itself). This commit also includes a change inspired by #2474. Now, *all* scheduler threads can suspend as long as there is at least one noisy actor registered with the ASIO subsystem. If there are no noisy actors registered with the ASIO subsystem then scheduler 0 is not allowed to suspend itself because it is reponsible for quiescence detection. Lastly, this commit adds logic to allow a scheduler thread to suspend even if it has already sent a scheduler block message so that we can now suspend scheduler threads in most scenarios.
|
@winksaville now that #2483 has been merged, can this issue be closed based on all your testing of that PR? |
|
@dipinhora, yes closing as I'm unable to reproduce this error with #2483 merged. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
It appears #2445 isn't solved. Previously I had run for 4 hours but with lots of debug output, yesterday I removed all the debug and then reran the simple while loop test:
And it hung after 18 minutes, so I used gdb to look at the code here are the logs:
I then ran it again this morning and it hung after about 6 mintes. Below is the gdb output and here are the logs. This is the first time I've seen 8 threads:
The text was updated successfully, but these errors were encountered: