Preview feature feedback: Prisma tracing (tracing)

[keerlu]

Please share your feedback about the tracing functionality released in v4.2.0 in this issue.

• If you encounter a bug, please open a bug report in this repo.
• If the feature is working well for you, please share this in a comment below or leave a 👍 on this issue.

If you have any questions, don't hesitate to ask them in the #prisma-client channel in the Prisma Slack.

[safareli]

With this, it's still not possible to "tag" prisma queries with the request id they are executed as part of, if i'm wrong please share how?

For context please take a look at #10425

[safareli]

Iin slack it this was shared:

Tracing allows you to track requests as they flow through your application. This is especially useful for debugging distributed systems where each request can span multiple services.

it would be very useful if we are able to attach request id of an http request to all queries which are created as part of the http request. (for logging, and for rate limiting)

[Akxe]

Please add this to the documentation (in some form):

To run setup locally one can use local installation of Jeager with this command:
.\jaeger-all-in-one.exe --collector.zipkin.host-port=:9411 --collector.otlp.enabled

I struggled for so long because I missed the --collector.otlp.enabled flag.

[millsp]

It would be great to have a way to "label" prisma queries so that name can appear in the traces. In other words, if your label is create_a_user, instead of having prisma:client:operation, you'd have prisma:client:operation:create_a_user.

[millsp]

I'd like to have another option in for the instrumentation package serialize: boolean, because it might not always be useful to pollute the spans with these prisma:*:serialize traces, I would like to disable it by default but give the option to enable it as necessary.

[brennan-airtime]

It appears that prisma is sending db spans with an attribute of db.type: postgres (from a pg example I have) but by the semantic conventions in the spec the key should be db.system and the value postgresql.

https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/database.md

Also the span kind for the db traces are the default internal kind, however other systems mark the db spans as client traces (since they are a client request to a server, and the sever could send spans to report its side of the trace).

With these 2 changes I believe observability platforms like datadog and newrelic would classify these spans as DB operations properly.

[alondayan2]

First of all, the new opentelemetry instrumentation is working great for us!

There is just 2 things that bother us:

• Each query creates a lot of spans which pollutes our tracing. An ability to control which span types you get would be awesome.
• The main prisma:engine span doesn't include the actual sql query that is made, which can be really helpful! + sometimes the queries contain sensitive information, so we need a hook or something similar to determine the final sql query attribute sent with the trace.

Thanks a lot!

[tgensol]

500% agreed with @alondayan2, Could be awesome if we could filter some traces like : "prisma:client:serialize", "prisma:engine:connection", "prisma:client:serialize", "prisma:engine:serialize", "prisma:client:connect" because today, Prisma tracing is 70% of all my traces so my tracing tools (honeycomb/datadog) went too expensive and I have to remove it.

Like https://www.npmjs.com/package/@opentelemetry/instrumentation-express is doing with ignoreLayersType

[lokankr]

With this, it's still not possible to "tag" prisma queries with the request id they are executed as part of, if i'm wrong please share how?

You can sort hack your way to attach it when a span is started

class MySimpleSpanProcessor extends SimpleSpanProcessor {
  onStart(span: Span) {
    span.setAttribute('request_id', getRequestId())
  }
}

// and then
provider.addSpanProcessor(new MySimpleSpanProcessor(exporter))

[RETFU]

It seems Prisma have an issue in the span inclusion, the bar prisma:client:operation should not be show after prisma:engine but it should "include" it right?

Btw what are the others ~30ms in my example?

[safareli]

@lokankr : You can sort hack your way to attach it when a span is started ...

This could work if you are using things like lambda function, but If you have one process where server is running that serves multiple requests this can't quite work.

[kibertoad]

@safareli It can still work if you use AsyncLocalStorage for storing request id.

[barryhagan]

Can someone explain what the prisma:engine:connection span comprises a bit more?

Specifically, we will occasionally see relatively long instances of these spans for traces in an environment where the connection pool should already be warm (the database shows the expected number of connections from the client for the given connection_limit setting). That leads us to believe these are waiting for an idle connection from the pool.

Are these spans the time takes to wait for a connection from the pool, or to create a new connection to the db, or both? I was hoping to use tracing to see if there is pool queuing for slow queries but I'm not sure I can distinguish queue waits vs new connection creations. Is that something that could be added as an attribute to the span (e.g. something like db.newConnection=true so we could ignore cold hits)?

[morlz]

When running on apple m1(try on 2 macbooks) there's no spans with prisma:engine:*,
only prisma:client:*

But it works perfect on linux

OS: 13.1
prisma: 4.9.0
@prisma/client: 4.9.0
@prisma/instrumentation: 4.9.0

same on 4.8.1 and 4.10.0-dev42

The script at the top of the code:

