search

nats-io / nats-server

High-Performance server for NATS.io, the cloud and edge native messaging system.
https://nats.io
Apache License 2.0
15.49k stars 1.38k forks source link

Mirror stream cross accounts not fully synced #2605

Closed phho closed 2 years ago

phho commented 2 years ago

Defect

Follow the document (https://github.com/nats-io/jetstream-leaf-nodes-demo#connect-streams-cross-accounts) to configure mirror stream from another account's stream. It's not fully synced even after a long time.

Versions of nats-server and affected client libraries used:

OS/Container environment:

Steps or code to reproduce the issue:

It is different from the documents (https://github.com/nats-io/jetstream-leaf-nodes-demo#connect-streams-cross-accounts), we only used one nats-sever and not in cluster mode to simplify the reproduction.

> curl -L https://github.com/nats-io/nats-server/releases/download/v2.6.1/nats-server-v2.6.1-linux-amd64.zip -o nats-server.zip
> unzip nats-server.zip -d nats-server
> sudo cp nats-server/nats-server-v2.6.1-linux-amd64/nats-server /usr/bin
> curl -L https://github.com/nats-io/nsc/releases/download/2.2.6/nsc-linux-amd64.zip -o nsc.zip
> unzip nsc.zip -d nsc
> sudo cp nsc/nsc /usr/bin
> curl -L https://github.com/nats-io/natscli/releases/download/0.0.26/nats-0.0.26-linux-amd64.zip -o natscli.zip
> unzip natscli.zip -d natscli
> sudo cp natscli/nats-0.0.26-linux-amd64/nats /usr/bin

# confirm nats cli/nsc/nats-erver versions
> nats --version
0.0.26
> nsc --version
nsc version 2.2.6
> nats-server --version
nats-server: v2.6.1

# add operator
> nsc add operator myoperator --sys
[ OK ] generated and stored operator key "ODNGXKJDMQ2PEQ5QFE74JA6UAYULSTJB6BM2JGEDV2F6RGKFLK3GEM2W"
[ OK ] added operator "myoperator"
[ OK ] When running your own nats-server, make sure they run at least version 2.2.0
[ OK ] created system_account: name:SYS id:ABNCZJRFOUHOMYWNTVLKQFXMV4BPFRACRKTMCRC5CQFAXHRARSJENM4J
[ OK ] created system account user: name:sys id:UAWZNHB3SJYEDORWWNRDRWRSR23XDNZWFYFSXDVR2OESUEZXLC2INZFN
[ OK ] system account user creds file stored in `~/.nkeys/creds/myoperator/SYS/sys.creds`

# create nats-account-resolver.cfg
> nsc generate config --config-file nats-account-resolver.cfg --nats-resolver
[ OK ] wrote server configuration to `~/nats-account-resolver.cfg`
Success!! - generated `~/nats-account-resolver.cfg`

# Add accounts and users 
> nsc add account -n TEST
> nsc edit account --name TEST --js-disk-storage -1 --js-streams -1 --js-consumer -1
> nsc add user --account TEST -n tuser
> nsc add account -n IMPORTER
> nsc edit account --name IMPORTER --js-disk-storage -1 --js-streams -1 --js-consumer -1
> nsc add user --account IMPORTER -n iuser
> nsc add export --account TEST --name Consumer-API --service --response-type Stream --subject '$JS.hub.API.CONSUMER.>'
> nsc add import --account IMPORTER --src-account TEST --name Remote-Consumer-API --service --remote-subject '$JS.hub.API.CONSUMER.>' --local-subject 'JS.test@hub.API.CONSUMER.>'
> nsc add export --account TEST --name Data-Path --response-type Stream --subject 'deliver.>'
> nsc add import --account IMPORTER --src-account TEST --name Remote-Data-Path --remote-subject 'deliver.importer.>'

# hub.cfg content
> cat hub.cfg
listen: localhost:4222
server_name: srv-4222
jetstream {
    store_dir: "./hub"
    domain: hub
}
include ./nats-account-resolver.cfg

# Start nats-server with hub.cfg 
> nats-server -c hub.cfg
# push to nats-server
> nsc push -A -u nats://localhost:4222

[ OK ] push to nats-server "nats://localhost:4222" using system account "SYS":
       [ OK ] push IMPORTER to nats-server with nats account resolver:
              [ OK ] pushed "IMPORTER" to nats-server srv-4222: jwt updated
              [ OK ] pushed to a total of 1 nats-server
       [ OK ] push SYS to nats-server with nats account resolver:
              [ OK ] pushed "SYS" to nats-server srv-4222: jwt updated
              [ OK ] pushed to a total of 1 nats-server
       [ OK ] push TEST to nats-server with nats account resolver:
              [ OK ] pushed "TEST" to nats-server srv-4222: jwt updated
              [ OK ] pushed to a total of 1 nats-server

Completed the account relationship as below diagram and update to nats-server, the next test will see the problem of message synchronization. relationships-between-accounts

# Create source stream
> nats stream create --creds ~/.nkeys/creds/myoperator/TEST/tuser.creds --js-domain hub
? Stream Name source-stream
? Subjects to consume test
? Storage backend file
? Retention Policy Limits
? Discard Policy Old
? Stream Messages Limit -1
? Per Subject Messages Limit -1
? Message size limit -1
? Maximum message age limit -1
? Maximum individual message size -1
? Duplicate tracking time window 2m
? Replicas 1
Stream source-stream was created

Information for Stream source-stream created 2021-10-08T22:16:00+08:00

Configuration:

             Subjects: test
     Acknowledgements: true
            Retention: File - Limits
             Replicas: 1
       Discard Policy: Old
     Duplicate Window: 2m0s
     Maximum Messages: unlimited
        Maximum Bytes: unlimited
          Maximum Age: 0.00s
 Maximum Message Size: unlimited
    Maximum Consumers: unlimited

# Create cross account mirror stream
> nats stream create crossacc --mirror source-stream --js-domain hub --creds ~/.nkeys/creds/myoperator/IMPORTER/iuser.creds
? Storage backend file
? Retention Policy Limits
? Discard Policy Old
? Stream Messages Limit -1
? Message size limit -1
? Maximum message age limit -1
? Maximum individual message size -1
? Replicas 1
? Adjust mirror start No
? Import mirror from a different JetStream domain No
? Import mirror from a different account Yes
? Foreign account API prefix JS.test@hub.API
? Foreign account delivery prefix deliver.importer.crossacc
Stream crossacc was created

Information for Stream crossacc created 2021-10-08T22:20:56+08:00

Configuration:

     Acknowledgements: true
            Retention: File - Limits
             Replicas: 1
       Discard Policy: Old
     Duplicate Window: 2m0s
     Maximum Messages: unlimited
        Maximum Bytes: unlimited
          Maximum Age: 0.00s
 Maximum Message Size: unlimited
    Maximum Consumers: unlimited
               Mirror: source-stream, API Prefix: JS.test@hub.API, Delivery Prefix: deliver.importer.crossacc

# publish to source-stream's subject
> nats pub test hello --count 1000 --js-domain hub --creds ~/.nkeys/creds/myoperator/TEST/tuser.creds

1000 / 1000 [===================================================================================================================================]    0s

> date
Fri Oct  8 22:24:57 CST 2021
> nats stream report --js-domain hub --creds ~/.nkeys/creds/myoperator/TEST/tuser.creds
Obtaining Stream stats

╭─────────────────────────────────────────────────────────────────────────────────────╮
│                                    Stream Report                                    │
├───────────────┬─────────┬───────────┬──────────┬────────┬──────┬─────────┬──────────┤
│ Stream        │ Storage │ Consumers │ Messages │ Bytes  │ Lost │ Deleted │ Replicas │
├───────────────┼─────────┼───────────┼──────────┼────────┼──────┼─────────┼──────────┤
│ source-stream │ File    │ 0         │ 1,000    │ 38 KiB │ 0    │ 0       │          │
╰───────────────┴─────────┴───────────┴──────────┴────────┴──────┴─────────┴──────────╯

# After a while, it didn't sync from source stream.
> date
Fri Oct  8 22:26:03 CST 2021
> nats stream report --js-domain hub --creds ~/.nkeys/creds/myoperator/IMPORTER/iuser.creds
Obtaining Stream stats

╭────────────────────────────────────────────────────────────────────────────────╮
│                                 Stream Report                                  │
├──────────┬─────────┬───────────┬──────────┬────────┬──────┬─────────┬──────────┤
│ Stream   │ Storage │ Consumers │ Messages │ Bytes  │ Lost │ Deleted │ Replicas │
├──────────┼─────────┼───────────┼──────────┼────────┼──────┼─────────┼──────────┤
│ crossacc │ File    │ 0         │ 639      │ 24 KiB │ 0    │ 0       │          │
╰──────────┴─────────┴───────────┴──────────┴────────┴──────┴─────────┴──────────╯

╭────────────────────────────────────────────────────────────────────────────╮
│                             Replication Report                             │
├──────────┬────────┬─────────────────┬───────────────┬────────┬─────┬───────┤
│ Stream   │ Kind   │ API Prefix      │ Source Stream │ Active │ Lag │ Error │
├──────────┼────────┼─────────────────┼───────────────┼────────┼─────┼───────┤
│ crossacc │ Mirror │ JS.test@hub.API │ source-stream │ 0.44s  │ 0   │       │
╰──────────┴────────┴─────────────────┴───────────────┴────────┴─────┴───────╯

# stop the nats-server and restart in debug mode
> nats-server -c hub.cfg --debug
[991] 2021/10/08 22:26:46.196566 [INF] Starting nats-server
[991] 2021/10/08 22:26:46.196634 [INF]   Version:  2.6.1
[991] 2021/10/08 22:26:46.196639 [INF]   Git:      [c91f0fe]
[991] 2021/10/08 22:26:46.196642 [DBG]   Go build: go1.16.8
[991] 2021/10/08 22:26:46.196644 [INF]   Name:     srv-4222
[991] 2021/10/08 22:26:46.196650 [INF]   Node:     KUNhoY7Q
[991] 2021/10/08 22:26:46.196668 [INF]   ID:       NBFHONLRY2LO7M3RFVJUX5ZRDH6JJPR2GH2D3M32UULZHT7RCMEJG6N2
[991] 2021/10/08 22:26:46.196671 [INF] Using configuration file: hub.cfg
[991] 2021/10/08 22:26:46.196674 [INF] Trusted Operators
[991] 2021/10/08 22:26:46.196676 [INF]   System  : ""
[991] 2021/10/08 22:26:46.196679 [INF]   Operator: "myoperator"
[991] 2021/10/08 22:26:46.199083 [INF]   Issued  : 2021-10-08 21:58:08 +0800 CST
[991] 2021/10/08 22:26:46.199152 [INF]   Expires : 1970-01-01 08:00:00 +0800 CST
[991] 2021/10/08 22:26:46.200121 [INF] Managing all jwt in exclusive directory /root/jetstream-test/jwt
[991] 2021/10/08 22:26:46.200158 [INF] Starting JetStream
[991] 2021/10/08 22:26:46.200198 [DBG] JetStream creating dynamic configuration - 2.19 GB memory, 177.56 GB disk
[991] 2021/10/08 22:26:46.200456 [INF]     _ ___ _____ ___ _____ ___ ___   _   __  __
[991] 2021/10/08 22:26:46.200494 [INF]  _ | | __|_   _/ __|_   _| _ \ __| /_\ |  \/  |
[991] 2021/10/08 22:26:46.200498 [INF] | || | _|  | | \__ \ | | |   / _| / _ \| |\/| |
[991] 2021/10/08 22:26:46.200500 [INF]  \__/|___| |_| |___/ |_| |_|_\___/_/ \_\_|  |_|
[991] 2021/10/08 22:26:46.200501 [INF]
[991] 2021/10/08 22:26:46.200503 [INF]          https://docs.nats.io/jetstream
[991] 2021/10/08 22:26:46.200505 [INF]
[991] 2021/10/08 22:26:46.200507 [INF] ---------------- JETSTREAM ----------------
[991] 2021/10/08 22:26:46.200511 [INF]   Max Memory:      2.19 GB
[991] 2021/10/08 22:26:46.200514 [INF]   Max Storage:     177.56 GB
[991] 2021/10/08 22:26:46.200516 [INF]   Store Directory: "hub/jetstream"
[991] 2021/10/08 22:26:46.200518 [INF]   Domain:          hub
[991] 2021/10/08 22:26:46.200520 [INF] -------------------------------------------
[991] 2021/10/08 22:26:46.200586 [DBG]   Exports:
[991] 2021/10/08 22:26:46.200614 [DBG]      $JS.API.>
[991] 2021/10/08 22:26:46.200817 [DBG] Account [AB3T7VYUNVT4CEWEDPH2FDQRDMPEJOQUMOA7ML6W54OCFEYULZPEMSSE] fetch took 20.3µs
[991] 2021/10/08 22:26:46.201162 [DBG] Updating account claims: AB3T7VYUNVT4CEWEDPH2FDQRDMPEJOQUMOA7ML6W54OCFEYULZPEMSSE/IMPORTER
[991] 2021/10/08 22:26:46.202536 [DBG] Account [ABIKUYZEAEMVU3YHCGFIWLDSMU6T5N5K2K7QIXRAANNUZ6OZOFLDGMY5] fetch took 1.3283ms
[991] 2021/10/08 22:26:46.202999 [DBG] Updating account claims: ABIKUYZEAEMVU3YHCGFIWLDSMU6T5N5K2K7QIXRAANNUZ6OZOFLDGMY5/TEST
[991] 2021/10/08 22:26:46.203082 [DBG] Adding service export "$JS.hub.API.CONSUMER.>" for ABIKUYZEAEMVU3YHCGFIWLDSMU6T5N5K2K7QIXRAANNUZ6OZOFLDGMY5/TEST
[991] 2021/10/08 22:26:46.203126 [DBG] Adding stream export "deliver.>" for ABIKUYZEAEMVU3YHCGFIWLDSMU6T5N5K2K7QIXRAANNUZ6OZOFLDGMY5/TEST
[991] 2021/10/08 22:26:46.203297 [DBG] Enabled JetStream for account "ABIKUYZEAEMVU3YHCGFIWLDSMU6T5N5K2K7QIXRAANNUZ6OZOFLDGMY5"
[991] 2021/10/08 22:26:46.203340 [DBG]   Max Memory:      0 B
[991] 2021/10/08 22:26:46.203353 [DBG]   Max Storage:     -1 B
[991] 2021/10/08 22:26:46.203401 [DBG] Recovering JetStream state for account "ABIKUYZEAEMVU3YHCGFIWLDSMU6T5N5K2K7QIXRAANNUZ6OZOFLDGMY5"
[991] 2021/10/08 22:26:46.204766 [INF]   Restored 1,000 messages for stream "source-stream"
[991] 2021/10/08 22:26:46.204905 [DBG] JetStream state for account "ABIKUYZEAEMVU3YHCGFIWLDSMU6T5N5K2K7QIXRAANNUZ6OZOFLDGMY5" recovered
[991] 2021/10/08 22:26:46.205106 [DBG] Adding service import ABIKUYZEAEMVU3YHCGFIWLDSMU6T5N5K2K7QIXRAANNUZ6OZOFLDGMY5/TEST:"JS.test@hub.API.CONSUMER.>" for AB3T7VYUNVT4CEWEDPH2FDQRDMPEJOQUMOA7ML6W54OCFEYULZPEMSSE/IMPORTER:"$JS.hub.API.CONSUMER.>"
[991] 2021/10/08 22:26:46.205250 [DBG] Adding stream import ABIKUYZEAEMVU3YHCGFIWLDSMU6T5N5K2K7QIXRAANNUZ6OZOFLDGMY5/TEST:"deliver.importer.>" for AB3T7VYUNVT4CEWEDPH2FDQRDMPEJOQUMOA7ML6W54OCFEYULZPEMSSE/IMPORTER:""
[991] 2021/10/08 22:26:46.206199 [DBG] Enabled JetStream for account "AB3T7VYUNVT4CEWEDPH2FDQRDMPEJOQUMOA7ML6W54OCFEYULZPEMSSE"
[991] 2021/10/08 22:26:46.206287 [DBG]   Max Memory:      0 B
[991] 2021/10/08 22:26:46.206294 [DBG]   Max Storage:     -1 B
[991] 2021/10/08 22:26:46.206321 [DBG] Recovering JetStream state for account "AB3T7VYUNVT4CEWEDPH2FDQRDMPEJOQUMOA7ML6W54OCFEYULZPEMSSE"
[991] 2021/10/08 22:26:46.207293 [INF]   Restored 639 messages for stream "crossacc"
[991] 2021/10/08 22:26:46.207383 [DBG] JetStream state for account "AB3T7VYUNVT4CEWEDPH2FDQRDMPEJOQUMOA7ML6W54OCFEYULZPEMSSE" recovered
[991] 2021/10/08 22:26:46.207818 [INF] Listening for client connections on localhost:4222
[991] 2021/10/08 22:26:46.207910 [INF] Server is ready
[991] 2021/10/08 22:26:52.207398 [DBG] Retrying mirror consumer for 'AB3T7VYUNVT4CEWEDPH2FDQRDMPEJOQUMOA7ML6W54OCFEYULZPEMSSE > crossacc'
[991] 2021/10/08 22:26:52.210242 [DBG] JETSTREAM - Creating import subscription on "deliver.importer.crossacc.M.2WcPfkBT" from account "ABIKUYZEAEMVU3YHCGFIWLDSMU6T5N5K2K7QIXRAANNUZ6OZOFLDGMY5"

# After restart nats-server, we see that the message is synced. Test message publish again and still the same issue happens.
> nats stream report --js-domain hub --creds ~/.nkeys/creds/myoperator/IMPORTER/iuser.creds
Obtaining Stream stats

╭────────────────────────────────────────────────────────────────────────────────╮
│                                 Stream Report                                  │
├──────────┬─────────┬───────────┬──────────┬────────┬──────┬─────────┬──────────┤
│ Stream   │ Storage │ Consumers │ Messages │ Bytes  │ Lost │ Deleted │ Replicas │
├──────────┼─────────┼───────────┼──────────┼────────┼──────┼─────────┼──────────┤
│ crossacc │ File    │ 0         │ 1,000    │ 38 KiB │ 0    │ 0       │          │
╰──────────┴─────────┴───────────┴──────────┴────────┴──────┴─────────┴──────────╯

╭────────────────────────────────────────────────────────────────────────────╮
│                             Replication Report                             │
├──────────┬────────┬─────────────────┬───────────────┬────────┬─────┬───────┤
│ Stream   │ Kind   │ API Prefix      │ Source Stream │ Active │ Lag │ Error │
├──────────┼────────┼─────────────────┼───────────────┼────────┼─────┼───────┤
│ crossacc │ Mirror │ JS.test@hub.API │ source-stream │ 1.15s  │ 0   │       │
╰──────────┴────────┴─────────────────┴───────────────┴────────┴─────┴───────╯

> nats pub test hello --count 1000 --js-domain hub --creds ~/.nkeys/creds/myoperator/TEST/tuser.creds

1000 / 1000 [===================================================================================================================================]    0s

> date
Fri Oct  8 22:30:23 CST 2021
> nats stream report --js-domain hub --creds ~/.nkeys/creds/myoperator/TEST/tuser.creds
Obtaining Stream stats

╭─────────────────────────────────────────────────────────────────────────────────────╮
│                                    Stream Report                                    │
├───────────────┬─────────┬───────────┬──────────┬────────┬──────┬─────────┬──────────┤
│ Stream        │ Storage │ Consumers │ Messages │ Bytes  │ Lost │ Deleted │ Replicas │
├───────────────┼─────────┼───────────┼──────────┼────────┼──────┼─────────┼──────────┤
│ source-stream │ File    │ 0         │ 2,000    │ 76 KiB │ 0    │ 0       │          │
╰───────────────┴─────────┴───────────┴──────────┴────────┴──────┴─────────┴──────────╯

# After a while, it didn't sync from source stream.
> date
Fri Oct  8 22:31:09 CST 2021
> nats stream report --js-domain hub --creds ~/.nkeys/creds/myoperator/IMPORTER/iuser.creds
Obtaining Stream stats

╭────────────────────────────────────────────────────────────────────────────────╮
│                                 Stream Report                                  │
├──────────┬─────────┬───────────┬──────────┬────────┬──────┬─────────┬──────────┤
│ Stream   │ Storage │ Consumers │ Messages │ Bytes  │ Lost │ Deleted │ Replicas │
├──────────┼─────────┼───────────┼──────────┼────────┼──────┼─────────┼──────────┤
│ crossacc │ File    │ 0         │ 1,268    │ 48 KiB │ 0    │ 0       │          │
╰──────────┴─────────┴───────────┴──────────┴────────┴──────┴─────────┴──────────╯

╭────────────────────────────────────────────────────────────────────────────╮
│                             Replication Report                             │
├──────────┬────────┬─────────────────┬───────────────┬────────┬─────┬───────┤
│ Stream   │ Kind   │ API Prefix      │ Source Stream │ Active │ Lag │ Error │
├──────────┼────────┼─────────────────┼───────────────┼────────┼─────┼───────┤
│ crossacc │ Mirror │ JS.test@hub.API │ source-stream │ 0.85s  │ 0   │       │
╰──────────┴────────┴─────────────────┴───────────────┴────────┴─────┴───────╯

Attach nsc nkey files and server config. nsc-and-server-config.zip

Expected result:

phho commented 2 years ago

Attach whole nats server configuration and jwt directory. Please unzip it and start nats-server with the configuration, then try to publish more than 1000 messages. We have tried to reproduce the same issue in Windows, linux and container environment test-creds.zip nats-server-cfg-and-jwt.zip

phho commented 2 years ago

If there is anything you are not clear about the issue, please let me know whether need to provide more information, thanks.

matthiashanel commented 2 years ago

@phho sorry, this is totally my fault. When making this I forgot to export/import the flow control API and didn't notice it as I sent only a few messages...

This should fix your issue:

nsc add export --account TEST --name FC-API --service --response-type Stream --subject '$JS.FC.>'
nsc add import --account IMPORTER --src-account TEST --name Remote-FC-API --service --remote-subject '$JS.FC.>'
# push and inspect streams (mirror crossacc should have 1000 messages now)
nsc push -A -u nats://localhost:4222
nats stream report --creds  keys/creds/myoperator/TEST/tuser.creds
nats stream report --creds keys/creds/myoperator/IMPORTER/iuser.creds

Please let me know if it does.

This area is still very complicated to set up, which is why we already decided to improve that going forward. Please watch the nats-server release notes for changes in this area.

phho commented 2 years ago

Hi @matthiashanel, Mirror stream works now after adding the flow control API export/import configs. Thanks.