Errors on source creation get lost

[RubenVerborgh]

Issue type:

• 🐛 Bug

---

Description:

const newEngine = require('@comunica/actor-init-sparql').newEngine;
const myEngine = newEngine();
myEngine.query('CONSTRUCT WHERE { ?s ?p ?o }',
  { source: { value: 'https://ruben.verborgh.orgz' } })
  .then(result => {
     result.quadStream.on('error', (e) => {
      console.error('error correctly emitted', e);
    });
    result.quadStream.on('data', data => {
      console.error('should not be reached, data from stream:', data);
    });
    console.log('error and data listeners attached');
  },
  e => console.error('should not be reached, query construction error:', e));

Expect this error to be caught by the error event, but it slips away as a rejected promise.

This is a specific case of #103 and the direct cause of LDflex/Query-Solid#30.

---

Environment:

| software            | version
| ------------------- | -------
| Comunica Init Actor | 1.9.4
| node                | v12.6.0
| npm                 | 6.9.0
| yarn                | 1.17.3
| Operating System    | darwin (Darwin 18.6.0)

Crash log:

(node:8115) UnhandledPromiseRejectionWarning: Error: getaddrinfo ENOTFOUND ruben.verborgh.orgz
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:60:26)
(node:8115) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 9)
(node:8115) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
error correctly emitted Error: getaddrinfo ENOTFOUND ruben.verborgh.orgz
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:60:26) {
  errno: 'ENOTFOUND',
  code: 'ENOTFOUND',
  syscall: 'getaddrinfo',
  hostname: 'ruben.verborgh.orgz'
}
(node:8115) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 9)

[RubenVerborgh]

I traced it back to LinkedRdfSourcesAsyncRdfIterator, in which setSourcesState does not attach an error handler to the result of getNextSourceCached/getNextSource.

When I did attach e => console.error(e) as a catch handler, the first error is eaten (without consequences, so also not good).

However, when I did attach this.emit('error', e) as a handler, we get another UnhandledPromiseRejectionWarning.

[rubensworks]

this.emit('error', e) is probably the way to go. But if it results in a UnhandledPromiseRejectionWarning, then we are probably missing an error handler somewhere higher up the stream chain.

Side-note: it's not the first time we run into uncaught error issues.
We may have to look into defining some best-practises on how to handle these situations (promise rejection to stream error, stream error to promise rejection, piping streams and their errors, ...), and accompanying helper functions.

[michielbdejong]

From what I discussed with @rubensworks,

the calling code is responsible for attaching an error handler to it, and then not exiting before it consumes the stream.

Indeed. I think LDflex already does this though.

IIUC, the unhandled promise rejection is expected in this snippet? myEngine.query returns immediately, before completing the http request. That is why it does not throw an error.

Calling myEngine.query has the side-effect of auto-playing the resulting stream in the background. That stream will then eventually either be ready to yield its result, or it will emit an error. If you don't wait for that in the calling code, then that is what causes the unhandled promise rejection. Right?

[RubenVerborgh]

IIUC, the unhandled promise rejection is expected in this snippet?

Not yet.

of auto-playing the resulting stream in the background

Not really; it's a lazy stream. Only preparatory actions will be undertaken (in this case, dereferencing the sources, which fails).

That stream will then eventually either be ready to yield its result, or it will emit an error. If you don't wait for that in the calling code

It's a bit more complex: since the stream is lazy, there is not necessarily a point where it is “ready to yield its result”; as such, we can't wait for it. Furthermore, errors can happen at any point.

As such, we need to listen for (zero or more) errorss and redirect them as (zero or more) events to the bindings stream. I.e., the promise rejection should manifest as an event, since we can't wait for it because it can occur at any point.

