Hi,
I had an issue that one of my events got stuck in system projections processing for 34 minutes.
It was published to original stream at 19:14:10 UTC but appeared in $ce and $et projections at 19:48:44 so more than 34 minutes later. Screenshot from $et-OrderFilled stream:
Has anyone had such an issue? Or maybe an idea where to find a reason for that? I am not sure how to debug it. Also, according to Prometheus exporter (https://github.com/marcinbudny/eventstore_exporter) all system projections were in a running state.
Below are the logs that I have from around both timestamps. I am not sure if the projections were working during this period because this was the only event that was waiting in this moment. Events that were before e.g. at 19:14:01 were processed correctly.
Before the event was published to original stream:
2023-01-19 20:14:15
2023-01-19T19:14:15.19742401Z stdout F [ 1,31,19:14:15.196,DBG] "streamExistenceFilter" is flushing at 48,350,026. Diff 50,342 ...
2023-01-19 20:14:07
2023-01-19T19:14:07.782674728Z stdout F [ 1,54,19:14:07.782,DBG] "streamExistenceFilter" took checkpoint at position: 48,349,312.
2023-01-19 20:14:02
2023-01-19T19:14:02.675483187Z stdout F [ 1,42,19:14:02.674,DBG] "streamExistenceFilter" has flushed at 48,349,312. Diff 49,628. Took 00:00:00.0070481
2023-01-19 20:14:02
2023-01-19T19:14:02.675167379Z stdout F [ 1,42,19:14:02.674,INF] Flushed 29 pages out of 33,334. 237,568 bytes. Delay 128 ms per batch. Total delay 0 ms. Actively flushing: 00:00:00.0066059 35.96 MB/s.
2023-01-19 20:14:02
2023-01-19T19:14:02.668869844Z stdout F [ 1,42,19:14:02.667,DBG] "streamExistenceFilter" is flushing at 48,349,312. Diff 49,628 ...
2023-01-19 20:14:00
2023-01-19T19:14:00.388272355Z stdout F [ 1,63,19:14:00.388,DBG] SLOW BUS MSG ["SubscriptionsBus"]: "EventCommitted" - 806ms. Handler: "SubscriptionsService`1".
2023-01-19 20:13:04
2023-01-19T19:13:04.605632164Z stdout F [ 1, 4,19:13:04.604,DBG] Persistent Subscriptions have been stopped.
2023-01-19 20:13:04
2023-01-19T19:13:04.605629153Z stdout F [ 1, 4,19:13:04.604,DBG] Persistent subscriptions received state change to Follower. Stopping listening
2023-01-19 20:13:04
2023-01-19T19:13:04.605626196Z stdout F [ 1, 4,19:13:04.604,DBG] Persistent Subscriptions have been stopped.
2023-01-19 20:13:04
2023-01-19T19:13:04.605622269Z stdout F [ 1, 4,19:13:04.604,DBG] Persistent subscriptions received state change to Clone. Stopping listening
2023-01-19 20:13:04
2023-01-19T19:13:04.605607564Z stdout F [ 1,21,19:13:04.604,DBG] PROJECTIONS SUBSYSTEM: Not stopping because subsystem is not in a started state. Current Subsystem state: Ready
2023-01-19 20:13:04
2023-01-19T19:13:04.605602592Z stdout F [ 1,21,19:13:04.604,DBG] PROJECTIONS SUBSYSTEM: Not stopping because subsystem is not in a started state. Current Subsystem state: Ready
2023-01-19 20:13:04
2023-01-19T19:13:04.605588928Z stdout F [ 1,14,19:13:04.604,INF] ========== ["0.0.0.0:2113"] IS FOLLOWER... LEADER IS ["10.0.3.192:2113/eventstore.default.svc.cluster.local",{33384843-4d69-4c0d-9653-2995a0e278fb}]
2023-01-19 20:13:04
2023-01-19T19:13:04.605488571Z stdout F [ 1,14,19:13:04.604,INF] ========== ["0.0.0.0:2113"] FOLLOWER ASSIGNMENT RECEIVED FROM ["10.0.3.192:1112/eventstore.default.svc.cluster.local","n/a",{33384843-4d69-4c0d-9653-2995a0e278fb}].
2023-01-19 20:13:04
2023-01-19T19:13:04.605362884Z stdout F [ 1,14,19:13:04.604,INF] ========== ["0.0.0.0:2113"] IS CLONE... LEADER IS ["10.0.3.192:2113/eventstore.default.svc.cluster.local",{33384843-4d69-4c0d-9653-2995a0e278fb}]
2023-01-19 20:13:04
2023-01-19T19:13:04.605099243Z stdout F [ 1,14,19:13:04.604,INF] ========== ["0.0.0.0:2113"] CLONE ASSIGNMENT RECEIVED FROM ["10.0.3.192:1112/eventstore.default.svc.cluster.local","n/a",{33384843-4d69-4c0d-9653-2995a0e278fb}].
2023-01-19 20:13:04
2023-01-19T19:13:04.330193899Z stdout F [ 1, 4,19:13:04.329,DBG] Persistent Subscriptions have been stopped.
2023-01-19 20:13:04
2023-01-19T19:13:04.330191199Z stdout F [ 1, 4,19:13:04.329,DBG] Persistent subscriptions received state change to CatchingUp. Stopping listening
2023-01-19 20:13:04
2023-01-19T19:13:04.330188519Z stdout F [ 1,21,19:13:04.329,DBG] PROJECTIONS SUBSYSTEM: Not stopping because subsystem is not in a started state. Current Subsystem state: Ready
2023-01-19 20:13:04
2023-01-19T19:13:04.330184339Z stdout F [ 1,10,19:13:04.329,INF] === SUBSCRIBED to ["10.0.3.192:1112/eventstore.default.svc.cluster.local",{33384843-4d69-4c0d-9653-2995a0e278fb}] at 48342047 (0x2E1A41F). SubscriptionId: {e6f1b5f7-eea5-47c3-b593-93cd770c6916}.
2023-01-19 20:13:04
2023-01-19T19:13:04.330150391Z stdout F [ 1,14,19:13:04.329,INF] ========== ["0.0.0.0:2113"] IS CATCHING UP... LEADER IS ["10.0.3.192:2113/eventstore.default.svc.cluster.local",{33384843-4d69-4c0d-9653-2995a0e278fb}]
2023-01-19 20:13:04
2023-01-19T19:13:04.329600243Z stdout F [ 1,14,19:13:04.329,INF] Subscribed replica ["Unspecified/10.0.2.194:1112",S:e6f1b5f7-eea5-47c3-b593-93cd770c6916] for data send at 48342047 (0x2E1A41F).
2023-01-19 20:13:04
2023-01-19T19:13:04.32940715Z stdout F [ 1,14,19:13:04.329,INF] SUBSCRIBE REQUEST from ["Unspecified/10.0.2.194:1112",V:1,C:{4c21ab41-a450-4aa6-9285-5c532dfd440e},S:{e6f1b5f7-eea5-47c3-b593-93cd770c6916},48342047(0x2E1A41F),"E0@0:{3298b413-720a-47d1-9626-5a9023d91c28}"]...
2023-01-19 20:13:04
2023-01-19T19:13:04.329265269Z stdout F [ 1,56,19:13:04.329,INF] Internal TCP connection accepted: [Normal, "10.0.2.194:44842", L"10.0.3.192:1112", {4c21ab41-a450-4aa6-9285-5c532dfd440e}].
2023-01-19 20:13:04
2023-01-19T19:13:04.329031571Z stdout F [ 1, 4,19:13:04.328,INF] Connection '"leader-normal"' ({455426e3-57db-4f83-8875-43809ad3a897}) to ["10.0.3.192:1112"] established.
2023-01-19 20:13:04
2023-01-19T19:13:04.329015115Z stdout F .
2023-01-19 20:13:04
2023-01-19T19:13:04.329012468Z stdout F "E0@0:{3298b413-720a-47d1-9626-5a9023d91c28}"...
2023-01-19 20:13:04
2023-01-19T19:13:04.329007604Z stdout F [ 1,14,19:13:04.328,INF] Subscribing at LogPosition: 48342047 (0x2E1A41F) to LEADER ["10.0.3.192:1112/eventstore.default.svc.cluster.local", {33384843-4d69-4c0d-9653-2995a0e278fb}] as replica with SubscriptionId: {e6f1b5f7-eea5-47c3-b593-93cd770c6916}, ConnectionId: {455426e3-57db-4f83-8875-43809ad3a897}, LocalEndPoint: [null], Epochs:
2023-01-19 20:13:04
2023-01-19T19:13:04.328966751Z stdout F [ 1,14,19:13:04.328,INF] "InaugurationManager" in state (PreReplica, Initial): IGNORING "ChaserCaughtUp". Not waiting for chaser.
2023-01-19 20:13:04
2023-01-19T19:13:04.328799031Z stdout F [ 1,21,19:13:04.328,DBG] PROJECTIONS SUBSYSTEM: Not stopping because subsystem is not in a started state. Current Subsystem state: Ready
2023-01-19 20:13:04
2023-01-19T19:13:04.328673053Z stdout F [ 1,32,19:13:04.327,DBG] Persistent Subscriptions have been stopped.
2023-01-19 20:13:04
2023-01-19T19:13:04.328547856Z stdout F [ 1,32,19:13:04.327,DBG] Persistent subscriptions received state change to PreReplica. Stopping listening
2023-01-19 20:13:04
2023-01-19T19:13:04.32838584Z stdout F [ 1,14,19:13:04.327,DBG] Closing connection '"leader-normal"""' ["10.0.3.192:1112/eventstore.default.svc.cluster.local", L"10.0.2.194:50948", {c0391ee3-6f24-4f12-9d88-d8eda1824410}] cleanly." Reason: Reconnecting from old leader [10.0.3.192:1112/eventstore.default.svc.cluster.local] to new leader: [10.0.3.192:1112/eventstore.default.svc.cluster.local]."
2023-01-19 20:13:04
2023-01-19T19:13:04.328012092Z stdout F [ 1,14,19:13:04.327,INF] ========== ["0.0.0.0:2113"] PRE-REPLICA STATE, WAITING FOR CHASER TO CATCH UP... LEADER IS ["10.0.3.192:2113/eventstore.default.svc.cluster.local",{33384843-4d69-4c0d-9653-2995a0e278fb}]
2023-01-19 20:13:04
2023-01-19T19:13:04.106442012Z stdout F [ 1,14,19:13:04.105,INF] Gossip Received, The node ["10.0.2.194:2113/eventstore.default.svc.cluster.local"] is not DEAD.
2023-01-19 20:13:04
2023-01-19T19:13:04.104328059Z stdout F [ 1,14,19:13:04.103,INF] Looks like node ["Unspecified/10.0.2.194:1112"] is DEAD (TCP connection lost). Issuing a gossip to confirm.
2023-01-19 20:13:04
2023-01-19T19:13:04.104046571Z stdout F [ 1,13,19:13:04.103,DBG] Closing connection '"internal-normal"""' ["10.0.2.194:50948", L"10.0.3.192:1112", {5bb9478b-bd05-4e95-a839-98d6e5c3325f}] cleanly." Reason: Closing replication subscription connection."
2023-01-19 20:13:03
2023-01-19T19:13:03.879113387Z stdout F [ 1,14,19:13:03.872,INF] Gossip Received, The node ["10.0.3.192:2113/eventstore.default.svc.cluster.local"] is not DEAD.
2023-01-19 20:13:03
2023-01-19T19:13:03.872030185Z stdout F [ 1,65,19:13:03.871,DBG] Persistent subscription lost connection from "10.0.2.194:50948"
2023-01-19 20:13:03
2023-01-19T19:13:03.827808361Z stdout F [ 1,14,19:13:03.822,INF] Looks like node ["10.0.3.192:1112/eventstore.default.svc.cluster.local"] is DEAD (TCP connection lost). Issuing a gossip to confirm.
2023-01-19 20:13:03
2023-01-19T19:13:03.827732982Z stdout F [ 1,32,19:13:03.822,INF] Connection '"leader-normal"""' ["10.0.3.192:1112", {c0391ee3-6f24-4f12-9d88-d8eda1824410}] closed: Success.
2023-01-19 20:13:03
2023-01-19T19:13:03.827653839Z stdout F [ 1,32,19:13:03.822,INF] ES "TcpConnection" closed [19:13:03.822: N"10.0.3.192:1112", L"10.0.2.194:50948", {c0391ee3-6f24-4f12-9d88-d8eda1824410}]:Close reason: [Success] "Socket closed"
2023-01-19 20:13:03
2023-01-19T19:13:03.827568769Z stdout F [ 1,32,19:13:03.822,INF] ES "TcpConnection" closed [19:13:03.822: N"10.0.3.192:1112", L"10.0.2.194:50948", {c0391ee3-6f24-4f12-9d88-d8eda1824410}]:Receive calls: 10, callbacks: 10
2023-01-19 20:13:03
2023-01-19T19:13:03.827452123Z stdout F [ 1,32,19:13:03.822,INF] ES "TcpConnection" closed [19:13:03.822: N"10.0.3.192:1112", L"10.0.2.194:50948", {c0391ee3-6f24-4f12-9d88-d8eda1824410}]:Send calls: 7, callbacks: 7
2023-01-19 20:13:03
2023-01-19T19:13:03.827077039Z stdout F [ 1,32,19:13:03.822,INF] ES "TcpConnection" closed [19:13:03.822: N"10.0.3.192:1112", L"10.0.2.194:50948", {c0391ee3-6f24-4f12-9d88-d8eda1824410}]:Received bytes: 657, Sent bytes: 336
2023-01-19 20:13:03
2023-01-19T19:13:03.827022894Z stdout F [ 1,12,19:13:03.822,INF] Connection '"internal-normal"""' ["10.0.2.194:50948", {5bb9478b-bd05-4e95-a839-98d6e5c3325f}] closed: Success.
2023-01-19 20:13:03
2023-01-19T19:13:03.827007803Z stdout F [ 1,12,19:13:03.822,INF] ES "TcpConnection" closed [19:13:03.822: N"10.0.2.194:50948", L"10.0.3.192:1112", {5bb9478b-bd05-4e95-a839-98d6e5c3325f}]:Close reason: [Success] "HEARTBEAT TIMEOUT at receiveProgressIndicator=314, sendProgressIndicator=657"
2023-01-19 20:13:03
2023-01-19T19:13:03.826975353Z stdout F [ 1,12,19:13:03.822,INF] ES "TcpConnection" closed [19:13:03.822: N"10.0.2.194:50948", L"10.0.3.192:1112", {5bb9478b-bd05-4e95-a839-98d6e5c3325f}]:Receive calls: 7, callbacks: 6
2023-01-19 20:13:03
2023-01-19T19:13:03.826847802Z stdout F [ 1,12,19:13:03.822,INF] ES "TcpConnection" closed [19:13:03.822: N"10.0.2.194:50948", L"10.0.3.192:1112", {5bb9478b-bd05-4e95-a839-98d6e5c3325f}]:Send calls: 11, callbacks: 11
2023-01-19 20:13:03
2023-01-19T19:13:03.822457401Z stdout F [ 1,12,19:13:03.822,INF] ES "TcpConnection" closed [19:13:03.822: N"10.0.2.194:50948", L"10.0.3.192:1112", {5bb9478b-bd05-4e95-a839-98d6e5c3325f}]:Received bytes: 314, Sent bytes: 657
2023-01-19 20:13:03
2023-01-19T19:13:03.822055504Z stdout F [ 1,12,19:13:03.821,DBG] Closing connection '"internal-normal"""' ["10.0.2.194:50948", L"10.0.3.192:1112", {5bb9478b-bd05-4e95-a839-98d6e5c3325f}] cleanly." Reason: HEARTBEAT TIMEOUT at receiveProgressIndicator=314, sendProgressIndicator=657"
2023-01-19 20:12:58
2023-01-19T19:12:58.880776655Z stdout F [ 1,37,19:12:58.880,DBG] Persistent Subscriptions have been stopped.
2023-01-19 20:12:58
2023-01-19T19:12:58.880717333Z stdout F [ 1,37,19:12:58.880,DBG] Persistent subscriptions received state change to Follower. Stopping listening
When the event appeared in projected streams:
2023-01-19 20:48:50
2023-01-19T19:48:50.261418192Z stdout F [ 1,46,19:48:50.261,INF] Flushed 18 pages out of 33,334. 147,456 bytes. Delay 128 ms per batch. Total delay 0 ms. Actively flushing: 00:00:00.0055764 26.44 MB/s.
2023-01-19 20:48:50
2023-01-19T19:48:50.255698784Z stdout F [ 1,46,19:48:50.255,DBG] "streamExistenceFilter" is flushing at 48,404,402. Diff 54,376 ...
2023-01-19 20:48:44
2023-01-19T19:48:44.227738858Z stdout F [ 1,46,19:48:44.226,DBG] Persistent Subscriptions have been stopped.
2023-01-19 20:48:44
2023-01-19T19:48:44.227736804Z stdout F [ 1,46,19:48:44.226,DBG] Persistent subscriptions received state change to Follower. Stopping listening
2023-01-19 20:48:44
2023-01-19T19:48:44.227734512Z stdout F [ 1,46,19:48:44.226,DBG] Persistent Subscriptions have been stopped.
2023-01-19 20:48:44
2023-01-19T19:48:44.227729276Z stdout F [ 1,46,19:48:44.226,DBG] Persistent subscriptions received state change to Clone. Stopping listening
2023-01-19 20:48:44
2023-01-19T19:48:44.22772658Z stdout F [ 1,21,19:48:44.226,DBG] PROJECTIONS SUBSYSTEM: Not stopping because subsystem is not in a started state. Current Subsystem state: Ready
2023-01-19 20:48:44
2023-01-19T19:48:44.227724197Z stdout F [ 1,14,19:48:44.226,INF] ========== ["0.0.0.0:2113"] IS FOLLOWER... LEADER IS ["10.0.3.192:2113/eventstore.default.svc.cluster.local",{33384843-4d69-4c0d-9653-2995a0e278fb}]
2023-01-19 20:48:44
2023-01-19T19:48:44.227715313Z stdout F [ 1,14,19:48:44.226,INF] ========== ["0.0.0.0:2113"] FOLLOWER ASSIGNMENT RECEIVED FROM ["10.0.3.192:1112/eventstore.default.svc.cluster.local","n/a",{33384843-4d69-4c0d-9653-2995a0e278fb}].
2023-01-19 20:48:44
2023-01-19T19:48:44.227712836Z stdout F [ 1,21,19:48:44.226,DBG] PROJECTIONS SUBSYSTEM: Not stopping because subsystem is not in a started state. Current Subsystem state: Ready
2023-01-19 20:48:44
2023-01-19T19:48:44.227708339Z stdout F [ 1,14,19:48:44.226,INF] ========== ["0.0.0.0:2113"] IS CLONE... LEADER IS ["10.0.3.192:2113/eventstore.default.svc.cluster.local",{33384843-4d69-4c0d-9653-2995a0e278fb}]
2023-01-19 20:48:44
2023-01-19T19:48:44.227679371Z stdout F [ 1,14,19:48:44.226,INF] ========== ["0.0.0.0:2113"] CLONE ASSIGNMENT RECEIVED FROM ["10.0.3.192:1112/eventstore.default.svc.cluster.local","n/a",{33384843-4d69-4c0d-9653-2995a0e278fb}].
2023-01-19 20:48:44
2023-01-19T19:48:44.169607916Z stdout F [ 1,46,19:48:44.169,DBG] Persistent Subscriptions have been stopped.
2023-01-19 20:48:44
2023-01-19T19:48:44.169604994Z stdout F [ 1,46,19:48:44.169,DBG] Persistent subscriptions received state change to CatchingUp. Stopping listening
2023-01-19 20:48:44
2023-01-19T19:48:44.169601721Z stdout F [ 1,21,19:48:44.169,DBG] PROJECTIONS SUBSYSTEM: Not stopping because subsystem is not in a started state. Current Subsystem state: Ready
2023-01-19 20:48:44
2023-01-19T19:48:44.169597811Z stdout F [ 1,10,19:48:44.169,INF] === SUBSCRIBED to ["10.0.3.192:1112/eventstore.default.svc.cluster.local",{33384843-4d69-4c0d-9653-2995a0e278fb}] at 48394956 (0x2E272CC). SubscriptionId: {a1615520-59d3-476c-a39c-3b82f66aea2f}.
2023-01-19 20:48:44
2023-01-19T19:48:44.169581316Z stdout F [ 1,14,19:48:44.169,INF] ========== ["0.0.0.0:2113"] IS CATCHING UP... LEADER IS ["10.0.3.192:2113/eventstore.default.svc.cluster.local",{33384843-4d69-4c0d-9653-2995a0e278fb}]
2023-01-19 20:48:44
2023-01-19T19:48:44.168877475Z stdout F [ 1,14,19:48:44.168,INF] Subscribed replica ["Unspecified/10.0.2.194:1112",S:a1615520-59d3-476c-a39c-3b82f66aea2f] for data send at 48394956 (0x2E272CC).
2023-01-19 20:48:44
2023-01-19T19:48:44.168835252Z stdout F [ 1,14,19:48:44.168,INF] SUBSCRIBE REQUEST from ["Unspecified/10.0.2.194:1112",V:1,C:{f4820686-2525-4b8e-a7c7-7b5b8c052476},S:{a1615520-59d3-476c-a39c-3b82f66aea2f},48394956(0x2E272CC),"E0@0:{3298b413-720a-47d1-9626-5a9023d91c28}"]...
2023-01-19 20:48:44
2023-01-19T19:48:44.168773596Z stdout F [ 1,68,19:48:44.168,INF] Internal TCP connection accepted: [Normal, "10.0.2.194:42072", L"10.0.3.192:1112", {f4820686-2525-4b8e-a7c7-7b5b8c052476}].
2023-01-19 20:48:44
2023-01-19T19:48:44.168467105Z stdout F [ 1,46,19:48:44.168,INF] Connection '"leader-normal"' ({550d64f2-85f6-40d6-8335-c4cd3da297c1}) to ["10.0.3.192:1112"] established.
2023-01-19 20:48:44
2023-01-19T19:48:44.168445882Z stdout F .
2023-01-19 20:48:44
2023-01-19T19:48:44.16814141Z stdout F "E0@0:{3298b413-720a-47d1-9626-5a9023d91c28}"...
2023-01-19 20:48:44
2023-01-19T19:48:44.168138682Z stdout F [ 1,14,19:48:44.167,INF] Subscribing at LogPosition: 48394956 (0x2E272CC) to LEADER ["10.0.3.192:1112/eventstore.default.svc.cluster.local", {33384843-4d69-4c0d-9653-2995a0e278fb}] as replica with SubscriptionId: {a1615520-59d3-476c-a39c-3b82f66aea2f}, ConnectionId: {550d64f2-85f6-40d6-8335-c4cd3da297c1}, LocalEndPoint: [null], Epochs:
2023-01-19 20:48:44
2023-01-19T19:48:44.168134288Z stdout F [ 1,14,19:48:44.167,INF] "InaugurationManager" in state (PreReplica, Initial): IGNORING "ChaserCaughtUp". Not waiting for chaser.
2023-01-19 20:48:44
2023-01-19T19:48:44.168131474Z stdout F [ 1,21,19:48:44.167,DBG] PROJECTIONS SUBSYSTEM: Not stopping because subsystem is not in a started state. Current Subsystem state: Ready
2023-01-19 20:48:44
2023-01-19T19:48:44.168125287Z stdout F [ 1,46,19:48:44.167,DBG] Persistent Subscriptions have been stopped.
2023-01-19 20:48:44
2023-01-19T19:48:44.168086369Z stdout F [ 1,46,19:48:44.167,DBG] Persistent subscriptions received state change to PreReplica. Stopping listening
2023-01-19 20:48:44
2023-01-19T19:48:44.167650609Z stdout F [ 1,14,19:48:44.167,DBG] Closing connection '"leader-normal"""' ["10.0.3.192:1112/eventstore.default.svc.cluster.local", L"10.0.2.194:44206", {3e816b20-2e04-4bd3-bf40-4bd81c6dce7f}] cleanly." Reason: Reconnecting from old leader [10.0.3.192:1112/eventstore.default.svc.cluster.local] to new leader: [10.0.3.192:1112/eventstore.default.svc.cluster.local]."
2023-01-19 20:48:44
2023-01-19T19:48:44.167617849Z stdout F [ 1,14,19:48:44.167,INF] ========== ["0.0.0.0:2113"] PRE-REPLICA STATE, WAITING FOR CHASER TO CATCH UP... LEADER IS ["10.0.3.192:2113/eventstore.default.svc.cluster.local",{33384843-4d69-4c0d-9653-2995a0e278fb}]
2023-01-19 20:48:43
2023-01-19T19:48:43.906985605Z stdout F [ 1,14,19:48:43.906,INF] Gossip Received, The node ["10.0.2.194:2113/eventstore.default.svc.cluster.local"] is not DEAD.
2023-01-19 20:48:43
2023-01-19T19:48:43.904430475Z stdout F [ 1,14,19:48:43.904,INF] Looks like node ["Unspecified/10.0.2.194:1112"] is DEAD (TCP connection lost). Issuing a gossip to confirm.
2023-01-19 20:48:43
2023-01-19T19:48:43.904302322Z stdout F [ 1,13,19:48:43.904,DBG] Closing connection '"internal-normal"""' ["10.0.2.194:44206", L"10.0.3.192:1112", {720d0d18-5bd9-4a8a-970e-b463781c37bf}] cleanly." Reason: Closing replication subscription connection."
2023-01-19 20:48:43
2023-01-19T19:48:43.666617886Z stdout F [ 1,14,19:48:43.666,INF] Gossip Received, The node ["10.0.3.192:2113/eventstore.default.svc.cluster.local"] is not DEAD.
2023-01-19 20:48:43
2023-01-19T19:48:43.664200204Z stdout F [ 1,14,19:48:43.663,INF] Looks like node ["10.0.3.192:1112/eventstore.default.svc.cluster.local"] is DEAD (TCP connection lost). Issuing a gossip to confirm.
2023-01-19 20:48:43
2023-01-19T19:48:43.664196734Z stdout F [ 1,39,19:48:43.663,INF] Connection '"leader-normal"""' ["10.0.3.192:1112", {3e816b20-2e04-4bd3-bf40-4bd81c6dce7f}] closed: Success.
2023-01-19 20:48:43
2023-01-19T19:48:43.664181057Z stdout F [ 1,39,19:48:43.663,INF] ES "TcpConnection" closed [19:48:43.663: N"10.0.3.192:1112", L"10.0.2.194:44206", {3e816b20-2e04-4bd3-bf40-4bd81c6dce7f}]:Close reason: [Success] "Socket closed"
2023-01-19 20:48:43
2023-01-19T19:48:43.664177707Z stdout F [ 1,39,19:48:43.663,INF] ES "TcpConnection" closed [19:48:43.663: N"10.0.3.192:1112", L"10.0.2.194:44206", {3e816b20-2e04-4bd3-bf40-4bd81c6dce7f}]:Receive calls: 252, callbacks: 252
2023-01-19 20:48:43
2023-01-19T19:48:43.664173009Z stdout F [ 1,39,19:48:43.663,INF] ES "TcpConnection" closed [19:48:43.663: N"10.0.3.192:1112", L"10.0.2.194:44206", {3e816b20-2e04-4bd3-bf40-4bd81c6dce7f}]:Send calls: 201, callbacks: 201
2023-01-19 20:48:43
2023-01-19T19:48:43.664141701Z stdout F [ 1,39,19:48:43.663,INF] ES "TcpConnection" closed [19:48:43.663: N"10.0.3.192:1112", L"10.0.2.194:44206", {3e816b20-2e04-4bd3-bf40-4bd81c6dce7f}]:Received bytes: 13384, Sent bytes: 6004
2023-01-19 20:48:43
2023-01-19T19:48:43.525386743Z stdout F [ 1,41,19:48:43.525,DBG] Persistent subscription lost connection from "10.0.2.194:44206"
2023-01-19 20:48:43
2023-01-19T19:48:43.525341143Z stdout F [ 1,12,19:48:43.524,INF] Connection '"internal-normal"""' ["10.0.2.194:44206", {720d0d18-5bd9-4a8a-970e-b463781c37bf}] closed: Success.
2023-01-19 20:48:43
2023-01-19T19:48:43.525278765Z stdout F [ 1,12,19:48:43.524,INF] ES "TcpConnection" closed [19:48:43.524: N"10.0.2.194:44206", L"10.0.3.192:1112", {720d0d18-5bd9-4a8a-970e-b463781c37bf}]:Close reason: [Success] "HEARTBEAT TIMEOUT at receiveProgressIndicator=5982, sendProgressIndicator=13384"
2023-01-19 20:48:43
2023-01-19T19:48:43.525177516Z stdout F [ 1,12,19:48:43.524,INF] ES "TcpConnection" closed [19:48:43.524: N"10.0.2.194:44206", L"10.0.3.192:1112", {720d0d18-5bd9-4a8a-970e-b463781c37bf}]:Receive calls: 201, callbacks: 201
2023-01-19 20:48:43
2023-01-19T19:48:43.525088775Z stdout F [ 1,12,19:48:43.524,INF] ES "TcpConnection" closed [19:48:43.524: N"10.0.2.194:44206", L"10.0.3.192:1112", {720d0d18-5bd9-4a8a-970e-b463781c37bf}]:Send calls: 255, callbacks: 255
2023-01-19 20:48:43
2023-01-19T19:48:43.524976251Z stdout F [ 1,12,19:48:43.524,INF] ES "TcpConnection" closed [19:48:43.524: N"10.0.2.194:44206", L"10.0.3.192:1112", {720d0d18-5bd9-4a8a-970e-b463781c37bf}]:Received bytes: 5982, Sent bytes: 13384
2023-01-19 20:48:43
2023-01-19T19:48:43.52458681Z stdout F [ 1,12,19:48:43.524,DBG] Closing connection '"internal-normal"""' ["10.0.2.194:44206", L"10.0.3.192:1112", {720d0d18-5bd9-4a8a-970e-b463781c37bf}] cleanly." Reason: HEARTBEAT TIMEOUT at receiveProgressIndicator=5982, sendProgressIndicator=13384"