Optional real time profiling support. #134

bawr · 2017-04-15T13:29:42Z

TL;DR: time.sleep() or waiting on IO can be detected now.

Rationale: vmprof is an excellent low-overhead profiler, but sometimes what we really want is to measure real time usage of the process, to detect situations when we're waiting for something else to happen.

That's especially handy when it comes to optimizing your code at a high-level, when the bottleneck is not in the Python code itself, but in the way it interacts with the rest of the system. Similarly, for that use case we want to sample all the threads, not just the thread that's currently running.

(Exact analysis of thread behaviour can be done downstream, because vmprof is already saving the thread ID for every stack snapshot.)

I'd love to support OSX, but I don't have a machine to test its signal behaviour.

Cheers!

planrich

Thanks again for your contribution! I like the changes. I will help with Mac OS X and see if I can find some API to the same on Mac.

planrich · 2017-04-15T13:49:43Z

src/vmprof.h

@@ -26,6 +26,7 @@
 #define PROFILE_LINES  '\x02'
 #define PROFILE_NATIVE '\x04'
 #define PROFILE_RPYTHON '\x08'
+#define PROFILE_REAL_TIME '\x0f'


"\x0f" is binary "0000 1111", I think it should be "\x10" for binary "0001 0000". If I remember correctly those macros specify bits for flags...

D'oh! Yes, this is wrong, and should be '\x10'.

planrich · 2017-04-15T14:10:17Z

src/vmprof_main.h

@@ -175,11 +179,43 @@ static PY_THREAD_STATE_T * _get_pystate_for_this_thread(void) {
 }
 #endif

+#ifdef VMPROF_LINUX
+static void broadcast_signal_for_threads(pid_t pid)


I do not see opendir in the list of signal safe functions. Neither is readdir_r and atoi. I might be wrong, but we need to double check if they are signal safe! Maybe there is another API that enumerates the thread ids of the process without asking the disk!

Ah, good call. In turn:

What can we do if they're not signal safe?

