Interest based stream sequence reset to 0 when upgrading to 2.10.25 and causes consumer error #6611

Alvaro82 · 2025-03-07T09:23:36Z

Observed behavior

Upgrading NATS from version 2.9.15 to version 2.10.25 has caused errors in Jetstream persistence. The first time I executed version 2.10.25 apparently there were no problems, at least the log was clean. But when I stopped NATS and executed it a second time, I got warnings about errors in the stream and finally the consumer was incorrect. I have tested it on 3 servers configured the same way and the error is the same with this stream.

This stream is empty and is configured with Interest based retention. There is another empty stream with Limits based retention and had no problems.

I also tried publishing messages in the stream in v2.9.15 so that it is not empty when updating and in that case there were no problems.
Then I tried purging the stream to leave it empty again, and there were no problems there either.
However, if I consume the new messages with the existing durable consumer and it becomes empty again, the error returns on update.

This problem seems to be similar #5412

Full log here: nats-server.log

[INF]   Starting restore for stream '$G > CONNECTOR'
[WRN] Filestore [CONNECTOR] Stream state outdated, last block has additional entries, will rebuild
[WRN] Filestore [CONNECTOR] Recovering stream state from index errored: prior state file
[INF]   Restored 0 messages for stream '$G > CONNECTOR' in 2ms
...
[INF]   Recovering 1 consumers for stream - '$G > CONNECTOR'
...
[WRN] Detected consumer '$G > CONNECTOR > Connector-SequentialSender' ack floor 5588 is ahead of stream's last sequence 0

This is the status of the stream and the consumer BEFORE the warning:

C:\>nats stream info
[basic] ? Select a Stream CONNECTOR
Information for Stream CONNECTOR created 2024-08-01 13:24:58

              Subjects: CONNECTOR.ERPNOTIFICATIONS
              Replicas: 1
               Storage: File

Options:

             Retention: Interest
       Acknowledgments: 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: 60d0h0m0s
  Maximum Message Size: unlimited
     Maximum Consumers: unlimited

State:

              Messages: 0
                 Bytes: 0 B
        First Sequence: 5,589
         Last Sequence: 5,588 @ 2024-10-22 16:28:40 UTC
      Active Consumers: 1


C:\>nats consumer info
[basic] ? Select a Stream CONNECTOR
[basic] ? Select a Consumer Connector-SequentialSender
Information for Consumer CONNECTOR > Connector-SequentialSender created 2024-10-10T15:37:53+02:00

Configuration:

                    Name: Connector-SequentialSender
        Delivery Subject: _INBOX.m23kQ0r_x9h6iDLA6zDx-g
          Filter Subject: CONNECTOR.ERPNOTIFICATIONS
          Deliver Policy: New
              Ack Policy: Explicit
                Ack Wait: 4m30s
           Replay Policy: Instant
         Max Ack Pending: 1
            Flow Control: false

State:

  Last Delivered Message: Consumer sequence: 5,603 Stream sequence: 5,588
    Acknowledgment Floor: Consumer sequence: 5,603 Stream sequence: 5,588
        Outstanding Acks: 0 out of maximum 1
    Redelivered Messages: 0
    Unprocessed Messages: 0
         Active Interest: No interest

And AFTER the warning. The sequence of the stream has been reset to 0:

C:\>nats stream info
[basic] ? Select a Stream CONNECTOR
Information for Stream CONNECTOR created 2024-08-01 13:24:58

              Subjects: CONNECTOR.ERPNOTIFICATIONS
              Replicas: 1
               Storage: File

Options:

             Retention: Interest
       Acknowledgments: 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: 60d0h0m0s
  Maximum Message Size: unlimited
     Maximum Consumers: unlimited

State:

              Messages: 0
                 Bytes: 0 B
        First Sequence: 0
         Last Sequence: 0
      Active Consumers: 1


C:\>nats consumer info
[basic] ? Select a Stream CONNECTOR
[basic] ? Select a Consumer Connector-SequentialSender
Information for Consumer CONNECTOR > Connector-SequentialSender created 2024-10-10T15:37:53+02:00

Configuration:

                    Name: Connector-SequentialSender
        Delivery Subject: _INBOX.m23kQ0r_x9h6iDLA6zDx-g
          Filter Subject: CONNECTOR.ERPNOTIFICATIONS
          Deliver Policy: New
              Ack Policy: Explicit
                Ack Wait: 4m30s
           Replay Policy: Instant
         Max Ack Pending: 1
            Flow Control: false

