[LBBS-19] tls.c: Occasional SEGV at shutdowns of TLS connections
This issue has manifested itself in various ways over time, but these are some examples:
Thread 1 (Thread 0x7f14d97326c0 (LWP 103933)):
#0 0x00007f14dbf3d8b4 in () at /lib/x86_64-linux-gnu/libcrypto.so.3
#1 0x00007f14dbf3d9db in () at /lib/x86_64-linux-gnu/libcrypto.so.3
#2 0x00007f14dbe0a07b in EVP_CipherInit_ex () at /lib/x86_64-linux-gnu/libcrypto.so.3
#3 0x00007f14db85c2f6 in () at /lib/x86_64-linux-gnu/libssl.so.3
#4 0x00007f14db856a50 in () at /lib/x86_64-linux-gnu/libssl.so.3
#5 0x00007f14db856f37 in () at /lib/x86_64-linux-gnu/libssl.so.3
#6 0x00007f14db8389c3 in SSL_write () at /lib/x86_64-linux-gnu/libssl.so.3
#7 0x00007f14d9737fc2 in ssl_io_thread (unused=unused@entry=0x0) at io_tls.c:550
write_attempts = 0
readpipe = <optimized out>
ssl = 0x7f14a805ed20
ores = 12
wres = <optimized out>
sfd = <optimized out>
res = <optimized out>
pfds = 0x7f14d00f26b0
readpipes = 0x7f14d000a3d0
ssl_list = 0x7f14d00ecf20
i = 2
prevfds = 11
oldnumfds = <optimized out>
numfds = 11
numssl = <optimized out>
needcreate = 0
buf = "bye LOGOUT\r\n Terminated\r\ned \\Draft \\Deleted \\Seen $Forwarded $MDNSent $NotPhishing $Phishing $label1 $label2 $label5 Junk NonJunk encry>
pending = <optimized out>
inovertime = 0
overtime = 0
err_msg = "error:00000000:lib(0)::reason(0)", '\000' <repeats 991 times>
__func__ = "ssl_io_thread"
#8 0x0000561d9a628ff9 in thread_run (data=<optimized out>) at thread.c:406
[2024-07-30 12:19:53.744] DEBUG[344170]: net_imap.c:4756 handle_client: 0x7f14a5ff85d0 => 12 LOGOUT
[2024-07-30 12:19:53.744] DEBUG[344170]: net_imap.c:4242 imap_process: 0x7f14a5ff85d0 <= * BYE IMAP4 Server logging out
[2024-07-30 12:19:53.744] DEBUG[344170]: net_imap.c:4243 imap_process: 0x7f14a5ff85d0 <= 12 OK LOGOUT completed
[2024-07-30 12:19:53.744] DEBUG[344170]: mod_mail.c:228 mailbox_dispatch_event: Dispatching mailbox event 'Logout'
[2024-07-30 12:19:53.744] DEBUG[344170]: imap_client.c:45 client_destroy: Destroying IMAP client Other REDACTED
[2024-07-30 12:19:53.744] DEBUG[344170]: io.c:322 bbs_io_teardown_all_transformers: Removing I/O transformer at index 0
[2024-07-30 12:19:53.744] DEBUG[103933]: io_tls.c:445 ssl_io_thread: SSL at index 2 / 1 = POLLHUP
[2024-07-30 12:19:53.744] DEBUG[103933]: io_tls.c:533 ssl_io_thread: read returned 0
[2024-07-30 12:19:53.744] DEBUG[103933]: io_tls.c:403 ssl_io_thread: SSL I/O thread now polling 13 -> 11 fds (5 connections)
[2024-07-30 12:19:53.744] DEBUG[344170]: io_tls.c:852 ssl_close: Exiting without receiving close notify from peer
[2024-07-30 12:19:53.746] DEBUG[344170]: imap_client.c:45 client_destroy: Destroying IMAP client REDACTED
[2024-07-30 12:19:53.746] DEBUG[344170]: io.c:322 bbs_io_teardown_all_transformers: Removing I/O transformer at index 0
[2024-07-30 12:19:53.746] DEBUG[344170]: io_tls.c:852 ssl_close: Exiting without receiving close notify from peer
Segmentation fault (core dumped)
Thread 1 (Thread 0x7f3239e576c0 (LWP 3593141)):
#0 0x00007f323c508630 in BIO_test_flags () at /lib/x86_64-linux-gnu/libcrypto.so.3
#1 0x00007f323bf4e871 in SSL_get_error () at /lib/x86_64-linux-gnu/libssl.so.3
#2 0x00007f3239e5d3f9 in ssl_io_thread (unused=unused@entry=0x0) at io_tls.c:553
err = <optimized out>
write_attempts = 0
readpipe = <optimized out>
ssl = 0x7f32300c6000
ores = 12
wres = 0
sfd = <optimized out>
res = <optimized out>
pfds = 0x7f32300fa590
readpipes = 0x7f32300aeed0
ssl_list = 0x7f32300f48a0
i = 6
prevfds = 13
oldnumfds = <optimized out>
numfds = 13
numssl = <optimized out>
needcreate = 0
buf = "bye LOGOUT\r\nere\r\ninated\r\n Completed.\r\ned $Forwarded)\r\n* 85977 EXISTS\r\n* 0 RECENT\r\n* OK [UNSEEN 51238]\r\n* OK [PERMANENTFLAGS (\\Answered \\Seen \\Draft \\Flagged \\>
pending = <optimized out>
inovertime = 0
overtime = 0
err_msg = "error:0A00007F:SSL routines::bad write retry\000hile reading", '\000' <repeats 966 times>
__func__ = "ssl_io_thread"
#3 0x000056118633eff9 in thread_run (data=<optimized out>) at thread.c:406Thread 1 (Thread 0x7f44da7076c0 (LWP 3506463)):
#0 0x00007f44dcd08630 in BIO_test_flags () at /lib/x86_64-linux-gnu/libcrypto.so.3
#1 0x00007f44dc7fe871 in SSL_get_error () at /lib/x86_64-linux-gnu/libssl.so.3
#2 0x00007f44da70d3f9 in ssl_io_thread (unused=unused@entry=0x0) at io_tls.c:553
err = <optimized out>
write_attempts = 0
readpipe = <optimized out>
ssl = 0x7f44cc0df6f0
ores = 12
wres = 0
sfd = <optimized out>
res = <optimized out>
pfds = 0x7f44d003f390
readpipes = 0x7f44d00f2b20
ssl_list = 0x7f44d00549e0
i = 4
prevfds = 5
oldnumfds = <optimized out>
numfds = 5
numssl = <optimized out>
needcreate = 0
buf = "bye LOGOUT\r\nNEXISTENT] Invalid folder: [Gmail] (Failure)\r\nVALIDITY)\r\n\n* 0 RECENT\r\n* OK [UNSEEN 51238]\r\n* OK [PERMANENTFLAGS (\\Answered \\Seen \\Draft \\Fl>
pending = <optimized out>
inovertime = 0
overtime = 0
err_msg = "error:00000000:lib(0)::reason(0)\000ocol is shutdown", '\000' <repeats 974 times>
__func__ = "ssl_io_thread"Thread 1 (Thread 0x7fefb0a596c0 (LWP 3497357)):
#0 0x00007fefb3108630 in BIO_test_flags () at /lib/x86_64-linux-gnu/libcrypto.so.3
#1 0x00007fefb2b60871 in SSL_get_error () at /lib/x86_64-linux-gnu/libssl.so.3
#2 0x00007fefb0a5f3f9 in ssl_io_thread (unused=unused@entry=0x0) at io_tls.c:553
err = <optimized out>
write_attempts = 0
readpipe = <optimized out>
ssl = 0x7fef900e3210
ores = 12
wres = 0
sfd = <optimized out>
res = <optimized out>
pfds = 0x7fefa8008e30
readpipes = 0x7fefa80f6460
ssl_list = 0x7fefa80033b0
i = 4
prevfds = 7
oldnumfds = <optimized out>
numfds = 7
numssl = <optimized out>
needcreate = 0
buf = "bye LOGOUT\r\nNEXISTENT] Invalid folder: [Gmail] (Failure)\r\nVALIDITY)\r\n\n* 0 RECENT\r\n* OK [UNSEEN 51238]\r\n* OK [PERMANENTFLAGS (\\Answered \\Seen \\Draft \\Fl>
pending = <optimized out>
inovertime = 0
overtime = 0
err_msg = "error:0A0000CF:SSL routines::protocol is shutdown", '\000' <repeats 974 times>
__func__ = "ssl_io_thread"Possibly related?
[2024-02-13 08:01:27.866] DEBUG[4160906]: node.c:1760 bbs_node_exit: Node 5 has ended its HTTPS session
[2024-02-13 08:01:27.866] DEBUG[4160906]: node.c:527 node_shutdown: Terminating node 5
...
[2024-02-13 08:01:27.866] DEBUG[4160906]: event.c:131 bbs_event_broadcast: Event NODE_SHORT_SESSION dispatched and consumed
[2024-02-13 08:01:27.866] DEBUG[4160906]: node.c:598 node_shutdown: Shutdown pending finalization for node 5
[2024-02-13 08:01:27.866] DEBUG[4160906]: node.c:615 node_free: Node 5 now freed
[2024-02-13 08:01:27.866] == Node 5 has exited
[2024-02-13 08:01:27.866] DEBUG[4160906]: thread.c:133 __thread_unregister: Thread 4160906 is exiting (detached)
free(): invalid next size (fast)
Aborted (core dumped)Comments
You must be
10/13/2024 10:44 AM — InterLinked
This was likely fixed by https://github.com/InterLinked1/lbbs/commit/4a854f96bfba68c7f97dde8317a12adcc187b483, with high confidence