[LBBS-153] net_imap: Lots of STATUS messages during APPEND can fill up delayed write pipe

← All Issues || New Issue →

Sort Normal || Priority

Details

Having a STATUS message for every single APPEND can be problematic, particularly if there are other clients connected, and each update gets queued up the session's pipe for delayed writes.

To reproduce this, open wssmail up, but don't select any folder. In this state, it cannot receive updates since it isn't idling. Then, append a large number of messages (i.e. thousands) in a different client. Each write will go to the pipe, but eventually, that will fill up; performance of the appends is seriously degraded as well. Selecting a folder flushes the contents of the pipe and performance goes back to normal.

Ideally, we would only generate the status after the last append has finished, which would avoid this issue.

[2026-03-14 09:10:18.538]   DEBUG[241296]: net_imap.c:3902 finish_auth: 0x7fe2b37fd830 <= 1 OK [CAPABILITY IMAP4rev1 AUTH=PLAIN UNSELECT UNAUTHENTICATE SPECIAL-USE LIST-EXTENDED LIST-STATUS XLIST CHILDREN IDLE NOTIFY NAMESPACE QUOTA QUOTA=RES-STORAGE ID SASL-IR ACL SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES URLAUTH ESEARCH ESORT SEARCHRES UIDPLUS LITERAL+ MULTIAPPEND APPENDLIMIT MOVE WITHIN ENABLE CONDSTORE QRESYNC STATUS=SIZE IDLE COMPRESS=DEFLATE] Success
[2026-03-14 09:10:18.541]   DEBUG[241296]: net_imap.c:5014 imap_process: 0x7fe2b37fd830 <= 2 OK DEFLATE active
[2026-03-14 09:10:18.541]   DEBUG[241297]: thread.c:106 thread_register: Thread 241297 spawned from io_thread             started by thread 241296 at io.c:454 bbs_io_transform_setup()
[2026-03-14 09:10:18.543]   DEBUG[241296]: net_imap.c:4648 imap_process: 0x7fe2b37fd830 <= * ID ("name" "LBBS.Imap4Server" "version" "0.7.3")
[2026-03-14 09:10:18.543]   DEBUG[241296]: net_imap.c:4649 imap_process: 0x7fe2b37fd830 <= 3 OK ID completed
[2026-03-14 09:10:18.550]   DEBUG[241296]: mod_mail.c:1236 mailbox_get_next_uid: Assigned UIDNEXT 1 (UIDVALIDITY 1773493290) - current max UID: 1
[2026-03-14 09:10:18.550]   DEBUG[241296]: imap_server_flags.c:475 maildir_msg_setflags_modseq: Renaming /home/bbs/maildir/1/.REDACTED/cur/1773493818549863_0,S=1615,U=1,M=1:2, -> /home/bbs/maildir/1/.REDACTED/cur/1773493818549863_0,S=1615,U=1,M=2:2,S
[2026-03-14 09:10:18.551]   DEBUG[241296]: net_imap.c:2407 process_append: Received 1615-byte upload (flags: S)
[2026-03-14 09:10:18.551]   DEBUG[241296]: net_imap.c:2480 handle_append: 1 message appended successfully
[2026-03-14 09:10:18.551]   DEBUG[241296]: net_imap.c:367 __imap_send_update_log: 692: 0x7fe2b3ffe830 (delayed) <= * STATUS "REDACTED" (MESSAGES 1 UIDNEXT 2 UNSEEN 0 HIGHESTMODSEQ 2)
[2026-03-14 09:10:18.552]   DEBUG[241296]: net_imap.c:2432 append_response: 0x7fe2b37fd830 <= 4 OK APPEND completed
[2026-03-14 09:10:18.580]   DEBUG[241296]: mod_mail.c:1236 mailbox_get_next_uid: Assigned UIDNEXT 2 (UIDVALIDITY 1773493290) - current max UID: 2
[2026-03-14 09:10:18.581]   DEBUG[241296]: imap_server_flags.c:475 maildir_msg_setflags_modseq: Renaming /home/bbs/maildir/1/.REDACTED/cur/1773493818579944_1,S=3339,U=2,M=2:2, -> /home/bbs/maildir/1/.REDACTED/cur/1773493818579944_1,S=3339,U=2,M=3:2,S
[2026-03-14 09:10:18.581]   DEBUG[241296]: net_imap.c:2407 process_append: Received 3339-byte upload (flags: S)
[2026-03-14 09:10:18.582]   DEBUG[241296]: net_imap.c:2480 handle_append: 1 message appended successfully
[2026-03-14 09:10:18.582]   DEBUG[241296]: net_imap.c:367 __imap_send_update_log: 692: 0x7fe2b3ffe830 (delayed) <= * STATUS "REDACTED" (MESSAGES 2 UIDNEXT 3 UNSEEN 0 HIGHESTMODSEQ 3)
[2026-03-14 09:10:18.583]   DEBUG[241296]: net_imap.c:2432 append_response: 0x7fe2b37fd830 <= 5 OK APPEND completed
...
(at this point, the pipe has filled up, and there are serious delays between each append as a result)
...
[2026-03-14 09:13:09.423]   DEBUG[241296]: socket.c:2464 timed_write: File descriptor 61 did not become writable after 1000 ms
[2026-03-14 09:13:09.424]   DEBUG[241296]: net_imap.c:2432 append_response: 0x7fe2b37fd830 <= 809 OK APPEND completed
[2026-03-14 09:13:09.441]   DEBUG[241296]: mod_mail.c:1236 mailbox_get_next_uid: Assigned UIDNEXT 807 (UIDVALIDITY 1773493290) - current max UID: 807
[2026-03-14 09:13:09.443]   DEBUG[241296]: imap_server_flags.c:475 maildir_msg_setflags_modseq: Renaming /home/bbs/maildir/1/.REDACTED/cur/1773493989439616_806,S=11535,U=807,M=807:2, -> /home/bbs/maildir/1/.REDACTED/cur/1773493989439616_806,S=11535,U=807,M=808:2,S
[2026-03-14 09:13:09.443]   DEBUG[241296]: net_imap.c:2407 process_append: Received 11535-byte upload (flags: S)
[2026-03-14 09:13:09.445]   DEBUG[241296]: net_imap.c:2480 handle_append: 1 message appended successfully
[2026-03-14 09:13:09.449]   DEBUG[241296]: net_imap.c:367 __imap_send_update_log: 692: 0x7fe2b3ffe830 (delayed) <= * STATUS "REDACTED" (MESSAGES 807 UIDNEXT 808 UNSEEN 0 HIGHESTMODSEQ 808)
[2026-03-14 09:13:10.451]   DEBUG[241296]: socket.c:2464 timed_write: File descriptor 61 did not become writable after 1000 ms
[2026-03-14 09:13:10.451]   DEBUG[241296]: net_imap.c:2432 append_response: 0x7fe2b37fd830 <= 810 OK APPEND completed
[2026-03-14 09:13:10.471]   DEBUG[241296]: mod_mail.c:1236 mailbox_get_next_uid: Assigned UIDNEXT 808 (UIDVALIDITY 1773493290) - current max UID: 808
[2026-03-14 09:13:10.474]   DEBUG[241296]: imap_server_flags.c:475 maildir_msg_setflags_modseq: Renaming /home/bbs/maildir/1/.REDACTED/cur/1773493990465271_807,S=24307,U=808,M=808:2, -> /home/bbs/maildir/1/.REDACTED/cur/1773493990465271_807,S=24307,U=808,M=809:2,S
[2026-03-14 09:13:10.474]   DEBUG[241296]: net_imap.c:2407 process_append: Received 24307-byte upload (flags: S)
[2026-03-14 09:13:10.503]   DEBUG[241296]: net_imap.c:2480 handle_append: 1 message appended successfully
[2026-03-14 09:13:10.507]   DEBUG[241296]: net_imap.c:367 __imap_send_update_log: 692: 0x7fe2b3ffe830 (delayed) <= * STATUS "REDACTED" (MESSAGES 808 UIDNEXT 809 UNSEEN 0 HIGHESTMODSEQ 809)

Comments

You must be logged in to leave a comment.