Data lost on reconnect even with recovery enabled #96
Description
Hello! I'm using pino-socket to transport data to Logstash and everything works great except it seems to disconnect after about 15 minutes of no use. Enabling reconnect fixed the issue of needing to reconnect after the 15 minutes, but it seems that the first message that triggers the reconnect never gets retried and never makes it to logstash. Any thoughts on how I can fix this?
pino v8.11.0
pino-socket v7.3.0
Pino Transport Config
const logstashTransport = pino.transport({
target: 'pino-socket',
options: {
address: lsHost,
port: lsPort,
mode: 'tcp',
reconnect: true,
recovery: true,
},
})
logstashTransport.on('socketError', (err: Error) => {
console.log('socketError', err)
})
logstashTransport.on('socketClose', (err: Error) => {
console.log('socketClose', err)
})
logstashTransport.on('open', (address: string) => {
console.log('open', address)
})
Logs
Feb 28 02:43:31 PM message: "END: [POST] /api/functions/example"
Feb 28 03:17:33 PM socketError Error: read ECONNRESET
Feb 28 03:17:33 PM at TCP.onStreamRead (node:internal/stream_base_commons:217:20)
Feb 28 03:17:33 PM socketClose Error: read ECONNRESET
Feb 28 03:17:33 PM at TCP.onStreamRead (node:internal/stream_base_commons:217:20)
Feb 28 03:17:33 PM open { address: 'some.ip.addr', family: 'IPv4', port: 43230 }
Feb 28 03:17:33 PM log.level: "info"
Feb 28 03:17:33 PM @timestamp: "2023-02-28T20:17:32.881Z"
Feb 28 03:17:33 PM process: {
Feb 28 03:17:33 PM "pid": 81
Feb 28 03:17:33 PM }
Feb 28 03:17:33 PM host: {
Feb 28 03:17:33 PM "hostname": "srv-123"
Feb 28 03:17:33 PM }
Feb 28 03:17:33 PM ecs: {
Feb 28 03:17:33 PM "version": "1.6.0"
Feb 28 03:17:33 PM }
Feb 28 03:17:33 PM service: {
Feb 28 03:17:33 PM "name": "render-server"
Feb 28 03:17:33 PM }
Feb 28 03:17:33 PM event: {
Feb 28 03:17:33 PM "dataset": "render-server.log"
Feb 28 03:17:33 PM }
Feb 28 03:17:33 PM trace: {
Feb 28 03:17:33 PM "id": "0b3fdd23de1b96bd9b0ef9b07dcd319c"
Feb 28 03:17:33 PM }
Feb 28 03:17:33 PM transaction: {
Feb 28 03:17:33 PM "id": "bf0b2258bb3dc3f0"
Feb 28 03:17:33 PM }
Feb 28 03:17:33 PM message: "START: [POST] /api/functions/example"
Feb 28 03:17:34 PM log.level: "info"
Feb 28 03:17:34 PM @timestamp: "2023-02-28T20:17:34.022Z"
Feb 28 03:17:34 PM process: {
Feb 28 03:17:34 PM "pid": 81
Feb 28 03:17:34 PM }
Feb 28 03:17:34 PM host: {
Feb 28 03:17:34 PM "hostname": "srv-123"
Feb 28 03:17:34 PM }
Feb 28 03:17:34 PM ecs: {
Feb 28 03:17:34 PM "version": "1.6.0"
Feb 28 03:17:34 PM }
Feb 28 03:17:34 PM service: {
Feb 28 03:17:34 PM "name": "render-server"
Feb 28 03:17:34 PM }
Feb 28 03:17:34 PM event: {
Feb 28 03:17:34 PM "dataset": "render-server.log"
Feb 28 03:17:34 PM }
Feb 28 03:17:34 PM trace: {
Feb 28 03:17:34 PM "id": "0b3fdd23de1b96bd9b0ef9b07dcd319c"
Feb 28 03:17:34 PM }
Feb 28 03:17:34 PM transaction: {
Feb 28 03:17:34 PM "id": "bf0b2258bb3dc3f0"
Feb 28 03:17:34 PM }
Feb 28 03:17:34 PM message: "END: [POST] /api/functions/example"
NOTE: The line after open never makes it to Logstash but the next message (starting at Feb 28 03:17:34 PM) does.