export function otelSetup() {
  const provider = new NodeTracerProvider({
    resource: Resource.default().merge(
      new Resource({
        'service.name': process.env.SERVICE_NAME
      })
    )
  })

  const otlpTraceExporter = new OTLPTraceExporter()
  provider.addSpanProcessor(new SimpleSpanProcessor(otlpTraceExporter))

  registerInstrumentations({
    tracerProvider: provider,
    instrumentations: [
      new PrismaInstrumentation()
    ]
  })

  provider.register()
}

[arcticmatt]

Is there a way to get variables to show up in traces? Right now I just see stuff like this:

WHERE "public"."User"."id" IN ($1) OFFSET $2

But when I find a slow trace, I'd like to dig into the specific variables to see if I can reproduce the query and investigate further

[janpio]

Unfortunately not. You can log them in logging, but that will not help with the traces obviously. Generally params are considered sensitive, so we never combined them back into the query and by default do not log or output them either. But good suggestions that for traces this might be beneficial (optional of course).

[marcus13371337]

It appears that prisma is sending db spans with an attribute of db.type: postgres (from a pg example I have) but by the semantic conventions in the spec the key should be db.system and the value postgresql.

https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/database.md

Also the span kind for the db traces are the default internal kind, however other systems mark the db spans as client traces (since they are a client request to a server, and the sever could send spans to report its side of the trace).

With these 2 changes I believe observability platforms like datadog and newrelic would classify these spans as DB operations properly.

I'm having issues with the tracing because of this. It seems as if the AzureSpanExporter does not pick up the attributes from our spans because of the missing db.system-attribute which should be required according to the specification. See their implementation of the exporter here

[marcus13371337]

Update regarding the db.system-field. Apparently (even though a bit unclear in the specification) the adopted practice seems to be to include db.system-field on all spans that are db-spans. So could you please add it to all the spans reported by Prisma in order to align your spans with other database providers? 🙏

A relevant discussion here:
Azure/azure-sdk-for-js#25322 (comment)

[Akxe]

Also the span kind for the db traces are the default internal kind, however other systems mark the db spans as client traces (since they are a client request to a server, and the sever could send spans to report its side of the trace).

I am not sure, I can agree on the kind of a span as some requests for DB are from crons and similar server activity that is not associated with client requests...

I could see an option where you define multiple Prisma clients where ea

interface PrismaClientOptions {
  // ... current 
  /**
   * @default "client"
   */
  kind?: 'cron' | 'internal' | 'client' //(or it could be simply string)
}

I can see myself using a special Prisma client for cron...

[mziwisky]

i need a way to "merge" spans for prisma model calls that end up batched by the dataloader.

for our GraphQL backend, we use prisma's dataloader functionality extensively to batch db queries for our GraphQL backend. we might have one GQL query that results in hundreds of findUnique prisma calls on the same model. when this happens, we get a span per call (actually multiple spans per -- there's at least a prisma.client.operation and a prisma.client.serialize). i'd prefer to merge those together into a single span.

for reference, the GraphQL instrumentation module has a mergeItems parameter that does the analogous thing resolvers.

i love the concept of OpenTelemetry, and think it's a brilliant decision for prisma to provide first-party support for it, but unfortunately this shortcoming makes it practically unusable for my application.

[jharrell]

Hey @mziwisky ! I've done some digging here and don't have a direct solution, but would encourage you to open up a specific feature request issue for something similar to the mergeItems parameter. In that issue if you could give us as much information as possible (current configuration, example queries and output, expected output, etc) that will really help us prioritize and come up with some helpful workarounds.

Until then, the best I can offer as a band-aid is our documentation on batching and sampling which may reduce your current load.

[mziwisky]

thank you @jharrell, i've opened #19271

[issackr]

@janpio Hey!
I am using some prisma queries with include:
this.prismaService.countries.findMany({ where: { country_id: 230 }, include: { state_provinces: true }, });

It took me a while to understand that such queries are executed as many select queries behind the scenes.
I am using prisma tracing to enrich spans with some extra query related data, and I see that only the main query has been commented with sql commenter:
SELECT "application"."countries"."country_id" ... **/* traceparent=00-62c562e2627babc37059a6e1428016a1-dde799de3d70af44-01 */**

while the following queries are missing the traceparent, in this example:
'SELECT "application"."state_provinces"."state_province_id", "application"."state_provinces"."state_province_code", "application"."state_provinces"."state_province_name", "application"."state_provinces"."country_id", "application"."state_provinces"."sales_territory", "application"."state_provinces"."latest_recorded_population", "application"."state_provinces"."last_edited_by" FROM "application"."state_provinces" WHERE "application"."state_provinces"."country_id" IN ($1) OFFSET $2' **--> NO COMMENT HERE! <--**

