spans based on [:phoenix, :endpoint] vs [:cowboy, :request]

[bryannaegele]

opentelemetry-beam/opentelemetry_phoenix#28

[dvic]

I'd suggest renaming this issue to 'create spans using a plug and not telemetry', to summarize from the previous issue:

The Plug.Telemetry documentation says: The :stop event is not guaranteed to be emitted in all error cases, so this Plug cannot be used as a Telemetry span. In my opinion, using two custom plugs (one for Endpoint and one for Router) using __before_compile__ is the way to go and I can work on this. Once you figure out what you want to do: let me know :)

[dvic]

By the way: I just came across https://hexdocs.pm/phoenix/Phoenix.Router.html#route_info/4. This can be used to compute the span name upfront right? (which is nice for an approach as the one I described above)

[bryannaegele]

I'd suggest renaming this issue to 'create spans using a plug and not telemetry'
So creating spans from a separate plug is just replicating what Plug.Telemetry already does; you're swapping one plug for another. None of the available information changes and the implementation would be the exact same either way, so adding another plug isn't a path I see going down.

There was a comment about the reliability of telemetry events for tracing from one of the repos which is a bit misleading. The intent of that comment is that Phoenix can fail somewhere lower in the callstack of plugs or in the application code which aborts the request and bypasses going back out the plug pipelines. One thing to note about tracing with otel in general is a process crashing before a span is closed results in that span essentially being lost. We have discussed the possibility of allowing users to mark a span to be monitored but this will add overhead and we haven't had time to tackle it.

This can be used to compute the span name upfront right?

The information generated by route_info is what is exposed in the phoenix router dispatch telemetry event. I don't believe it is possible to pre-compute a span name as we don't know what the route is until the request has been matched by the router.

Going back to the original issue, we can summarize the problem as phoenix spans not encompassing the entirety of the actual request time. The furthest out we can get in the BEAM is at cowboy but there is very little usable info at the cowboy level; many of the attributes we're looking for and the ability to name the span meaningfully to the spec are only available after further processing by Plug.Match in a pure Plug implementation and Phoenix events, such as the router dispatch event.

What we're looking for in the end is a span started at the cowboy level and then enhanced as the request travels through the request lifecycle. This is the approach the opentelemetry_phoenix library already takes. The next step is to move out to the cowboy-level to start and end the span if the user opts into wanting that (there are sampling issues folks may need to address) and a span has been started.

The good news is I have a beta version of opentelemetry_cowboy created now which will get an initial release once opentelemetry-rc.3 is released. Once we get that out, I'll be adding support for opentelemetry_phoenix to continue a cowboy span if one is already in progress, otherwise it will create a new span as it already does. :)

[dvic]

There was a comment about the reliability of telemetry events for tracing from one of the repos which is a bit misleading. The intent of that comment is that Phoenix can fail somewhere lower in the callstack of plugs or in the application code which aborts the request and bypasses going back out the plug pipelines. One thing to note about tracing with otel in general is a process crashing before a span is closed results in that span essentially being lost. We have discussed the possibility of allowing users to mark a span to be monitored but this will add overhead and we haven't had time to tackle it.

I think we can tackle this issue by not using a regular Plug but by wrapping the entire produced plug. An example of this is AppSignal.Plug:
https://github.com/appsignal/appsignal-elixir-plug/blob/main/lib/appsignal_plug.ex#L28-L73

In this way we can just do a try catch and handle errors properly. Instead of doing plug OpenTelemetry.Phoenix users would do use OpenTelemetry.Phoenix at the top of the router.

The information generated by route_info is what is exposed in the phoenix router dispatch telemetry event. I don't believe it is possible to pre-compute a span name as we don't know what the route is until the request has been matched by the router.

If I look at the example in the docs, it looks like it's possible? https://hexdocs.pm/phoenix/Phoenix.Router.html#route_info/4 :

One downside of this is that the route matching logic would be execute twice, which would increase the cpu usage, but I think we can agree that this is acceptable given the fact we solve exception problem? (usually route matching won't be the bottleneck in a phoenix app)

The good news is I have a beta version of opentelemetry_cowboy created now which will get an initial release once opentelemetry-rc.3 is released. Once we get that out, I'll be adding support for opentelemetry_phoenix to continue a cowboy span if one is already in progress, otherwise it will create a new span as it already does. :)

That sounds like a plan!

[bryannaegele]

Yeah, the AppSignal example actually runs quite a bit further into the call than Plug.Telemetry does. Router is the last thing called in the pipeline which starts in Endpoint. To start higher in the pipeline, you'd have to do a new macro at the top of your endpoint but you're still not gaining any different info than what is exposed by each of the telemetry events in cowboy and phoenix.

I think you'll find the cowboy continuation to deliver what you're looking for. ;)

[dvic]

but you're still not gaining any different info than what is exposed by each of the telemetry events in cowboy and phoenix.

Correct me if I'm wrong, but the main advantage of this macro approach is that errors are caught properly right?

I think you'll find the cowboy continuation to deliver what you're looking for. ;)

So when we have the cowboy continuation any errors will be caught in that span you mean?