Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

I receive the following log with no context in production no details about closed transaction #21357

Open
Raynos opened this issue Oct 4, 2023 · 8 comments
Labels
kind/improvement An improvement to existing feature and code. team/client Issue for team Client. topic: interactiveTransactions topic: transaction

Comments

@Raynos
Copy link

Raynos commented Oct 4, 2023

Bug description

The log statement gives me no context other then a postgres transaciton was closed.

See prisma/prisma-engines#3391

Adding more context in the transaction prisma engine would really help.

How to reproduce

Expected behavior

No response

Prisma information

// Add your schema.prisma
// Add your code using Prisma Client

Environment & setup

  • OS:
  • Database:
  • Node.js version:

Prisma Version


@Raynos Raynos added the kind/bug A reported bug. label Oct 4, 2023
@janpio
Copy link
Member

janpio commented Oct 4, 2023

What other information would you expect?

@Raynos
Copy link
Author

Raynos commented Oct 5, 2023

I don't know what other information is available about the database transaction, anything could be helpful.

What operation was trying to run when we found the transaction was closed.

The actual SQL source code of the transaction,

Whether its a $queryRaw or $queryRawUnsafeor$executeRaw` or a part of $transaction or $transactionCb

Whether its a method like upsert or createMany with many nested connectOrCreate and had an internal transaction as part of the ORM implementation details.

Anything that helps me figure out which part of my business logic caused a failed transaction.

@janpio
Copy link
Member

janpio commented Oct 5, 2023

Wouldn't that be more a thing you figure out via a try catch block around your $transaction call? Or are you looking for information which part of the transaction was the last that was executed before the error occurred?

@aqrln
Copy link
Member

aqrln commented Oct 5, 2023

As @janpio said above, the kind of information you are interested in is something that the engine doesn't really know a lot about on this level, this would be something that's best solved on the Prisma Client side. Much of the information you are asking about should already be in the error message — is that not the case for you?

As for the engine-side state that is relevant here, the log line you get means that we can't provide information about whether the operation failed because the transaction had already been committed or rolled back, or if it had expired (and what amount of time elapsed since the start of the transaction compared to the declared transaction timeout in the latter case) because it has already been evicted from the LRU cache. You can increase the size of that cache by setting the CLOSED_TX_CACHE_SIZE environment variable to some higher value than the default 100 closed transactions.

@aqrln aqrln added kind/improvement An improvement to existing feature and code. topic: transaction team/client Issue for team Client. topic: interactiveTransactions and removed kind/bug A reported bug. labels Oct 5, 2023
@Raynos
Copy link
Author

Raynos commented Oct 6, 2023

I am using the prisma error logging events ( https://www.prisma.io/docs/reference/api-reference/prisma-client-reference#log )

With code like

basePrisma.$on('error', event => {
  perWorkerMetrics.increment('soundxyz.prisma.db-error', 1);

  // Some errors are designed to retry. Downgrade to warn
  if (event.message.includes(ERROR_WRITE_CONFLICT_RETRYABLE)) {
    moduleLogger.warn(
      {
        eventMessage: event.message,
        err: {
          message: event.message,
        },
        eventTarget: event.target,
        rawEvent: event,
      },
      'Got a retry-safe error from prisma client library',
    );
  } else if (
    event.message.includes(ERROR_CHECK_NOTIFICATION_OVERLAP_CONSTRAINT)
  ) {
    return;
  } else {
    moduleLogger.error(
      {
        eventMessage: event.message,
        err: {
          message: event.message,
        },
        eventTarget: event.target,
        rawEvent: event,
      },
      'Got an error from prisma client library',
    );
  }
});

In this context I have not instrumented every single one of the 2000 reads & writes a novel try / catch and a novel logger error.

Also the error bubbling of promises & try catch means that in my HTTP handler I also have zero context.

Since the API is promise based and error bubbling based I expect all the useful meta data to exist as fields on the error class.

@Raynos
Copy link
Author

Raynos commented Oct 6, 2023

image

What I receive in production logs looks like a rust exception wrapped in a javascript error with zero extra Prisma client context.

@Raynos
Copy link
Author

Raynos commented Oct 6, 2023

You can increase the size of that cache by setting the CLOSED_TX_CACHE_SIZE environment variable to some higher value than the default 100 closed transactions.

Please put that in the error object, that's really really useful and valuable information.

@Raynos
Copy link
Author

Raynos commented Oct 6, 2023

Can I set that progmatically without having to set an environment variable ? as a parameter into the prisma client class ?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/improvement An improvement to existing feature and code. team/client Issue for team Client. topic: interactiveTransactions topic: transaction
Projects
None yet
Development

No branches or pull requests

3 participants