Skip to content

Conversation

@rmosolgo
Copy link
Owner

@rmosolgo rmosolgo commented Dec 4, 2025

This improves DetailedTrace in 3 ways:

  • Its .inspect call is now customizable. You can subclass DetailedTrace and provide a new implementation for def inspect_object(object). Arguably this isn't good enough since under the hood it still creates DebugAnnotations. Also note that only instances of non-built-in classes get routed to that method. String, Symbol, true, false, nil, numbers, Hash, Array, Module (others?) all are still handled by the tracer directly.
  • .inspect calls are now outside the spans that they relate to. Previously, time spent building inspect strings would get counted along field execution (maybe also data loader sources, analysis, and validation).
  • Debug annotations can be complete turned off. Always with use ..., debug: false or per-query with context: { detailed_trace_debug: false }.

Before, .inspect is silently included in field span:

<img width="568" height="140" alt="image" src="https://github.com/user-attachments/assets/484afaa5-34b0-4783-b6eb-50eaa4972b73" />

After, .inspect is separate from application code and gets its own span:

<img width="841" height="175" alt="Screenshot 2025-12-04 at 3 55 21 PM" src="https://github.com/user-attachments/assets/1c4c2ed3-bf63-4a9b-9928-8f2317dedcf8" />

Basically, those pink parts were previously included in the preceding field execution spans, but now they aren't.

To accomplish this, I had to make sure that, for TYPE_SLICE_END packets, it captures the timestamp before creating the debug_annotations: ..., then pass the timestamp into the packet method. I also handled extra_counter_values: this way so that asking Ruby about allocations wouldn't get lumped in with field execution time.

TYPE_SLICE_BEGIN packets get this for free because Ruby evaluates the arguments for the method first, including values for debug_annotations: and counter_values:, then calls the method with those objects, where ts grabs the current timestamp.

Also, inspect spans are tagged with the debug field that triggered the inspect. In this example, it was result:

image

It could also be arguments, fetch keys, or any ActiveSupport::Notifications payload key.

Fixes #5423

@rmosolgo rmosolgo added this to the 2.5.15 milestone Dec 4, 2025
@rmosolgo rmosolgo merged commit 156f6f3 into master Dec 5, 2025
12 of 13 checks passed
@rmosolgo rmosolgo deleted the perfetto-better-inspect branch December 5, 2025 16:18
@rmosolgo rmosolgo changed the title Improve .inspect support for DetailedTrace Improve .inspect support for DetailedTrace, support debug: false Dec 5, 2025
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.

Misleading Perfetto trace

2 participants