And I have no way to connect the span with the correct trace. I would expect that each sub query will contain the traceparent comment...

p.s - I am also using client middleware to inspect the queries before execution, but the sub select queries when using include are not generating the same client operation, I think that the implementation still need to act as the client generated all the queries

Thanks

[casey-chow]

One thing I've noticed with this feature so far when integrating with Datadog is that we aren't able to get prisma:engine spans anymore. This has also been raised on an issue in dd-trace-js (DataDog/dd-trace-js#1244 (comment)) and prevents us from using Prisma's instrumentation with Datadog.

[alandotcom]

It would be great if the db.statement tag didn't include any trailing comments, see DataDog/dd-trace-js#1244 (comment)

[janpio]

An observation from @rtbenfield:

prisma_client_queries_total increments as soon as the query is received.
prisma_datasource_queries_total does not increment until the datasource query succeeds.
prisma_client_queries_wait increments once a connection is allocated to the query.
prisma_client_queries_duration does not increment until the query succeeds.
prisma_datasource_queries_duration does not increment until the datasource query succeeds.

[casey-chow]

Is there a way to get traces attributed to a particular client? Especially with read replicas, it would be tremendously useful to understand whether a span is hitting the primary or a replica.

[janpio]

Generally the traces are directly connected to the Client that they are coming from. This might be more of a problem of the read replica extension - so maybe open an issue over there.

[Ankcorn]

I know a few people have mentioned it but as it stands I find the output of this instrumentation frustrating and confusing.

For us it's better for our customers to have fewer spans with more enriched information

[janpio]

What would you expect instead of what you showed above @Ankcorn?

[Ankcorn]

Thanks @janpio

Ideally, an option to just have the root Prisma client span and also some hooks to capture the input and response from the Prisma Client.

I can see how the current spans are awesome for debugging more complex performance issues but 90% of issues we see are just in the basic usage or doing too many queries on a route negatively effecting the page load perf rather than something internal to prisma

[marcus13371337]

Update regarding the db.system-field. Apparently (even though a bit unclear in the specification) the adopted practice seems to be to include db.system-field on all spans that are db-spans. So could you please add it to all the spans reported by Prisma in order to align your spans with other database providers? 🙏

A relevant discussion here: Azure/azure-sdk-for-js#25322 (comment)

Any updates on the missing "db.system"-field, which can be interpreted from the spec as required on all spans reported regarding a db-operation?

[janpio]

Thanks for the explanations @Ankcorn - I think that makes a lot of sense for the common use cases.
No update @marcus13371337, we'll hopefully be able to look into improving the current implementation soon.

[lewinskimaciej]

Is there a way we could somehow help get out #20113 sooner rather than later?
We also recently introduced OTel into our app and Prisma just creates way too many spans for our liking. Would be nice to have some kind of control over that.

[mopatches]

Hi folks! We're big fans of Prisma and tracing! We've found our Prisma traces to be quite verbose -- way too many spans to be useful, and sometimes enough spans to crash our collector.

Is there a way to configure Prisma traces to be only one span per Prisma call?

[patryk-smc]

It would be great if you guys could reduce the amount of spans, that would help us reduce our bills for otel.

[Frumba]

Hey ! Same on my side, I love having so much information, but having a way to reduce the spans would be amazing to reduce the costs on our side too 🙏 Thanks for the work !

[overbit]

Hi folks! We're big fans of Prisma and tracing! We've found our Prisma traces to be quite verbose -- way too many spans to be useful, and sometimes enough spans to crash our collector.

Is there a way to configure Prisma traces to be only one span per Prisma call?

Probably this is what you are looking for but it's still awaiting for review...
#20113

[adammetis]

Adam from Metis here.

One thing that would be great to see is support for autoinstrumentation with out-of-process configuration from OpenTelemetry. See this link

Autoinstrumentation enables turning open telemetry on by installing a couple of OTel libraries and setting some environment variables. This way users can enable instrumentation without modifying their application code at all. This works great for many libraries including pg (Postgres driver), Sequelize or web servers. See the list

I think Prisma should support autoinstrumentation by environment variables as well (or generally, Prisma should integrate with OTLP to support any kind of autoinstrumentation). This way users would be able to enable OpenTelemetry with no application code changes, and could use tools like Metis out of the box.

[janpio]

That is a great suggestion @adammetis. Do you maybe want to turn it into its own feature request? I think that is relevant and big enough to justify that. Thanks!

[demurgos]

This a minor issue, but Prisma uses the wrong value for db.system with Postgres, see OpenTelemetry documentation

• expected: `db.system = "postgresql"
• actual: `db.system = "postgres"

[DonPerinon]

Hi, Can I ask a quick question, does the auto-instrumentation for Prisma capture errors from the $on('error') event?