At the moment, something is not listening to the errors emitted by the LinkedRdfSourcesAsyncRdfIterator (but I don't know who should listen).

[michielbdejong]

the [error] should manifest as an event, since we can't wait for it because it can occur at any point.

OK and then how would that event end up triggering newEngine.query(...).catch? Maybe errors that occur during the "preparatory actions" (like DNS lookup) should manifest as promise rejections, but errors that occur later should not - after the preparatory actions have completed, the promise returned by newEngine.query should resolve (it can't wait forever!), and then if errors occur after that, they should manifest as errors thrown by it.next()? Is that the current desired behaviour?

Another option would be if newEngine.query returns a promise that always resolves to a stream, even if you pass it a garbage query that is not even a string, and then errors only ever manifest as events on that stream. Is that what you meant with "not yet"?

[RubenVerborgh]

OK and then how would that event end up triggering newEngine.query(...).catch?

It does not. The result to .query has a bindingsStream which has error events.

Maybe errors that occur during the "preparatory actions" (like DNS lookup) should manifest as promise rejections

No time for that; it is of utmost importance that .query returns as soon as possible, so result streams can be attached to different components.

Another option would be if newEngine.query returns a promise that always resolves to a stream, even if you pass it a garbage query that is not even a string, and then errors only ever manifest as events on that stream. Is that what you meant with "not yet"?

Exactly, and it does this at the moment. It's just that one specific error does not find its way to that stream.

(On that note, why is it necessary for it to be a promise, @rubensworks? Could it return sync?) (Never mind, I understand that query parsing might be async, and we need the query to know what to return.)

[michielbdejong]

how would that event end up triggering newEngine.query(...).catch?

It does not.

Hm, but going back to the snippet (sorry, I wrote newEngine.query, I meant myEngine.query):

myEngine.query('CONSTRUCT WHERE { ?s ?p ?o }',
  { source: { value: 'https://ruben.verborgh.orgz' } })
  .catch(e => console.error('error correctly caught', e));

there we do expect the error to trigger .catch(e => console.error('error correctly caught', e)), right? What am I missing?

[RubenVerborgh]

When something goes wrong during construction of the query: syntax error, component missing, etc.

[rubensworks]

When something goes wrong during construction of the query: syntax error, component missing, etc.

Exactly.

Since source URLs are dereferenced during actual query execution, the .query promise will already be resolved with a bindingsStream, and any following errors should be emitted as error events in that stream.

[michielbdejong]

OK so then IIUC let's update the snippet to:

const newEngine = require('@comunica/actor-init-sparql').newEngine;
const myEngine = newEngine();
myEngine.query('CONSTRUCT WHERE { ?s ?p ?o }',
  { source: { value: 'https://ruben.verborgh.orgz' } })
  .then(result => {
    result.quadStream.on('error', (e) => {
      console.error('error correctly emitted', e);
    });
    result.quadStream.on('data', data => {
      console.error('should not be reached, data from stream:', data);
    });
  }).catch(e => console.error('should not be reached, query construction error:', e));

And then there is no problem:

~/gh/comunica/comunica $ node test2.js 
error correctly emitted Error: getaddrinfo ENOTFOUND ruben.verborgh.orgz
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:60:26) {
  errno: 'ENOTFOUND',
  code: 'ENOTFOUND',
  syscall: 'getaddrinfo',
  hostname: 'ruben.verborgh.orgz'
}

Or am I still missing something here?

[RubenVerborgh]

@michielbdejong It's probably a timing issue. While I was briefly able to reproduce what you have above, the same code currently consistently gives me:

$ node test.js
(node:8115) UnhandledPromiseRejectionWarning: Error: getaddrinfo ENOTFOUND ruben.verborgh.orgz
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:60:26)
(node:8115) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 9)
(node:8115) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
error correctly emitted Error: getaddrinfo ENOTFOUND ruben.verborgh.orgz
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:60:26) {
  errno: 'ENOTFOUND',
  code: 'ENOTFOUND',
  syscall: 'getaddrinfo',
  hostname: 'ruben.verborgh.orgz'
}
(node:8115) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 9)

[michielbdejong]

@RubenVerborgh hold on, you are skipping ahead, let's first decide what the desired behaviour is.

Desired behaviour, option 1:

const newEngine = require('@comunica/actor-init-sparql').newEngine;
const myEngine = newEngine();
myEngine.query('CONSTRUCT WHERE { ?s ?p ?o }',
  { source: { value: 'https://ruben.verborgh.orgz' } })
  .catch(e => console.error('error correctly caught', e));

Desired behaviour, option 2:

const newEngine = require('@comunica/actor-init-sparql').newEngine;
const myEngine = newEngine();
myEngine.query('CONSTRUCT WHERE { ?s ?p ?o }',
  { source: { value: 'https://ruben.verborgh.orgz' } })
  .then(result => {
    result.quadStream.on('error', (e) => {
      console.error('error correctly emitted', e);
    });
    result.quadStream.on('data', data => {
      console.error('should not be reached, data from stream:', data);
    });
  }).catch(e => console.error('should not be reached, query construction error:', e));

[RubenVerborgh]

Option 2, we established that above (#565 (comment)). Updated the description of the issue.

[michielbdejong]

ok! Great, thanks. But then I can't reproduce this issue. I see this:

~/gh/comunica/comunica $ node test3.js 
error correctly emitted Error: getaddrinfo ENOTFOUND ruben.verborgh.orgz
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:60:26) {
  errno: 'ENOTFOUND',
  code: 'ENOTFOUND',
  syscall: 'getaddrinfo',
  hostname: 'ruben.verborgh.orgz'
}

@rubensworks could you try on your machine?

[RubenVerborgh]

@michielbdejong As explained above, it is a timing issue, so you might or might not see it. Below a screenshot of two consecutive invocations, one of which works, the other fails:

The error bubbles up two times: one time when preparing sources, the other when querying them. It is this second error that is caught by the code above. The timing of these errors is crucial: if source preparation is still pending while execution starts, then the error is handled by the query execution mechanism. If source preparation finishes earlier, then the error goes uncaught initially, only to surface again (and then be caught) during execution.

We know that there is a bug:

I traced it back to LinkedRdfSourcesAsyncRdfIterator, in which setSourcesState does not attach an error handler to the result of getNextSourceCached/getNextSource.

[michielbdejong]

