kit icon indicating copy to clipboard operation
kit copied to clipboard

Animated page transitions break snapshotting

Open robertadamsonsmith opened this issue 1 year ago • 1 comments

Describe the bug

Animated page transitions, cause the capture() callback in exported snapshot handlers to not always be called correctly, resulting in unexpected behaviour.

The behaviour can be seen here, with instructions:

https://www.sveltelab.dev/md7wsue2ps2nkfm

The transition is already local (to rule out global transition related issues). If the page transition is removed then snapshots work correctly again. Snapshots are also fine when navigating to external urls.

Oddly, it appears that if the value that is snapshotted isn't altered, then capture() is called when changing pages, but if the value that is snapshotted is altered, then capture() is not called (apart from for the first time).

Reproduction

https://www.sveltelab.dev/md7wsue2ps2nkfm

Logs

No response

System Info

Sveltelab repro, currently on "@sveltejs/kit": "^1.5.0",

Severity

serious, but I can work around it

Additional Information

No response

robertadamsonsmith avatar Jun 22 '23 23:06 robertadamsonsmith

Duplicate of https://github.com/prisma/prisma/issues/6882

Sytten avatar Jun 14 '21 14:06 Sytten

If you ignore the middleware aspect of this that you assumed @Sytten, this is essentially about e.g. creating a query id (or request id) and logging that with each query, so any external tooling can pick those out of the logs and correlate Prisma Client query to logged SQL query.

janpio avatar Jun 14 '21 19:06 janpio

Possibly also duplicate of #6519 and #5956

Would assume it shouldn't really depend on which tracing solution is used, but the end result should be queries being traced which are as well correlated to the trigger on prisma client side (and furthermore the root of the prisma client call -> API Request, Background Job, etc).

tak1n avatar Sep 05 '21 00:09 tak1n

same issue + 1 any solution?

lake2 avatar Oct 02 '21 10:10 lake2

Hi, having the same issue. Is there any plan to create something like this?

moshcohen110 avatar Oct 06 '21 13:10 moshcohen110

Hi, having the same issue. Is there any plan to create something like this?

Its already on the roadmap of prisma https://www.notion.so/Support-Tracing-in-Prisma-Client-c0afd7599022435da2b8fc05c30cd1c0

tak1n avatar Oct 07 '21 10:10 tak1n

@tak1n this doesn't require tracing support in Prisma, per se. The issue is that since Prisma queries are sent to a rust engine, all of the context from the dd-trace library added with https://nodejs.org/api/async_hooks.html#async-hooks is lost in the $on() callback. From dd-trace's perspective, $on() is its own entry-point into the app, and did not occur within the context of a GQL resolver or REST endpoint's span.

A simple solution would be to have callbacks that run synchronously on the client side, prior to sending the request to rust and after receiving the response, running within the context of our GQL resolver or REST endpoint. Instead, our only way with the existing API today is to observe the query via an asynchronous [inter process] RPC.

This is a feature request to have middleware in the client that wraps the outbound request to Rust, allowing us to log not only the request/response but also the surrounding context like dd-trace spans attached via https://nodejs.org/api/async_hooks.html#async-hooks would be preserved this way. This would be much preferred over logging UUIDs like @janpio suggested, since that does preserve the information but is otherwise a pain to extract by 3rd party tools. If it just logged on the client side, everything would "just work" :)

Instead, what we have today is a notification from Rust that it received an inbound request (at which point the context surrounding the original request we sent is lost)

A workaround would be for me to wrap my Prisma client to "decorate" the behavior by wrapping each of the method calls in dd-trace's tracer.wrap() method, so that all of my calls like await prisma.users.findFirst() become await tracer.wrap('my_query', prisma.users.findFirst()), and then the tracing would work as expected. But ideally Prisma could surface a middlware API instead of end users wrapping their Prisma clients manually.

joshribakoff-sm avatar Aug 01 '22 22:08 joshribakoff-sm

I tried this approach:

prisma.$use(async (params, next) => {
  return await tracer.trace('prisma.query', async (span) => {
    span?.setTag('model', params.model);
    span?.setTag('action', params.action);
    span?.setTag('runInTransaction', params.runInTransaction);
    logger.debug('Prisma query', {
      model: params.model,
      action: params.action,
      runInTransaction: params.runInTransaction,
    });
    const result = await next(params);
    return result;
  });
});

The spans are also taken out of context of the parent span from where I sent my Prisma query.

  try {
    throw new Error();
  } catch (e) {
    console.log(e);
  }

the above debug logging shows the stack trace lost the context that I called my prisma query from a particular GQL resolver / file:

Error: 
    at /Users/jribakoff/groundwater/dist/apps/api/webpack:/groundwater/apps/api/src/app/db.ts:16:11
    at consumer (/Users/jribakoff/groundwater/node_modules/@prisma/client/runtime/index.js:49914:20)
    at /Users/jribakoff/groundwater/node_modules/@prisma/client/runtime/index.js:49920:76
    at runInChildSpan (/Users/jribakoff/groundwater/node_modules/@prisma/client/runtime/index.js:49133:12)
    at /Users/jribakoff/groundwater/node_modules/@prisma/client/runtime/index.js:49920:20
    at AsyncResource.runInAsyncScope (node:async_hooks:199:9)
    at PrismaClient._request (/Users/jribakoff/groundwater/node_modules/@prisma/client/runtime/index.js:49919:86)
    at /Users/jribakoff/groundwater/node_modules/@prisma/client/runtime/index.js:46474:25
    at _callback (/Users/jribakoff/groundwater/node_modules/@prisma/client/runtime/index.js:46233:52)
    at Proxy.then (/Users/jribakoff/groundwater/node_modules/@prisma/client/runtime/index.js:46240:14)

