fix: mysql query stack traces #11273
Conversation
Rearrange the `query` function in the MySQL query runner to build the error outside of the query callback scope, so it includes the caller's stack trace. The inner stack trace, if desired, is still available via the wrapped `driverError`. Closes: typeorm#11271
|
Example of what I see when testing the PR at hand:
Much easier to see that I missed passing the transaction manager to the audit log service. |
| try { | ||
| const hygge = repository.create() | ||
| hygge.description = | ||
| "Soft blankets and candlelight on a snowy evening." | ||
| await repository.save(hygge) | ||
|
|
||
| const hygge2 = repository.create() | ||
| hygge2.id = hygge.id // Id collision. | ||
| hygge2.description = | ||
| "Eating homemade simply wonderfuls." | ||
| await repository.insert(hygge2) | ||
| } catch (err) { | ||
| //console.log("observed stack:", err.stack) | ||
| expect(err.stack).to.include("my_named_function_1234") | ||
| confirmedStackError = true | ||
| } finally { | ||
| // Confirm that we actually checked an error. | ||
| expect(confirmedStackError).to.equal(true) | ||
| } | ||
| } |
There was a problem hiding this comment.
You could improve the readability of the test by separating the assertions from the tested code. Also applies on the previous test.
| try { | |
| const hygge = repository.create() | |
| hygge.description = | |
| "Soft blankets and candlelight on a snowy evening." | |
| await repository.save(hygge) | |
| const hygge2 = repository.create() | |
| hygge2.id = hygge.id // Id collision. | |
| hygge2.description = | |
| "Eating homemade simply wonderfuls." | |
| await repository.insert(hygge2) | |
| } catch (err) { | |
| //console.log("observed stack:", err.stack) | |
| expect(err.stack).to.include("my_named_function_1234") | |
| confirmedStackError = true | |
| } finally { | |
| // Confirm that we actually checked an error. | |
| expect(confirmedStackError).to.equal(true) | |
| } | |
| } | |
| const hygge = repository.create() | |
| hygge.description = | |
| "Soft blankets and candlelight on a snowy evening." | |
| await repository.save(hygge) | |
| const hygge2 = repository.create() | |
| hygge2.id = hygge.id // Id collision. | |
| hygge2.description = | |
| "Eating homemade simply wonderfuls." | |
| await repository.insert(hygge2) | |
| } | |
| expect(my_named_function_1234()).rejectsToThrow('my_named_function_1234') |
There was a problem hiding this comment.
Good idea. Updated the test.
Figuring out chai promises is a bit of a rabbithole... seems the normal rejectedWith doesn't check the stack text.
await expect(my_named_function_1234()).to.be.rejected.and.eventually.have.property("stack").that.include("my_named_function_1234")
There was a problem hiding this comment.
hi @mukunda- would you like to continue working on this? We are considering dropping mysql suppprt in favour of mysql2 and this seems to be important part of this move...
There was a problem hiding this comment.
Hi @pkuczynski Sorry I'm no longer working on the project that needed these changes so I don't have time for this lately. If someone else could pick this up that would be great
Clean up test structure.
|
same issue, i have to restart server, this issue blocked my server, i insert a data to a table, no error, and the db table is right, but this error happened, no error stack, how to resolve this issue? |
| const queryStartTime = +new Date() | ||
| const queryStartTime = +new Date() | ||
| return await new Promise<any>((ok, fail) => { | ||
| databaseConnection.query( |
There was a problem hiding this comment.
To get rid of the promise wrapper, you can do this:
const queryAsync = promisify(databaseConnection.query).bind(databaseConnection)
const raw = await queryAsync(query, parameters)promisify is a NodeJS built-in, but it has a simple implementation, which we could add to util. We could even create ObjectUtils.promisifyMethod(obj, method) that does obj[method].call(obj, ...args, cb), so it would already be bound to the object. 🤷🏻 There's a JS example (without types) in node_modules/@sap/hana-client/extension/Promise.js 😉
Then you won't need any callbacks :)
If we want to catch exceptions in an async function, we need to await it (this was the fix, wasn't it?). This is arguably more obvious when functions are used instead of promises 😉
There was a problem hiding this comment.
Good idea. I don't have much time currently to update and test but it will be on my todo list somewhere
alumni
left a comment
There was a problem hiding this comment.
Actually, I see we do the same in all drivers, I wonder if we shouldn't adjust the logger instead.
gioboa
left a comment
There was a problem hiding this comment.
Can you solve the conflicts please?
Description of change
Rearrange the
queryfunction in the MySQL query runner to build the error outside of the query callback scope, so it includes the caller's stack trace.The inner stack trace, if desired, is still available via the wrapped
driverError.Functionality wise, this is a cosmetic change for diagnostics. It doesn't change program behavior, only stack trace logs. Only MySQL and equivalent flavors are in the blast radius here.
See #11271 for more details. Currently, when there's an query error while using mysql, it's hard to tell where it's coming from since the stack doesn't show the caller. (The "trace" option of the MySQL driver also does not reach outside of the typeorm code.) Working with traces like these is frustrating:
Fixes #11271
Fixes #11765
Pull-Request Checklist
masterbranchnpm run formatto apply prettier formattingnpm run testpasses with this changeFixes #0000