Hello Experts,
We are testing redis 7.0.5 before rolling out this version to production. For testing we are using below command
redis-benchmark -p 6382 -c 1000 -r 1700000 -n 1700000 -t hset -d 18000 -P 750 This command inserted around 21 Gig of data in redis but we observed that data synching between master and slave node didn't get completed even after 20 minutes.
Please see below screenshot
Plesae see below logs
11:M 16 Nov 2022 09:17:19.695 * Replica 10.3.50.102:6379 asks for synchronization 11:M 16 Nov 2022 09:17:19.695 * Unable to partial resync with replica 10.3.50.102:6379 for lack of backlog (Replica request was: 3866175099). 11:M 16 Nov 2022 09:17:19.695 * Can't attach the replica to the current BGSAVE. Waiting for next BGSAVE for SYNC 11:M 16 Nov 2022 09:17:19.695 * Replica 10.3.52.107:6381 asks for synchronization 11:M 16 Nov 2022 09:17:19.695 * Unable to partial resync with replica 10.3.52.107:6381 for lack of backlog (Replica request was: 3446617532). 11:M 16 Nov 2022 09:17:19.695 * Can't attach the replica to the current BGSAVE. Waiting for next BGSAVE for SYNC 11:M 16 Nov 2022 09:17:19.806 # Background saving terminated by signal 10 11:M 16 Nov 2022 09:17:19.806 * Starting BGSAVE for SYNC with target: disk 11:M 16 Nov 2022 09:17:20.144 * Background saving started by pid 101 101:C 16 Nov 2022 09:20:10.362 * DB saved on disk 101:C 16 Nov 2022 09:20:10.462 * Fork CoW for RDB: current 621 MB, peak 621 MB, average 621 MB 11:M 16 Nov 2022 09:20:10.742 * Background saving terminated with success 11:M 16 Nov 2022 09:22:55.841 # Write error sending DB to replica: Connection reset by peer 11:M 16 Nov 2022 09:22:55.841 # Connection with replica client id #1099 lost. 11:M 16 Nov 2022 09:22:55.850 * Replica 10.3.50.102:6379 asks for synchronization 11:M 16 Nov 2022 09:22:55.850 * Unable to partial resync with replica 10.3.50.102:6379 for lack of backlog (Replica request was: 3866175099). 11:M 16 Nov 2022 09:22:55.850 * Starting BGSAVE for SYNC with target: disk 11:M 16 Nov 2022 09:22:56.168 * Background saving started by pid 104 11:M 16 Nov 2022 09:22:56.523 * Synchronization with replica 10.3.52.107:6381 succeeded 104:C 16 Nov 2022 09:31:08.475 * DB saved on disk 104:C 16 Nov 2022 09:31:08.568 * Fork CoW for RDB: current 1 MB, peak 1 MB, average 1 MB 11:M 16 Nov 2022 09:31:10.804 * Background saving terminated with success 11:M 16 Nov 2022 09:35:57.878 # Connection with replica client id #1101 lost. 11:M 16 Nov 2022 09:35:57.879 * Replica 10.3.50.102:6379 asks for synchronization 11:M 16 Nov 2022 09:35:57.879 * Unable to partial resync with replica 10.3.50.102:6379 for lack of backlog (Replica request was: 3866175099). 11:M 16 Nov 2022 09:35:57.879 * Starting BGSAVE for SYNC with target: disk 11:M 16 Nov 2022 09:35:58.191 * Background saving started by pid 105 105:C 16 Nov 2022 09:45:13.829 * DB saved on disk 105:C 16 Nov 2022 09:45:13.925 * Fork CoW for RDB: current 7 MB, peak 7 MB, average 7 MB 11:M 16 Nov 2022 09:45:14.124 * Background saving terminated with success 11:M 16 Nov 2022 09:47:59.335 # Connection with replica client id #1102 lost. 11:M 16 Nov 2022 09:47:59.337 * Replica 10.3.50.102:6379 asks for synchronization 11:M 16 Nov 2022 09:47:59.337 * Unable to partial resync with replica 10.3.50.102:6379 for lack of backlog (Replica request was: 3866175099). 11:M 16 Nov 2022 09:47:59.337 * Starting BGSAVE for SYNC with target: disk 11:M 16 Nov 2022 09:47:59.656 * Background saving started by pid 139 11:M 16 Nov 2022 09:54:31.039 # Connection with replica 10.3.52.107:6381 lost. 11:M 16 Nov 2022 09:54:31.316 # Connection with replica 10.3.50.102:6379 lost. 139:signal-handler (1668592471) Received SIGUSR1 in child, exiting now. 11:M 16 Nov 2022 09:54:31.818 # Background saving terminated by signal 10 11:S 16 Nov 2022 10:01:42.719 * Before turning into a replica, using my own master parameters to synthesize a cached master: I may be able to synchronize with the new master with just a partial transfer. 11:S 16 Nov 2022 10:01:42.719 * Connecting to MASTER 10.3.52.107:6381 11:S 16 Nov 2022 10:01:42.719 * MASTER <-> REPLICA sync started 11:S 16 Nov 2022 10:01:42.719 * REPLICAOF 10.3.52.107:6381 enabled (user request from 'id=1120 addr=10.3.50.102:41422 laddr=172.17.0.3:6382 fd=12 name=sentinel-58a5b870-cmd age=401 idle=0 flags=x db=0 sub=0 psub=0 ssub=0 multi=4 qbuf=226 qbuf-free=20248 argv-mem=4 multi-mem=205 rbs=2048 rbp=1024 obl=45 oll=0 omem=0 tot-mem=23625 events=r cmd=exec user=default redir=-1 resp=2') 11:S 16 Nov 2022 10:01:42.749 # CONFIG REWRITE executed with success. 11:S 16 Nov 2022 10:01:42.749 * Non blocking connect for SYNC fired the event. 11:S 16 Nov 2022 10:01:42.749 * Master replied to PING, replication can continue... 11:S 16 Nov 2022 10:01:42.750 * Trying a partial resynchronization (request bd3d8dd8abf63a071a75ded6bce1c0f406bdbb83:34125929899). 11:S 16 Nov 2022 10:01:42.750 * Full resync from master: 5ff5e4f82dc501c9c5fb3a1a4619d11b245cbd0e:34125844776 11:S 16 Nov 2022 10:03:15.777 * MASTER <-> REPLICA sync: receiving 21054514277 bytes from master to disk 11:S 16 Nov 2022 10:06:03.335 * Discarding previously cached master state. 11:S 16 Nov 2022 10:06:03.335 * MASTER <-> REPLICA sync: Flushing old data 11:S 16 Nov 2022 10:06:06.070 * MASTER <-> REPLICA sync: Loading DB in memory 11:S 16 Nov 2022 10:06:06.080 * Loading RDB produced by version 7.0.5 11:S 16 Nov 2022 10:06:06.080 * RDB age 348 seconds 11:S 16 Nov 2022 10:06:06.080 * RDB memory usage when created 21682.32 Mb 11:S 16 Nov 2022 10:06:36.085 * Done loading RDB, keys loaded: 1, keys expired: 0. 11:S 16 Nov 2022 10:06:36.085 * MASTER <-> REPLICA sync: Finished with success
Logs from another node: 9:S 16 Nov 2022 10:05:43.344 * MASTER <-> REPLICA sync started 9:S 16 Nov 2022 10:05:43.344 # Error condition on socket for SYNC: Connection refused
Is there any way to optimize the sync process because we write to masters and read from slaves if data isn't present in the slave nodes then we risk reloading data from db.
Comment From: geekthread
syncing between the masters and slaves is very slow.
Comment From: geekthread
Can someone please help us on this ?
Comment From: enjoy-binbin
Please try to show the full info command output, each node, and with a code block, like:
master:
INFO command
balabala
node-1:
INFO command
balabala
node-2:
INFO command
balabala
master logs:
balabala
node-1, node-2 logs as well.
also please try to see this config and others: https://github.com/redis/redis/blob/7.0.5/redis.conf#L579 it may help
Comment From: enjoy-binbin
Disk-backed look like a typo? Disk-based looks better. anyway, @oranagra maybe you have better suggestions for the above log information
# 1) Disk-backed: The Redis master creates a new process that writes the RDB
# file on disk. Later the file is transferred by the parent
# process to the replicas incrementally.
Comment From: geekthread
Hello @enjoy-binbin ,
If we use diskless sync then how will system behave in case of failovers?
Please find the output of info from all nodes Master `# Server redis_version:7.0.5 redis_git_sha1:00000000 redis_git_dirty:0 redis_build_id:d701cb24dcc014da redis_mode:standalone os:Linux 3.10.0-1160.76.1.el7.x86_64 x86_64 arch_bits:64 monotonic_clock:POSIX clock_gettime multiplexing_api:epoll atomicvar_api:atomic-builtin gcc_version:4.8.5 process_id:11 process_supervised:no run_id:b38ddc090695886303043bc9b7fdea7168fbb576 tcp_port:6382 server_time_usec:1669110844377609 uptime_in_seconds:16235 uptime_in_days:0 hz:10 configured_hz:10 lru_clock:8166460 executable:/apps/redis/bin/redis-server config_file:/etc/redis/redis.conf io_threads_active:0
Clients
connected_clients:7 cluster_connections:0 maxclients:10000 client_recent_max_input_buffer:20480 client_recent_max_output_buffer:20504 blocked_clients:0 tracking_clients:0 clients_in_timeout_table:0
Memory
used_memory:22522338672 used_memory_human:20.98G used_memory_rss:26012930048 used_memory_rss_human:24.23G used_memory_peak:24394929000 used_memory_peak_human:22.72G used_memory_peak_perc:92.32% used_memory_overhead:166592900 used_memory_startup:859688 used_memory_dataset:22355745772 used_memory_dataset_perc:99.26% allocator_allocated:22522432760 allocator_active:27009814528 allocator_resident:27225096192 total_system_memory:67383754752 total_system_memory_human:62.76G used_memory_lua:31744 used_memory_vm_eval:31744 used_memory_lua_human:31.00K used_memory_scripts_eval:0 number_of_cached_scripts:0 number_of_functions:0 number_of_libraries:0 used_memory_vm_functions:32768 used_memory_vm_total:64512 used_memory_vm_total_human:63.00K used_memory_functions:184 used_memory_scripts:184 used_memory_scripts_human:184B maxmemory:33285996544 maxmemory_human:31.00G maxmemory_policy:volatile-lru allocator_frag_ratio:1.20 allocator_frag_bytes:4487381768 allocator_rss_ratio:1.01 allocator_rss_bytes:215281664 rss_overhead_ratio:0.96 rss_overhead_bytes:-1212166144 mem_fragmentation_ratio:1.15 mem_fragmentation_bytes:3490631256 mem_not_counted_for_evict:0 mem_replication_backlog:104858916 mem_total_replication_buffers:105206024 mem_clients_slaves:348424 mem_clients_normal:136872 mem_cluster_links:0 mem_aof_buffer:0 mem_allocator:jemalloc-5.2.1 active_defrag_running:3 lazyfree_pending_objects:0 lazyfreed_objects:0
Persistence
loading:0 async_loading:0 current_cow_peak:0 current_cow_size:0 current_cow_size_age:0 current_fork_perc:0.00 current_save_keys_processed:0 current_save_keys_total:0 rdb_changes_since_last_save:4978 rdb_bgsave_in_progress:0 rdb_last_save_time:1669094968 rdb_last_bgsave_status:ok rdb_last_bgsave_time_sec:157 rdb_current_bgsave_time_sec:-1 rdb_saves:12 rdb_last_cow_size:2249818112 rdb_last_load_keys_expired:0 rdb_last_load_keys_loaded:0 aof_enabled:0 aof_rewrite_in_progress:0 aof_rewrite_scheduled:0 aof_last_rewrite_time_sec:-1 aof_current_rewrite_time_sec:-1 aof_last_bgrewrite_status:ok aof_rewrites:0 aof_rewrites_consecutive_failures:0 aof_last_write_status:ok aof_last_cow_size:0 module_fork_in_progress:0 module_fork_last_cow_size:0
Stats
total_connections_received:1076 total_commands_processed:1851183 instantaneous_ops_per_sec:5 total_net_input_bytes:31498495111 total_net_output_bytes:48848465914 total_net_repl_input_bytes:0 total_net_repl_output_bytes:48799768885 instantaneous_input_kbps:0.24 instantaneous_output_kbps:6.84 instantaneous_input_repl_kbps:0.00 instantaneous_output_repl_kbps:0.21 rejected_connections:0 sync_full:22 sync_partial_ok:1 sync_partial_err:21 expired_keys:0 expired_stale_perc:0.00 expired_time_cap_reached_count:0 expire_cycle_cpu_milliseconds:203 evicted_keys:0 evicted_clients:0 total_eviction_exceeded_time:0 current_eviction_exceeded_time:0 keyspace_hits:0 keyspace_misses:0 pubsub_channels:1 pubsub_patterns:0 pubsubshard_channels:0 latest_fork_usec:364372 total_forks:12 migrate_cached_sockets:0 slave_expires_tracked_keys:0 active_defrag_hits:37722 active_defrag_misses:855478571 active_defrag_key_hits:37722 active_defrag_key_misses:213850832 total_active_defrag_time:16112701 current_active_defrag_time:16112701 tracking_total_keys:0 tracking_total_items:0 tracking_total_prefixes:0 unexpected_error_replies:0 total_error_replies:0 dump_payload_sanitizations:0 total_reads_processed:1497597 total_writes_processed:1681384 io_threaded_reads_processed:0 io_threaded_writes_processed:0 reply_buffer_shrinks:5898 reply_buffer_expands:4888
Replication
role:master connected_slaves:2 slave0:ip=10.3.52.107,port=6381,state=online,offset=31489274327,lag=1 slave1:ip=10.3.50.102,port=6379,state=online,offset=31489274510,lag=0 master_failover_state:no-failover master_replid:9e0fd1151e864e243f5ef9980dea010d671710e7 master_replid2:0000000000000000000000000000000000000000 master_repl_offset:31489274510 second_repl_offset:-1 repl_backlog_active:1 repl_backlog_size:104857600 repl_backlog_first_byte_offset:31384414041 repl_backlog_histlen:104860470
CPU
used_cpu_sys:90.894377 used_cpu_user:499.831868 used_cpu_sys_children:27.316701 used_cpu_user_children:141.016453 used_cpu_sys_main_thread:88.707306 used_cpu_user_main_thread:499.529569
Modules
Errorstats
Cluster
cluster_enabled:0
Keyspace
db0:keys=1090290,expires=0,avg_ttl=0 `
Slave-1 `# Server redis_version:7.0.5 redis_git_sha1:00000000 redis_git_dirty:0 redis_build_id:d701cb24dcc014da redis_mode:standalone os:Linux 3.10.0-1160.76.1.el7.x86_64 x86_64 arch_bits:64 monotonic_clock:POSIX clock_gettime multiplexing_api:epoll atomicvar_api:atomic-builtin gcc_version:4.8.5 process_id:11 process_supervised:no run_id:b72bd97fa93db5e96e01ef4417ebaa93d68e852a tcp_port:6381 server_time_usec:1669094973596675 uptime_in_seconds:364 uptime_in_days:0 hz:10 configured_hz:10 lru_clock:8150589 executable:/apps/redis/bin/redis-server config_file:/etc/redis/redis.conf io_threads_active:0
Clients
connected_clients:7 cluster_connections:0 maxclients:10000 client_recent_max_input_buffer:20480 client_recent_max_output_buffer:0 blocked_clients:0 tracking_clients:0 clients_in_timeout_table:0
Memory
used_memory:4994577864 used_memory_human:4.65G used_memory_rss:5948395520 used_memory_rss_human:5.54G used_memory_peak:4994577864 used_memory_peak_human:4.65G used_memory_peak_perc:100.00% used_memory_overhead:117879487 used_memory_startup:859784 used_memory_dataset:4876698377 used_memory_dataset_perc:97.66% allocator_allocated:4994700920 allocator_active:5990256640 allocator_resident:6039732224 total_system_memory:67383754752 total_system_memory_human:62.76G used_memory_lua:31744 used_memory_vm_eval:31744 used_memory_lua_human:31.00K used_memory_scripts_eval:0 number_of_cached_scripts:0 number_of_functions:0 number_of_libraries:0 used_memory_vm_functions:32768 used_memory_vm_total:64512 used_memory_vm_total_human:63.00K used_memory_functions:184 used_memory_scripts:184 used_memory_scripts_human:184B maxmemory:33285996544 maxmemory_human:31.00G maxmemory_policy:volatile-lru allocator_frag_ratio:1.20 allocator_frag_bytes:995555720 allocator_rss_ratio:1.01 allocator_rss_bytes:49475584 rss_overhead_ratio:0.98 rss_overhead_bytes:-91336704 mem_fragmentation_ratio:1.19 mem_fragmentation_bytes:953857544 mem_not_counted_for_evict:0 mem_replication_backlog:105207340 mem_total_replication_buffers:105206024 mem_clients_slaves:0 mem_clients_normal:202187 mem_cluster_links:0 mem_aof_buffer:0 mem_allocator:jemalloc-5.2.1 active_defrag_running:3 lazyfree_pending_objects:0 lazyfreed_objects:0
Persistence
loading:0 async_loading:0 current_cow_peak:0 current_cow_size:0 current_cow_size_age:0 current_fork_perc:0.00 current_save_keys_processed:0 current_save_keys_total:0 rdb_changes_since_last_save:256366 rdb_bgsave_in_progress:0 rdb_last_save_time:1669094642 rdb_last_bgsave_status:ok rdb_last_bgsave_time_sec:0 rdb_current_bgsave_time_sec:-1 rdb_saves:1 rdb_last_cow_size:2396160 rdb_last_load_keys_expired:0 rdb_last_load_keys_loaded:0 aof_enabled:0 aof_rewrite_in_progress:0 aof_rewrite_scheduled:0 aof_last_rewrite_time_sec:-1 aof_current_rewrite_time_sec:-1 aof_last_bgrewrite_status:ok aof_rewrites:0 aof_rewrites_consecutive_failures:0 aof_last_write_status:ok aof_last_cow_size:0 module_fork_in_progress:0 module_fork_last_cow_size:0
Stats
total_connections_received:49 total_commands_processed:259054 instantaneous_ops_per_sec:7 total_net_input_bytes:5591285446 total_net_output_bytes:4900738 total_net_repl_input_bytes:5591154863 total_net_repl_output_bytes:8660 instantaneous_input_kbps:121894.20 instantaneous_output_kbps:18.01 instantaneous_input_repl_kbps:121893.88 instantaneous_output_repl_kbps:0.00 rejected_connections:0 sync_full:1 sync_partial_ok:0 sync_partial_err:0 expired_keys:0 expired_stale_perc:0.00 expired_time_cap_reached_count:0 expire_cycle_cpu_milliseconds:0 evicted_keys:0 evicted_clients:0 total_eviction_exceeded_time:0 current_eviction_exceeded_time:0 keyspace_hits:0 keyspace_misses:0 pubsub_channels:1 pubsub_patterns:0 pubsubshard_channels:0 latest_fork_usec:650 total_forks:1 migrate_cached_sockets:0 slave_expires_tracked_keys:0 active_defrag_hits:1 active_defrag_misses:19460243 active_defrag_key_hits:1 active_defrag_key_misses:4865060 total_active_defrag_time:241977 current_active_defrag_time:241977 tracking_total_keys:0 tracking_total_items:0 tracking_total_prefixes:0 unexpected_error_replies:0 total_error_replies:32 dump_payload_sanitizations:0 total_reads_processed:142654 total_writes_processed:4542 io_threaded_reads_processed:0 io_threaded_writes_processed:0 reply_buffer_shrinks:174 reply_buffer_expands:425
Replication
role:slave master_host:10.3.52.111 master_port:6382 master_link_status:down master_last_io_seconds_ago:-1 master_sync_in_progress:1 slave_read_repl_offset:4626408815 slave_repl_offset:4626408815 master_sync_total_bytes:19621222150 master_sync_read_bytes:964739072 master_sync_left_bytes:18656483078 master_sync_perc:4.92 master_sync_last_io_seconds_ago:0 master_link_down_since_seconds:224 slave_priority:100 slave_read_only:1 replica_announced:1 connected_slaves:0 master_failover_state:no-failover master_replid:9e0fd1151e864e243f5ef9980dea010d671710e7 master_replid2:0000000000000000000000000000000000000000 master_repl_offset:4626408815 second_repl_offset:-1 repl_backlog_active:1 repl_backlog_size:104857600 repl_backlog_first_byte_offset:4521532401 repl_backlog_histlen:104876415
CPU
used_cpu_sys:7.962130 used_cpu_user:8.917144 used_cpu_sys_children:0.001114 used_cpu_user_children:0.001114 used_cpu_sys_main_thread:7.958047 used_cpu_user_main_thread:8.910807
Modules
Errorstats
errorstat_NOMASTERLINK:count=32
Cluster
cluster_enabled:0
Keyspace
db0:keys=237821,expires=0,avg_ttl=0`
Slave-2 `# Server redis_version:7.0.5 redis_git_sha1:00000000 redis_git_dirty:0 redis_build_id:d701cb24dcc014da redis_mode:standalone os:Linux 3.10.0-1160.76.1.el7.x86_64 x86_64 arch_bits:64 monotonic_clock:POSIX clock_gettime multiplexing_api:epoll atomicvar_api:atomic-builtin gcc_version:4.8.5 process_id:9 process_supervised:no run_id:734736bb54c8488b2bec91821bafc934c4f25e9c tcp_port:6379 server_time_usec:1669094995312849 uptime_in_seconds:386 uptime_in_days:0 hz:10 configured_hz:10 lru_clock:8150611 executable:/apps/redis/bin/redis-server config_file:/etc/redis/redis.conf io_threads_active:0
Clients
connected_clients:7 cluster_connections:0 maxclients:10000 client_recent_max_input_buffer:20480 client_recent_max_output_buffer:0 blocked_clients:0 tracking_clients:0 clients_in_timeout_table:0
Memory
used_memory:5108001280 used_memory_human:4.76G used_memory_rss:6083608576 used_memory_rss_human:5.67G used_memory_peak:5108399584 used_memory_peak_human:4.76G used_memory_peak_perc:99.99% used_memory_overhead:118014167 used_memory_startup:859536 used_memory_dataset:4989987113 used_memory_dataset_perc:97.71% allocator_allocated:5108342272 allocator_active:6126538752 allocator_resident:6176731136 total_system_memory:67383754752 total_system_memory_human:62.76G used_memory_lua:31744 used_memory_vm_eval:31744 used_memory_lua_human:31.00K used_memory_scripts_eval:0 number_of_cached_scripts:0 number_of_functions:0 number_of_libraries:0 used_memory_vm_functions:32768 used_memory_vm_total:64512 used_memory_vm_total_human:63.00K used_memory_functions:184 used_memory_scripts:184 used_memory_scripts_human:184B maxmemory:33285996544 maxmemory_human:31.00G maxmemory_policy:volatile-lru allocator_frag_ratio:1.20 allocator_frag_bytes:1018196480 allocator_rss_ratio:1.01 allocator_rss_bytes:50192384 rss_overhead_ratio:0.98 rss_overhead_bytes:-93122560 mem_fragmentation_ratio:1.19 mem_fragmentation_bytes:975647184 mem_not_counted_for_evict:0 mem_replication_backlog:105207340 mem_total_replication_buffers:105206024 mem_clients_slaves:0 mem_clients_normal:116195 mem_cluster_links:0 mem_aof_buffer:0 mem_allocator:jemalloc-5.2.1 active_defrag_running:3 lazyfree_pending_objects:0 lazyfreed_objects:0
Persistence
loading:0 async_loading:0 current_cow_peak:0 current_cow_size:0 current_cow_size_age:0 current_fork_perc:0.00 current_save_keys_processed:0 current_save_keys_total:0 rdb_changes_since_last_save:262802 rdb_bgsave_in_progress:0 rdb_last_save_time:1669094609 rdb_last_bgsave_status:ok rdb_last_bgsave_time_sec:-1 rdb_current_bgsave_time_sec:-1 rdb_saves:0 rdb_last_cow_size:0 rdb_last_load_keys_expired:0 rdb_last_load_keys_loaded:0 aof_enabled:0 aof_rewrite_in_progress:0 aof_rewrite_scheduled:0 aof_last_rewrite_time_sec:-1 aof_current_rewrite_time_sec:-1 aof_last_bgrewrite_status:ok aof_rewrites:0 aof_rewrites_consecutive_failures:0 aof_last_write_status:ok aof_last_cow_size:0 module_fork_in_progress:0 module_fork_last_cow_size:0
Stats
total_connections_received:115 total_commands_processed:265805 instantaneous_ops_per_sec:7 total_net_input_bytes:8165339970 total_net_output_bytes:5183727 total_net_repl_input_bytes:8165186964 total_net_repl_output_bytes:0 instantaneous_input_kbps:122791.27 instantaneous_output_kbps:18.70 instantaneous_input_repl_kbps:122790.94 instantaneous_output_repl_kbps:0.00 rejected_connections:0 sync_full:0 sync_partial_ok:0 sync_partial_err:0 expired_keys:0 expired_stale_perc:0.00 expired_time_cap_reached_count:0 expire_cycle_cpu_milliseconds:0 evicted_keys:0 evicted_clients:0 total_eviction_exceeded_time:0 current_eviction_exceeded_time:0 keyspace_hits:0 keyspace_misses:0 pubsub_channels:1 pubsub_patterns:0 pubsubshard_channels:0 latest_fork_usec:0 total_forks:0 migrate_cached_sockets:0 slave_expires_tracked_keys:0 active_defrag_hits:0 active_defrag_misses:20620232 active_defrag_key_hits:0 active_defrag_key_misses:5155058 total_active_defrag_time:263651 current_active_defrag_time:263651 tracking_total_keys:0 tracking_total_items:0 tracking_total_prefixes:0 unexpected_error_replies:0 total_error_replies:63 dump_payload_sanitizations:0 total_reads_processed:149032 total_writes_processed:4529 io_threaded_reads_processed:0 io_threaded_writes_processed:0 reply_buffer_shrinks:186 reply_buffer_expands:413
Replication
role:slave master_host:10.3.52.111 master_port:6382 master_link_status:down master_last_io_seconds_ago:-1 master_sync_in_progress:1 slave_read_repl_offset:4742552871 slave_repl_offset:4742552871 master_sync_total_bytes:19621222150 master_sync_read_bytes:3422618880 master_sync_left_bytes:16198603270 master_sync_perc:17.44 master_sync_last_io_seconds_ago:0 master_link_down_since_seconds:242 slave_priority:100 slave_read_only:1 replica_announced:1 connected_slaves:0 master_failover_state:no-failover master_replid:9e0fd1151e864e243f5ef9980dea010d671710e7 master_replid2:0000000000000000000000000000000000000000 master_repl_offset:4742552871 second_repl_offset:-1 repl_backlog_active:1 repl_backlog_size:104857600 repl_backlog_first_byte_offset:4637692921 repl_backlog_histlen:104859951
CPU
used_cpu_sys:11.318126 used_cpu_user:9.482673 used_cpu_sys_children:0.000000 used_cpu_user_children:0.000000 used_cpu_sys_main_thread:11.309606 used_cpu_user_main_thread:9.480567
Modules
Errorstats
errorstat_NOMASTERLINK:count=63
Cluster
cluster_enabled:0
Keyspace
db0:keys=243344,expires=0,avg_ttl=0 `
Comment From: geekthread
@enjoy-binbin , I think rdb-compression is not working fine in redis 7.0.5, is there any way to validate this ?
Comment From: enjoy-binbin
as far as I know, we did not make any changes to rdb-compression in 7.0
/* Try LZF compression - under 20 bytes it's unable to compress even
* aaaaaaaaaaaaaaaaaa so skip it */
if (server.rdb_compression && len > 20) {
n = rdbSaveLzfStringObject(rdb,s,len);
if (n == -1) return -1;
if (n > 0) return n;
/* Return value of 0 means data can't be compressed, save the old way */
}
Comment From: geekthread
same command (redis-benchmark -p 6382 -c 1000 -r 1700000 -n 1700000 -t hset -d 18000 -P 750) on redis 5.0.5 is able to do quite well and dump size are very well under few hudred mb's whereas in redis 7.0.5 this seems to be causing the issue.
Is there any config change that you would recommend to mitigate this issue ?
Comment From: geekthread
I tried with diskless sync on , slaves were synced in around 3-4 minutes , but dump file again was size around 19 -20 gb. Please see below logs from master node.
` 11:S 22 Nov 2022 12:05:05.016 * Reconnecting to MASTER keng03-dev01-ins01-dmc39-app-1667814641-1.int.dev.mykronos.com:6379 11:S 22 Nov 2022 12:05:05.017 * MASTER <-> REPLICA sync started 11:S 22 Nov 2022 12:05:05.017 * Non blocking connect for SYNC fired the event. 11:S 22 Nov 2022 12:05:05.288 * Master replied to PING, replication can continue... 11:S 22 Nov 2022 12:05:05.333 * Trying a partial resynchronization (request 36f49bb3ca9d18a0f0cc5f524fcd918068e54462:5329083804). 11:S 22 Nov 2022 12:05:08.091 * Full resync from master: 36f49bb3ca9d18a0f0cc5f524fcd918068e54462:9348725138 11:S 22 Nov 2022 12:05:08.322 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk 11:S 22 Nov 2022 12:05:13.803 # I/O error trying to sync with MASTER: connection lost 11:S 22 Nov 2022 12:05:13.803 * Reconnecting to MASTER keng03-dev01-ins01-dmc39-app-1667814641-1.int.dev.mykronos.com:6379 after failure 11:S 22 Nov 2022 12:05:13.804 * MASTER <-> REPLICA sync started 11:S 22 Nov 2022 12:05:13.807 * Non blocking connect for SYNC fired the event. 11:S 22 Nov 2022 12:05:13.894 * Master replied to PING, replication can continue... 11:S 22 Nov 2022 12:05:13.933 * Trying a partial resynchronization (request 36f49bb3ca9d18a0f0cc5f524fcd918068e54462:5329083804). 11:S 22 Nov 2022 12:05:18.871 * Full resync from master: 36f49bb3ca9d18a0f0cc5f524fcd918068e54462:14356258871 11:S 22 Nov 2022 12:05:19.146 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk 11:S 22 Nov 2022 12:05:25.283 # I/O error trying to sync with MASTER: connection lost 11:S 22 Nov 2022 12:05:25.283 * Reconnecting to MASTER keng03-dev01-ins01-dmc39-app-1667814641-1.int.dev.mykronos.com:6379 after failure 11:S 22 Nov 2022 12:05:25.284 * MASTER <-> REPLICA sync started 11:S 22 Nov 2022 12:05:25.284 * Non blocking connect for SYNC fired the event. 11:S 22 Nov 2022 12:05:25.355 * Master replied to PING, replication can continue... 11:S 22 Nov 2022 12:05:25.383 * Trying a partial resynchronization (request 36f49bb3ca9d18a0f0cc5f524fcd918068e54462:5329083804). 11:S 22 Nov 2022 12:05:30.953 * Full resync from master: 36f49bb3ca9d18a0f0cc5f524fcd918068e54462:19832935930 11:S 22 Nov 2022 12:05:31.303 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk 11:S 22 Nov 2022 12:05:37.405 # I/O error trying to sync with MASTER: connection lost 11:S 22 Nov 2022 12:05:37.405 * Reconnecting to MASTER keng03-dev01-ins01-dmc39-app-1667814641-1.int.dev.mykronos.com:6379 after failure 11:S 22 Nov 2022 12:05:37.406 * MASTER <-> REPLICA sync started 11:S 22 Nov 2022 12:05:37.406 * Non blocking connect for SYNC fired the event. 11:S 22 Nov 2022 12:05:37.521 * Master replied to PING, replication can continue... 11:S 22 Nov 2022 12:05:37.570 * Trying a partial resynchronization (request 36f49bb3ca9d18a0f0cc5f524fcd918068e54462:5329083804). 11:S 22 Nov 2022 12:05:42.997 * Full resync from master: 36f49bb3ca9d18a0f0cc5f524fcd918068e54462:25683959396 11:S 22 Nov 2022 12:05:43.406 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk 11:S 22 Nov 2022 12:05:49.612 # I/O error trying to sync with MASTER: connection lost 11:S 22 Nov 2022 12:05:49.612 * Reconnecting to MASTER keng03-dev01-ins01-dmc39-app-1667814641-1.int.dev.mykronos.com:6379 after failure 11:S 22 Nov 2022 12:05:49.613 * MASTER <-> REPLICA sync started 11:S 22 Nov 2022 12:05:49.613 * Non blocking connect for SYNC fired the event. 11:S 22 Nov 2022 12:05:49.708 * Master replied to PING, replication can continue... 11:S 22 Nov 2022 12:05:49.751 * Trying a partial resynchronization (request 36f49bb3ca9d18a0f0cc5f524fcd918068e54462:5329083804). 11:S 22 Nov 2022 12:05:54.154 * Full resync from master: 36f49bb3ca9d18a0f0cc5f524fcd918068e54462:30779847992 11:S 22 Nov 2022 12:05:54.663 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk 11:S 22 Nov 2022 12:08:49.507 * Discarding previously cached master state. 11:S 22 Nov 2022 12:08:49.507 * MASTER <-> REPLICA sync: Flushing old data 11:S 22 Nov 2022 12:08:50.001 * MASTER <-> REPLICA sync: Loading DB in memory 11:S 22 Nov 2022 12:08:50.003 * Loading RDB produced by version 7.0.5 11:S 22 Nov 2022 12:08:50.003 * RDB age 176 seconds 11:S 22 Nov 2022 12:08:50.003 * RDB memory usage when created 21268.40 Mb 11:S 22 Nov 2022 12:09:20.312 * Done loading RDB, keys loaded: 1077376, keys expired: 0. 11:S 22 Nov 2022 12:09:20.312 * Removing the RDB file obtained from the master. This replica has persistence disabled 11:S 22 Nov 2022 12:09:20.312 * MASTER <-> REPLICA sync: Finished with success
`
Comment From: oranagra
i'm guessing this is due to this #7196 (seems to have been released in redis 6.0.4)
Comment From: geekthread
@oranagra , @enjoy-binbin - what will be the eta for this fix ? Will this fix be backported to 7.0.5 ?
Comment From: oranagra
what fix? it's not a fix, it's a change that was done in redis-benchmark in 6.0.4. now it generates random content, so it's not as "complressible" as it used to be in 5.0.
you can use an old redis-benchmark, or a different tool, or just change your test to create less data or tune some limits (timeout / client-output-buffer limit, or use less aggressive traffic)
in theory we can add a flag to redis-benchmark to disable randomization, but i don't see the benefit of doing that.
Comment From: geekthread
Hi @oranagra , Few queries 1. How to disable randomization in redis-benchmark ? 2. Can you please share list of steps to be followed for using redis-benchmark from redis 5.0.5
Comment From: helloKaiDing
您的来件已收到！
Comment From: enjoy-binbin
@geekthread
How to disable randomization in redis-benchmark ?
For now, there is no way to disable it, it is a feature, and as Oran say, we don't see the benefit of doing that (disable it).
Can you please share list of steps to be followed for using redis-benchmark from redis 5.0.5
There is no any special steps, just use an older version redis-benchmark, use it with some host config (please check redis-benchmark --help for more details), make it connect to your server (the 7.0.5 one)
Comment From: geekthread
@enjoy-binbin
Are there any chances of missing any edge case if we use benchmark from redis 5.0.5?
Comment From: enjoy-binbin
I don't understand your concerns, benchmark or sync?
Comment From: oranagra
you should have no problem using an old redis-benchmark, it's not specific to the redis version it comes with.. just bundled there for conveneice.
Comment From: geekthread
thanks @oranagra , @enjoy-binbin for sharing valuable information in this discussion