[PROF-9342] Introduce profiler workaround for Ruby Dir interruption bug

[ivoanjo]

What does this PR do?

This PR introduces the "dir interruption" workaround to the profiler. This workaround targets an issue in the Ruby Dir class that was originally reported by a customer in #3450 .

In short, 13 of the Ruby Dir class APIs can be, in rare situations, interrupted by the profiler's sampling mechanism. This interruption makes Ruby incorrectly think that it has reached the end of a directory it is reading, so this could mean for the affected APIs:

• Ruby would return that a directory is empty when it isn't
• Ruby would return only some, but not all of the files in the directory

The "dir interruption" workaround prevents this issue from happening by monkey patching the affected APIs to wrap the critical regions with calls to CpuAndWallTimeWorker._native_hold_interruptions, CpuAndWallTimeWorker._native_resume_interruptions, preventing the profiler from interrupting those APIs at the wrong time.

Because all stable Ruby versions are known to be affected by this issue, the workaround is applied by default. This PR adds a new setting that can be used to turn it off:

• DD_PROFILING_DIR_INTERRUPTION_WORKAROUND_ENABLED=false
• Datadog.configure { |c| c.profiling.advanced.dir_interruption_workaround_enabled = false }

Motivation:

Avoid triggering bug out-of-the box.

Additional Notes:

I also plan to report the issue upstream, and hopefully work with the Ruby core team to fix it.

Update: reported upstream as https://bugs.ruby-lang.org/issues/20586 and https://bugs.ruby-lang.org/issues/20587 .

The "no signals" workaround documented in our FAQ also prevents this issue from happening, but at the cost of lower quality data gathering, and since this affects every Ruby version, we didn't want to have to toggle the "no signals" workaround enabled by default.

How to test the change?

This PR includes a lot of test coverage.

I've also tested the monkey patch with the Ruby standard library specs ( https://github.com/ruby/spec/tree/master/core/dir ) on my local machine. I'll follow up this PR with a PR on the https://github.com/datadog/prof-correctness/ to automatically add this to CI there, as otherwise it was a bit awkward to add to the dd-trace-rb repository.

For datadog folks, I've setup a simple GCS bucket than can be used to trigger this issue:

