Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add Fiber Running / Fiber Switch events to the marker chart #107

Merged
merged 8 commits into from
Nov 28, 2024

Conversation

tenderlove
Copy link
Collaborator

Fiber Running and Fiber Switch events give us information about what Fibers in the system are doing. The Fiber Running span in the marker chart allow us to easily select work that a particular Fiber is doing, where the Fiber Switch event allows us to identify why a Fiber changed.

Here is a sample program we'll profile with Vernier:

require "async"
require "async/queue"

def measure
  x = Process.clock_gettime(Process::CLOCK_MONOTONIC)
  yield
  Process.clock_gettime(Process::CLOCK_MONOTONIC) - x
end

def fib(n)
  if n < 2
    n
  else
    fib(n-2) + fib(n-1)
  end
end

# find fib that takes ~50ms
fib_i = 50.times.find { |i| measure { fib(i) } >= 0.05 }
sleep_i = measure { fib(fib_i) }

Async {
  latch = Async::Queue.new

  workers = [
    Async {
      latch.pop # block until ready to measure

      100.times {
        sleep(sleep_i)
        # stalls happen here. This worker wants to be scheduled so it can
        # continue the loop, but will be blocked by another worker executing fib
      }
    },
    Async {
      latch.pop # block until ready to measure

      100.times { fib(fib_i) }
    },
  ]

  2.times { latch << nil }
  workers.each(&:wait)
}

The sample program has one Fiber that is CPU bound. It's calculating Fib in a loop. The other Fiber is simulating IO work by calling sleep.

Here I've highlighted the marker where we have one Fiber using the CPU for a long time:

Screenshot 2024-11-19 at 4 20 51 PM

Selecting that marker lets us verify that in fact it's spending time calculating Fib:

Screenshot 2024-11-19 at 4 23 17 PM

@jhawthorn
Copy link
Owner

jhawthorn commented Nov 25, 2024

I realized only after we wrote this 😅, I think we need to scope the pairing of fiber switch events and converting them to the "fiber running" spans by thread.

jhawthorn and others added 5 commits November 27, 2024 16:54
This records Fiber switch events in the marker chart.  We later convert
these to intervals so that you can see what a fiber is doing when it has
the CPU.
"Fiber Running" spans allow us to isolate the profile for a particular
Fiber where "Fiber Switch" events give us the stack trace at the point
where the Fiber yielded.

We can use the Fiber Running spans to see what a Fiber is doing, and the
Fiber Switches to see why a Fiber switched
Previously we originally had the markers split, then combined them
together, and then split them again. Let's just not
@jhawthorn
Copy link
Owner

I refactored a whole bunch so that keeping things scoped by thread wasn't so awkward so 🤞 that didn't break too much

@jhawthorn jhawthorn merged commit 243c9d4 into jhawthorn:main Nov 28, 2024
11 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants