nats-server icon indicating copy to clipboard operation
nats-server copied to clipboard

Recovering consumer takes too long [v2.10.7 - v2.10.18]

Open Ivlyth opened this issue 6 months ago • 4 comments

Observed behavior

[14452] 2024/08/20 14:42:14.995238 [INF] Starting nats-server
[14452] 2024/08/20 14:42:15.008306 [INF]   Version:  2.10.7
[14452] 2024/08/20 14:42:15.008318 [INF]   Git:      [fa8464d]
[14452] 2024/08/20 14:42:15.008326 [INF]   Name:     nats-01
[14452] 2024/08/20 14:42:15.008334 [INF]   Node:     pZeTdFV7
[14452] 2024/08/20 14:42:15.008338 [INF]   ID:       NBE3TNB4N3NCUFQHLSIRWOTN6I2I7INYJWVXQWMJ34QVT25S3UPCYYJG
[14452] 2024/08/20 14:42:15.008357 [WRN] Plaintext passwords detected, use nkeys or bcrypt
[14452] 2024/08/20 14:42:15.008392 [INF] Using configuration file: /opt/nats/conf/nats-server.conf
[14452] 2024/08/20 14:42:15.009861 [INF] Starting http monitor on 0.0.0.0:8222
[14452] 2024/08/20 14:42:15.009926 [INF] Starting JetStream
[14452] 2024/08/20 14:42:15.018372 [INF]     _ ___ _____ ___ _____ ___ ___   _   __  __
[14452] 2024/08/20 14:42:15.018391 [INF]  _ | | __|_   _/ __|_   _| _ \ __| /_\ |  \/  |
[14452] 2024/08/20 14:42:15.018397 [INF] | || | _|  | | \__ \ | | |   / _| / _ \| |\/| |
[14452] 2024/08/20 14:42:15.018401 [INF]  \__/|___| |_| |___/ |_| |_|_\___/_/ \_\_|  |_|
[14452] 2024/08/20 14:42:15.018406 [INF]
[14452] 2024/08/20 14:42:15.018411 [INF]          https://docs.nats.io/jetstream
[14452] 2024/08/20 14:42:15.018415 [INF]
[14452] 2024/08/20 14:42:15.018421 [INF] ---------------- JETSTREAM ----------------
[14452] 2024/08/20 14:42:15.018431 [INF]   Max Memory:      141.48 GB
[14452] 2024/08/20 14:42:15.018439 [INF]   Max Storage:     50.00 TB
[14452] 2024/08/20 14:42:15.018444 [INF]   Store Directory: "/data/nats-storage/jetstream"
[14452] 2024/08/20 14:42:15.018449 [INF] -------------------------------------------
[14452] 2024/08/20 14:42:15.057389 [INF]   Starting restore for stream '$G > event-action'
[14452] 2024/08/20 14:42:15.082226 [INF]   Restored 6 messages for stream '$G > event-action' in 25ms
[14452] 2024/08/20 14:42:15.090720 [INF]   Starting restore for stream '$G > event-base'
[14452] 2024/08/20 14:42:15.349544 [INF]   Restored 80,060,781 messages for stream '$G > event-base' in 259ms
[14452] 2024/08/20 14:42:15.350631 [INF]   Starting restore for stream '$G > event-transformed'
[14452] 2024/08/20 14:42:15.618664 [INF]   Restored 27,711,311 messages for stream '$G > event-transformed' in 268ms
[14452] 2024/08/20 14:42:15.618804 [INF]   Recovering 1 consumers for stream - '$G > event-action'
[14452] 2024/08/20 14:42:15.655177 [INF]   Recovering 1 consumers for stream - '$G > event-base'
[14452] 2024/08/20 14:48:06.249467 [INF]   Recovering 2 consumers for stream - '$G > event-transformed'
[14452] 2024/08/20 14:48:06.587266 [INF] Listening for client connections on 0.0.0.0:4222
[14452] 2024/08/20 14:48:06.587731 [INF] Server is ready
[14994] 2024/08/20 14:48:40.895462 [INF] Starting nats-server
[14994] 2024/08/20 14:48:40.895615 [INF]   Version:  2.10.18
[14994] 2024/08/20 14:48:40.895620 [INF]   Git:      [57d23ac]
[14994] 2024/08/20 14:48:40.895624 [INF]   Name:     nats-01
[14994] 2024/08/20 14:48:40.895628 [INF]   Node:     pZeTdFV7
[14994] 2024/08/20 14:48:40.895631 [INF]   ID:       NBCC3KDHZPOC6ZP4HMRFUF6BJ6C7RW735OFQOPMTBBT6JMI4ZFERV5LI
[14994] 2024/08/20 14:48:40.895641 [WRN] Plaintext passwords detected, use nkeys or bcrypt
[14994] 2024/08/20 14:48:40.895656 [INF] Using configuration file: /opt/nats/conf/nats-server.conf
[14994] 2024/08/20 14:48:40.896231 [INF] Starting http monitor on 0.0.0.0:8222
[14994] 2024/08/20 14:48:40.896280 [INF] Starting JetStream
[14994] 2024/08/20 14:48:40.896467 [INF]     _ ___ _____ ___ _____ ___ ___   _   __  __
[14994] 2024/08/20 14:48:40.896475 [INF]  _ | | __|_   _/ __|_   _| _ \ __| /_\ |  \/  |
[14994] 2024/08/20 14:48:40.896478 [INF] | || | _|  | | \__ \ | | |   / _| / _ \| |\/| |
[14994] 2024/08/20 14:48:40.896482 [INF]  \__/|___| |_| |___/ |_| |_|_\___/_/ \_\_|  |_|
[14994] 2024/08/20 14:48:40.896486 [INF]
[14994] 2024/08/20 14:48:40.896489 [INF]          https://docs.nats.io/jetstream
[14994] 2024/08/20 14:48:40.896506 [INF]
[14994] 2024/08/20 14:48:40.896509 [INF] ---------------- JETSTREAM ----------------
[14994] 2024/08/20 14:48:40.896514 [INF]   Max Memory:      141.48 GB
[14994] 2024/08/20 14:48:40.896517 [INF]   Max Storage:     50.00 TB
[14994] 2024/08/20 14:48:40.896519 [INF]   Store Directory: "/data/nats-storage/jetstream"
[14994] 2024/08/20 14:48:40.896522 [INF] -------------------------------------------
[14994] 2024/08/20 14:48:40.911069 [INF]   Starting restore for stream '$G > event-action'
[14994] 2024/08/20 14:48:40.947712 [INF]   Restored 6 messages for stream '$G > event-action' in 37ms
[14994] 2024/08/20 14:48:40.952908 [INF]   Starting restore for stream '$G > event-base'
[14994] 2024/08/20 14:48:41.179296 [INF]   Restored 80,060,781 messages for stream '$G > event-base' in 226ms
[14994] 2024/08/20 14:48:41.180456 [INF]   Starting restore for stream '$G > event-transformed'
[14994] 2024/08/20 14:48:41.457482 [INF]   Restored 27,711,311 messages for stream '$G > event-transformed' in 277ms
[14994] 2024/08/20 14:48:41.457581 [INF]   Recovering 1 consumers for stream - '$G > event-action'
[14994] 2024/08/20 14:48:41.490819 [INF]   Recovering 1 consumers for stream - '$G > event-base'
[14994] 2024/08/20 14:55:38.762911 [INF]   Recovering 2 consumers for stream - '$G > event-transformed'
[14994] 2024/08/20 14:55:39.022916 [INF] Listening for client connections on 0.0.0.0:4222
[14994] 2024/08/20 14:55:39.024199 [INF] Server is ready

in the log for version 2.10.7, we can see recovering consumer for stream event-transformed takes too long, about 5m30s and in the log for version 2.10.18, we can see the time is even long, it's about 7min

Expected behavior

when server restart, recovering the consumer not take so long

Server and client version

server: 2.10.7 and 2.10.18

Host environment

No response

Steps to reproduce

No response

Ivlyth avatar Aug 20 '24 06:08 Ivlyth