nats-server
nats-server copied to clipboard
Should I pay attention to "Delivery Terminated" advisory messages?
I have a application subscribed to a durable consumer. When a message is consumed it is removed by the stream as per retention rules. The setup seems to be working as the stream message count stays at 0.
However when observing nats event --js-advisory
results I noticed these every few minutes or so
...
[ More "Delivery Terminated" events ]
...
[15:57:24] [GG9sNLjwyDKp4JVxIfwp3v] Delivery Terminated
Consumer: logs > logs-consumer
Stream Sequence: 277535989
Deliveries: 0
[16:00:00] [GG9sNLjwyDKp4JVxIfwp4c] Delivery Terminated
Consumer: logs > logs-consumer
Stream Sequence: 277536551
Deliveries: 0
...
[ More "Delivery Terminated" events ]
...
Should I be concerned about the above? Sounds like delivery was terminated and something did not get the message? Why would Delivery Terminated be recorded for 2 messages but not for the rest? As far as application logic is concerned all messages (including these 2) should have been processed exactly the same way. There are also no errors in application logs. But the advisory log suggests something distinctly different happened to these 2 messages (and other "Delivery Terminated" messages).
nats stream info logs
Information for Stream logs created 2022-07-13 20:07:45
Subjects: logs.>
Replicas: 3
Storage: File
Options:
Retention: Interest
Acknowledgements: true
Discard Policy: Old
Duplicate Window: 2m0s
Allows Msg Delete: true
Allows Purge: true
Allows Rollups: false
Limits:
Maximum Messages: unlimited
Maximum Per Subject: unlimited
Maximum Bytes: 1.0 GiB
Maximum Age: 5d0h0m0s
Maximum Message Size: unlimited
Maximum Consumers: unlimited
Cluster Information:
Name: nats-cluster
Leader: nats2
Replica: nats3, current, seen 0.23s ago
Replica: nats1, current, seen 0.23s ago
State:
Messages: 0
Bytes: 0 B
FirstSeq: 281,225,307
LastSeq: 281,225,306 @ 2023-03-13T16:46:13 UTC
Active Consumers: 2
nats consumer info logs logs-consumer
Information for Consumer logs > logs-consumer created 2023-02-09T08:34:06Z
Configuration:
Durable Name: logs-consumer
Delivery Subject: logs-consumer.logs
Deliver Policy: All
Deliver Queue Group: logs-consumer
Ack Policy: Explicit
Ack Wait: 30s
Replay Policy: Instant
Max Ack Pending: 1,000
Flow Control: false
Cluster Information:
Name: nats-cluster
Leader: nats1
Replica: nats3, current, seen 0.45s ago
Replica: nats2, current, seen 0.45s ago
State:
Last Delivered Message: Consumer sequence: 281,139,766 Stream sequence: 281,225,537 Last delivery: 0.45s ago
Acknowledgment floor: Consumer sequence: 281,139,766 Stream sequence: 281,225,537 Last Ack: 0.45s ago
Outstanding Acks: 0 out of maximum 1,000
Redelivered Messages: 0
Unprocessed Messages: 0
Active Interest: Active using Queue Group logs-consumer
Is there reason for concern?
I did some spelunking in the code and it seems these are generated - among others - when a limit is evicting a message that is still being processed (we have an outstanding ack).
Fair enough to get a notice about that, but I think the server needs to start adding reasons to these so they can be distinguished as now that isnt useful. (This is also mentioned in the comments in the code).