Ah, so then how about a variation on option 2, but with a delay before consuming the stream? On my machine, this starts failing when I set the setTimeout delay higher than about 5 or 6 ms. So with a 1000ms timeout I can now easily reproduce this bug, great!

So the error occurs before the error handler has been attached to the stream. Maybe it should queue up errors in this case?

Desired behaviour, option 3:

const newEngine = require('@comunica/actor-init-sparql').newEngine;
const myEngine = newEngine();
myEngine.query('CONSTRUCT WHERE { ?s ?p ?o }',
  { source: { value: 'https://ruben.verborgh.orgz' } })
  .then(result => {
    setTimeout(() => {
      result.quadStream.on('error', (e) => {
        console.error('error correctly emitted', e);
      });
      result.quadStream.on('data', data => {
        console.error('should not be reached, data from stream:', data);
      });
    }, 1000);
  },
  e => console.error('should not be reached, query construction error:', e));

[RubenVerborgh]

Ah, so then how about a variation on option 2, but with a delay before consuming the stream?

I was almost on board with that and had already edited the issue… but I realized it's slightly more subtle:

So the error occurs before the error handler has been attached to the stream.

That's not the case; I added a logging statement to the code to make that explicit.
With the updated code, we get:

$ node test.js
error and data listeners attached
(node:9697) UnhandledPromiseRejectionWarning: Error: getaddrinfo ENOTFOUND ruben.verborgh.orgz
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:60:26)
(node:9697) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 9)
(node:9697) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
error correctly emitted Error: getaddrinfo ENOTFOUND ruben.verborgh.orgz
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:60:26) {
  errno: 'ENOTFOUND',
  code: 'ENOTFOUND',
  syscall: 'getaddrinfo',
  hostname: 'ruben.verborgh.orgz'
}

My understanding of what's happening on .query is as follows:

1. a process is triggered to start discovering sources
2. another process is triggered to return results

The error from 2 is the one we pick up. The error from 1 is lost if 1 finished before 2.

Note that losing the error is not because of the error handler that we attach; the logging statement shows that this one is attached on time.

The problem is that:
a. LinkedRdfSourcesAsyncRdfIterator is not listening to errors from sources it caches
b. even if a) is fixed, no one is listening to errors from LinkedRdfSourcesAsyncRdfIterator

Now a) I can solve easily: after

comunica/packages/actor-rdf-resolve-quad-pattern-hypermedia/lib/LinkedRdfSourcesAsyncRdfIterator.ts

Line 112 in f6330c4

source = this.getNextSource(url, handledDatasets);

, we need to insert source.then(source => source.on('error', e => this.emit('error', e))).

My problem with b) is that I don't know who should be listening for it. Whomever should be listening, is responsible for taking the error emitted by LinkedRdfSourcesAsyncRdfIterator and re-emitting it on the quadStream, such that it is caught there.

So the error occurs before the error handler has been attached to the stream. Maybe it should queue up errors in this case?

No, it is the task of whoever calls .query to set up error handlers in a timely way (as the logging shows we do). It's just that the error is not getting delivered there.

[michielbdejong]

Very insightful summary! That's very helpful, I'll debug it further next week.

[michielbdejong]

Sorry, didn't find time to work on this more, and have lots of other things to do in the near future. I did just read https://nodesource.com/blog/understanding-streams-in-nodejs/ which mentions the pipeline() method, which sounds cool (apparently it was introduced in Node 10, I don't know if it can be browserified). Mentioning it here in case it's useful or at least can help us develop our thoughts around good ways to deal with errors on streams.

[rubensworks]

the pipeline() method

Oh TIL, looks like a useful thing to investigate indeed.

apparently it was introduced in Node 10

Setting our min Node version to 10 shouldn't be a major problem.

[rubensworks]

It looks like this is not fully fixed yet: LDflex/Query-Solid#30 (comment)

Can be reproduced via the JS API, by for example querying over 'https://rubensworks.net/aa'.

[RubenVerborgh]

Key is that all bases are covered = all rejections are caught.

For example: https://github.com/LDflex/LDflex-Comunica/blob/v3.4.0/src/ComunicaEngine.js#L17

What's important here is that, on this specific line, we don't care about handling the error, because it will bubble up anyway on https://github.com/LDflex/LDflex-Comunica/blob/v3.4.0/src/ComunicaEngine.js#L28 I.e., this is where promises are different from traditional try/catch, in that you can "catch" multiple times. However, we should not leave any potentially failing promises open, hence the seemingly pointless .catch(() => null), which prevents a UnhandledPromiseRejectionWarning (i.e., as soon as a promise failure is caught once, Node is happy).

[RubenVerborgh]

Maybe we even want to have a reusable

export function silenceRejection(promise) { 
  promise.catch(() => null);
  return promise;
}

to make the intent more clear.

[rubensworks]

This was a false-positive, it was a bug in my debugging environment that caused unhandled promise rejections.
So I can confirm that all errors are properly being emitted via error events in the resulting bindingsStream.

In any case, I've discovered some minor problems related to this, so the effort was not useless:

• 6e170f2
• 45fe4a0