central-backend icon indicating copy to clipboard operation
central-backend copied to clipboard

Error: Premature close

Open alxndrsn opened this issue 3 years ago • 7 comments

Written to stderr:

Error [ERR_STREAM_PREMATURE_CLOSE]: Premature close
    at new NodeError (node:internal/errors:387:5)
    at ServerResponse.onclose (node:internal/streams/end-of-stream:145:30)
    at ServerResponse.emit (node:events:525:35)
    at ServerResponse.emit (node:domain:489:12)
    at Socket.onServerResponseClose (node:_http_server:258:23)
    at Socket.emit (node:events:525:35)
    at Socket.emit (node:domain:489:12)
    at TCP.<anonymous> (node:net:757:14)

"Premature close" has been mentioned in previous issues:

  • https://github.com/getodk/central-backend/issues/485
  • https://github.com/getodk/central-backend/pull/480
  • https://github.com/getodk/central-backend/issues/521
  • https://github.com/getodk/central-backend/pull/637
  • https://forum.getodk.org/t/postgres-error-causing-internal-server-error-500/37535

The error can be recreated fairly reliably (substitute IDs and auth credentials as appropriate):

for i in {1..20};do \
echo; echo "Starting iteration #$i..."; echo; \
(curl "localhost:8383/------------------------------ITERATION-[$i]-BEGINNING------------------------------"; \
tim=$((3 + $RANDOM % 12)); \
echo; echo "Running for $tim seconds..."; echo; \
timeout $tim siege -v \
http://localhost:8989/v1/projects/1/forms/all-widgets.svc/Submissions \
-H 'Authorization: Basic ...'); \
done

alxndrsn avatar Nov 07 '22 08:11 alxndrsn

Can you also trigger a true premature close (e.g., cancelling a download halfway or shutting of the connection)? It'd be ideal if we could identify and ignore true premature closes.

yanokwa avatar Nov 07 '22 13:11 yanokwa

More consistent reproduction:

const { Socket } = require('node:net');

const s = new Socket(); 

s.on('connect', () => {
  s.write(
    'GET /v1/projects/1/forms/all-widgets.svc/Submissions HTTP/1.1\r\n' +
    'Host: localhost:8989\r\n' +
    'User-Agent: curl/7.68.0\r\n' +
    'Accept: */*\r\n' +
    'Authorization: Basic ...\r\n' +
    '\r\n' +
  '');
});
s.on('data', data => console.log('RECEIVED:', data.toString()));

s.connect('8989', 'localhost');
s.pause();

alxndrsn avatar Nov 07 '22 20:11 alxndrsn

Simpler reproduction:

$ curl http://localhost:8989/v1/projects/1/forms/all-widgets/submissions.csv.zip -H 'Authorization: Basic ...'
Warning: Binary output can mess up your terminal. Use "--output -" to tell 
Warning: curl to output it to your terminal anyway, or consider "--output 
Warning: <FILE>" to save to a file.

alxndrsn avatar Nov 08 '22 09:11 alxndrsn

I've confirmed that I can trigger the error in Sentry by exiting out of the Power Query Editor in Excel (and presumably PowerBI) while a preview is being generated. These Sentry entries are all triggered by me in normal usage. The best way I see to limit the noisiness is to speed up some of those queries if we can.

lognaturel avatar Nov 08 '22 17:11 lognaturel

Agreed that we should speed up the queries, but if Power BI is somehow not closing things properly, we could also not log "false" premature closes.

yanokwa avatar Nov 08 '22 17:11 yanokwa

Perhaps these errors should be caught and handled, and a Problem returned to the client if possible. However, it's still useful to monitor them in Sentry, so they should also be reported there.

This will probably require a top-level express error handler in lib/bin/run-server.js.

For another error that should be handled similarly, see #658.

alxndrsn avatar Nov 08 '22 18:11 alxndrsn