[LBBS-15] smtp: Locking errors, deadlock when queue runs during delivery
Several locking errors that result in assertions:
...
[2024-06-19 11:30:02.263] DEBUG[2740208]: mod_mail.c:228 mailbox_dispatch_event: Dispatching mailbox event 'MessageNew'
[2024-06-19 11:30:02.263] DEBUG[2740208]: mod_mail.c:1140 mailbox_get_next_uid: Current max UID: 0
[2024-06-19 11:30:02.264] DEBUG[2740208]: mod_mail.c:1140 mailbox_get_next_uid: Current max UID: 0
[2024-06-19 11:30:02.264] DEBUG[2740208]: net_smtp.c:1958 expand_and_deliver: SMTP delivery agent returned 1
[2024-06-19 11:30:02.264] DEBUG[2740208]: net_smtp.c:2016 expand_and_deliver: 0x7f24d2f61900 <= 250 2.6.0 Message accepted for delivery
[2024-06-19 11:30:02.264] DEBUG[2740208]: mod_smtp_mailing_lists.c:465 list_post_message: Delivered post to 5 local users (5 explicitly) and 0 external users
...
[2024-06-19 11:30:26.505] WARNING[2740196]: mod_smtp_delivery_external.c:1549 smtp_async_send: Spent 30 seconds so far waiting to rdlock &queue_lock, possible deadlock? (rwlock acquired at mod_smtp_delivery_exter:1238 30 s ago by LWP 2740166)
[2024-06-19 11:30:26.506] ERROR[2740196]: backtrace.c:263 bbs_log_backtrace: Got 6 backtrace records
[2024-06-19 11:30:26.510] WARNING[2740198]: mod_smtp_delivery_external.c:1549 smtp_async_send: Spent 30 seconds so far waiting to rdlock &queue_lock, possible deadlock? (rwlock acquired at mod_smtp_delivery_exter:1238 30 s ago by LWP 2740166)
[2024-06-19 11:30:26.511] ERROR[2740198]: backtrace.c:263 bbs_log_backtrace: Got 6 backtrace records
[2024-06-19 11:30:26.513] WARNING[2740199]: mod_smtp_delivery_external.c:1549 smtp_async_send: Spent 30 seconds so far waiting to rdlock &queue_lock, possible deadlock? (rwlock acquired at mod_smtp_delivery_exter:1238 30 s ago by LWP 2740166)
[2024-06-19 11:30:26.513] ERROR[2740199]: backtrace.c:263 bbs_log_backtrace: Got 6 backtrace records
[2024-06-19 11:30:26.517] WARNING[2740197]: mod_smtp_delivery_external.c:1549 smtp_async_send: Spent 30 seconds so far waiting to rdlock &queue_lock, possible deadlock? (rwlock acquired at mod_smtp_delivery_exter:1238 30 s ago by LWP 2740166)
[2024-06-19 11:30:26.517] ERROR[2740197]: backtrace.c:263 bbs_log_backtrace: Got 6 backtrace records
[2024-06-19 11:30:26.519] WARNING[2740195]: mod_smtp_delivery_external.c:1549 smtp_async_send: Spent 30 seconds so far waiting to rdlock &queue_lock, possible deadlock? (rwlock acquired at mod_smtp_delivery_exter:1238 30 s ago by LWP 2740166)
[2024-06-19 11:30:26.520] ERROR[2740195]: backtrace.c:263 bbs_log_backtrace: Got 6 backtrace records
[2024-06-19 11:30:26.540] WARNING[2740200]: mod_smtp_delivery_external.c:1549 smtp_async_send: Spent 30 seconds so far waiting to rdlock &queue_lock, possible deadlock? (rwlock acquired at mod_smtp_delivery_exter:1238 30 s ago by LWP 2740166)
[2024-06-19 11:30:26.541] ERROR[2740200]: backtrace.c:263 bbs_log_backtrace: Got 6 backtrace records
[2024-06-19 11:30:26.543] WARNING[2740202]: mod_smtp_delivery_external.c:1549 smtp_async_send: Spent 30 seconds so far waiting to rdlock &queue_lock, possible deadlock? (rwlock acquired at mod_smtp_delivery_exter:1238 30 s ago by LWP 2740166)
[2024-06-19 11:30:26.544] ERROR[2740202]: backtrace.c:263 bbs_log_backtrace: Got 6 backtrace records
[2024-06-19 11:30:26.546] WARNING[2740201]: mod_smtp_delivery_external.c:1549 smtp_async_send: Spent 30 seconds so far waiting to rdlock &queue_lock, possible deadlock? (rwlock acquired at mod_smtp_delivery_exter:1238 30 s ago by LWP 2740166)
[2024-06-19 11:30:26.546] ERROR[2740201]: backtrace.c:263 bbs_log_backtrace: Got 6 backtrace records
[2024-06-19 11:30:26.547] WARNING[2740194]: parallel.c:121 run_task: Spent 30 seconds so far waiting to wrlock &p->tasks, possible deadlock? (rwlock acquired at parallel.c:300 30 s ago by LWP 2740166)
[2024-06-19 11:30:26.547] ERROR[2740194]: backtrace.c:263 bbs_log_backtrace: Got 6 backtrace records
[2024-06-19 11:30:26.548] WARNING[2740203]: mod_smtp_delivery_external.c:1549 smtp_async_send: Spent 30 seconds so far waiting to rdlock &queue_lock, possible deadlock? (rwlock acquired at mod_smtp_delivery_exter:1238 30 s ago by LWP 2740166)
[2024-06-19 11:30:26.548] ERROR[2740203]: backtrace.c:263 bbs_log_backtrace: Got 6 backtrace records
[2024-06-19 11:30:26.676] ERROR[2740196]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-06-19 11:30:26.680] ERROR[2740196]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_rwlock_rdlock()
[2024-06-19 11:30:26.680] ERROR[2740196]: backtrace.c:283 bbs_log_backtrace: 2: [0x7f24eeb91cab] mod_smtp_delivery_external.so stdio2.h:54 snprintf()
[2024-06-19 11:30:26.680] ERROR[2740196]: backtrace.c:283 bbs_log_backtrace: 2: [ inlined] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1558 smtp_async_send()
[2024-06-19 11:30:26.681] ERROR[2740196]: backtrace.c:287 bbs_log_backtrace: 3: lbbs <unknown>()
[2024-06-19 11:30:26.681] ERROR[2740196]: backtrace.c:287 bbs_log_backtrace: 4: [0x7f25086a8134] libc.so.6 pthread_create.c:442 start_thread()
[2024-06-19 11:30:26.681] ERROR[2740196]: backtrace.c:287 bbs_log_backtrace: 5: [0x7f25087287dc] libc.so.6 clone3.S:83 clone3()
[2024-06-19 11:30:26.812] ERROR[2740199]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-06-19 11:30:26.817] ERROR[2740199]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_rwlock_rdlock()
[2024-06-19 11:30:26.817] ERROR[2740199]: backtrace.c:283 bbs_log_backtrace: 2: [0x7f24eeb91cab] mod_smtp_delivery_external.so stdio2.h:54 snprintf()
[2024-06-19 11:30:26.818] ERROR[2740199]: backtrace.c:283 bbs_log_backtrace: 2: [ inlined] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1558 smtp_async_send()
[2024-06-19 11:30:26.818] ERROR[2740199]: backtrace.c:287 bbs_log_backtrace: 3: lbbs <unknown>()
[2024-06-19 11:30:26.818] ERROR[2740199]: backtrace.c:287 bbs_log_backtrace: 4: [0x7f25086a8134] libc.so.6 pthread_create.c:442 start_thread()
[2024-06-19 11:30:26.819] ERROR[2740199]: backtrace.c:287 bbs_log_backtrace: 5: [0x7f25087287dc] libc.so.6 clone3.S:83 clone3()
[2024-06-19 11:30:26.951] ERROR[2740194]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-06-19 11:30:26.954] ERROR[2740194]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_rwlock_wrlock()
[2024-06-19 11:30:26.954] ERROR[2740194]: backtrace.c:287 bbs_log_backtrace: 2: lbbs <unknown>()
[2024-06-19 11:30:26.955] ERROR[2740194]: backtrace.c:287 bbs_log_backtrace: 3: lbbs <unknown>()
[2024-06-19 11:30:26.955] ERROR[2740194]: backtrace.c:287 bbs_log_backtrace: 4: [0x7f25086a8134] libc.so.6 pthread_create.c:442 start_thread()
[2024-06-19 11:30:26.956] ERROR[2740194]: backtrace.c:287 bbs_log_backtrace: 5: [0x7f25087287dc] libc.so.6 clone3.S:83 clone3()
[2024-06-19 11:30:27.069] ERROR[2740203]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-06-19 11:30:27.069] ERROR[2740203]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_rwlock_rdlock()
[2024-06-19 11:30:27.069] ERROR[2740203]: backtrace.c:283 bbs_log_backtrace: 2: [0x7f24eeb91cab] mod_smtp_delivery_external.so stdio2.h:54 snprintf()
[2024-06-19 11:30:27.069] ERROR[2740203]: backtrace.c:283 bbs_log_backtrace: 2: [ inlined] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1558 smtp_async_send()
[2024-06-19 11:30:27.070] ERROR[2740203]: backtrace.c:287 bbs_log_backtrace: 3: lbbs <unknown>()
[2024-06-19 11:30:27.073] ERROR[2740203]: backtrace.c:287 bbs_log_backtrace: 4: [0x7f25086a8134] libc.so.6 pthread_create.c:442 start_thread()
[2024-06-19 11:30:27.074] ERROR[2740203]: backtrace.c:287 bbs_log_backtrace: 5: [0x7f25087287dc] libc.so.6 clone3.S:83 clone3()
[2024-06-19 11:30:27.218] ERROR[2740200]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-06-19 11:30:27.223] ERROR[2740200]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_rwlock_rdlock()
[2024-06-19 11:30:27.223] ERROR[2740200]: backtrace.c:283 bbs_log_backtrace: 2: [0x7f24eeb91cab] mod_smtp_delivery_external.so stdio2.h:54 snprintf()
[2024-06-19 11:30:27.224] ERROR[2740200]: backtrace.c:283 bbs_log_backtrace: 2: [ inlined] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1558 smtp_async_send()
[2024-06-19 11:30:27.224] ERROR[2740200]: backtrace.c:287 bbs_log_backtrace: 3: lbbs <unknown>()
[2024-06-19 11:30:27.224] ERROR[2740200]: backtrace.c:287 bbs_log_backtrace: 4: [0x7f25086a8134] libc.so.6 pthread_create.c:442 start_thread()
[2024-06-19 11:30:27.224] ERROR[2740200]: backtrace.c:287 bbs_log_backtrace: 5: [0x7f25087287dc] libc.so.6 clone3.S:83 clone3()
[2024-06-19 11:30:27.379] ERROR[2740202]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-06-19 11:30:27.380] ERROR[2740202]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_rwlock_rdlock()
[2024-06-19 11:30:27.384] ERROR[2740202]: backtrace.c:283 bbs_log_backtrace: 2: [0x7f24eeb91cab] mod_smtp_delivery_external.so stdio2.h:54 snprintf()
[2024-06-19 11:30:27.384] ERROR[2740202]: backtrace.c:283 bbs_log_backtrace: 2: [ inlined] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1558 smtp_async_send()
[2024-06-19 11:30:27.384] ERROR[2740202]: backtrace.c:287 bbs_log_backtrace: 3: lbbs <unknown>()
[2024-06-19 11:30:27.385] ERROR[2740202]: backtrace.c:287 bbs_log_backtrace: 4: [0x7f25086a8134] libc.so.6 pthread_create.c:442 start_thread()
[2024-06-19 11:30:27.385] ERROR[2740202]: backtrace.c:287 bbs_log_backtrace: 5: [0x7f25087287dc] libc.so.6 clone3.S:83 clone3()
[2024-06-19 11:30:27.543] ERROR[2740197]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-06-19 11:30:27.543] ERROR[2740197]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_rwlock_rdlock()
[2024-06-19 11:30:27.549] ERROR[2740197]: backtrace.c:283 bbs_log_backtrace: 2: [0x7f24eeb91cab] mod_smtp_delivery_external.so stdio2.h:54 snprintf()
[2024-06-19 11:30:27.549] ERROR[2740197]: backtrace.c:283 bbs_log_backtrace: 2: [ inlined] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1558 smtp_async_send()
[2024-06-19 11:30:27.549] ERROR[2740197]: backtrace.c:287 bbs_log_backtrace: 3: lbbs <unknown>()
[2024-06-19 11:30:27.549] ERROR[2740197]: backtrace.c:287 bbs_log_backtrace: 4: [0x7f25086a8134] libc.so.6 pthread_create.c:442 start_thread()
[2024-06-19 11:30:27.549] ERROR[2740197]: backtrace.c:287 bbs_log_backtrace: 5: [0x7f25087287dc] libc.so.6 clone3.S:83 clone3()
[2024-06-19 11:30:27.715] ERROR[2740201]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-06-19 11:30:27.715] ERROR[2740201]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_rwlock_rdlock()
[2024-06-19 11:30:27.715] ERROR[2740201]: backtrace.c:283 bbs_log_backtrace: 2: [0x7f24eeb91cab] mod_smtp_delivery_external.so stdio2.h:54 snprintf()
[2024-06-19 11:30:27.716] ERROR[2740201]: backtrace.c:283 bbs_log_backtrace: 2: [ inlined] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1558 smtp_async_send()
[2024-06-19 11:30:27.716] ERROR[2740201]: backtrace.c:287 bbs_log_backtrace: 3: lbbs <unknown>()
[2024-06-19 11:30:27.716] ERROR[2740201]: backtrace.c:287 bbs_log_backtrace: 4: [0x7f25086a8134] libc.so.6 pthread_create.c:442 start_thread()
[2024-06-19 11:30:27.716] ERROR[2740201]: backtrace.c:287 bbs_log_backtrace: 5: [0x7f25087287dc] libc.so.6 clone3.S:83 clone3()
[2024-06-19 11:30:27.910] ERROR[2740198]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-06-19 11:30:27.915] ERROR[2740198]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_rwlock_rdlock()
[2024-06-19 11:30:27.915] ERROR[2740198]: backtrace.c:283 bbs_log_backtrace: 2: [0x7f24eeb91cab] mod_smtp_delivery_external.so stdio2.h:54 snprintf()
[2024-06-19 11:30:27.916] ERROR[2740198]: backtrace.c:283 bbs_log_backtrace: 2: [ inlined] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1558 smtp_async_send()
[2024-06-19 11:30:27.916] ERROR[2740198]: backtrace.c:287 bbs_log_backtrace: 3: lbbs <unknown>()
[2024-06-19 11:30:27.916] ERROR[2740198]: backtrace.c:287 bbs_log_backtrace: 4: [0x7f25086a8134] libc.so.6 pthread_create.c:442 start_thread()
[2024-06-19 11:30:27.916] ERROR[2740198]: backtrace.c:287 bbs_log_backtrace: 5: [0x7f25087287dc] libc.so.6 clone3.S:83 clone3()
[2024-06-19 11:30:28.098] ERROR[2740195]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-06-19 11:30:28.099] ERROR[2740195]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_rwlock_rdlock()
[2024-06-19 11:30:28.099] ERROR[2740195]: backtrace.c:283 bbs_log_backtrace: 2: [0x7f24eeb91cab] mod_smtp_delivery_external.so stdio2.h:54 snprintf()
[2024-06-19 11:30:28.099] ERROR[2740195]: backtrace.c:283 bbs_log_backtrace: 2: [ inlined] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1558 smtp_async_send()
[2024-06-19 11:30:28.100] ERROR[2740195]: backtrace.c:287 bbs_log_backtrace: 3: lbbs <unknown>()
[2024-06-19 11:30:28.100] ERROR[2740195]: backtrace.c:287 bbs_log_backtrace: 4: [0x7f25086a8134] libc.so.6 pthread_create.c:442 start_thread()
[2024-06-19 11:30:28.100] ERROR[2740195]: backtrace.c:287 bbs_log_backtrace: 5: [0x7f25087287dc] libc.so.6 clone3.S:83 clone3()
Thread 1 (Thread 0x7f24d676b6c0 (LWP 2740197)):
#0 __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at ./nptl/pthread_kill.c:44
#1 0x00007f25086a9e8f in __pthread_kill_internal (signo=6, threadid=<optimized out>) at ./nptl/pthread_kill.c:78
#2 0x00007f250865afb2 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#3 0x00007f2508645472 in __GI_abort () at ./stdlib/abort.c:79
#4 0x0000559b593d7957 in __bbs_assert_fatal (condition_str=<optimized out>, file=<optimized out>, line=<optimized out>, function=<optimized out>) at backtrace.c:311
#5 0x0000559b593e64f8 in __bbs_assert (function=<optimized out>, line=<optimized out>, file=<optimized out>, condition_str=<optimized out>, condition=<optimized out>) at ../include/bbs.h:440
#6 __bbs_rwlock_rdlock (t=t@entry=0x7f24eeb96720 <queue_lock>, filename=filename@entry=0x7f24eeb93000 "mod_smtp_delivery_external.c", lineno=lineno@entry=1549, func=func@entry=0x7f24eeb94490 <__func__.22> "smtp_async_send", name=name@entry=0x7f24eeb932a4 "&queue_lock") at lock.c:348
#7 0x00007f24eeb91cab in smtp_async_send (varg=varg@entry=0x559b5a540430) at mod_smtp_delivery_external.c:1549Likely related:
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:453 ssl_io_thread: SSL at index 2 / 1 = POLLHUP
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:541 ssl_io_thread: read returned 0
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:544 ssl_io_thread: SSL connection 0x7fbc44383490 now marked as dead
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7fbc44383490 at index 1 / 0
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:453 ssl_io_thread: SSL at index 2 / 1 = POLLHUP
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:541 ssl_io_thread: read returned 0
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:544 ssl_io_thread: SSL connection 0x7fbc44383490 now marked as dead
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7fbc44383490 at index 1 / 0
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:453 ssl_io_thread: SSL at index 2 / 1 = POLLHUP
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:541 ssl_io_thread: read returned 0
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:544 ssl_io_thread: SSL connection 0x7fbc44383490 now marked as dead
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7fbc44383490 at index 1 / 0
[2024-06-13 15:40:09.979] DEBUG[2405377]: tls.c:453 ssl_io_thread: SSL at index 2 / 1 = POLLHUP
[2024-06-13 15:40:09.980] DEBUG[2405377]: tls.c:541 ssl_io_thread: read returned 0
[2024-06-13 15:40:09.972] ERROR[2405385]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-06-13 15:40:09.980] ERROR[2405385]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_assert_fatal()
[2024-06-13 15:40:09.980] ERROR[2405385]: backtrace.c:287 bbs_log_backtrace: 2: lbbs __bbs_rwlock_wrlock()
[2024-06-13 15:40:09.980] ERROR[2405385]: backtrace.c:287 bbs_log_backtrace: 3: [0x7fbc600382fd] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1239 run_queue()
[2024-06-13 15:40:09.980] ERROR[2405385]: backtrace.c:283 bbs_log_backtrace: 4: [0x7fbc600384c2] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1280 queue_handler()
[2024-06-13 15:40:09.980] ERROR[2405385]: backtrace.c:283 bbs_log_backtrace: 4: [ inlined] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1263 queue_handler()
[2024-06-13 15:40:09.980] ERROR[2405385]: backtrace.c:287 bbs_log_backtrace: 5: lbbs <unknown>()
[2024-06-13 15:40:09.980] ERROR[2405385]: backtrace.c:287 bbs_log_backtrace: 6: [0x7fbc63250134] libc.so.6 pthread_create.c:442 start_thread()
[2024-06-13 15:40:09.980] ERROR[2405385]: backtrace.c:287 bbs_log_backtrace: 7: [0x7fbc632d07dc] libc.so.6 clone3.S:83 clone3()
[2024-06-13 15:40:09.980] DEBUG[2405377]: tls.c:544 ssl_io_thread: SSL connection 0x7fbc44383490 now marked as dead
[2024-06-13 15:40:09.980] DEBUG[2405377]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7fbc44383490 at index 1 / 0
[2024-06-13 15:40:09.980] DEBUG[2405377]: tls.c:453 ssl_io_thread: SSL at index 2 / 1 = POLLHUP
Aborted (core dumped)Another instance of this issue:
[2024-09-01 11:06:32.128] ERROR[3703433]: mod_smtp_delivery_external.c:1238 run_queue: Spent 327 seconds so far waiting to wrlock &queue_lock, probable deadlock? (rwlock acquired at mod_smtp_delivery_exter:1549 300 s ago by LWP 3792658)
[2024-09-01 11:06:32.857] DEBUG[3703425]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7f7e50014a70 at index 1 / 0
[2024-09-01 11:06:32.828] ERROR[3703433]: backtrace.c:287 bbs_log_backtrace: 0: lbbs bbs_log_backtrace()
[2024-09-01 11:06:32.857] ERROR[3703433]: backtrace.c:287 bbs_log_backtrace: 1: lbbs __bbs_assert_fatal()
[2024-09-01 11:06:32.857] DEBUG[3703425]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7f7e4c0d0020 at index 3 / 1
[2024-09-01 11:06:32.858] DEBUG[3703425]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7f7e440fe640 at index 5 / 2
[2024-09-01 11:06:32.858] ERROR[3703433]: backtrace.c:287 bbs_log_backtrace: 2: lbbs __bbs_rwlock_wrlock()
[2024-09-01 11:06:32.858] DEBUG[3703425]: tls.c:448 ssl_io_thread: Skipping SSL at index 4 / 2 = POLLNVAL
[2024-09-01 11:06:32.858] ERROR[3703433]: backtrace.c:287 bbs_log_backtrace: 3: [0x7f7e6017a2bd] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1239 run_queue()
[2024-09-01 11:06:32.858] DEBUG[3703425]: tls.c:449 ssl_io_thread: SSL connection 0x7f7e440fe640 now marked as dead
[2024-09-01 11:06:32.858] ERROR[3703433]: backtrace.c:283 bbs_log_backtrace: 4: [0x7f7e6017a482] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1280 queue_handler()
[2024-09-01 11:06:32.858] DEBUG[3703425]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7f7e50014a70 at index 1 / 0
[2024-09-01 11:06:32.858] ERROR[3703433]: backtrace.c:283 bbs_log_backtrace: 4: [ inlined] mod_smtp_delivery_external.so mod_smtp_delivery_external.c:1263 queue_handler()
[2024-09-01 11:06:32.858] DEBUG[3703425]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7f7e4c0d0020 at index 3 / 1
[2024-09-01 11:06:32.859] DEBUG[3703425]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7f7e440fe640 at index 5 / 2
[2024-09-01 11:06:32.858] ERROR[3703433]: backtrace.c:287 bbs_log_backtrace: 5: lbbs <unknown>()
[2024-09-01 11:06:32.859] DEBUG[3703425]: tls.c:448 ssl_io_thread: Skipping SSL at index 4 / 2 = POLLNVAL
[2024-09-01 11:06:32.859] ERROR[3703433]: backtrace.c:287 bbs_log_backtrace: 6: [0x7f7e694a8134] libc.so.6 pthread_create.c:442 start_thread()
[2024-09-01 11:06:32.859] DEBUG[3703425]: tls.c:449 ssl_io_thread: SSL connection 0x7f7e440fe640 now marked as dead
[2024-09-01 11:06:32.859] ERROR[3703433]: backtrace.c:287 bbs_log_backtrace: 7: [0x7f7e695287dc] libc.so.6 clone3.S:83 clone3()
[2024-09-01 11:06:32.859] DEBUG[3703425]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7f7e50014a70 at index 1 / 0
[2024-09-01 11:06:32.859] DEBUG[3703425]: tls.c:394 ssl_io_thread: Skipping dead SSL read connection 0x7f7e4c0d0020 at index 3 / 1
Thread 26 (Thread 0x7f7e317e26c0 (LWP 3792645)):
#0 0x00007f7e6951b15f in __GI___poll (fds=fds@entry=0x7f7e317dfdd8, nfds=nfds@entry=1, timeout=timeout@entry=300000) at ../sysdeps/unix/sysv/linux/poll.c:29
#1 0x000055ec2bab5c19 in poll (__timeout=300000, __nfds=1, __fds=0x7f7e317dfdd8) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2 bbs_poll (fd=fd@entry=109, ms=ms@entry=300000) at socket.c:1407
#3 0x000055ec2bab6b0a in bbs_poll_read (fd=fd@entry=109, ms=ms@entry=300000, buf=0x7f7e317e05e0 "220 2.0.0 SMTP server ready", len=255) at socket.c:1807
#4 0x000055ec2bab11af in bbs_readline (fd=109, rldata=rldata@entry=0x7f7e317dffd0, delim=delim@entry=0x7f7e68126135 "\r\n", timeout=timeout@entry=300000) at readline.c:149
#5 0x000055ec2babeacb in bbs_tcp_client_expect (client=client@entry=0x7f7e317dffc0, delim=delim@entry=0x7f7e68126135 "\r\n", attempts=0, attempts@entry=1, ms=ms@entry=300000, str=str@entry=0x7f7e6812610b "250") at tcp.c:98
#6 0x00007f7e68125681 in bbs_smtp_client_expect_final (smtpclient=smtpclient@entry=0x7f7e317dffc0, ms=ms@entry=300000, code=code@entry=0x7f7e6812610b "250", codelen=codelen@entry=3) at mod_smtp_client.c:115
#7 0x00007f7e681259ae in bbs_smtp_client_handshake (smtpclient=smtpclient@entry=0x7f7e317dffc0, require_secure=require_secure@entry=1) at mod_smtp_client.c:141
#8 0x00007f7e68125ac7 in bbs_smtp_client_starttls (smtpclient=smtpclient@entry=0x7f7e317dffc0) at mod_smtp_client.c:175
#9 0x00007f7e60178428 in try_send (smtp=smtp@entry=0x0, tx=tx@entry=0x7f7e317e07e0, hostname=hostname@entry=0x7f7e40007c30 "live-com.olc.protection.outlook.com", port=port@entry=25, secure=secure@entry=0, username=username@entry=0x0, password=<optimized out>, sender=<optimized out>, recipient=<optimized out>, recipients=<optimized out>, prepend=<optimized out>, prependlen=<optimized out>, datafd=<optimized out>, offset=<optimized out>, writelen=<optimized out>, buf=<optimized out>, len=<optimized out>) at mod_smtp_delivery_external.c:449
#10 0x00007f7e6017abd4 in process_queue_file (qrun=qrun@entry=0x7f7e317e17b0, mqf=mqf@entry=0x7f7e317e0bd0) at mod_smtp_delivery_external.c:1109
#11 0x00007f7e6017bbdb in on_queue_file (dir_name=dir_name@entry=0x7f7e317e1850 "/home/bbs/maildir/mailq/new", filename=filename@entry=0x7f7e401dc1e0 "1725188464128857.0", obj=obj@entry=0x7f7e317e17b0) at mod_smtp_delivery_external.c:1215
#12 0x00007f7e6017bd6e in smtp_async_send (varg=varg@entry=0x7f7e401dc1e0) at mod_smtp_delivery_external.c:1585
Thread 25 (Thread 0x7f7e32fe56c0 (LWP 3792644)):
#0 0x00007f7e6951b15f in __GI___poll (fds=fds@entry=0x7f7e32fe2dc8, nfds=nfds@entry=1, timeout=timeout@entry=600000) at ../sysdeps/unix/sysv/linux/poll.c:29
#1 0x000055ec2bab5c19 in poll (__timeout=600000, __nfds=1, __fds=0x7f7e32fe2dc8) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2 bbs_poll (fd=fd@entry=151, ms=ms@entry=600000) at socket.c:1407
#3 0x000055ec2bab6b0a in bbs_poll_read (fd=fd@entry=151, ms=ms@entry=600000, buf=0x7f7e32fe35e0 "354 Start mail input, end with <CRLF>.<CRLF>", len=255) at socket.c:1807
#4 0x000055ec2bab11af in bbs_readline (fd=151, rldata=rldata@entry=0x7f7e32fe2fd0, delim=delim@entry=0x7f7e68126135 "\r\n", timeout=timeout@entry=600000) at readline.c:149
#5 0x000055ec2babeacb in bbs_tcp_client_expect (client=client@entry=0x7f7e32fe2fc0, delim=delim@entry=0x7f7e68126135 "\r\n", attempts=0, attempts@entry=1, ms=ms@entry=600000, str=str@entry=0x7f7e6017d163 "250") at tcp.c:98
#6 0x00007f7e68125681 in bbs_smtp_client_expect_final (smtpclient=smtpclient@entry=0x7f7e32fe2fc0, ms=ms@entry=600000, code=code@entry=0x7f7e6017d163 "250", codelen=codelen@entry=3) at mod_smtp_client.c:115
#7 0x00007f7e60178775 in try_send (smtp=smtp@entry=0x0, tx=tx@entry=0x7f7e32fe37e0, hostname=hostname@entry=0x7f7e500127d0 "mx.yandex.net", port=port@entry=25, secure=secure@entry=0, username=username@entry=0x0, password=<optimized out>, sender=<optimized out>, recipient=<optimized out>, recipients=<optimized out>, prepend=<optimized out>, prependlen=<optimized out>, datafd=<optimized out>, offset=<optimized out>, writelen=<optimized out>, buf=<optimized out>, len=<optimized out>) at mod_smtp_delivery_external.c:595
#8 0x00007f7e6017abd4 in process_queue_file (qrun=qrun@entry=0x7f7e32fe47b0, mqf=mqf@entry=0x7f7e32fe3bd0) at mod_smtp_delivery_external.c:1109
#9 0x00007f7e6017bbdb in on_queue_file (dir_name=dir_name@entry=0x7f7e32fe4850 "/home/bbs/maildir/mailq/new", filename=filename@entry=0x7f7e40049e60 "1725188464125756.0", obj=obj@entry=0x7f7e32fe47b0) at mod_smtp_delivery_external.c:1215
#10 0x00007f7e6017bd6e in smtp_async_send (varg=varg@entry=0x7f7e40049e60) at mod_smtp_delivery_external.c:1585
Thread 24 (Thread 0x7f7e367ec6c0 (LWP 3792637)):
#0 0x00007f7e6951b15f in __GI___poll (fds=fds@entry=0x7f7e367e9dd8, nfds=nfds@entry=1, timeout=timeout@entry=300000) at ../sysdeps/unix/sysv/linux/poll.c:29
#1 0x000055ec2bab5c19 in poll (__timeout=300000, __nfds=1, __fds=0x7f7e367e9dd8) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2 bbs_poll (fd=fd@entry=101, ms=ms@entry=300000) at socket.c:1407
#3 0x000055ec2bab6b0a in bbs_poll_read (fd=fd@entry=101, ms=ms@entry=300000, buf=0x7f7e367ea5e0 "220 Go ahead", len=255) at socket.c:1807
#4 0x000055ec2bab11af in bbs_readline (fd=101, rldata=rldata@entry=0x7f7e367e9fd0, delim=delim@entry=0x7f7e68126135 "\r\n", timeout=timeout@entry=300000) at readline.c:149
#5 0x000055ec2babeacb in bbs_tcp_client_expect (client=client@entry=0x7f7e367e9fc0, delim=delim@entry=0x7f7e68126135 "\r\n", attempts=0, attempts@entry=1, ms=ms@entry=300000, str=str@entry=0x7f7e6812610b "250") at tcp.c:98
#6 0x00007f7e68125681 in bbs_smtp_client_expect_final (smtpclient=smtpclient@entry=0x7f7e367e9fc0, ms=ms@entry=300000, code=code@entry=0x7f7e6812610b "250", codelen=codelen@entry=3) at mod_smtp_client.c:115
#7 0x00007f7e681259ae in bbs_smtp_client_handshake (smtpclient=smtpclient@entry=0x7f7e367e9fc0, require_secure=require_secure@entry=1) at mod_smtp_client.c:141
#8 0x00007f7e68125ac7 in bbs_smtp_client_starttls (smtpclient=smtpclient@entry=0x7f7e367e9fc0) at mod_smtp_client.c:175
#9 0x00007f7e60178428 in try_send (smtp=smtp@entry=0x0, tx=tx@entry=0x7f7e367ea7e0, hostname=hostname@entry=0x7f7e4c01b0d0 "mx.yandex.net", port=port@entry=25, secure=secure@entry=0, username=username@entry=0x0, password=<optimized out>, sender=<optimized out>, recipient=<optimized out>, recipients=<optimized out>, prepend=<optimized out>, prependlen=<optimized out>, datafd=<optimized out>, offset=<optimized out>, writelen=<optimized out>, buf=<optimized out>, len=<optimized out>) at mod_smtp_delivery_external.c:449
#10 0x00007f7e6017abd4 in process_queue_file (qrun=qrun@entry=0x7f7e367eb7b0, mqf=mqf@entry=0x7f7e367eabd0) at mod_smtp_delivery_external.c:1109
#11 0x00007f7e6017bbdb in on_queue_file (dir_name=dir_name@entry=0x7f7e367eb850 "/home/bbs/maildir/mailq/new", filename=filename@entry=0x7f7e50002900 "1725188463581998.0", obj=obj@entry=0x7f7e367eb7b0) at mod_smtp_delivery_external.c:1215
#12 0x00007f7e6017bd6e in smtp_async_send (varg=varg@entry=0x7f7e50002900) at mod_smtp_delivery_external.c:1585
Thread 1 (Thread 0x7f7e4b7fe6c0 (LWP 3703433)):
#0 0x00007f7e694a9e2c in __pthread_kill_implementation (threadid=3703424, signo=3703433, signo@entry=6, no_tid=6, no_tid@entry=0) at ./nptl/pthread_kill.c:43
#1 0x00007f7e694a9e9f in __pthread_kill_internal (signo=6, threadid=<optimized out>) at ./nptl/pthread_kill.c:78
#2 0x00007f7e6945afb2 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#3 0x00007f7e69445472 in __GI_abort () at ./stdlib/abort.c:79
#4 0x000055ec2ba88957 in __bbs_assert_fatal (condition_str=<optimized out>, file=<optimized out>, line=<optimized out>, function=<optimized out>) at backtrace.c:311
#5 0x000055ec2ba97b09 in __bbs_assert (function=<optimized out>, line=<optimized out>, file=<optimized out>, condition_str=<optimized out>, condition=<optimized out>) at ../include/bbs.h:440
#6 __bbs_rwlock_wrlock (t=t@entry=0x7f7e60180720 <queue_lock>, filename=filename@entry=0x7f7e6017d000 "mod_smtp_delivery_external.c", lineno=lineno@entry=1238, func=func@entry=0x7f7e6017e378 <__func__.8> "run_queue", name=name@entry=0x7f7e6017d2a4 "&queue_lock") at lock.c:416
#7 0x00007f7e6017a2bd in run_queue (qrun=qrun@entry=0x7f7e4b7fdac0, queue_file_cb=0x7f7e6017b9d0 <on_queue_file>) at mod_smtp_delivery_external.c:1238
#8 0x00007f7e6017a482 in queue_handler (unused=0x0) at mod_smtp_delivery_external.c:1279
#9 queue_handler (unused=unused@entry=0x0) at mod_smtp_delivery_external.c:1263Comments
You must be