KeyDB
KeyDB copied to clipboard
[CRASH] on X509_get_subject_name
Crash report
Paste the complete crash log between the quotes below. Please include a few lines from the log preceding the crash report to provide some context.
3478:3478:C 08 Aug 2023 17:21:13.630 # WARNING supervised by systemd - you MUST set appropriate values for TimeoutStartSec and TimeoutStopSec in your service unit.
3478:3478:C 08 Aug 2023 17:21:13.631 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
3478:3478:C 08 Aug 2023 17:21:13.631 # KeyDB version=6.3.3, bits=64, commit=3909d513, modified=0, pid=3478, just started
3478:3478:C 08 Aug 2023 17:21:13.631 # Configuration loaded
3478:3478:S 08 Aug 2023 17:21:13.634 * monotonic clock: POSIX clock_gettime
_
_-(+)-_
_-- / \ --_
_-- / \ --_ KeyDB 6.3.3 (3909d513/0) 64 bit
__-- / \ --__
(+) _ / \ _ (+) Running in standalone mode
| -- / \ -- | Port: 22506
| /--_ _ _--\ | PID: 3478
| / -(+)- \ |
| / | \ | https://docs.keydb.dev
| / | \ |
| / | \ |
(+)_ -- -- -- | -- -- -- _(+)
--_ | _--
--_ | _--
-(+)- KeyDB has now joined Snap! See the announcement at: https://docs.keydb.dev/news
3478:3478:S 08 Aug 2023 17:21:13.858 # Server initialized
3478:3478:S 08 Aug 2023 17:21:13.859 * Ready to accept connections
3478:3488:S 08 Aug 2023 17:21:13.859 * Thread 0 alive.
3478:3488:S 08 Aug 2023 17:21:13.860 * Connecting to MASTER 10.xxx.1.31:22501
3478:3488:S 08 Aug 2023 17:21:13.860 * MASTER <-> REPLICA sync started
3478:3489:S 08 Aug 2023 17:21:13.861 * Thread 1 alive.
3478:3488:S 08 Aug 2023 17:21:14.000 * Non blocking connect for SYNC fired the event.
3478:3488:S 08 Aug 2023 17:21:14.021 # Error reply to PING from master: '-Reading from master: Success'
=== KEYDB BUG REPORT START: Cut & paste starting from here ===
3478:3488:S 08 Aug 2023 17:21:14.761 # KeyDB 6.3.3 crashed by signal: 11, si_code: 1
3478:3488:S 08 Aug 2023 17:21:14.761 # Accessing address: (nil)
3478:3488:S 08 Aug 2023 17:21:14.761 # Crashed running the instruction at: 0x7fc61f73f100
------ STACK TRACE ------
EIP:
/lib64/libcrypto.so.10(X509_get_subject_name+0) [0x7fc61f73f100]
Backtrace:
/lib64/libpthread.so.0(+0xf630) [0x7fc61d3aa630]
/lib64/libcrypto.so.10(X509_get_subject_name+0) [0x7fc61f73f100]
/usr/bin/keydb-server 10.xxx.1.31:22506(tlsValidateCertificateName(tls_connection*)+0x94) [0x5f2044]
/usr/bin/keydb-server 10.xxx.1.31:22506(tlsHandleEvent(tls_connection*, int)+0x1f9) [0x5f2459]
/usr/bin/keydb-server 10.xxx.1.31:22506(ProcessEventCore+0xfc) [0x514afc]
/usr/bin/keydb-server 10.xxx.1.31:22506(aeProcessEvents+0x165) [0x516435]
/usr/bin/keydb-server 10.xxx.1.31:22506(aeMain+0x37) [0x51f447]
/usr/bin/keydb-server 10.xxx.1.31:22506(workerThreadMain(void*)+0x73) [0x5bfbd3]
/lib64/libpthread.so.0(+0x7ea5) [0x7fc61d3a2ea5]
/lib64/libc.so.6(clone+0x6d) [0x7fc61d0cbb0d]
------ REGISTERS ------
3478:3488:S 08 Aug 2023 17:21:14.763 #
RAX:0000000000000000 RBX:0000000000000000
RCX:0000000000000000 RDX:0000000000000003
RDI:0000000000000000 RSI:00007fc60cfeff90
RBP:00007fc618866800 RSP:00007fc60cfeff68
R8 :00007fc618a00900 R9 :00007fc611d4c818
R10:00007fc60cfef9e0 R11:00007fc61f73f100
R12:0000000000000009 R13:0000000000000001
R14:00007fc60a20f000 R15:00007fc60cff2700
RIP:00007fc61f73f100 EFL:0000000000010202
CSGSFS:0000000000000033
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff77) -> 00007fc60cff2700
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff76) -> 0000000000000000
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff75) -> 0000000000000000
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff74) -> 0000000000000009
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff73) -> 00007fc618866800
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff72) -> 00007fc60a20f000
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff71) -> 00007fc618866800
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff70) -> 000000000060f820
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff6f) -> 000000000060f650
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff6e) -> 507eb6fa0f77ee00
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff6d) -> 0000000000000000
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff6c) -> 000000000060f820
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff6b) -> 000000000060f650
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff6a) -> 0000000000000003
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff69) -> 0000000000000000
3478:3488:S 08 Aug 2023 17:21:14.763 # (00007fc60cfeff68) -> 00000000005f2044
------ INFO OUTPUT ------
# Server
redis_version:6.3.3
redis_git_sha1:3909d513
redis_git_dirty:0
redis_build_id:c2fa7fa741085ae
redis_mode:standalone
os:Linux 3.10.0-1160.92.1.el7.x86_64 x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:7.3.1
process_id:3478
process_supervised:systemd
run_id:79e0054baaed5fbe38c033acac709a4943e7a903
tcp_port:22506
server_time_usec:1691515274763608
uptime_in_seconds:1
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:13793674
executable:/usr/bin/keydb-server
config_file:/etc/keydb/eusw.conf
# Clients
connected_clients:1
cluster_connections:0
maxclients:10000
client_recent_max_input_buffer:0
client_recent_max_output_buffer:0
blocked_clients:0
tracking_clients:0
clients_in_timeout_table:0
current_client_thread:0
thread_0_clients:1
thread_1_clients:0
# Memory
used_memory:2187696
used_memory_human:2.09M
used_memory_rss:15278080
used_memory_rss_human:14.57M
used_memory_peak:2187696
used_memory_peak_human:2.09M
used_memory_peak_perc:100.08%
used_memory_overhead:2163704
used_memory_startup:2163704
used_memory_dataset:23992
used_memory_dataset_perc:100.00%
allocator_allocated:3352328
allocator_active:3997696
allocator_resident:6803456
total_system_memory:1923514368
total_system_memory_human:1.79G
used_memory_lua:37888
used_memory_lua_human:37.00K
used_memory_scripts:0
used_memory_scripts_human:0B
number_of_cached_scripts:0
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.19
allocator_frag_bytes:645368
allocator_rss_ratio:1.70
allocator_rss_bytes:2805760
rss_overhead_ratio:2.25
rss_overhead_bytes:8474624
mem_fragmentation_ratio:7.06
mem_fragmentation_bytes:13113176
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:0
mem_aof_buffer:0
mem_allocator:jemalloc-5.2.1
active_defrag_running:0
lazyfree_pending_objects:0
lazyfreed_objects:0
storage_provider:none
# Persistence
loading: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:0
rdb_bgsave_in_progress:0
rdb_last_save_time:1691515273
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:-1
rdb_last_cow_size: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_last_write_status:ok
aof_last_cow_size:0
module_fork_in_progress:0
module_fork_last_cow_size:0
# Stats
total_connections_received:0
total_commands_processed:0
instantaneous_ops_per_sec:0
total_net_input_bytes:0
total_net_output_bytes:0
instantaneous_input_kbps:0.00
instantaneous_output_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
keyspace_hits:0
keyspace_misses:0
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:0
total_forks:0
migrate_cached_sockets:0
slave_expires_tracked_keys:0
active_defrag_hits:0
active_defrag_misses:0
active_defrag_key_hits:0
active_defrag_key_misses:0
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:0
total_writes_processed:0
instantaneous_lock_contention:0
avg_lock_contention:0.000000
storage_provider_read_hits:0
storage_provider_read_misses:0
# Replication
role:active-replica
master_global_link_status:down
connected_masters:0
master_host:10.185.1.31
master_port:22501
master_link_status:down
master_last_io_seconds_ago:-1
master_sync_in_progress:0
slave_read_repl_offset:1
slave_repl_offset:1
master_link_down_since_seconds:-1
master_1_host:10.184.1.31
master_1_port:22501
master_1_link_status:down
master_1_last_io_seconds_ago:-1
master_1_sync_in_progress:0
slave_read_repl_offset:0
slave_repl_offset:0
master_1_link_down_since_seconds:-1
slave_priority:100
slave_read_only:0
replica_announced:1
connected_slaves:0
master_failover_state:no-failover
master_replid:2c24c0cb1b39a5389591bc5da9da6d0dfd96d8b3
master_replid2:0000000000000000000000000000000000000000
master_repl_offset:0
second_repl_offset:-1
repl_backlog_active:0
repl_backlog_size:1048576
repl_backlog_first_byte_offset:0
repl_backlog_histlen:0
# CPU
used_cpu_sys:0.027455
used_cpu_user:0.033235
used_cpu_sys_children:0.000000
used_cpu_user_children:0.000000
server_threads:2
long_lock_waits:0
used_cpu_sys_main_thread:0.005970
used_cpu_user_main_thread:0.017910
# Modules
# Commandstats
# Errorstats
# Cluster
cluster_enabled:0
# Keyspace
# KeyDB
mvcc_depth:0
------ CLIENT LIST OUTPUT ------
id=5 addr=10.184.1.31:45107 laddr=10.xxx.1.31:22501 fd=0 name= age=0 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=4 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=20488 events=r cmd=NULL user=default redir=-1
------ MODULES INFO OUTPUT ------
------ FAST MEMORY TEST ------
3478:3488:S 08 Aug 2023 17:21:14.764 # main thread terminated
3478:3488:S 08 Aug 2023 17:21:14.764 # Bio thread for job type #0 terminated
3478:3488:S 08 Aug 2023 17:21:14.764 # Bio thread for job type #1 terminated
3478:3488:S 08 Aug 2023 17:21:14.764 # Bio thread for job type #2 terminated
Fast memory test PASSED, however your memory can still be broken. Please run a memory test for several hours if possible.
------ DUMPING CODE AROUND EIP ------
Symbol: X509_get_subject_name (base: 0x7fc61f73f100)
Module: /lib64/libcrypto.so.10 (base 0x7fc61f5dd000)
$ xxd -r -p /tmp/dump.hex /tmp/dump.bin
$ objdump --adjust-vma=0x7fc61f73f100 -D -b binary -m i386:x86-64 /tmp/dump.bin
------
3478:3488:S 08 Aug 2023 17:21:14.764 # dump of function (hexdump of 128 bytes):
488b07488b4028c30f1f840000000000488b07488b4008c30f1f8400000000005531d24889f5beffffffff534889fb4883ec08e89844010031d2beffffffff4889efe889440100488db5a8000000488dbba8000000ba14000000e811acf0ff85c0753f488b0b8b416085c07533488b75008b566085d2752a488b515889d02b46
=== KEYDB BUG REPORT END. Make sure to include from START to END. ===
Config:
bind 10.xxx.1.31
port 2xx6
protected-mode no
tcp-backlog 128
timeout 0
tcp-keepalive 120
requirepass XXXXX
masterauth XXXXX
active-replica yes
multi-master yes
replicaof 10.xxx.1.31 22501
replicaof 10.xxx.1.31 22501
tls-allowlist *.xxxxxx.xxx
tls-port 2xx1
tls-cert-file /storage/KeyDb/Certs/serverCert.pem
tls-key-file /storage/KeyDb/Certs/serverKey.pem
tls-client-cert-file /storage/KeyDb/Certs/clientCert.pem
tls-client-key-file /storage/KeyDb/Certs/clientKey.pem
tls-ca-cert-file /storage/KeyDb/Certs/ca.pem
tls-auth-clients no
tls-replication yes
tls-protocols "TLSv1.2"
tls-session-cache-size 1024
tls-session-cache-timeout 110
tls-rotation no
supervised systemd
daemonize yes
dir /storage/KeyDb/EuropeSouthWest/Data
pidfile /storage/KeyDb/EuropeSouthWest/Proc/keydb-server.pid
logfile /storage/KeyDb/EuropeSouthWest/Logs/keydb-server-err.log
databases 1
save ""
loglevel notice
stop-writes-on-bgsave-error yes
proc-title-template "{title} {listen-addr} {server-mode}"
always-show-logo yes
set-proc-title yes
rdbcompression yes
rdbchecksum yes
dbfilename dump.rdb
rdb-del-sync-files no
replica-serve-stale-data yes
replica-read-only no
repl-diskless-sync no
repl-diskless-sync-delay 5
repl-diskless-load disabled
repl-disable-tcp-nodelay no
replica-priority 100
lazyfree-lazy-eviction no
lazyfree-lazy-expire no
lazyfree-lazy-server-del no
replica-lazy-flush no
lazyfree-lazy-user-del no
lazyfree-lazy-user-flush no
oom-score-adj no
oom-score-adj-values 0 200 800
disable-thp yes
appendonly no
appendfilename "appendonly.aof"
appendfsync everysec
no-appendfsync-on-rewrite no
auto-aof-rewrite-percentage 100
auto-aof-rewrite-min-size 64mb
aof-load-truncated yes
aof-use-rdb-preamble yes
lua-time-limit 5000
slowlog-log-slower-than 10000
slowlog-max-len 128
latency-monitor-threshold 0
notify-keyspace-events ""
hash-max-ziplist-entries 512
hash-max-ziplist-value 64
list-max-ziplist-size -2
list-compress-depth 0
set-max-intset-entries 512
zset-max-ziplist-entries 128
zset-max-ziplist-value 64
hll-sparse-max-bytes 3000
stream-node-max-bytes 4096
stream-node-max-entries 100
activerehashing yes
client-output-buffer-limit normal 0 0 0
client-output-buffer-limit replica 256mb 64mb 60
client-output-buffer-limit pubsub 32mb 8mb 60
hz 10
dynamic-hz yes
aof-rewrite-incremental-fsync yes
rdb-save-incremental-fsync yes
jemalloc-bg-thread yes
server-threads 2
replica-weighting-factor 2
Aditional information
- OS distribution and version: CentOS 7.9.2009
- Steps to reproduce (if any): Fresh Install, generated 2x certificates (one server RSA-4096, one client RSA-2048) + keys. Upload in PEM format.
Start one instance, runs. Start second instance and it crashes when trying to sync to the first instance. It appears the issue is validating the CN from the cert of the server (/usr/bin/keydb-server 10.xxx.1.31:22506(tlsValidateCertificateName(tls_connection*)+0x94) [0x5f2044])
Hi,
We followed the documentation from: https://github.com/Snapchat/KeyDB/blob/441b74a936f46724f93a2810c90dafd8dcce06a5/keydb.conf#L174C3-L178C2 and divided the certificates into distinct Extended Key Usage: Client Authentication / Server Authentication.
Commenting out the TLS config from above and the masters sync as expected:
4299:4299:C 08 Aug 2023 19:28:11.019 # WARNING supervised by systemd - you MUST set appropriate values for TimeoutStartSec and TimeoutStopSec in your service unit.
4299:4299:C 08 Aug 2023 19:28:11.019 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
4299:4299:C 08 Aug 2023 19:28:11.019 # KeyDB version=6.3.3, bits=64, commit=3909d513, modified=0, pid=4299, just started
4299:4299:C 08 Aug 2023 19:28:11.019 # Configuration loaded
4299:4299:S 08 Aug 2023 19:28:11.021 * monotonic clock: POSIX clock_gettime
_
_-(+)-_
_-- / \ --_
_-- / \ --_ KeyDB 6.3.3 (3909d513/0) 64 bit
__-- / \ --__
(+) _ / \ _ (+) Running in standalone mode
| -- / \ -- | Port: 22506
| /--_ _ _--\ | PID: 4299
| / -(+)- \ |
| / | \ | https://docs.keydb.dev
| / | \ |
| / | \ |
(+)_ -- -- -- | -- -- -- _(+)
--_ | _--
--_ | _--
-(+)- KeyDB has now joined Snap! See the announcement at: https://docs.keydb.dev/news
4299:4299:S 08 Aug 2023 19:28:11.249 # Server initialized
4299:4309:S 08 Aug 2023 19:28:11.250 * Thread 0 alive.
4299:4309:S 08 Aug 2023 19:28:11.250 * Connecting to MASTER 10.xxx.1.31:22501
4299:4309:S 08 Aug 2023 19:28:11.250 * MASTER <-> REPLICA sync started
4299:4310:S 08 Aug 2023 19:28:11.252 * Thread 1 alive.
4299:4309:S 08 Aug 2023 19:28:11.291 * Non blocking connect for SYNC fired the event.
4299:4309:S 08 Aug 2023 19:28:11.333 * Master replied to PING, replication can continue...
4299:4309:S 08 Aug 2023 19:28:11.415 * Trying a partial resynchronization (request e12f65adb6c1911f19263a1ab0d5d9df20bf5273:1).
4299:4309:S 08 Aug 2023 19:28:11.458 * Full resync from master: e69f8d2d388547c6de3ded74cf90e61e2567f223:114
4299:4309:S 08 Aug 2023 19:28:11.458 * Discarding previously cached master state.
4299:4309:S 08 Aug 2023 19:28:11.525 * MASTER <-> REPLICA sync: receiving 229 bytes from master to disk
4299:4309:S 08 Aug 2023 19:28:11.525 * MASTER <-> REPLICA sync: Loading DB in memory
4299:4309:S 08 Aug 2023 19:28:11.527 * Loading RDB produced by version 6.3.3
4299:4309:S 08 Aug 2023 19:28:11.527 * RDB age 6 seconds
4299:4309:S 08 Aug 2023 19:28:11.527 * RDB memory usage when created 3.12 Mb
4299:4309:S 08 Aug 2023 19:28:11.527 # Done loading RDB, keys loaded: 0, keys expired: 0.
4299:4309:S 08 Aug 2023 19:28:11.527 * RDB contains information on 0 masters
4299:4309:S 08 Aug 2023 19:28:11.527 * MASTER <-> REPLICA sync: Finished with success
I tried with this config
port 0
protected-mode no
tcp-backlog 128
timeout 0
tcp-keepalive 120
active-replica yes
multi-master yes
replicaof localhost 6380
tls-port 6379
tls-cert-file /KeyDB/tests/tls/server.crt
tls-key-file /KeyDB/tests/tls/server.key
tls-client-cert-file /KeyDB/tests/tls/client.crt
tls-client-key-file /KeyDB/tests/tls/client.key
tls-ca-cert-file /KeyDB/tests/tls/ca.crt
tls-auth-clients no
tls-replication yes
tls-protocols "TLSv1.2"
tls-session-cache-size 1024
tls-session-cache-timeout 110
tls-rotation no
databases 1
save ""
loglevel notice
stop-writes-on-bgsave-error yes
proc-title-template "{title} {listen-addr} {server-mode}"
always-show-logo yes
set-proc-title yes
rdbcompression yes
rdbchecksum yes
dbfilename dump.rdb
rdb-del-sync-files no
replica-serve-stale-data yes
replica-read-only no
repl-diskless-sync no
repl-diskless-sync-delay 5
repl-diskless-load disabled
repl-disable-tcp-nodelay no
replica-priority 100
lazyfree-lazy-eviction no
lazyfree-lazy-expire no
lazyfree-lazy-server-del no
replica-lazy-flush no
lazyfree-lazy-user-del no
lazyfree-lazy-user-flush no
oom-score-adj no
oom-score-adj-values 0 200 800
disable-thp yes
appendonly no
appendfilename "appendonly.aof"
appendfsync everysec
no-appendfsync-on-rewrite no
auto-aof-rewrite-percentage 100
auto-aof-rewrite-min-size 64mb
aof-load-truncated yes
aof-use-rdb-preamble yes
lua-time-limit 5000
slowlog-log-slower-than 10000
slowlog-max-len 128
latency-monitor-threshold 0
notify-keyspace-events ""
hash-max-ziplist-entries 512
hash-max-ziplist-value 64
list-max-ziplist-size -2
list-compress-depth 0
set-max-intset-entries 512
zset-max-ziplist-entries 128
zset-max-ziplist-value 64
hll-sparse-max-bytes 3000
stream-node-max-bytes 4096
stream-node-max-entries 100
activerehashing yes
client-output-buffer-limit normal 0 0 0
client-output-buffer-limit replica 256mb 64mb 60
client-output-buffer-limit pubsub 32mb 8mb 60
hz 10
dynamic-hz yes
aof-rewrite-incremental-fsync yes
rdb-save-incremental-fsync yes
jemalloc-bg-thread yes
server-threads 2
replica-weighting-factor 2
and was unable to reproduce the issue, I generated my certs using the script here: https://github.com/Snapchat/KeyDB/blob/main/utils/gen-test-certs.sh can you try that and see if the issue persists?