$blackfire->createProbe() usually does not have a timeline

[weaverryan]

Hi!

Me again. I'm trying to use $blackfire->createProbe() (same as in #44). I first tried to create a probe in my controller and then later refactored it to a subscriber so that we could create the probe earlier in the request (to profile more code) and close it all the way at the end. This seems to work fine, except that the timeline is usually (but not always) broken. When it does work, it doesn't make a lot of sense.

Here's the reproducer: https://github.com/SymfonyCasts/blackfire/tree/testing-manual-subscriber-probe

The src/EventSubscriber/BlackfireAutoProfileSubscriber.php file is responsible for creating and then closing the probe. Usually, the timeline is completely empty:

When it's not, it's weird:

Notice that RequestEvent takes up the entire length of the timeline... and in the bottom right, you can see ResponseEvent, which appears to be inside RequestEvent.

Am I trying to improperly use the SDK? If so, how should createProbe() be used?

Thanks!

[weaverryan]

Ping! :) Any info?

[lolautruche]

Hello @weaverryan . Have your tried again with the latest version of the probe and the agent?

[weaverryan]

I'm already on the latest of both - I upgraded to fix #44 - and just verified that my versions match the ones on https://blackfire.io/docs/up-and-running/update?action=update&mode=full&location=local&os=macos&language=php&agent=8d29d6e1-3315-45a9-b274-1158f94158f0

Are you able to replicate this with my code above? Or is this only me?

[lolautruche]

Ping @iamluc

[iamluc]

Hi Ryan!

I cannot reproduce the "empty" timeline issue. Could you give me a link of a broken profile?

Also when you enable a probe manually, Blackfire keeps the call stack from the entrypoint to the probe activation. As the duration of these functions is unknown, the rows from run_init::public/index.php to Probe::enable take the full width of the Timeline.

I guess that's something we could improve.

[weaverryan]

EMPTY TIMELINE

Here's the empty timeline: https://blackfire.io/profiles/ccc4dc35-ca8f-4cc3-8f77-ecb564c4fbc3/graph

I can navigate around this by not showing the timeline. It just makes me nervous that I'm doing something wrong... and so may be drawing incorrect conclusions from the call graph.

ODD TIMELINE

And here is the other timeline that looked weird to me (the screenshot above): https://blackfire.io/profiles/625f3b29-563e-4eaf-abdf-7a9f6adce04c/graph

Also when you enable a probe manually, Blackfire keeps the call stack from the entrypoint to the probe activation. As the duration of these functions is unknown, the rows from run_init::public/index.php to Probe::enable take the full width of the Timeline.

The key problem is that this shows the Response event happening inside (under) the RequestEvent. Is it fair to say that this is simply a "display bug" for this situation? Basically because we are doing this "sort of" weird thing of profiling only part of the request, it's a bit challenging to represent it fully on the timeline. Is that accurate?

Thanks!

[iamluc]

Just to let you know that I think we found the bug that causes the empty timeline.

I hope the fix is going to be release soon. I will let you know.

[weaverryan]

Thank you! Please let me know when it is :).

[weaverryan]

And actually, is it just a display bug (e.g. on the website) or something with how the data is collected in the probe? If it's just a display bug, then I can continue my work before the fix.

Thanks!

[iamluc]

The new release (1.29.5) should fix the empty timeline issue. Merry Christmas :santa: :smile_cat:

[weaverryan]

Hahaha, Thank you! I will test it soon! Merry Christmas indeed ;)

[marcw]

@weaverryan Are we ok on this issue?