$ gcsfuse test_fs_dd_trace_rb fuse-testing/
$ ls fuse-testing/
hello.txt  test.html  test.txt
# Trigger issue without the workaround
$ DD_PROFILING_ENABLED=true DD_PROFILING_DIR_INTERRUPTION_WORKAROUND_ENABLED=false bundle exec ddprofrb exec ruby -e "Datadog::Profiling.wait_until_running; pp Dir.children('fuse-testing/')"
[]
# Trigger issue with workaround
$ DD_PROFILING_ENABLED=true DD_PROFILING_DIR_INTERRUPTION_WORKAROUND_ENABLED=true bundle exec ddprofrb exec ruby -e "Datadog::Profiling.wait_until_running; pp Dir.children('fuse-testing/')"
["hello.txt", "test.html", "test.txt"]
# The "no signals" workaround can be used instead of the "dir interruption" workaround
$ DD_PROFILING_ENABLED=true DD_PROFILING_DIR_INTERRUPTION_WORKAROUND_ENABLED=false DD_PROFILING_NO_SIGNALS_WORKAROUND_ENABLED=true bundle exec ddprofrb exec ruby -e "Datadog::Profiling.wait_until_running; pp Dir.children('fuse-testing/')"
W, [2024-06-14T15:30:09.108975 #948820]  WARN -- datadog: [datadog] Profiling "no signals" workaround enabled via configuration. Profiling data will have lower quality.
["hello.txt", "test.html", "test.txt"]

[codecov-commenter]

Codecov Report

Attention: Patch coverage is 58.54271% with 165 lines in your changes missing coverage. Please review.

Project coverage is 97.89%. Comparing base (4cd328d) to head (259e134).
Report is 7 commits behind head on master.

Files	Patch %	Lines
lib/datadog/profiling/ext/dir_monkey_patches.rb	21.96%	135 Missing ⚠️
...c/datadog/profiling/ext/dir_monkey_patches_spec.rb	82.14%	30 Missing ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##           master    #3720      +/-   ##
==========================================
- Coverage   98.11%   97.89%   -0.22%     
==========================================
  Files        1235     1237       +2     
  Lines       73749    74146     +397     
  Branches     3560     3594      +34     
==========================================
+ Hits        72357    72588     +231     
- Misses       1392     1558     +166     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[lloeki]

Shouldn't it be in an ensure as well?

[ivoanjo]

🤔 I don't think so...? It's ok to deliver signals during exception handling, so if an exception gets raised in the client code, it should be fine for the profiler to continue operating from them on, since no more directory calls will be made by Ruby.

Or do you mean making sure that _native_hold_interruptions never raises or something similar?

[lloeki]

I really don't know, hence why I ask ;)

I'm basing myself on the following outline:

begin
  # [A+] enter our code: hold
  super do
    # [B-] exit our code back to not-our-code: resume
    yield
    # [B+] enter our code: hold
  end
ensure
  # [A-] exit our code: resume
end

On the super happy path the execution order is [A+] [B-] [B+] [A-].

But if yield raises it becomes [A+] [B-] [A-], which in my mind triggers some "consistency" alarms and makes me wonder about internal details:

• what happens when _native_resume_signals is called twice in a row? is it a NOOP? is it doing work twice (e.g invoking a syscall) but idempotent?
• there seems to be work to be protected after yield (because of that [B+]) and before method exit ([A-]) so I presume that work is in super, but if yield raises there may be work to protect too in a hypothetical ensure block inside that super too? Or is [B+] entirely superfluous even in the happy yield case?

Conversely, imagine an abstraction like so:

module SignalHolder
  def hold
	# hold
    yield
  ensure
    # resume
  end

  def ignore
    # resume
    yield
  ensure
    # hold
  end
end

And the code becoming:

SignalHolder.hold do
  super { SignalHolder.ignore { yield } }
end

The above is not even a suggestion it's merely to materialise and compare the kind of structural "consistency".

It could simply instead just need a comment to prevent the mind tripwire or help someone who would refactor this code in the future for some reason.

But really, I'd say it's fine to merge if you're confident and my concerns are unwarranted.

[ivoanjo]

Got it, thanks for explaining!

So, in parts:

• Yes, it's OK if the yield raises. Specifically:

  • We can call _native_resume_signals many times in a row.

    As you suspected, it leads to pthread_sigmask which I believe on Linux will lead to the rt_sigprocmask system call being called.
    I've included a benchmark in the PR of what the cost of this is, and here's a run I did:

    ruby 3.1.4p223 (2023-03-30 revision 957bb7cb81) [x86_64-linux]
    Warming up --------------------------------------
           hold / resume   391.856k i/100ms
    Calculating -------------------------------------
           hold / resume      3.829M (± 1.9%) i/s -     38.402M in  10.033530s
    

    ...so I think we're fine if we end up calling it a few more times than strictly needed.

  • The root of the issue in the Ruby VM happens because in the affected APIs Ruby silently interprets an interruption as "end of folder/empty folder". When an exception is being raised, the iteration will stop anyway, so there's no longer a concern of the interruption causing a semantic mismatch (at least that I can see).

I've pushed 259e134 to add this note to the code as in hindsight I agree it was not very clear before (and hopefully this clarifies it)

[lloeki]

Should this be more functionally named? ("what" instead of "how")

WDYT of dir_signal_masking?

[ivoanjo]

I went with this name because I know it will show up in the profiling flamegraph for customers.

My thinking is that it's clearer if you see "oh, why is there a datadog thing here? ah, it's monkey patching my uses of dir". Signal masking makes me think a bit more along hte lines of "what is this signal masking thing? what is masking anyway?".

[lloeki]

Ha, interesting! I was thinking that if I saw that in a stack trace or something I would wonder "why is Datadog monkey patching dir stuff at all?". In a way "monkey patching" is how but not what/why. In a way it's also redundant with ext, the sort of conventional way to say "this folder contains things that extend stuff". dir_signal_fix maybe?

But at this stage that's becoming bikeshedding and certainly not a blocker. Feel free to move forward.

Adding links to upstream issues in the comment at the top of the file would help too I think (I reread it and with only the Datadog issue link it makes it like this is a Datadog issue when it's really an upstream issue)

[ivoanjo]

I think the joke about naming things being hard applies here >_>. I suspect/fear just relying on ext/ may be too subtle (e.g. when you're looking a flamegraph), but am open to changing if folks get confused about the current name.

+1 I've added a link to the upstream ticket in 259e134.

[ivoanjo]

I've updated the PR description with links to the upstream reports for this issue https://bugs.ruby-lang.org/issues/20586 / https://bugs.ruby-lang.org/issues/20587 .