Fix/DB Connection spans presented poorly

[jamescrosswell]

Leveraging the work from Fix/db spans not finishing #2398 this turned out to be a fairly easy fix. The connections that are being opened/closed before/after executing DB commands typically all share the same connection id... which means we can tell if we're getting the same connection from the pool.

When we receive an EFConnectionOpening event then, we check to see if the Transaction contains an existing span with a matching ConnectionId (from the EFConnectionOpening event data). If so, we reuse it rather than creating a new span. To "reuse" it, we simply set the Status = null and EndTimestamp = null.

Resulting waterfall charts now look like this:

[jamescrosswell]

@mattjohnsonpint I checked this with SqlClient as well. Apparently SqlClient never had any such similar issues.

However I did notice that SqlClient puts all the queries under the relevant DB Connection. We could revert to doing that with for EntityFramework as well. Now that we're consolidating connections by ConnectionId, I don't think that would be an issue visually for the user... and the diagnostic events contain a ConnectionId as well as a CommandId for command/query events.

Thoughts?

[jamescrosswell]

@mattjohnsonpint this should be good to go now I think.

[mattjohnsonpint]

This is coming together very nicely, but after some usability testing I think some additional changes are needed (per our conversation):

• On the db.connection span description, let's show "name (host:port)"
• Add db.name, server.address (the host name), and server.port to the span data (extras)
• Undo our decision to put db.query spans as children of the db.connection span. Instead, just place them both under the same original parent.

As for why not to parent them, consider the following

var transaction = SentrySdk.StartTransaction("Program Main", "function");

await db.Blogs.OrderBy(b => b.BlogId).ToListAsync();
await db.Blogs.OrderBy(b => b.BlogId).ToListAsync();

transaction.Finish();

That renders correctly, like this:

But now do some unrelated work between those queries:

var transaction = SentrySdk.StartTransaction("Program Main", "function");

await db.Blogs.OrderBy(b => b.BlogId).ToListAsync();

var span = transaction.StartChild("task", "some custom stuff");
await Task.Delay(100);
span.Finish();

await db.Blogs.OrderBy(b => b.BlogId).ToListAsync();

transaction.Finish();

... and you get:

Because the task span is not parented to the db.connection, it gets put last. And since there was some other span happening, Sentry (on the server side) think that there is "missing span instrumentation" during that time period. There wasn't, it's just showing the place that the task span is logically supposed to be.

Since it would be very strange for non-db spans to be grouped under a db.connection parent span, I think we should unparent the db.connection from the db.query spans.

It makes sense also from the perspective of the parent/child spans having any sort of causal relationship. The db.query.compile, db.connection, db.query, and the custom task were all things that were caused by the function implementation. The queries weren't caused by the connection, they just used the connection.

I am glad that we figured out how to only show one connection span though. There shouldn't be another connection span unless it has a different connection_id, such as when multiple queries are happening simultaneously, or if we got a different connection from the connection pool. Keep that part. 😅

Thanks!

[mattjohnsonpint]

Here's another example. In this one, I do a create, read, update, and delete. But the db.query.compile occurs just before the read - after the first create. So it gets pushed to the bottom and a we get another "missing span instrumentation".

Just more to support flattening them. Thanks.

[jamescrosswell]

OK I think we're getting close. The db.connection and db.query spans have now been "flattened" so that these both appear at the same level in the hierarchy (see screenshot in the pull summary above).

In terms of enriching the db.connection description, there isn't much we can use from the ConnectionEventData that we receive other than the Database name (here are all the properties). Using Postgres, for example, it looks like the Host and Port are available but actually I'm seeing Host == null and Port==0 for my local instance... neither of which is accurate. I suspect any properties we find in there that aren't documented on the base DbConnection are probably inconsistent and unreliable across DB vendors. Per a subsequent conversation with @mattjohnsonpint then, we won't leverage these for the time being.

The latest code does, however, store the db.name in the Extra data for the connection.

All of those changes have been made for both SQL Client and Entity Framework so functionality should be consistent when using either of those.

[mattjohnsonpint]

Looking great! I pushed a few nitpicks.

One last thing - can we put db.name in the extras on query spans also?

Thanks

[mattjohnsonpint]

This is pretty much perfect now. Thanks!

Just for the record, here's new versions of the two scenarios I showed earlier, with the final implementation: