conn reset unhandled error

[dazoot]

I have started seeing latelly this error in the zonemta logs:

Feb 19 11:35:01 baku zone-mta: events.js:174
Feb 19 11:35:01 baku zone-mta:       throw er; // Unhandled 'error' event
Feb 19 11:35:01 baku zone-mta:       ^
Feb 19 11:35:01 baku zone-mta:
Feb 19 11:35:01 baku zone-mta: Error: read ECONNRESET
Feb 19 11:35:01 baku zone-mta:     at TCP.onStreamRead (internal/stream_base_commons.js:111:27)
Feb 19 11:35:01 baku zone-mta: Emitted 'error' event at:
Feb 19 11:35:01 baku zone-mta:     at emitErrorNT (internal/streams/destroy.js:91:8)
Feb 19 11:35:01 baku zone-mta:     at emitErrorAndCloseNT (internal/streams/destroy.js:59:3)
Feb 19 11:35:01 baku zone-mta:     at process._tickCallback (internal/process/next_tick.js:63:19)
Feb 19 11:35:01 baku zone-mta: events.js:174
Feb 19 11:35:01 baku zone-mta:       throw er; // Unhandled 'error' event

Zonemta is behind haproxy loadbalance.

Something to worry or ignore ?

[andris9]

Not a catastrophic issue but "Unhandled 'error' event" is never a good thing as it usually means that the worker process will restart. As it's also internal then the trace does not give much good information of where and why it happened.

[dazoot]

Yes it seems the process dies:

Feb 19 12:10:15 baku zone-mta: ERR! SMTP/smtps/30099 Reciver process 5e372055b9873dbe68d0 for smtps exited with 1

This happens for the SMTP auth interafce:

processes = 25
maxSize = 20971520
authentication = true
maxRecipients = 100
starttls = false
secure = false
useProxy = true
disableReverseLookup = true

SSL is handled by haproxy here.

[dazoot]

More logs:

Feb 20 10:30:06 caspian zone-mta: events.js:174
Feb 20 10:30:06 caspian zone-mta:       throw er; // Unhandled 'error' event
Feb 20 10:30:06 caspian zone-mta:       ^
Feb 20 10:30:06 caspian zone-mta: 
Feb 20 10:30:06 caspian zone-mta: Error: read ECONNRESET
Feb 20 10:30:06 caspian zone-mta:     at TCP.onStreamRead (internal/stream_base_commons.js:111:27)
Feb 20 10:30:06 caspian zone-mta: Emitted 'error' event at:
Feb 20 10:30:06 caspian zone-mta:     at emitErrorNT (internal/streams/destroy.js:91:8)
Feb 20 10:30:06 caspian zone-mta:     at emitErrorAndCloseNT (internal/streams/destroy.js:59:3)
Feb 20 10:30:06 caspian zone-mta:     at process._tickCallback (internal/process/next_tick.js:63:19)
Feb 20 10:30:06 caspian zone-mta: ERR! Process Uncaught exception
Feb 20 10:30:06 caspian zone-mta: ERR! Process Error [ERR_IPC_CHANNEL_CLOSED]: Channel closed
Feb 20 10:30:06 caspian zone-mta: ERR! Process     at ChildProcess.target.send (internal/child_process.js:636:16)
Feb 20 10:30:06 caspian zone-mta: ERR! Process     at SMTPProxy.connection (/usr/local/zonemta/node_modules/zone-mta/lib/receiver/smtp-proxy.js:168:22)
Feb 20 10:30:06 caspian zone-mta: ERR! Process     at Server.server.net.createServer.socket (/usr/local/zonemta/node_modules/zone-mta/lib/receiver/smtp-proxy.js:228:59)
Feb 20 10:30:06 caspian zone-mta: ERR! Process     at Server.emit (events.js:198:13)
Feb 20 10:30:06 caspian zone-mta: ERR! Process     at TCP.onconnection (net.js:1520:8)
Feb 20 10:30:06 caspian zone-mta: ERR! Process  { Error [ERR_IPC_CHANNEL_CLOSED]: Channel closed
Feb 20 10:30:06 caspian zone-mta: ERR! Process     at ChildProcess.target.send (internal/child_process.js:636:16)
Feb 20 10:30:06 caspian zone-mta: ERR! Process     at SMTPProxy.connection (/usr/local/zonemta/node_modules/zone-mta/lib/receiver/smtp-proxy.js:168:22)
Feb 20 10:30:06 caspian zone-mta: ERR! Process     at Server.server.net.createServer.socket (/usr/local/zonemta/node_modules/zone-mta/lib/receiver/smtp-proxy.js:228:59)
Feb 20 10:30:06 caspian zone-mta: ERR! Process     at Server.emit (events.js:198:13)
Feb 20 10:30:06 caspian zone-mta: ERR! Process     at TCP.onconnection (net.js:1520:8)
Feb 20 10:30:06 caspian zone-mta: ERR! Process   stack:
Feb 20 10:30:06 caspian zone-mta: ERR! Process    'Error [ERR_IPC_CHANNEL_CLOSED]: Channel closed\n    at ChildProcess.target.send (internal/child_process.js:636:16)\n    at SMTPProxy.connection (/usr/local/zonemta/node_modules/zone-mta/lib/receiver/smtp-proxy.js:168:22)\n    at Server.server.net.createServer.socket (/usr/local/zonemta/node_modules/zone-mta/lib/receiver/smtp-proxy.js:228:59)\n    at Server.emit (events.js:198:13)\n    at TCP.onconnection (net.js:1520:8)' }
Feb 20 10:30:06 caspian zone-mta: info Process Server closing down...
Feb 20 10:30:06 caspian zone-mta: info API Service closed

[andris9]

From the logs it seems like child process failed to handle some kind of socket error and exited. Then the master process failed to assign a new connection to the child process as the child process had already exited. Still have to figure out the initial issue, where the first unexpected ECONNRESET happens.

[dazoot]

Could it be related to the changes did for the max size bug ?

[dazoot]

I did an node upgrade from 10 to 14 and the error happens less often.

Mar 13 20:37:22 caspian zone-mta: events.js:292
Mar 13 20:37:22 caspian zone-mta:       throw er; // Unhandled 'error' event
Mar 13 20:37:22 caspian zone-mta:       ^
Mar 13 20:37:22 caspian zone-mta: 
Mar 13 20:37:22 caspian zone-mta: Error: read ECONNRESET
Mar 13 20:37:22 caspian zone-mta:     at TCP.onStreamRead (internal/stream_base_commons.js:209:20)
Mar 13 20:37:22 caspian zone-mta: Emitted 'error' event on Socket instance at:
Mar 13 20:37:22 caspian zone-mta:     at emitErrorNT (internal/streams/destroy.js:106:8)
Mar 13 20:37:22 caspian zone-mta:     at emitErrorCloseNT (internal/streams/destroy.js:74:3)
Mar 13 20:37:22 caspian zone-mta:     at processTicksAndRejections (internal/process/task_queues.js:80:21) {
Mar 13 20:37:22 caspian zone-mta:   errno: -104,
Mar 13 20:37:22 caspian zone-mta:   code: 'ECONNRESET',
Mar 13 20:37:22 caspian zone-mta:   syscall: 'read'
Mar 13 20:37:22 caspian zone-mta: }
Mar 13 20:37:22 caspian zone-mta: ERR! SMTP/submission/26059 Reciver process 1feaac4c146970dbf3e8 for submission exited with 1

[dazoot]

We did not see this latelly for a long time so i guess we can close it.