State:

  Last Delivered Message: Consumer sequence: 5,603 Stream sequence: 5,588
    Acknowledgment Floor: Consumer sequence: 5,603 Stream sequence: 5,588
        Outstanding Acks: 0 out of maximum 1
    Redelivered Messages: 0
    Unprocessed Messages: 0
         Active Interest: No interest

Expected behavior

The sequence should not have been reset and the consumer should remain valid.

Server and client version

Tested with version 2.10.25 and 2.10.26 and NATS CLI

Host environment

Running a single-node NATS JetStream in Windows with this configuration:

max_payload: 8MB
port: 4222
monitor_port: 8222

#Logging
debug: true
trace: true
trace_verbose: true
logfile_size_limit: 30MB
logfile_max_num: 3
log_file: "nats-server.log"

jetstream {
  max_file_store: 30GB
  max_memory_store: 10GB
  store_dir: data
}

Steps to reproduce

No response

The text was updated successfully, but these errors were encountered:

neilalexander · 2025-03-07T12:01:33Z

Thanks for the report, I think I may know what's happening here but will look into it.

Alvaro82 · 2025-03-20T10:09:43Z

Any update on this? There seem to be several similar problems, some closed and some still open...

wallyqs · 2025-03-20T16:58:56Z

first would recommend to upgrade to v2.10.26 since there was a regression with interest based streams on v2.10.25: #6526

Alvaro82 · 2025-03-21T10:28:04Z

I already tested it with v2.10.26 and it also returned the same error.
And I just tested it with v2.11.0 and it is not fixed.

[30636] 2025/03/21 11:21:56.248369 [INF] Starting nats-server
[30636] 2025/03/21 11:21:56.291984 [INF]   Version:  2.11.0
[30636] 2025/03/21 11:21:56.291984 [INF]   Git:      [99e836e]
[30636] 2025/03/21 11:21:56.291984 [INF]   Name:     NCTYJHT436UYK5BI4FVNWPUZJY2IIEKXEDSIFCMAZDRR7OQYH5XHK55S
[30636] 2025/03/21 11:21:56.291984 [INF]   Node:     jQsfNGpC
[30636] 2025/03/21 11:21:56.291984 [INF]   ID:       NCTYJHT436UYK5BI4FVNWPUZJY2IIEKXEDSIFCMAZDRR7OQYH5XHK55S
[30636] 2025/03/21 11:21:56.291984 [INF] Using configuration file: nats-server.conf (sha256:f4a16e93203160ee52c43c93f5b894c114634f07e53b23dd689923c435ed092e)
[30636] 2025/03/21 11:21:56.294694 [INF] Starting http monitor on 0.0.0.0:8222
[30636] 2025/03/21 11:21:56.295220 [INF] Starting JetStream
[30636] 2025/03/21 11:21:56.296791 [INF]     _ ___ _____ ___ _____ ___ ___   _   __  __
[30636] 2025/03/21 11:21:56.296791 [INF]  _ | | __|_   _/ __|_   _| _ \ __| /_\ |  \/  |
[30636] 2025/03/21 11:21:56.296791 [INF] | || | _|  | | \__ \ | | |   / _| / _ \| |\/| |
[30636] 2025/03/21 11:21:56.296791 [INF]  \__/|___| |_| |___/ |_| |_|_\___/_/ \_\_|  |_|
[30636] 2025/03/21 11:21:56.296791 [INF]
[30636] 2025/03/21 11:21:56.296791 [INF]          https://docs.nats.io/jetstream
[30636] 2025/03/21 11:21:56.296791 [INF]
[30636] 2025/03/21 11:21:56.296791 [INF] ---------------- JETSTREAM ----------------
[30636] 2025/03/21 11:21:56.297308 [INF]   Max Memory:      10.00 GB
[30636] 2025/03/21 11:21:56.297308 [INF]   Max Storage:     30.00 GB
[30636] 2025/03/21 11:21:56.297308 [INF]   Store Directory: "data\jetstream"
[30636] 2025/03/21 11:21:56.297308 [INF]   API Level:       1
[30636] 2025/03/21 11:21:56.297308 [INF] -------------------------------------------
[30636] 2025/03/21 11:21:56.298347 [INF]   Starting restore for stream '$G > CONNECTOR'
[30636] 2025/03/21 11:21:56.299405 [WRN] Filestore [CONNECTOR] Stream state outdated, last block has additional entries, will rebuild
[30636] 2025/03/21 11:21:56.299405 [WRN] Filestore [CONNECTOR] Recovering stream state from index errored: prior state file
[30636] 2025/03/21 11:21:56.300455 [INF]   Restored 0 messages for stream '$G > CONNECTOR' in 2ms
[30636] 2025/03/21 11:21:56.300973 [INF]   Starting restore for stream '$G > FEEDBACK'
[30636] 2025/03/21 11:21:56.302005 [INF]   Restored 1,494 messages for stream '$G > FEEDBACK' in 1ms
[30636] 2025/03/21 11:21:56.302523 [INF]   Starting restore for stream '$G > INTEGRATION'
[30636] 2025/03/21 11:21:56.303563 [INF]   Restored 996 messages for stream '$G > INTEGRATION' in 1ms
[30636] 2025/03/21 11:21:56.304116 [INF]   Starting restore for stream '$G > INVENTORY'
[30636] 2025/03/21 11:21:56.305709 [INF]   Restored 19 messages for stream '$G > INVENTORY' in 2ms
[30636] 2025/03/21 11:21:56.306233 [INF]   Starting restore for stream '$G > MONITORING'
[30636] 2025/03/21 11:21:56.307814 [INF]   Restored 1,237,401 messages for stream '$G > MONITORING' in 2ms
[30636] 2025/03/21 11:21:56.308866 [INF]   Starting restore for stream '$G > PRODUCTION'
[30636] 2025/03/21 11:21:56.310454 [INF]   Restored 1,697 messages for stream '$G > PRODUCTION' in 2ms
[30636] 2025/03/21 11:21:56.310985 [INF]   Starting restore for stream '$G > RESPONSE'
[30636] 2025/03/21 11:21:56.312090 [INF]   Restored 2,171 messages for stream '$G > RESPONSE' in 1ms
[30636] 2025/03/21 11:21:56.312090 [INF]   Recovering 1 consumers for stream - '$G > CONNECTOR'
[30636] 2025/03/21 11:21:56.313123 [INF]   Recovering 5 consumers for stream - '$G > FEEDBACK'
[30636] 2025/03/21 11:21:56.316986 [INF]   Recovering 4 consumers for stream - '$G > INTEGRATION'
[30636] 2025/03/21 11:21:56.321903 [INF]   Recovering 1 consumers for stream - '$G > INVENTORY'
[30636] 2025/03/21 11:21:56.322991 [INF]   Recovering 4 consumers for stream - '$G > MONITORING'
[30636] 2025/03/21 11:21:56.325118 [INF]   Recovering 7 consumers for stream - '$G > PRODUCTION'
[30636] 2025/03/21 11:21:56.330057 [INF]   Recovering 6 consumers for stream - '$G > RESPONSE'
[30636] 2025/03/21 11:21:56.334504 [WRN] Detected consumer '$G > CONNECTOR > Connector-SequentialSender' ack floor 5588 is ahead of stream's last sequence 0
[30636] 2025/03/21 11:21:56.335022 [INF] Listening for client connections on 0.0.0.0:4222
[30636] 2025/03/21 11:21:56.445595 [INF] Server is ready

