search

CartoDB / camshaft

Analysis library to create data views from queries
BSD 3-Clause "New" or "Revised" License
17 stars 7 forks source link

Uncaught exception: Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed #383

Closed Algunenano closed 3 years ago

Algunenano commented 5 years ago

From api-blue-05 logs:

[2019-02-27 00:18:41.238] [ERROR] [default] - Uncaught exception: Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed
    at doWrite (_stream_writable.js:406:19)
    at writeOrBuffer (_stream_writable.js:394:5)
    at WriteStream.Writable.write (_stream_writable.js:294:11)
    at Logger._emit (/home/ubuntu/www/node-windshaft/releases/20190214142235/node_modules/bunyan/lib/bunyan.js:938:22)
    at Logger.info (/home/ubuntu/www/node-windshaft/releases/20190214142235/node_modules/bunyan/lib/bunyan.js:1037:24)
    at AnalysisLogger.logLimitsError (/home/ubuntu/www/node-windshaft/releases/20190214142235/node_modules/camshaft/lib/logging/logger.js:38:21)
    at LimitsContext.logError (/home/ubuntu/www/node-windshaft/releases/20190214142235/node_modules/camshaft/lib/limits/context.js:18:21)
    at Object.limitNumberOfRows (/home/ubuntu/www/node-windshaft/releases/20190214142235/node_modules/camshaft/lib/node/limits.js:10:17)
    at BaseNode.Node.checkLimits (/home/ubuntu/www/node-windshaft/releases/20190214142235/node_modules/camshaft/lib/node/node.js:535:12)
    at /home/ubuntu/www/node-windshaft/releases/20190214142235/node_modules/camshaft/lib/limits/checker.js:12:17

cc/ @CartoDB/rt-managers (Backend)

ramiroaznar commented 5 years ago

@Algunenano could you share more info? Backend/Infra? What is the priority of this issue?

Algunenano commented 5 years ago

Backend/Infra?

Backend. It's node code.

What is the priority of this issue?

The process kept running, but it's left in an unknown status. In fact, more modern stable releases of node would have killed the process. So it's not high priority but something we should look into sooner rather than later.

Algunenano commented 5 years ago

As a side note, if https://github.com/CartoDB/Windshaft-cartodb/issues/1065 was already place the process would have shutdown and restarted, and in this case it should be avoided.

dgaubert commented 5 years ago

This is happening, under some circumstances, while rotating the logging file for analysis: node-windshaft-analysis.log (once per day, usually at 00:17 AM). The stream to that file has been closed and Bunyan is not able to refresh the file descriptor before writing a new entry log despite we've implemented a callback to refresh it. We had a similar issue while implementing cluster-mode (plus graceful shutdown) for Tilesets API and I had to overwrite the method .close() in Logger to handle it properly.

We need to spend some time to determine the right place and approach to fix it.

jsanz commented 5 years ago

@dgaubert please let @CartoDB/rt-managers now if this is appropriate to tackle at the RT

dgaubert commented 5 years ago

Back from vacations!

please let @CartoDB/rt-managers now if this is appropriate to tackle at the RT

Sure thing!

dgaubert commented 5 years ago

Fixed: https://github.com/CartoDB/camshaft/pull/384

Algunenano commented 5 years ago

It happened again tonight:

[2019-06-04 00:17:26.061] [FATAL] [default] - Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed
    at doWrite (_stream_writable.js:406:19)
    at writeOrBuffer (_stream_writable.js:394:5)
    at WriteStream.Writable.write (_stream_writable.js:294:11)
    at Logger._emit (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/bunyan/lib/bunyan.js:938:22)
    at Logger.info (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/bunyan/lib/bunyan.js:1037:24)
    at AnalysisLogger.logLimitsError (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/camshaft/lib/logging/logger.js:41:21)
    at LimitsContext.logError (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/camshaft/lib/limits/context.js:18:21)
    at Object.limitNumberOfRows (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/camshaft/lib/node/limits.js:10:17)
    at BaseNode.Node.checkLimits (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/camshaft/lib/node/node.js:535:12)
    at /home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/camshaft/lib/limits/checker.js:12:17
Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed
    at doWrite (_stream_writable.js:406:19)
    at writeOrBuffer (_stream_writable.js:394:5)
    at WriteStream.Writable.write (_stream_writable.js:294:11)
    at Logger._emit (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/bunyan/lib/bunyan.js:938:22)
    at Logger.info (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/bunyan/lib/bunyan.js:1037:24)
    at AnalysisLogger.logLimitsError (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/camshaft/lib/logging/logger.js:41:21)
    at LimitsContext.logError (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/camshaft/lib/limits/context.js:18:21)
    at Object.limitNumberOfRows (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/camshaft/lib/node/limits.js:10:17)
    at BaseNode.Node.checkLimits (/home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/camshaft/lib/node/node.js:535:12)
    at /home/ubuntu/www/node-windshaft/releases/20190521103931/node_modules/camshaft/lib/limits/checker.js:12:17
[2019-06-04 00:17:26.062] [INFO] [default] - Process is going to exit with code: 1
[2019-06-04 00:18:11.063] [INFO] [default] - Process didn't close on time. Force exit
[2019-06-04 00:18:15.816] [INFO] console - {"name":"windshaft-server","db":8,"action":"acquire","elapsed":103,"waiting":0}

Notice it's a fatal error so it's restarting the service.

dgaubert commented 5 years ago