I've actually tried to find another API for thread enumeration and failed, I don't like the readdir solution, either. (Although technically it's asking the kernel, not the disk.)

Yes, true the kernel delivers that info. If they calls are not signal safe, the program most likely freezes or crashes.
We could think about hooking into thread creation, that would register/unregister the thread id. Though a solution asking the kernel would be much better.

planrich · 2017-04-15T14:16:40Z

src/vmprof_main.h

+    // For the real timer, the signal gets delivered to the main thread, seemingly always.
+    // Consequently if we want to sample all threads, we need to forward the signal with tgkill.
+    if ((signal_type == SIGALRM) && (pid == tid)) {
+        broadcast_signal_for_threads(pid);


I'm fine with this hack, I need to test it a little though. One question I have:

signal A (to main thread tid == pid == 1) arrives and uses tgkill to send a new signal to thread 2-3... (assuming there are 3 threads (1-3))

signal B to thread 2... OK

signal C to thread 1 (issuing more signals to thread 2 and 3)

signal D to thread 3 ...

Will thread 3 get another signal initiated by signal C? Is it swallowed?
If the signal dispatching takes to long I think that should be recoginized...

I'm pretty sure these signals are allowed to be coalesced / swallowed, yes.
I don't think there's a good way to detect this, but I might be wrong?

Possible workarounds:

Ignore it, when we read the profile later we can check for lost signals / stack traces if we know the threads were present for the whole profile duration. If we don't know that, it gets tricky.

Trigger a real-time signal from the main thread instead, and set other threads to catch that real-time signal instead of the SIGALRM from the timer?

Other?

bawr · 2017-04-15T19:04:39Z

Hmm. Instead of waiting for signals and re-broadcasting them from the signal handler, can we instead spawn a designated signalling thread, whose only function is to act as a timer and deliver the signals to other threads in the process?

Then we could use thread-unsafe functions, but we'd need to handle forks correctly, spawning another signalling thread per-process, I guess.

bawr · 2017-04-15T21:47:53Z

Here's a simplified verion that's maybe more suitable to start with - we pin ourselves to the thread that requested the profile, and make sure all profiling is done on that thread, ignoring others. A better option for thread handling could be the next version of the feature, maybe?

Ideally, in the fullness of time, we'd go from supporting one real-time thread, to multiple threads, to multiple threads and/or processes, but it's useful to start small. I also added some simple tests to show that it's working, and how.

bawr · 2017-04-15T22:11:24Z

(Note: even with obvious small fixes, this still fails the tests on RPython, I'll probably need a hand there.)

bawr · 2017-04-16T11:10:30Z

Aaaand here's a version where we perform no signal-unsafe functions in the handler.

We can register and unregister threads from sampling, and in real time mode it's up to the caller.

bawr · 2017-04-16T13:02:34Z

Here's a small patch for PyPy, now all the tests pass over there, too.
https://gist.github.com/bawr/d80d99278b3619a6646c80646fa0dcf5

bawr · 2017-04-21T16:21:00Z

Any progress on this?

I'll be free to do some open-source stuff within the next week, so if I can make some changes to push it forward, I'll do just that. In particular, if we're fine with spawning a designated signalling thread, I already know how to support both Linux and MacOS, without relying on signal delivery details on Linux. ;)

planrich · 2017-04-22T13:38:47Z

Looks good to me. Though the osx support is missing right? I'll merge it if we both support linux & osx.

bawr · 2017-04-28T17:00:56Z

Seems to work on OSX now. 🎉

In other words - I think it's merge-ready? Probably want to squash it, though.

planrich

Thanks, I have two minor questions/comments otherwise I'm happy to merge it

planrich · 2017-04-29T12:14:25Z

src/vmprof_main.h

+    pthread_t tid;
+    while (i < thread_count) {
+        tid = threads[i];
+        if (pthread_equal(tid, self))


Can we add curly brackets for if & else here? it is really hard to read and potential risk for errors

planrich · 2017-04-29T12:18:15Z

src/vmprof_main.h

+    // Consequently if we want to sample multiple threads, we need to forward this signal.
+    if (signal_type == SIGALRM) {
+        if (is_main_thread() && broadcast_signal_for_threads()) {
+            __sync_lock_release(&spinlock);


Unsure why the spinlock is released here. It occurs to me as if the spinlock is only used to protect the threads array?

Yes and no - it's used to protect whatever it was normally protecting and the threads array.

If we don't need to sample the main thread (when it's not registered for real-time sampling in the first place), we can bail out early here, because we just need to broadcast the signal - but we still need to release the spinlock before the immediate return.

bawr · 2017-04-29T13:29:24Z

Rebased against upstream master and addressed the comments. Cheers! ;)

planrich · 2017-05-01T16:19:20Z

Thanks again!

bawr · 2017-05-02T05:57:07Z

Cool! Could you maybe make a .dev version with this available on pip?

I'd like to test some stuff about it later, and it's much simpler to set up if I can just pip install. ;)

planrich · 2017-05-02T12:29:08Z

Yes I did, there is 0.4.6.dev0

planrich · 2017-06-05T21:03:55Z

I'm currently rewriting some C code in Python. However I noticed that real time profiling is now some times not working. see: https://travis-ci.org/vmprof/vmprof-python/jobs/239723456

Could you maybe have a look at that? What is the reason for that?

bawr · 2017-06-06T15:18:50Z

Interesting... I can have a proper look over the weekend, will ping you earlier if it's something obvious.

Did you only notice it failing in tests, or did something weird happen with some real-world case as well?

planrich · 2017-06-06T16:13:08Z

Thanks. Currently I disabled one test with xfail...

…

On Tue, Jun 6, 2017, 11:18 AM Bartosz Wróblewski ***@***.***> wrote: Interesting... I can have a proper look over the weekend, will ping you earlier if it's something obvious. — You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub <#134 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAcL2gcfsbOTYiSZ-3v-422QaxjJem2lks5sBW3egaJpZM4M-WTQ> .

bawr force-pushed the real-time branch 3 times, most recently from 6b0d5cb to c4bc027 Compare April 15, 2017 14:04

planrich reviewed Apr 15, 2017

View reviewed changes

bawr force-pushed the real-time branch from c4bc027 to aec8991 Compare April 15, 2017 19:02

bawr force-pushed the real-time branch from a74e13b to e309753 Compare April 15, 2017 22:08

bawr force-pushed the real-time branch from 916e5dd to b996031 Compare April 28, 2017 16:28

planrich requested changes Apr 29, 2017

View reviewed changes

bawr added 5 commits April 29, 2017 15:21

Real time profiling support.

975b51d

Real time profiling, simple version.

ad7d9a2

Real time profiling, thread version.

a488f4f

Real time profiling, somewhat portable.

5001a6d

Minor clarity enchancement.

a53d732

bawr force-pushed the real-time branch from 2b4733f to a53d732 Compare April 29, 2017 13:28

planrich merged commit ccae9f7 into vmprof:master May 1, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Optional real time profiling support. #134

Optional real time profiling support. #134

bawr commented Apr 15, 2017

planrich left a comment

planrich Apr 15, 2017

bawr Apr 15, 2017

planrich Apr 15, 2017

bawr Apr 15, 2017

planrich Apr 15, 2017

planrich Apr 15, 2017

bawr Apr 15, 2017

bawr commented Apr 15, 2017

bawr commented Apr 15, 2017

bawr commented Apr 15, 2017

bawr commented Apr 16, 2017

bawr commented Apr 16, 2017

bawr commented Apr 21, 2017 •

edited

Loading

planrich commented Apr 22, 2017

bawr commented Apr 28, 2017 •

edited

Loading

planrich left a comment

planrich Apr 29, 2017

bawr Apr 29, 2017

planrich Apr 29, 2017

bawr Apr 29, 2017

bawr commented Apr 29, 2017

planrich commented May 1, 2017

bawr commented May 2, 2017

planrich commented May 2, 2017

planrich commented Jun 5, 2017

bawr commented Jun 6, 2017 •

edited

Loading

planrich commented Jun 6, 2017 via email

Optional real time profiling support. #134

Optional real time profiling support. #134

Conversation

bawr commented Apr 15, 2017

planrich left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

bawr commented Apr 15, 2017

bawr commented Apr 15, 2017

bawr commented Apr 15, 2017

bawr commented Apr 16, 2017

bawr commented Apr 16, 2017

bawr commented Apr 21, 2017 • edited Loading

planrich commented Apr 22, 2017

bawr commented Apr 28, 2017 • edited Loading

planrich left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

bawr commented Apr 29, 2017

planrich commented May 1, 2017

bawr commented May 2, 2017

planrich commented May 2, 2017

planrich commented Jun 5, 2017

bawr commented Jun 6, 2017 • edited Loading

planrich commented Jun 6, 2017 via email

bawr commented Apr 21, 2017 •

edited

Loading

bawr commented Apr 28, 2017 •

edited

Loading

bawr commented Jun 6, 2017 •

edited

Loading