Prisma-client-js: Unreadable error trace message

[soqt]

I got a "INTERNAL_SERVER_ERROR" and the stacktrace is totally unreadable, it looks something like this:

prisma/photon: 2.0.0-preview018.2
nexus: ^0.12.0-rc.5
nexus-prisma: ^0.6.1

[janpio]

What were you doing when you got this error?
Can you paste the full error output you were getting?
Can you identify the code that was being executed?

[soqt]

Here is my data model:

model Product {
  id                    String   @default(cuid()) @id
  title                 String
  stock                 Int      @default(99)
  createdAt             DateTime @default(now())
  updatedAt             DateTime @updatedAt

  owner User
}

model User {
  id               String           @default(cuid()) @id
  email            String?          @unique
  phone            String?          @unique
  password         String
}

I was trying to create a product using await photon.products.create({ data }), data has all required information and connect to User's id.
Here is the error code:

{
  "errors": [
    {
      "message": "\n\u001b[31mInvalid \u001b[1m`product = await this.store.products.create()`\u001b[22m invocation in \u001b[4m/Users/samwang/Developer/project/node-project/src/datasource/ProductSource.ts:54:47\u001b[24m\u001b[39m\n\n\u001b[2m  \u001b[90m 50 \u001b[39m\u001b[22m\n\u001b[2m  \u001b[90m 51 \u001b[39mconsole\u001b[38;2;107;139;140m.\u001b[39m\u001b[36mlog\u001b[39m\u001b[38;2;107;139;140m(\u001b[39mdata\u001b[38;2;107;139;140m)\u001b[39m\u001b[22m\n\u001b[2m  \u001b[90m 52 \u001b[39m\u001b[22m\n\u001b[2m  \u001b[90m 53 \u001b[39m\u001b[22m\n\u001b[31m\u001b[1m→\u001b[22m\u001b[39m \u001b[90m 54 \u001b[39m\u001b[36mconst\u001b[39m product = \u001b[36mawait\u001b[39m \u001b[36mthis\u001b[39m\u001b[38;2;107;139;140m.\u001b[39mstore\u001b[38;2;107;139;140m.\u001b[39mproducts\u001b[38;2;107;139;140m.\u001b[39m\u001b[36mcreate\u001b[39m\u001b[38;2;107;139;140m(\u001b[39m\n\n\u001b[31m\u001b[1mReason: \u001b[22m\u001b[39m\u001b[31mError occurred during query execution:\u001b[39m\n\u001b[31mConnectorError(ConnectorError { user_facing_error: None, kind: QueryError(Server(ServerError { code: 1054, message: \"Unknown column \\'available\\' in \\'field list\\'\", state: \"42S22\" })\u001b[39m\n\u001b[31m\u001b[39m\n\u001b[31mstack backtrace:\u001b[39m\n\u001b[31m   0: backtrace::backtrace::trace\u001b[39m\n\u001b[31m   1: backtrace::capture::Backtrace::new_unresolved\u001b[39m\n\u001b[31m   2: failure::backtrace::internal::InternalBacktrace::new\u001b[39m\n\u001b[31m   3: <failure::backtrace::Backtrace as core::default::Default>::default\u001b[39m\n\u001b[31m   4: quaint::connector::mysql::error::<impl core::convert::From<mysql_async::error::Error> for quaint::error::Error>::from\u001b[39m\n\u001b[31m   5: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m   6: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m   7: std::future::poll_with_tls_context\u001b[39m\n\u001b[31m   8: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m   9: query_core::interpreter::query_interpreters::write::execute::{{closure}}\u001b[39m\n\u001b[31m  10: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m  11: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m  12: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m  13: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m  14: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m  15: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m  16: std::future::poll_with_tls_context\u001b[39m\n\u001b[31m  17: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m  18: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m  19: std::panicking::try::do_call\u001b[39m\n\u001b[31m  20: __rust_maybe_catch_panic\u001b[39m\n\u001b[31m  21: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m  22: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m  23: hyper::proto::h1::dispatch::Dispatcher<D,Bs,I,T>::poll_catch\u001b[39m\n\u001b[31m  24: <hyper::server::conn::spawn_all::NewSvcTask<I,N,S,E,W> as core::future::future::Future>::poll\u001b[39m\n\u001b[31m  25: tokio::task::core::Core<T>::poll\u001b[39m\n\u001b[31m  26: std::panicking::try::do_call\u001b[39m\n\u001b[31m  27: __rust_maybe_catch_panic\u001b[39m\n\u001b[31m  28: tokio::task::harness::Harness<T,S>::poll\u001b[39m\n\u001b[31m  29: tokio::runtime::thread_pool::worker::GenerationGuard::run_task\u001b[39m\n\u001b[31m  30: tokio::runtime::thread_pool::worker::GenerationGuard::run\u001b[39m\n\u001b[31m  31: std::thread::local::LocalKey<T>::with\u001b[39m\n\u001b[31m  32: std::thread::local::LocalKey<T>::with\u001b[39m\n\u001b[31m  33: tokio::runtime::thread_pool::worker::Worker::run\u001b[39m\n\u001b[31m  34: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once\u001b[39m\n\u001b[31m  35: std::panicking::try::do_call\u001b[39m\n\u001b[31m  36: __rust_maybe_catch_panic\u001b[39m\n\u001b[31m  37: tokio::task::harness::Harness<T,S>::poll\u001b[39m\n\u001b[31m  38: tokio::runtime::blocking::pool::Inner::run2\u001b[39m\n\u001b[31m  39: tokio::time::clock::Clock::enter\u001b[39m\n\u001b[31m  40: tokio::runtime::time::variant::with_default\u001b[39m\n\u001b[31m  41: tokio::runtime::blocking::pool::Inner::run\u001b[39m\n\u001b[31m  42: std::sys_common::backtrace::__rust_begin_short_backtrace\u001b[39m\n\u001b[31m  43: __rust_maybe_catch_panic\u001b[39m\n\u001b[31m  44: core::ops::function::FnOnce::call_once{{vtable.shim}}\u001b[39m\n\u001b[31m  45: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once\u001b[39m\n\u001b[31m  46: std::sys::unix::thread::Thread::new::thread_start\u001b[39m\n\u001b[31m  47: _pthread_start\u001b[39m\n\u001b[31m) })\u001b[39m\n\u001b[31m\u001b[39m",
      "locations": [
        {
          "line": 2,
          "column": 3
        }
      ],
      "path": [
        "productCreate"
      ],
      "extensions": {
        "code": "INTERNAL_SERVER_ERROR",
        "exception": {
          "stacktrace": [
            "Error: ",
            "\u001b[31mInvalid \u001b[1m`product = await this.store.products.create()`\u001b[22m invocation in \u001b[4m/Users/samwang/Developer/project/node-project/src/datasource/ProductSource.ts:54:47\u001b[24m\u001b[39m",
            "",
            "\u001b[2m  \u001b[90m 50 \u001b[39m\u001b[22m",
            "\u001b[2m  \u001b[90m 51 \u001b[39mconsole\u001b[38;2;107;139;140m.\u001b[39m\u001b[36mlog\u001b[39m\u001b[38;2;107;139;140m(\u001b[39mdata\u001b[38;2;107;139;140m)\u001b[39m\u001b[22m",
            "\u001b[2m  \u001b[90m 52 \u001b[39m\u001b[22m",
            "\u001b[2m  \u001b[90m 53 \u001b[39m\u001b[22m",
            "\u001b[31m\u001b[1m→\u001b[22m\u001b[39m \u001b[90m 54 \u001b[39m\u001b[36mconst\u001b[39m product = \u001b[36mawait\u001b[39m \u001b[36mthis\u001b[39m\u001b[38;2;107;139;140m.\u001b[39mstore\u001b[38;2;107;139;140m.\u001b[39mproducts\u001b[38;2;107;139;140m.\u001b[39m\u001b[36mcreate\u001b[39m\u001b[38;2;107;139;140m(\u001b[39m",
            "",
            "\u001b[31m\u001b[1mReason: \u001b[22m\u001b[39m\u001b[31mError occurred during query execution:\u001b[39m",
            "\u001b[31mConnectorError(ConnectorError { user_facing_error: None, kind: QueryError(Server(ServerError { code: 1054, message: \"Unknown column \\'available\\' in \\'field list\\'\", state: \"42S22\" })\u001b[39m",
            "\u001b[31m\u001b[39m",
            "\u001b[31mstack backtrace:\u001b[39m",
            "\u001b[31m   0: backtrace::backtrace::trace\u001b[39m",
            "\u001b[31m   1: backtrace::capture::Backtrace::new_unresolved\u001b[39m",
            "\u001b[31m   2: failure::backtrace::internal::InternalBacktrace::new\u001b[39m",
            "\u001b[31m   3: <failure::backtrace::Backtrace as core::default::Default>::default\u001b[39m",
            "\u001b[31m   4: quaint::connector::mysql::error::<impl core::convert::From<mysql_async::error::Error> for quaint::error::Error>::from\u001b[39m",
            "\u001b[31m   5: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m   6: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m   7: std::future::poll_with_tls_context\u001b[39m",
            "\u001b[31m   8: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m   9: query_core::interpreter::query_interpreters::write::execute::{{closure}}\u001b[39m",
            "\u001b[31m  10: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m  11: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m  12: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m  13: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m  14: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m  15: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m  16: std::future::poll_with_tls_context\u001b[39m",
            "\u001b[31m  17: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m  18: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m  19: std::panicking::try::do_call\u001b[39m",
            "\u001b[31m  20: __rust_maybe_catch_panic\u001b[39m",
            "\u001b[31m  21: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m  22: <std::future::GenFuture<T> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m  23: hyper::proto::h1::dispatch::Dispatcher<D,Bs,I,T>::poll_catch\u001b[39m",
            "\u001b[31m  24: <hyper::server::conn::spawn_all::NewSvcTask<I,N,S,E,W> as core::future::future::Future>::poll\u001b[39m",
            "\u001b[31m  25: tokio::task::core::Core<T>::poll\u001b[39m",
            "\u001b[31m  26: std::panicking::try::do_call\u001b[39m",
            "\u001b[31m  27: __rust_maybe_catch_panic\u001b[39m",
            "\u001b[31m  28: tokio::task::harness::Harness<T,S>::poll\u001b[39m",
            "\u001b[31m  29: tokio::runtime::thread_pool::worker::GenerationGuard::run_task\u001b[39m",
            "\u001b[31m  30: tokio::runtime::thread_pool::worker::GenerationGuard::run\u001b[39m",
            "\u001b[31m  31: std::thread::local::LocalKey<T>::with\u001b[39m",
            "\u001b[31m  32: std::thread::local::LocalKey<T>::with\u001b[39m",
            "\u001b[31m  33: tokio::runtime::thread_pool::worker::Worker::run\u001b[39m",
            "\u001b[31m  34: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once\u001b[39m",
            "\u001b[31m  35: std::panicking::try::do_call\u001b[39m",
            "\u001b[31m  36: __rust_maybe_catch_panic\u001b[39m",
            "\u001b[31m  37: tokio::task::harness::Harness<T,S>::poll\u001b[39m",
            "\u001b[31m  38: tokio::runtime::blocking::pool::Inner::run2\u001b[39m",
            "\u001b[31m  39: tokio::time::clock::Clock::enter\u001b[39m",
            "\u001b[31m  40: tokio::runtime::time::variant::with_default\u001b[39m",
            "\u001b[31m  41: tokio::runtime::blocking::pool::Inner::run\u001b[39m",
            "\u001b[31m  42: std::sys_common::backtrace::__rust_begin_short_backtrace\u001b[39m",
            "\u001b[31m  43: __rust_maybe_catch_panic\u001b[39m",
            "\u001b[31m  44: core::ops::function::FnOnce::call_once{{vtable.shim}}\u001b[39m",
            "\u001b[31m  45: <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once\u001b[39m",
            "\u001b[31m  46: std::sys::unix::thread::Thread::new::thread_start\u001b[39m",
            "\u001b[31m  47: _pthread_start\u001b[39m",
            "\u001b[31m) })\u001b[39m",
            "\u001b[31m\u001b[39m",
            "    at PhotonFetcher.<anonymous> (/Users/samwang/Developer/project/node-project/node_modules/@prisma/photon/index.js:65:27)",
            "    at Generator.throw (<anonymous>)",
            "    at rejected (/Users/samwang/Developer/project/node-project/node_modules/@prisma/photon/index.js:6:65)",
            "    at process._tickCallback (internal/process/next_tick.js:68:7)"
          ]
        }
      }
    }
  ],
  "data": null
}

[pantharshit00]

Stacktrace is shown in your cli with proper formatting(it is the interactive error that we create).

But I do think we should strip the ANSI characters in the error object that we throw to the user.

[janpio]

Unreadable error message definitely is a bug. (Possibly even a regression because of the implementation of the error spec.)

[soqt]

It seems happen if I didn't lift up new data models.

[divyenduz]

Closing this as a duplicate of https://github.com/prisma/photonjs/issues/195

It was never implemented, I am adding a candidate label to this so it is (hopefully) picked up by us soon 🙏

This workaround might work for you, if the error throwing logic is in your application or you can modify that in your server library: https://github.com/prisma/photonjs/issues/195#issuecomment-535909631

[divyenduz]

@soqt From your last comment, it looks like this was fixed for you anyways? Is that correct?