ConnectionClosed exception about event-store-client HOT 7 CLOSED

@enumag this is related: #85

About the connection getting closed: there seems to be a problem with the tcp connection logic, I receive this error as well quite often which is a problem to me. Will need to look further into this, but it's hard to debug, as it happens not regular.

from event-store-client.

Maybe we could try debug it with something like phptrace.

Is there a way to work around this for now and reconnect manually? I tried to implement it today but since I can't reproduce the issue reliably I have no way to test if it works.

from event-store-client.

from event-store-client.

It seems that reconnecting doesn't really help. Or actually it does but it only projects a few events before the connection is closed and then it takes several seconds to reconnect. This is completely useless because I have tens of thousands of events waiting in the queue so with a pause after every few events it will never finish.

Here is something from docker-compose logs. The reason is always the same HEARTBEAT TIMEOUT at msgNum 2:

eventstore_1  | [00001,13,08:37:35.081] Closing connection '"external-normal"":1c6f372d33600741adaf5030299bc0ef"' [172.19.0.5:39810, L172.19.0.2:1113, {831b6de3-e5af-4b05-9a59-cf937a73ed12}] cleanly." Reason: HEARTBEAT TIMEOUT at msgNum 2"
eventstore_1  | [00001,13,08:37:35.081] ES "TcpConnection" closed [08:37:35.082: N172.19.0.5:39810, L172.19.0.2:1113, {831b6de3-e5af-4b05-9a59-cf937a73ed12}]:Received bytes: 121, Sent bytes: 239094
eventstore_1  | [00001,13,08:37:35.081] ES "TcpConnection" closed [08:37:35.083: N172.19.0.5:39810, L172.19.0.2:1113, {831b6de3-e5af-4b05-9a59-cf937a73ed12}]:Send calls: 5, callbacks: 5
eventstore_1  | [00001,13,08:37:35.084] ES "TcpConnection" closed [08:37:35.084: N172.19.0.5:39810, L172.19.0.2:1113, {831b6de3-e5af-4b05-9a59-cf937a73ed12}]:Receive calls: 3, callbacks: 2
eventstore_1  | [00001,13,08:37:35.084] ES "TcpConnection" closed [08:37:35.084: N172.19.0.5:39810, L172.19.0.2:1113, {831b6de3-e5af-4b05-9a59-cf937a73ed12}]:Close reason: [Success] "HEARTBEAT TIMEOUT at msgNum 2"
eventstore_1  | [00001,13,08:37:35.084] Connection '"external-normal"":1c6f372d33600741adaf5030299bc0ef"' [172.19.0.5:39810, {831b6de3-e5af-4b05-9a59-cf937a73ed12}] closed: Success.
eventstore_1  | [00001,46,08:37:35.084] Persistent subscription lost connection from 172.19.0.5:39810
eventstore_1  | [00001,46,08:37:35.084] Retrying message "everything::projection" "everything"/56926
eventstore_1  | [00001,46,08:37:35.084] Retrying message "everything::projection" "everything"/58503
eventstore_1  | [00001,46,08:37:35.084] Retrying message "everything::projection" "everything"/58504

from event-store-client.

Do you know what is the heartbeat about? Could some changes to ConnectionSettings::heartbeatInterval() and ConnectionSettings::heartbeatTimeout() fix it?

I found the default values here but I'm not sure what settings I should try. The issue is still not easy to reproduce for me to experiment with it properly.

Btw. the failure seems to always occur right after an event that is somewhat bigger than usual (holds more data inside).

from event-store-client.

Hypothesis: Maybe the heartbeat does not occur while I'm processing an event so if the processing of one event takes longer than heartbeatTimeout then the connection is closed.

from event-store-client.

Upon further investigation: This is not a bug in the library!

The problem occurs when the server is sending too many data for the client to handle and thus the server decides, the connection is broken, because too much data is piling up.

There are two possible options:

1. ConnectionPendingSendBytesThreshold is a setting on the server, the default is 10485760. You can increase this number.
2. Use a smaller batchSize - if you set batchSize to 1000 and have 50KB event size, you reach that pending bytes treshold really fast.

Most of the times, the server is much faster sending data than any php script could handle.

from event-store-client.