souravagrawal · 2025-03-25T05:20:49Z

By any chance did you see abnormal termination of NATS after which you have started seeing this issue ?

Alvaro82 · 2025-03-25T08:18:01Z

I have not seen any previous errors in the logs in version 2.9.15 but it is true that in the test environment where this instance of NATS was running it would restart from time to time without properly stopping the NATS server. This has been fixed, but it doesn't seem to be a problem in version 2.9.15.
Could it be that some corrupted data produced by a non-graceful stop causes this error in the v2.10 storage format change?

Alvaro82 added the defect Suspected defect such as a bug or regression label Mar 7, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Interest based stream sequence reset to 0 when upgrading to 2.10.25 and causes consumer error #6611

Interest based stream sequence reset to 0 when upgrading to 2.10.25 and causes consumer error #6611

Alvaro82 commented Mar 7, 2025

neilalexander commented Mar 7, 2025

Alvaro82 commented Mar 20, 2025

wallyqs commented Mar 20, 2025

Alvaro82 commented Mar 21, 2025

souravagrawal commented Mar 25, 2025

Alvaro82 commented Mar 25, 2025

Interest based stream sequence reset to 0 when upgrading to 2.10.25 and causes consumer error #6611

Interest based stream sequence reset to 0 when upgrading to 2.10.25 and causes consumer error #6611

Comments

Alvaro82 commented Mar 7, 2025

Observed behavior

Expected behavior

Server and client version

Host environment

Steps to reproduce

neilalexander commented Mar 7, 2025

Alvaro82 commented Mar 20, 2025

wallyqs commented Mar 20, 2025

Alvaro82 commented Mar 21, 2025

souravagrawal commented Mar 25, 2025

Alvaro82 commented Mar 25, 2025