Log errors from watched queries - #1068
Conversation
Errors raised while resolving or executing a watched query were only reported on the query state and to error listeners. Neither is inspected by default, so `useQuery` appeared to silently do nothing when the query was invalid. Log the error with the database's logger from `AbstractQueryProcessor`, which covers both the table resolution and query execution paths, and do the same for the `runQueryOnce` path in `useSingleQuery`. The default `onError` handler of `watchWithCallback` logged the error itself. That is now handled by the watched query, so the default handler no longer logs to avoid emitting the same error twice.
🦋 Changeset detectedLatest commit: afdfbc5 The changes in this PR will be included in the next version bump. This PR includes changesets to release 9 packages
Not sure what this means? Click here to learn what changesets are. Click here if you're a maintainer who wants to add another changeset to this PR |
simolus3
left a comment
simolus3
left a comment
There was a problem hiding this comment.
I like the idea of logging errors by default. I still think it should be possible to opt-out of that to reduce noise in cases where we know the user has their own error hooks. That's impossible for hooks, but maybe we can improve that for watched queries.
| } | ||
|
|
||
| if (typeof update.error !== 'undefined') { | ||
| if (update.error) { |
There was a problem hiding this comment.
To avoid duplicate logs when users install their own error handlers, could we skip the log if an onError handler exists through iterateAsyncListenersWithError? That means we'd make the onError parameter nullable in watchWithCallback then.
There was a problem hiding this comment.
Done in afdfbc5. AbstractQueryProcessor now skips the log when listenerCounts[WatchedQueryListenerEvent.ON_ERROR] > 0, i.e. when at least one of the listeners iterateAsyncListenersWithError dispatches to handles the error itself.
That also resolved the watchWithCallback default in the other direction than this PR originally had it. onError is now left undefined when the caller supplies no handler, and the listener registered on the watched query is the caller's handler rather than a wrapper — otherwise the presence check would always be true for that API and it could never log. So callers that pass an onError keep exactly their pre-existing behaviour (their handler is the only consumer, nothing is logged), and callers that pass none get the watched query's log instead of the old default handler's 'Error in watch' log. The only user-visible difference for the callback API is the message text.
Covered by two new tests in packages/web/tests/watch.test.ts: the same failing watch logs without an onError and does not log with one.
| error: undefined | ||
| })); | ||
| } catch (error) { | ||
| // Matches the logging done by watched queries, so that `runQueryOnce` failures are just as |
There was a problem hiding this comment.
Can we move the compiledQuery variable out of the try block (but still only assign it in there in case compile() throws)? That way, we could include the generated SQL text for queries if execute fails.
There was a problem hiding this comment.
Done in afdfbc5. compiledQuery is declared before the try and still only assigned inside it, so it stays undefined if compile() is what threw and the message falls back to the plain 'Error in watched query'. When it is set, the message becomes Error in watched query: <sql>.
New test in packages/react/tests/useQuery.test.tsx uses a query whose compile() succeeds and whose execute() rejects, and asserts the SQL text is in both the log record and the console.error output.
Review feedback on powersync-ja#1068. The processor now skips its log when a listener registered an `onError` handler, since such a listener already reports the error itself. That makes `watchWithCallback`'s default `onError` unnecessary: it is left undefined when the caller does not supply one, restoring the original behaviour of that API for callers that do handle errors, while callers that do not still get a log. `useSingleQuery` hoists `compiledQuery` out of the try block (still only assigned inside it, so a throwing `compile()` leaves it undefined) so the generated SQL can be included in the log when `execute` fails.
2 participants
Overview
useQuerygives no signal at all when the underlying query fails. The error is stored on the returnederrorfield and dispatched toonErrorlisteners, but nothing is inspected by default, so an invalid query looks like a query that simply never returns rows — the console stays empty, as reported in #834.The deprecated callback API does not have this problem:
watchWithCallbackdefaultsonErrorto a logger call, so theWatchedQuery/useQuerypath lost that behaviour rather than never having it.Changes
Errors are now logged with the database's
logger, matching the existing'Watched query error handler threw an Error'log in the same file.AbstractQueryProcessor.updateStatelogs whenever an error is set on the state. This is the single funnel every watched-query failure passes through, which matters because the two paths are separate:linkQuery(caught byrunWithReporting) — this is what a missing table hits, sinceresolveTablesrunsEXPLAIN <sql>;onChangecallbacks ofOnChangeQueryProcessorandDifferentialQueryProcessor) — this is where runtime failures such as SQLite I/O errors surface.error: nullis used to clear a previous error, so only truthy errors are logged.The log is skipped when a listener registered an
onErrorhandler. Such a listener already reports the error itself, so logging would only duplicate its output — this is the opt-out for watched queries.watchWithCallbackno longer defaultsonErrorto anything and only registers the listener handler the caller supplied. Callers that pass anonErrortherefore keep their pre-existing behaviour of being the only error consumer, and callers that do not now get a log where they previously got the API's own default log.useSingleQuerylogs the same way for therunQueryOncepath, which does not go through a query processor.compiledQueryis declared outside thetryblock (but still only assigned inside it, so a throwingcompile()leaves itundefined), which lets the log include the generated SQL whenexecuteis what failed.On log noise
Queries that are expected to fail will now produce output where they previously produced none, unless the caller handles the error itself. That seemed like the right trade-off given the issue: the error is only emitted once per failure, at
errorlevel, and applications that want to handle failures themselves can install anonErrorhandler, supply aloggerwith a higherminLevel, or provide their own logger implementation when constructing the database.Tests
packages/react/tests/useQuery.test.tsx(run in both normal andStrictMode), one test per failure path: table resolution, query execution,runQueryOnce, andrunQueryOncewith a failingexecuteasserting the generated SQL is in the message. Each asserts that the logged record carries the real underlying error, and that it reachesconsole.errorthrough the default logger — the console being empty is what the issue actually describes.packages/web/tests/watch.test.tscovers the opt-out on thewatchWithCallbackAPI: the same failing watch logs when noonErroris supplied and does not log when one is.Fixes #834.