Samples skewed by Thread#join

[igorwwwwwwwwwwwwwwwwwwww]

I'm working on rolling out stackprof for gitlab.com (ref), and started testing on our canary hosts today.

I got very odd results, for some reason a Thread#join from puma kept showing up as 80% of the profile.

In an attempt to verify the accuracy of this, I ran a perf record while running stackprof, in order to get a C-level flamegraph and possibly be able to correlate. Luckily, perf record stacks include thread names, making it feasible to compare the flamegraphs directly.

In the perf profile, that very same Thread#join code path shows up as consuming only 1.4% of all samples.

I am seeing stackprof_job_handler in that stack though, triggered by the RUBY_VM_CHECK_INTS_BLOCKING call in ruby's thread_join_sleep. This makes me wonder if the SIGPROF is waking up the waiting thread, and then that thread instantly runs the signal handler (presumably before going back to sleep), leading to that code path being over-represented in the stackprof profile.

That is just a hypothesis. Would love to get more input on this. Have any of you seen anything similar?

Flamegraphs:

• stackprof:
  flamegraph.svg.gz
• perf:
  flamegraph.meta.svg.gz

Possibly related to #25 and #91.

[igorwwwwwwwwwwwwwwwwwwww]

Oh wow, I figured it out while preparing a reproduce case.

For some reason I was under the impression that the default mode was :cpu. Turns out, it's actually :wall. 🤦‍♀️

That would explain it. Switching to :cpu should fix this. Sorry for the noise! :)

[igorwwwwwwwwwwwwwwwwwwww]

Ah, README currently claims :cpu to be the default mode. But based on this line this does not appear to be the case, at least for StackProf.start().

One of the two should probably be corrected for accuracy.