Logs are not sent if the TCP server wasn't available when the logger was initialized

[ggrossetie]

It seems that pino-socket can reconnect to a TCP server (using the reconnect option) but if the TCP server wasn't available when the logger (multistream?) was initialized then the server won't receive any data.

I've created a simple reproduction case because it's hard to explain but relatively straightforward to reproduce: https://github.com/Mogztter/pino-socket-reconnect

My observations:

• pino-socket successfully reconnect (connect) to the TCP server and stops sending connect ECONNREFUSED 127.0.0.1:13370 as soon as the server is started
• stream.write(data) in multistream is called
• ThreadStream.write is called but writeSync is not, we keep calling nextFlush
• the write function defined on the outputStream in TcpConnection is not called

Hopefully, I didn't miss something obvious 😅

[mcollina]

Thanks for reporting! Would you like to send a Pull Request to address this issue? Remember to add unit tests.

[mcollina]

This should be fixed in pino-socket, moving it there.

[ggrossetie]

This should be fixed in pino-socket, moving it there.

I cannot reproduce this issue when using TcpConnection directly.

Remember to add unit tests.

I can add a unit test to demonstrate that TcpConnection can reconnect even if the TCP server wasn't available at the start.

[ggrossetie]

I think I found two issues!

The first one is that we shouldn't emit an error on the writable stream when reconnect is true (because it's a recoverable error). Otherwise, thread-stream will destroy the stream/worker.

The second one is that we do not emit outputStream.emit('open', socket.address()) when we reconnect. If the initial connect fails then we won't emit open and as a result we won't receive any data.

Here's the initial connect:

pino-socket/lib/TcpConnection.js

Lines 198 to 200 in 7db92b4

	connect(() => {
	outputStream.emit('open', socket.address())
	})

And here's the reconnect where we do not emit open:

pino-socket/lib/TcpConnection.js

Lines 206 to 213 in 7db92b4

	connect((err) => {
	if (connected === false) {
	return retry.backoff(err)
	}
	if (options.recovery) {
	recoverEnqueuedData()
	}
	})

Is it OK to emit an open event every time we connect or reconnect?

[mcollina]

Yes it should be ok to emit open multiple times