search

MiniProfiler / rack-mini-profiler

Profiler for your development and production Ruby rack apps.
MIT License
3.7k stars 402 forks source link

Flamegraph & % in sql queries don't show up #506

Closed jaydorsey closed 3 years ago

jaydorsey commented 3 years ago

I'm seeing some odd behavior in the 2.3.2 release where:

I think this is maybe a bug, or regression, so I've provided some information to try to describe what I expect to see, what I actually see, and why I expect what I expect (tldr; it's what I've seen in earlier versions of rack-mini-profiler)

I've got a demo repository & replication instructions here: https://github.com/jaydorsey/profiler

I think this is a fairly vanilla setup, but I'm testing an API endpoint. Maybe I'm just using the tool incorrectly? Another set of eyes would be appreciated.

Examples of what rack-mini-profiler shows in the latest gem release:

No SQL queries (in any of the requests that show up):

image

They do show up in the server logs:

image

The flamegraphs have no meaningful data:

image

I've tried to curl the endpoint to confirm it loads fine; no server errors as far as I can tell.

Things I've tried:

This behavior happens in another repository as well (a real application that has many more dependencies)

I looked thru the diff between 2.3.1 and 2.3.2 and I don't see anything at all SQL related that might cause this. Another engineer confirmed the same behavior on their computer (to try to confirm it wasn't a local setting)

Was wondering if anyone else can confirm the behavior and/or maybe sees something that I missed?

One other thing I noted when looking at stackprof itself:

image

The mode doesn't appear configurable in rack-mini-profiler so I'm not sure if this was intentional or if I'm just using the tool incorrectly.

* No async-flamegraph; assuming that was added recently

smridge commented 3 years ago

I've cloned your repo, while I was waiting for the setup I noticed in the gem README

NOTE: Be sure to require rack_mini_profiler below the pg and mysql gems in your Gemfile. rack_mini_profiler will identify these gems if they are loaded to insert instrumentation. If included too early no SQL will show up.

smridge commented 3 years ago

I definitely think this is a regression. Using your repo:

gem version 2.3.2

bad

gem version 2.3.1

good

SamSaffron commented 3 years ago

thanks, we will have a look!

OsamaSayegh commented 3 years ago

Hey @jaydorsey / @smridge

This is actually by design. When you ask Mini Profiler to generate a flamegraph for a request, it doesn't record SQL timings:

https://github.com/MiniProfiler/rack-mini-profiler/blob/4e6d463b03a6979037171ae2866a85e11fc344df/lib/mini_profiler/profiler.rb#L357-L357

The reason for that is to keep Mini Profiler's methods that are responsible for generating SQL timings out of the flamegraph. If we were to remove that line and enable SQL timings when generating flamegraphs, you would see frames like these (#record_sql and its children) scattered all over your flamegraphs:

(screenshot taken from my development Discourse instance)

I've created PR #507 to add a note in the README about this behavior.

smridge commented 3 years ago

Awesome, thank you for updating the README!

jaydorsey commented 3 years ago

This is actually by design. When you ask Mini Profiler to generate a flamegraph for a request, it doesn't record SQL timings:

Thank you, this makes sense for the SQL timing data to be empty.

I'll take another look thru the codebase & my setup to see if I can make sense of the missing/empty flamegraph data. I may have been distracted by the two separate concerns and missed something in my configuration.