Hey!

Since we implemented graceful shutdown, we are not leaving any request w/o response. In any case, we should fix it. This issue fits to be tackled in RT.

cc/ @CartoDB/rt-managers

Algunenano commented 5 years ago

And again:

[2019-07-28 00:17:36.031] [FATAL] [default] - Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed
    at doWrite (_stream_writable.js:406:19)
    at writeOrBuffer (_stream_writable.js:394:5)
    at WriteStream.Writable.write (_stream_writable.js:294:11)
    at Logger._emit (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/bunyan/lib/bunyan.js:938:22)
    at Logger.info (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/bunyan/lib/bunyan.js:1037:24)
    at AnalysisLogger.logLimitsError (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/camshaft/lib/logging/logger.js:41:21)
    at LimitsContext.logError (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/camshaft/lib/limits/context.js:18:21)
    at Object.limitNumberOfRows (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/camshaft/lib/node/limits.js:10:17)
    at BaseNode.Node.checkLimits (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/camshaft/lib/node/node.js:535:12)
    at /home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/camshaft/lib/limits/checker.js:12:17
Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed
    at doWrite (_stream_writable.js:406:19)
    at writeOrBuffer (_stream_writable.js:394:5)
    at WriteStream.Writable.write (_stream_writable.js:294:11)
    at Logger._emit (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/bunyan/lib/bunyan.js:938:22)
    at Logger.info (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/bunyan/lib/bunyan.js:1037:24)
    at AnalysisLogger.logLimitsError (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/camshaft/lib/logging/logger.js:41:21)
    at LimitsContext.logError (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/camshaft/lib/limits/context.js:18:21)
    at Object.limitNumberOfRows (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/camshaft/lib/node/limits.js:10:17)
    at BaseNode.Node.checkLimits (/home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/camshaft/lib/node/node.js:535:12)
    at /home/ubuntu/www/node-windshaft/releases/20190723161603/node_modules/camshaft/lib/limits/checker.js:12:17
[2019-07-28 00:17:36.032] [INFO] [default] - Process is going to exit with code: 1
[2019-07-28 00:18:21.033] [INFO] [default] - Process didn't close on time. Force exit
Algunenano commented 5 years ago

Again:

[2019-08-12 00:17:33.055] [FATAL] [default] - Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed
    at doWrite (_stream_writable.js:406:19)
    at writeOrBuffer (_stream_writable.js:394:5)
    at WriteStream.Writable.write (_stream_writable.js:294:11)
    at Logger._emit (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/bunyan/lib/bunyan.js:938:22)
    at Logger.info (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/bunyan/lib/bunyan.js:1037:24)
    at AnalysisLogger.logLimitsError (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/camshaft/lib/logging/logger.js:41:21)
    at LimitsContext.logError (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/camshaft/lib/limits/context.js:18:21)
    at Object.limitNumberOfRows (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/camshaft/lib/node/limits.js:10:17)
    at BaseNode.Node.checkLimits (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/camshaft/lib/node/node.js:535:12)
    at /home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/camshaft/lib/limits/checker.js:12:17
Error [ERR_STREAM_DESTROYED]: Cannot call write after a stream was destroyed
    at doWrite (_stream_writable.js:406:19)
    at writeOrBuffer (_stream_writable.js:394:5)
    at WriteStream.Writable.write (_stream_writable.js:294:11)
    at Logger._emit (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/bunyan/lib/bunyan.js:938:22)
    at Logger.info (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/bunyan/lib/bunyan.js:1037:24)
    at AnalysisLogger.logLimitsError (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/camshaft/lib/logging/logger.js:41:21)
    at LimitsContext.logError (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/camshaft/lib/limits/context.js:18:21)
    at Object.limitNumberOfRows (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/camshaft/lib/node/limits.js:10:17)
    at BaseNode.Node.checkLimits (/home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/camshaft/lib/node/node.js:535:12)
    at /home/ubuntu/www/node-windshaft/releases/20190730102543/node_modules/camshaft/lib/limits/checker.js:12:17
[2019-08-12 00:17:33.056] [INFO] [default] - Process is going to exit with code: 1

[2019-08-12 00:18:18.057] [INFO] [default] - Process didn't close on time. Force exit
[2019-08-12 00:18:49.980] [INFO] console - {"name":"windshaft-server","db":8,"action":"acquire","elapsed":1017,"waiting":0}
shivam8800 commented 5 years ago

is there any solution for this error ? I am stuck in it and don't know what to do

dgaubert commented 5 years ago

@shivam8800 are you setting up a log rotator in your installation?. Or are you experiencing the same issue with Bunyan?

This issue is related to the integration among Windshaft-CartoDB, Bunyan and the log rotator. For Bunyan's support, please, open an issue in Bunyan's repository.

shivam8800 commented 5 years ago

Oh got it, Actually, It was from pm2 Sorry for mentioning here :(

nickgrealy commented 5 years ago

I got this error... searched further up in the logs and found this message, which was the cause:

Unhandled rejection Error: ENOSPC: no space left on device, write

Jarryxin commented 5 years ago

@shivam8800 are you setting up a log rotator in your installation?. Or are you experiencing the same issue with Bunyan?

This issue is related to the integration among Windshaft-CartoDB, Bunyan and the log rotator. For Bunyan's support, please, open an issue in Bunyan's repository.

确实由 Bunyan 引起的 😂

Algunenano commented 3 years ago

Closing stale ticket