In my opinion the proposal from @matthewmueller in https://github.com/prisma/prisma/issues/6882#issuecomment-1175427037 doesn't have anything to do with solving this issue. I do not want to manually get the parent span and pass it into every Prisma query. If I was willing to accept that boilerplate, I could just wrap every prisma query callsite in a span manually. What I really want is I just want the middleware to run from within the context where I called my Prisma query.

I also noticed if the middleware throws an error, the query never resolves or rejects and it causes the upstream http request to never respond. Seems like middleware are not useful (for this use case) or production ready (errors will never be surfaced or logged).

joshribakoff-sm avatar Aug 02 '22 21:08 joshribakoff-sm

or production ready (errors will never be surfaced or logged).

Can you please make sure an issue with more information for this exists? Thanks.

janpio avatar Aug 05 '22 22:08 janpio

i've discovered that if you use the binary query engine instead of the default Node-API based one, then the async context is not lost in the client.$on('query', handler) handler. i don't know why this is, have been reading the LibraryEngine and BinaryEngine code to try to find a difference that might matter, but so far haven't figured it out.

it would be nice if the docs would talk a little more about the differences between those engines. the only thing it really says is "The Node-API library approach is recommended since it reduces the communication overhead between the Prisma Client and the query engine." but that makes me wonder why the binary engine is even an option at this point?

mziwisky avatar Apr 07 '23 23:04 mziwisky

but that makes me wonder why the binary engine is even an option at this point?

Because sometimes the Node-API library gets something wrong, that works fine with the binary engine. Then it is a temporary workaround to use the binary engine. It is not recommended to use in other cases, and might be removed at any time.

janpio avatar Apr 12 '23 23:04 janpio

@janpio would you consider this loss of async context an instance of the Node-API library getting something wrong? if so, can it be fixed? or is there some fundamental limitation with the Node-API approach that will never allow this to work? i still don't really understand why the query event handler gets invoked in a different async context than that which initiated the prisma query (especially since it's only the case with the Node-API engine but not with the binary engine)

mziwisky avatar Apr 13 '23 06:04 mziwisky

Right now we do not give any expectation that the async context would be kept - it is not part of our documented API -, which is why this feature request exists and tracks this expectation (or other solutions to achieve the same outcome). So right now this seems to be undefined to me. If you really need it, you can use the binary to work around that - but be aware that you are off the really recommended path then and might have other negative (or positive) effects that are not documented.

janpio avatar Apr 13 '23 13:04 janpio

Right now we do not give any expectation that the async context would be kept - it is not part of our documented API -, which is why this feature request exists and tracks this expectation (or other solutions to achieve the same outcome). So right now this seems to be undefined to me. If you really need it, you can use the binary to work around that - but be aware that you are off the really recommended path then and might have other negative (or positive) effects that are not documented.

I tried to use the binary to work around that but it does not really work. I use NestJS-CLS package, for saving information on the async context, but when I try to access it on query event.

    this.$on<any>('query', async (e) => {
      this.logger.debug({query: e.query, params: e.params});
      const info = this.clsService.get("info")
    });

The clsService return undefined.

My prisma engine was loaded with binary

✔ Generated Prisma Client (4.15.0 | binary) to ./node_modules/@prisma/client in 553ms

any idea?

EladIsraeli avatar Jun 22 '23 12:06 EladIsraeli

Hi @janpio, I really want to contribute to that. I commented above and the solution you suggested has not worked, how can I contribute to the project, or have a solution for that

EladIsraeli avatar Jul 23 '23 11:07 EladIsraeli

@janpio would you consider this loss of async context an instance of the Node-API library getting something wrong? if so, can it be fixed? or is there some fundamental limitation with the Node-API approach that will never allow this to work? i still don't really understand why the query event handler gets invoked in a different async context than that which initiated the prisma query (especially since it's only the case with the Node-API engine but not with the binary engine)

Have you managed to make it work?

EladIsraeli avatar Jul 23 '23 11:07 EladIsraeli

Have you managed to make it work?

@EladIsraeli sorry i missed your question until now. i've been away from this problem for long enough now that i don't recall the details, but i recall a few things that might help you here if you're still stuck and still wanting to work around it with the binary engine.

i was using the cls-hooked library, and it includes a bindEmitter function that i know i experimented with, but don't recall whether it was necessary to make my workaround work. but i believe that function exists because EventEmitter handlers don't get fired with the proper async context by default, so that function somehow propagates the context to them. if NestJS-CLS has some similar kind of helper, you might need to apply it to your prisma client.

mziwisky avatar Aug 30 '23 22:08 mziwisky

The issue is that since Prisma queries are sent to a rust engine, all of the context ... added with https://nodejs.org/api/async_hooks.html#async-hooks is lost

This is a perfect summary by @joshribakoff-sm.

In short

  • The Prisma engine written in Rust loses access to the Node.js context from which a query was triggered, so these Prisma features can't help solve this problem:
    • $on()
    • $use() middlewares
    • $extends() extentensions
  • As a result, a request-specific context can't be shared when a database query is being executed. It doesn't work with
    • Native Node.js AsyncLocalStorage
    • cls-hooked
    • continuation-local-storage
    • and similar request-specific storage libraries that return undefined

One workaround I found is using the Prisma preview feature that allows the use of native Node.js database driver adapters to perform queries instead of the Prisma engine. Because these database adapters are executed in Node.js, async_hooks should just work fine.

You can find an example using https://github.com/brianc/node-postgres in @bemi-db/prisma that allows tracking all database changes and stitching them with request-specific context (user ID, API endpoint, etc.) automatically.

exAspArk avatar Dec 20 '23 14:12 exAspArk