mjl- / mox

modern full-featured open source secure mail server for low-maintenance self-hosted email
https://www.xmox.nl
MIT License
3.71k stars 113 forks source link

Error when moving message out of Junk folder #61

Closed x8x closed 1 year ago

x8x commented 1 year ago

When manually moving a message from Junk to Inbox the message is not moved.

Relevant logs:

Sep 22 10:24:39 mail mox[495739]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=57 modseq=859 keywords=[junk];6 total, -50 deleted, 6 unread, -44 unseen, size -2446939 bytes;mailboxid=4 uids=[57] modseq=860;6 total, -51 deleted, 6 unread, -45 unseen, size -2466777 bytes]" cid=18a39da2d72 delta=343.936797ms username=user@domain.com
Sep 22 10:24:39 mail mox[495739]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=4 uids=[57] modseq=861;6 total, -52 deleted, 6 unread, -46 unseen, size -2486615 bytes]" cid=18a39da2daf delta=297.142729ms username=user@domain.com
Sep 22 10:24:39 mail mox[495739]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uids=[57] modseq=860;6 total, -51 deleted, 6 unread, -45 unseen, size -2466777 bytes]" cid=18a39da2daf delta="110.841µs" username=user@domain.com
Sep 22 10:24:39 mail mox[495739]: l=error m="removing message file for expunge" err="remove data/accounts/user/msg/a/526: no such file or directory" pkg=imapserver cid=18a39da2daf delta="64.201µs" username=user@domain.com
Sep 22 10:24:39 mail mox[495739]: l=info m="imap command ioerror" err="unknown uid 57 (fatal protocol error)" pkg=imapserver cmd="uid expunge" duration=2.836901ms cid=18a39da2daf delta="25.08µs" username=user@domain.com
Sep 22 10:24:39 mail mox[495739]: goroutine 79402 [running]:
Sep 22 10:24:39 mail mox[495739]: runtime/debug.Stack()
Sep 22 10:24:39 mail mox[495739]:         runtime/debug/stack.go:24 +0x64
Sep 22 10:24:39 mail mox[495739]: runtime/debug.PrintStack()
Sep 22 10:24:39 mail mox[495739]:         runtime/debug/stack.go:16 +0x1c
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).command.func1()
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:775 +0x9c0
Sep 22 10:24:39 mail mox[495739]: panic({0x819160?, 0x4001ab8870?})
Sep 22 10:24:39 mail mox[495739]:         runtime/panic.go:914 +0x218
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.xserverErrorf(...)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/error.go:36
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).xsequence(0x7d56a0?, 0x343e90?)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:954 +0x114
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).applyChanges(0x4000908000, {0x4000431960, 0x2, 0x2}, 0x0)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:1264 +0xefc
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).bwriteresultf(0x4000908000, {0x8ed792, 0x21}, {0x4000ded898, 0x2, 0x2})
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:543 +0xd8
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).writeresultf(0x35d?, {0x8ed792?, 0x8cb778?}, {0x4000ded898?, 0x4000ded858?, 0x1?})
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:532 +0x28
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).cmdxExpunge(0x4000908000, {0x4000e28048, 0x5}, {0x4000e2804e, 0xb}, 0xb11bc?)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:3046 +0x27c
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).cmdUIDExpunge(0x4000908000, {0x4000e28048, 0x5}, {0x4000e2804e, 0xb}, 0x40011b6140)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:3007 +0xe0
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).command(0x4000908000)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:860 +0x2dc
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.serve({0x400019dd01, 0x6}, 0x18a39da2daf, 0x4000413ba0, {0xa5c980, 0x4000c2e380?}, 0x1, 0x0)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:725 +0xd68
Sep 22 10:24:39 mail mox[495739]: created by github.com/mjl-/mox/imapserver.listen1.func1 in goroutine 93
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:362 +0x294
Sep 22 10:24:39 mail mox[495739]: l=info m="connection closed" err="unknown uid 57 (fatal protocol error)" pkg=imapserver cid=18a39da2daf delta="318.642µs" username=user@domain.com
Sep 22 10:24:39 mail mox[495739]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uids=[57] modseq=861;6 total, -52 deleted, 6 unread, -46 unseen, size -2486615 bytes]" cid=18a39da2dbd delta=131.482178ms username=user@domain.com
Sep 22 10:24:39 mail mox[495739]: l=info m="imap command ioerror" err="unknown uid 57 (fatal protocol error)" pkg=imapserver cmd=idle duration=104.044454ms cid=18a39da2dbd delta="35µs" username=user@domain.com
Sep 22 10:24:39 mail mox[495739]: goroutine 79521 [running]:
Sep 22 10:24:39 mail mox[495739]: runtime/debug.Stack()
Sep 22 10:24:39 mail mox[495739]:         runtime/debug/stack.go:24 +0x64
Sep 22 10:24:39 mail mox[495739]: runtime/debug.PrintStack()
Sep 22 10:24:39 mail mox[495739]:         runtime/debug/stack.go:16 +0x1c
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).command.func1()
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:775 +0x9c0
Sep 22 10:24:39 mail mox[495739]: panic({0x819160?, 0x4001ab8cd0?})
Sep 22 10:24:39 mail mox[495739]:         runtime/panic.go:914 +0x218
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.xserverErrorf(...)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/error.go:36
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).xsequence(0x7d56a0?, 0xefbc0?)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:954 +0x114
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).applyChanges(0x4000c66580, {0x4000d1c480, 0x2, 0x2}, 0x0)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:1264 +0xefc
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).cmdIdle(0x4000c66580, {0x400089a000, 0x7}, {0x400089a008, 0x4}, 0x6c1b6c?)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:2795 +0xac
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.(*conn).command(0x4000c66580)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:860 +0x2dc
Sep 22 10:24:39 mail mox[495739]: github.com/mjl-/mox/imapserver.serve({0x400019dd01, 0x6}, 0x18a39da2dbd, 0x4000413ba0, {0xa5c980, 0x4000cfe700?}, 0x1, 0x0)
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:725 +0xd68
Sep 22 10:24:39 mail mox[495739]: created by github.com/mjl-/mox/imapserver.listen1.func1 in goroutine 93
Sep 22 10:24:39 mail mox[495739]:         github.com/mjl-/mox@v0.0.6/imapserver/server.go:362 +0x294
Sep 22 10:24:39 mail mox[495739]: l=info m="connection closed" err="unknown uid 57 (fatal protocol error)" pkg=imapserver cid=18a39da2dbd delta="210.201µs" username=user@domain.com
Sep 22 10:24:39 mail mox[495739]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uids=[57] modseq=861;6 total, -52 deleted, 6 unread, -46 unseen, size -2486615 bytes]" cid=18a39da2d72 delta=5.108798ms username=user@domain.com
Sep 22 10:24:39 mail mox[495739]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uids=[57] modseq=861;6 total, -52 deleted, 6 unread, -46 unseen, size -2486615 bytes]" cid=18a39da109c delta=212.108017ms username=user@domain.com

After restarting Mox, the move works but logs still shows some error, not sure it is actually related:

Sep 22 10:31:06 mail mox[779514]: l=info m="processing fetch attribute" err="reading header: open data/accounts/user/msg/a/373: no such file or directory" pkg=imapserver uid=115 cid=18abc7119b6 delta=210.499372ms username=user@domain.com
Sep 22 10:31:06 mail mox[779514]: l=debug m="imap command user error" err="processing fetch attribute: reading header: open data/accounts/user/msg/a/373: no such file or directory" pkg=imapserver cmd=fetch duration="663.205µs" cid=18abc7119b6 delta="98.081µs" username=user@domain.com
Sep 22 10:31:06 mail mox[779514]: l=debug m="imap command done" pkg=imapserver cmd=select duration=1.201169ms cid=18abc7119b6 delta=209.293883ms username=user@domain.com
Sep 22 10:31:06 mail mox[779514]: l=info m="client id" pkg=imapserver params="map[name:Mac OS X Mail os:Mac OS X os-version:14.0 (23A344) vendor:Apple Inc. version:16.0 (3774.100.2.1.4)]" cid=18abc7119ba delta=682.704978ms
mjl- commented 1 year ago

I think you're running into the bug that was fixed by this commit: https://github.com/mjl-/mox/commit/f029db3f47b0783ec5b387cb49c4dbf8356f4f37 The commit message has commands that help correct the problem. I started on release notes this morning, they will reference that commit and instructions, but I wasn't sure if anyone ran into the issue. I'll put the symptoms and instructions in the release notes more prominently.

And I'll add a test for this case.

x8x commented 1 year ago

I followed the instruction at f029db3.

While version 0.0.6 was running, I executed the following commands:

After this I did a backup which returned following error:

./mox backup backup
warning: creating hardlink to message: link data/accounts/user/msg/a/45 /home/mox/backup/accounts/user/msg/a/45: invalid cross-device link; srcpath=data/accounts/user/msg/a/45; dstpath=/home/mox/backup/accounts/user/msg/a/45

Rerunning the same command would output the same error but sometimes for another account/msg but always only one instance. System logs do not show any filesystem corruption.

Ignored above error and proceeded with: ./mox verifydata backup which returned quite some errors:

./mox verifydata backup
error: backup/accounts/user/index.db: mailbox "DMARC" (id 11) has uidvalidity 844885606 >= account nextuidvalidity 844885606: inconsistent uidvalidity for mailbox/account, see "mox fixuidmeta"
error: backup/accounts/user/index.db: mailbox "Notes" (id 12) has uidvalidity 844885607 >= account nextuidvalidity 844885606: inconsistent uidvalidity for mailbox/account, see "mox fixuidmeta"
error: backup/accounts/user2/index.db: mailbox "Rejects" (id 8) has uidvalidity 847374171 >= account nextuidvalidity 847374171: inconsistent uidvalidity for mailbox/account, see "mox fixuidmeta"
error: backup/accounts/user3/index.db: mailbox "Inbox" (id 1) has uidvalidity 847374118 >= account nextuidvalidity 847374118: inconsistent uidvalidity for mailbox/account, see "mox fixuidmeta"
error: backup/accounts/user3/index.db: mailbox "Archive" (id 2) has uidvalidity 847374118 >= account nextuidvalidity 847374118: inconsistent uidvalidity for mailbox/account, see "mox fixuidmeta"
error: backup/accounts/user3/index.db: mailbox "Drafts" (id 3) has uidvalidity 847374118 >= account nextuidvalidity 847374118: inconsistent uidvalidity for mailbox/account, see "mox fixuidmeta"
error: backup/accounts/user3/index.db: mailbox "Junk" (id 4) has uidvalidity 847374118 >= account nextuidvalidity 847374118: inconsistent uidvalidity for mailbox/account, see "mox fixuidmeta"
error: backup/accounts/user3/index.db: mailbox "Sent" (id 5) has uidvalidity 847374118 >= account nextuidvalidity 847374118: inconsistent uidvalidity for mailbox/account, see "mox fixuidmeta"
error: backup/accounts/user3/index.db: mailbox "Trash" (id 6) has uidvalidity 847374118 >= account nextuidvalidity 847374118: inconsistent uidvalidity for mailbox/account, see "mox fixuidmeta"
error: backup/accounts/user4/index.db: mailbox "Drafts" (id 3) has wrong counts 0 total, -38 deleted, 0 unread, 0 unseen, size -3395775 bytes, should be 0 total, 0 deleted, 0 unread, 0 unseen, size 0 bytes: wrong mailbox counts, see "mox recalculatemailboxcounts"
error: backup/accounts/user5/index.db: mailbox "Trash" (id 6) has wrong counts 0 total, -2 deleted, 0 unread, 0 unseen, size -53973 bytes, should be 0 total, 0 deleted, 0 unread, 0 unseen, size 0 bytes: wrong mailbox counts, see "mox recalculatemailboxcounts"
error: backup/accounts/user6/index.db: mailbox "Drafts" (id 3) has wrong counts 0 total, -9 deleted, 0 unread, 0 unseen, size -80216 bytes, should be 0 total, 0 deleted, 0 unread, 0 unseen, size 0 bytes: wrong mailbox counts, see "mox recalculatemailboxcounts"
error: backup/accounts/user7/index.db: mailbox "Trash" (id 6) has wrong counts 0 total, -47 deleted, 0 unread, -2 unseen, size -2472791 bytes, should be 0 total, 0 deleted, 0 unread, 0 unseen, size 0 bytes: wrong mailbox counts, see "mox recalculatemailboxcounts"
error: backup/accounts/user7/index.db: mailbox "Import/Inbox" (id 8) has wrong counts 23 total, -2 deleted, 0 unread, 0 unseen, size 1656578 bytes, should be 23 total, 0 deleted, 0 unread, 0 unseen, size 3374322 bytes: wrong mailbox counts, see "mox recalculatemailboxcounts"
error: backup/accounts/user7/index.db: mailbox "Inbox" (id 1) has wrong counts 652 total, -2 deleted, 24 unread, 24 unseen, size 214448939 bytes, should be 652 total, 0 deleted, 24 unread, 24 unseen, size 214478648 bytes: wrong mailbox counts, see "mox recalculatemailboxcounts"
error: backup/accounts/user7/index.db: mailbox "Drafts" (id 3) has wrong counts 0 total, -4 deleted, 0 unread, 0 unseen, size -10394 bytes, should be 0 total, 0 deleted, 0 unread, 0 unseen, size 0 bytes: wrong mailbox counts, see "mox recalculatemailboxcounts"
error: backup/accounts/user8/index.db: mailbox "Drafts" (id 5) has wrong counts 0 total, -6 deleted, 0 unread, 0 unseen, size -11600 bytes, should be 0 total, 0 deleted, 0 unread, 0 unseen, size 0 bytes: wrong mailbox counts, see "mox recalculatemailboxcounts"
error: backup/accounts/user8/index.db: mailbox "Sent" (id 2) has wrong counts 5 total, -9 deleted, 0 unread, 0 unseen, size -1450 bytes, should be 5 total, 0 deleted, 0 unread, 0 unseen, size 1850 bytes: wrong mailbox counts, see "mox recalculatemailboxcounts"
error: backup/accounts/user8/index.db: mailbox "Trash" (id 4) has wrong counts 0 total, -24 deleted, 0 unread, 0 unseen, size -42654 bytes, should be 0 total, 0 deleted, 0 unread, 0 unseen, size 0 bytes: wrong mailbox counts, see "mox recalculatemailboxcounts"
errors were found

I then run the suggested commands, remade a backup and reverified the backup which this time returned OK.

Next step I built mox at commit a0f3856e4005 then run it with no errors showing in the logs.

Then in Mail.app I tried to move some messages out of Junk folder but that failed. These are the relevant logs:

Sep 23 08:47:29 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=15.024426075s cid=18ac0e5d920 delta=15.230249739s username=user@domain.com
Sep 23 08:47:29 mail mox[999]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=1 uid=282 modseq=1477 keywords=[junk];mailboxid=1 uid=283 modseq=1477 keywords=[junk];mailboxid=1 uid=284 modseq=1477 keywords=[junk];mailboxid=1 uid=285 modseq=1477 keywords=[junk];mailboxid=1 uid=286 modseq=1477 keywords=[junk];mailboxid=1 uid=287 modseq=1477 keywords=[junk];11 total, 3 deleted, 11 unread, 14 unseen, size 570480 bytes]" cid=18ac0e5d920 delta=215.080044ms username=user@domain.com
Sep 23 08:47:29 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uid=282 modseq=1477 keywords=[junk];mailboxid=1 uid=283 modseq=1477 keywords=[junk];mailboxid=1 uid=284 modseq=1477 keywords=[junk];mailboxid=1 uid=285 modseq=1477 keywords=[junk];mailboxid=1 uid=286 modseq=1477 keywords=[junk];mailboxid=1 uid=287 modseq=1477 keywords=[junk];11 total, 3 deleted, 11 unread, 14 unseen, size 570480 bytes]" cid=18ac0e5d904 delta=15.445452425s username=user@domain.com
Sep 23 08:47:29 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uid=282 modseq=1477 keywords=[junk];mailboxid=1 uid=283 modseq=1477 keywords=[junk];mailboxid=1 uid=284 modseq=1477 keywords=[junk];mailboxid=1 uid=285 modseq=1477 keywords=[junk];mailboxid=1 uid=286 modseq=1477 keywords=[junk];mailboxid=1 uid=287 modseq=1477 keywords=[junk];11 total, 3 deleted, 11 unread, 14 unseen, size 570480 bytes]" cid=18ac0e5d903 delta=15.445558345s username=user@domain.com
Sep 23 08:47:29 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uid=282 modseq=1477 keywords=[junk];mailboxid=1 uid=283 modseq=1477 keywords=[junk];mailboxid=1 uid=284 modseq=1477 keywords=[junk];mailboxid=1 uid=285 modseq=1477 keywords=[junk];mailboxid=1 uid=286 modseq=1477 keywords=[junk];mailboxid=1 uid=287 modseq=1477 keywords=[junk];11 total, 3 deleted, 11 unread, 14 unseen, size 570480 bytes]" cid=18ac0e5d910 delta=15.445559505s username=user@domain.com
Sep 23 08:47:29 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid copy" duration=8.510335ms cid=18ac0e5d920 delta="463.323µs" username=user@domain.com
Sep 23 08:47:29 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=1m36.822114668s cid=18ac0e5d903 delta=30.766081ms username=user@domain.com
Sep 23 08:47:29 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd=fetch duration=4.70923ms cid=18ac0e5d903 delta=32.823094ms username=user@domain.com
Sep 23 08:47:29 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=27.45066ms cid=18ac0e5d903 delta=99.132568ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=false untrainjunk=false train=true trainjunk=true cid=18ac0e5d903 delta=44.103608ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=21.342142257s cid=18ac0e5d910 delta=206.918831ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=false untrainjunk=false train=true trainjunk=true cid=18ac0e5d903 delta=5.110713ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=false untrainjunk=false train=true trainjunk=true cid=18ac0e5d903 delta=2.362255ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=false untrainjunk=false train=true trainjunk=true cid=18ac0e5d903 delta=3.594624ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=false untrainjunk=false train=true trainjunk=true cid=18ac0e5d903 delta="755.085µs" username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=false untrainjunk=false train=true trainjunk=true cid=18ac0e5d903 delta=5.187314ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="inserting words in junkfilter db" pkg=imapserver words=985 cid=18ac0e5d903 delta=4.005546ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=4 uid=87 modseq=1478 keywords=[junk];mailboxid=4 uid=88 modseq=1478 keywords=[junk];mailboxid=4 uid=89 modseq=1478 keywords=[junk];mailboxid=4 uid=90 modseq=1478 keywords=[junk];mailboxid=4 uid=91 modseq=1478 keywords=[junk];mailboxid=4 uid=92 modseq=1478 keywords=[junk];15 total, 0 deleted, 14 unread, 14 unseen, size 880121 bytes]" cid=18ac0e5d903 delta=19.220765ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid copy" duration=54.522236ms cid=18ac0e5d903 delta="155.361µs" username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=87 modseq=1478 keywords=[junk];mailboxid=4 uid=88 modseq=1478 keywords=[junk];mailboxid=4 uid=89 modseq=1478 keywords=[junk];mailboxid=4 uid=90 modseq=1478 keywords=[junk];mailboxid=4 uid=91 modseq=1478 keywords=[junk];mailboxid=4 uid=92 modseq=1478 keywords=[junk];15 total, 0 deleted, 14 unread, 14 unseen, size 880121 bytes]" cid=18ac0e5d904 delta=247.317535ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=87 modseq=1478 keywords=[junk];mailboxid=4 uid=88 modseq=1478 keywords=[junk];mailboxid=4 uid=89 modseq=1478 keywords=[junk];mailboxid=4 uid=90 modseq=1478 keywords=[junk];mailboxid=4 uid=91 modseq=1478 keywords=[junk];mailboxid=4 uid=92 modseq=1478 keywords=[junk];15 total, 0 deleted, 14 unread, 14 unseen, size 880121 bytes]" cid=18ac0e5d920 delta=247.117174ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=1m37.082479888s cid=18ac0e5d904 delta=21.789662ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=3.892506ms cid=18ac0e5d903 delta=32.05309ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.582977ms cid=18ac0e5d904 delta=28.505786ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=3.951665ms cid=18ac0e5d903 delta=25.847168ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=3.289821ms cid=18ac0e5d904 delta=28.645587ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.878339ms cid=18ac0e5d904 delta=20.694655ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=1 uid=282 modseq=1479 keywords=[junk];mailboxid=1 uid=283 modseq=1479 keywords=[junk];mailboxid=1 uid=284 modseq=1479 keywords=[junk];mailboxid=1 uid=285 modseq=1479 keywords=[junk];mailboxid=1 uid=286 modseq=1479 keywords=[junk];mailboxid=1 uid=287 modseq=1479 keywords=[junk];5 total, 9 deleted, 5 unread, 14 unseen, size 570480 bytes]" cid=18ac0e5d903 delta=89.065142ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid store" duration=3.492902ms cid=18ac0e5d903 delta="509.043µs" username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uid=282 modseq=1479 keywords=[junk];mailboxid=1 uid=283 modseq=1479 keywords=[junk];mailboxid=1 uid=284 modseq=1479 keywords=[junk];mailboxid=1 uid=285 modseq=1479 keywords=[junk];mailboxid=1 uid=286 modseq=1479 keywords=[junk];mailboxid=1 uid=287 modseq=1479 keywords=[junk];5 total, 9 deleted, 5 unread, 14 unseen, size 570480 bytes]" cid=18ac0e5d920 delta=147.445483ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=204.972459ms cid=18ac0e5d920 delta=16.088345ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd=fetch duration=6.704884ms cid=18ac0e5d910 delta=212.134185ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=1 uids=[282;283;284;285;286;287] modseq=1480;5 total, 3 deleted, 5 unread, 8 unseen, size 172993 bytes]" cid=18ac0e5d903 delta=35.733634ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid expunge" duration=8.111933ms cid=18ac0e5d903 delta="268.921µs" username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uid=282 modseq=1479 keywords=[junk];mailboxid=1 uid=283 modseq=1479 keywords=[junk];mailboxid=1 uid=284 modseq=1479 keywords=[junk];mailboxid=1 uid=285 modseq=1479 keywords=[junk];mailboxid=1 uid=286 modseq=1479 keywords=[junk];mailboxid=1 uid=287 modseq=1479 keywords=[junk];5 total, 9 deleted, 5 unread, 14 unseen, size 570480 bytes;mailboxid=1 uids=[282;283;284;285;286;287] modseq=1480;5 total, 3 deleted, 5 unread, 8 unseen, size 172993 bytes]" cid=18ac0e5d904 delta=89.782466ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=4 uid=81 modseq=1481 keywords=[junk];mailboxid=4 uid=82 modseq=1481 keywords=[junk];mailboxid=4 uid=83 modseq=1481 keywords=[junk];mailboxid=4 uid=84 modseq=1481 keywords=[junk];mailboxid=4 uid=85 modseq=1481 keywords=[junk];mailboxid=4 uid=86 modseq=1481 keywords=[junk];9 total, 6 deleted, 8 unread, 14 unseen, size 880121 bytes]" cid=18ac0e5d920 delta=210.497054ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=81 modseq=1481 keywords=[junk];mailboxid=4 uid=82 modseq=1481 keywords=[junk];mailboxid=4 uid=83 modseq=1481 keywords=[junk];mailboxid=4 uid=84 modseq=1481 keywords=[junk];mailboxid=4 uid=85 modseq=1481 keywords=[junk];mailboxid=4 uid=86 modseq=1481 keywords=[junk];9 total, 6 deleted, 8 unread, 14 unseen, size 880121 bytes]" cid=18ac0e5d903 delta=190.978607ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=81 modseq=1481 keywords=[junk];mailboxid=4 uid=82 modseq=1481 keywords=[junk];mailboxid=4 uid=83 modseq=1481 keywords=[junk];mailboxid=4 uid=84 modseq=1481 keywords=[junk];mailboxid=4 uid=85 modseq=1481 keywords=[junk];mailboxid=4 uid=86 modseq=1481 keywords=[junk];9 total, 6 deleted, 8 unread, 14 unseen, size 880121 bytes]" cid=18ac0e5d904 delta=185.080449ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uids=[282;283;284;285;286;287] modseq=1480;5 total, 3 deleted, 5 unread, 8 unseen, size 172993 bytes]" cid=18ac0e5d920 delta="216.162µs" username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid store" duration=4.055786ms cid=18ac0e5d920 delta="384.402µs" username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=87 modseq=1478 keywords=[junk];mailboxid=4 uid=88 modseq=1478 keywords=[junk];mailboxid=4 uid=89 modseq=1478 keywords=[junk];mailboxid=4 uid=90 modseq=1478 keywords=[junk];mailboxid=4 uid=91 modseq=1478 keywords=[junk];mailboxid=4 uid=92 modseq=1478 keywords=[junk];15 total, 0 deleted, 14 unread, 14 unseen, size 880121 bytes;mailboxid=1 uid=282 modseq=1479 keywords=[junk];mailboxid=1 uid=283 modseq=1479 keywords=[junk];mailboxid=1 uid=284 modseq=1479 keywords=[junk];mailboxid=1 uid=285 modseq=1479 keywords=[junk];mailboxid=1 uid=286 modseq=1479 keywords=[junk];mailboxid=1 uid=287 modseq=1479 keywords=[junk];5 total, 9 deleted, 5 unread, 14 unseen, size 570480 bytes;mailboxid=1 uids=[282;283;284;285;286;287] modseq=1480;5 total, 3 deleted, 5 unread, 8 unseen, size 172993 bytes;mailboxid=4 uid=81 modseq=1481 keywords=[junk];mailboxid=4 uid=82 modseq=1481 keywords=[junk];mailboxid=4 uid=83 modseq=1481 keywords=[junk];mailboxid=4 uid=84 modseq=1481 keywords=[junk];mailboxid=4 uid=85 modseq=1481 keywords=[junk];mailboxid=4 uid=86 modseq=1481 keywords=[junk];9 total, 6 deleted, 8 unread, 14 unseen, size 880121 bytes]" cid=18ac0e5d910 delta=401.089499ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=true untrainjunk=true train=false trainjunk=false cid=18ac0e5d920 delta=215.764409ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=true untrainjunk=true train=false trainjunk=false cid=18ac0e5d920 delta=7.905092ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=true untrainjunk=true train=false trainjunk=false cid=18ac0e5d920 delta=4.787351ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=true untrainjunk=true train=false trainjunk=false cid=18ac0e5d920 delta=3.399822ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=true untrainjunk=true train=false trainjunk=false cid=18ac0e5d920 delta="651.764µs" username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="updating junk filter" pkg=imapserver untrain=true untrainjunk=true train=false trainjunk=false cid=18ac0e5d920 delta=5.424596ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="inserting words in junkfilter db" pkg=imapserver words=985 cid=18ac0e5d920 delta=1.132887ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=4 uids=[81;82;83;84;85;86] modseq=1482;9 total, 0 deleted, 8 unread, 8 unseen, size 482634 bytes]" cid=18ac0e5d920 delta=12.076399ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uids=[81;82;83;84;85;86] modseq=1482;9 total, 0 deleted, 8 unread, 8 unseen, size 482634 bytes]" cid=18ac0e5d904 delta=251.427682ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid expunge" duration=39.640379ms cid=18ac0e5d920 delta="169.041µs" username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uids=[81;82;83;84;85;86] modseq=1482;9 total, 0 deleted, 8 unread, 8 unseen, size 482634 bytes]" cid=18ac0e5d910 delta=53.042746ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uids=[81;82;83;84;85;86] modseq=1482;9 total, 0 deleted, 8 unread, 8 unseen, size 482634 bytes]" cid=18ac0e5d903 delta=251.600683ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd=fetch duration=6.399482ms cid=18ac0e5d920 delta=212.225106ms username=user@domain.com
Sep 23 08:47:30 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=280.395391ms cid=18ac0e5d910 delta=227.279724ms username=user@domain.com
Sep 23 08:47:31 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid store" duration=1.173928ms cid=18ac0e5d910 delta=206.508469ms username=user@domain.com
Sep 23 08:47:31 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid store" duration=1.020767ms cid=18ac0e5d910 delta=209.073645ms username=user@domain.com
Sep 23 08:47:31 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=205.2015ms cid=18ac0e5d920 delta=573.359064ms username=user@domain.com
Sep 23 08:47:31 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=3.434022ms cid=18ac0e5d920 delta=213.107431ms username=user@domain.com
Sep 23 08:47:31 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=1.697051ms cid=18ac0e5d920 delta=161.165532ms username=user@domain.com
Sep 23 08:47:32 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.452936ms cid=18ac0e5d920 delta=417.098364ms username=user@domain.com
Sep 23 08:47:32 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.911659ms cid=18ac0e5d920 delta=506.681228ms username=user@domain.com
Sep 23 08:47:33 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.836338ms cid=18ac0e5d920 delta=440.346955ms username=user@domain.com
Sep 23 08:47:33 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=1.986933ms cid=18ac0e5d920 delta=161.494495ms username=user@domain.com
Sep 23 08:47:33 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=1.671931ms cid=18ac0e5d920 delta=1.717331ms username=user@domain.com
Sep 23 08:47:33 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.261695ms cid=18ac0e5d920 delta=433.860993ms username=user@domain.com
Sep 23 08:47:33 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=1.874012ms cid=18ac0e5d920 delta=162.42442ms username=user@domain.com
Sep 23 08:47:33 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=1.377569ms cid=18ac0e5d920 delta=1.41877ms username=user@domain.com
Sep 23 08:47:33 mail mox[999]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=1.229048ms cid=18ac0e5d920 delta=1.266008ms username=user@domain.com
./mox version
v0.0.7-0.20230922135305-a0f3856e4005
uname -a
Linux mail 6.1.0-12-arm64 #1 SMP Debian 6.1.52-1 (2023-09-07) aarch64 GNU/Linux
mjl- commented 1 year ago
  • mox bumpuidvalidity ... same, found and fixed issues, but for one specific account it returned open account: timeout and nothing showed up in the logs set to debug.

This means the account was still open by a session in a running mox, could be an IMAP idle connection or webmail. mox bumpuidvalidity goes straight to the database file, and the database library (bstore with boltdb) locks the database file, so only one can access at a time. You could work around this by closing the imap/webmail session, or stopping mox altogether while running (not attractive...). It isn't easy to make bumpuidvalidity work properly while connections are running. There's a todo at https://github.com/mjl-/mox/blob/main/main.go#L2097

After this I did a backup which returned following error:

./mox backup backup
warning: creating hardlink to message: link data/accounts/user/msg/a/45 /home/mox/backup/accounts/user/msg/a/45: invalid cross-device link; srcpath=data/accounts/user/msg/a/45; dstpath=/home/mox/backup/accounts/user/msg/a/45

Rerunning the same command would output the same error but sometimes for another account/msg but always only one instance. System logs do not show any filesystem corruption.

This happens because mox is running with some paths remounted, I believe with https://github.com/mjl-/mox/blob/main/mox.service#L21 It does not indicate file system corruption. I'll make it more clear that it's continuing to copy the data (which is slower), and won't be warned about again. See https://github.com/mjl-/mox/blob/main/backup.go#L234 The solution I use is to backup to data/tmp/backup. That causes file operations to stay in the bind/mountpoint, allowing hardlinking.

Ignored above error and proceeded with: ./mox verifydata backup which returned quite some errors:


./mox verifydata backup
error: backup/accounts/user/index.db: mailbox "DMARC" (id 11) has uidvalidity 844885606 >= account nextuidvalidity 844885606: inconsistent uidvalidity for mailbox/account, see "mox fixuidmeta"

These surprised me, but looking into the cause, I see they are caused by mox bumpuidvalidity, that only updates the mailbox uidvalidity, without changing the per-account nextuidvalidity. I'm going to make a fix for this. This error isn't cause any actual trouble, but it is a consistency violation.

error: backup/accounts/user4/index.db: mailbox "Drafts" (id 3) has wrong counts 0 total, -38 deleted, 0 unread, 0 unseen, size -3395775 bytes, should be 0 total, 0 deleted, 0 unread, 0 unseen, size 0 bytes: wrong mailbox counts, see "mox recalculatemailboxcounts"

I believe these were for the expunging issue that we we were trying to get fix, so hopefully they will be gone for good.

Then in Mail.app I tried to move some messages out of Junk folder but that failed. These are the relevant logs: [...]

I'm not seeing error messages in the log. Are you getting error messages in Mail.app? Could you perhaps turn on "trace" level (can be enabled for just IMAP) and try the operation again?

Thanks for the clear report, very helpful in understanding what is going on.

x8x commented 1 year ago

After stopping mox I was able to successfully run mox bumpuidvalidity user@domain.com.

I then executed these commands after starting mox server:

# ./mox backup data/tmp/backup
# ./mox verifydata data/tmp/backup
data/tmp/backup: OK
# ./mox loglevels trace

If I understand correctly the output should confirm that mox data was in good shape.

In macOS's Mail.app, I selected the problematic account and run Synchronise user@domain.com.

I then selected 5 unread messages from Junk and dragged them to Inbox. The operation was not successfull.

These are the related logs:

Sep 23 13:05:29 mail mox[3638]: l=trace m="C: DONE\r\n" pkg=imapserver cid=18ac218d395 delta=15.401480257s username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="S: 68.12 OK IDLE done\r\n" pkg=imapserver cid=18ac218d395 delta="115.881µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=15.401652619s cid=18ac218d395 delta="53.521µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="C: 69.12 UID COPY 118:122 INBOX\r\n" pkg=imapserver cid=18ac218d395 delta=207.295735ms username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=1 uid=320 modseq=1546 keywords=[junk];mailboxid=1 uid=321 modseq=1546 keywords=[junk];mailboxid=1 uid=322 modseq=1546 keywords=[junk];mailboxid=1 uid=323 modseq=1546 keywords=[junk];mailboxid=1 uid=324 modseq=1546 keywords=[junk];12 total, 0 deleted, 11 unread, 11 unseen, size 590313 bytes]" cid=18ac218d395 delta=9.869314ms username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="S: 69.12 OK [COPYUID 847374170 118:122 320:324] copied\r\n" pkg=imapserver cid=18ac218d395 delta="89.24µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid copy" duration=9.942034ms cid=18ac218d395 delta="48.041µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uid=320 modseq=1546 keywords=[junk];mailboxid=1 uid=321 modseq=1546 keywords=[junk];mailboxid=1 uid=322 modseq=1546 keywords=[junk];mailboxid=1 uid=323 modseq=1546 keywords=[junk];mailboxid=1 uid=324 modseq=1546 keywords=[junk];12 total, 0 deleted, 11 unread, 11 unseen, size 590313 bytes]" cid=18ac218d38f delta=15.824773473s username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="S: * 12 EXISTS\r\n* 8 FETCH (UID 320 FLAGS (junk) MODSEQ (1546))\r\n* 9 FETCH (UID 321 FLAGS (junk) MODSEQ (1546))\r\n* 10 FETCH (UID 322 FLAGS (junk) MODSEQ (1546))\r\n* 11 FETCH (UID 323 FLAGS (junk) MODSEQ (1546))\r\n* 12 FETCH (UID 324 FLAGS (junk) MODSEQ (1546))\r\n" pkg=imapserver cid=18ac218d38f delta="42.4µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uid=320 modseq=1546 keywords=[junk];mailboxid=1 uid=321 modseq=1546 keywords=[junk];mailboxid=1 uid=322 modseq=1546 keywords=[junk];mailboxid=1 uid=323 modseq=1546 keywords=[junk];mailboxid=1 uid=324 modseq=1546 keywords=[junk];12 total, 0 deleted, 11 unread, 11 unseen, size 590313 bytes]" cid=18ac218d372 delta=15.824924114s username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="S: * 12 EXISTS\r\n* 8 FETCH (UID 320 FLAGS (junk) MODSEQ (1546))\r\n* 9 FETCH (UID 321 FLAGS (junk) MODSEQ (1546))\r\n* 10 FETCH (UID 322 FLAGS (junk) MODSEQ (1546))\r\n* 11 FETCH (UID 323 FLAGS (junk) MODSEQ (1546))\r\n* 12 FETCH (UID 324 FLAGS (junk) MODSEQ (1546))\r\n" pkg=imapserver cid=18ac218d372 delta="36.481µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uid=320 modseq=1546 keywords=[junk];mailboxid=1 uid=321 modseq=1546 keywords=[junk];mailboxid=1 uid=322 modseq=1546 keywords=[junk];mailboxid=1 uid=323 modseq=1546 keywords=[junk];mailboxid=1 uid=324 modseq=1546 keywords=[junk];12 total, 0 deleted, 11 unread, 11 unseen, size 590313 bytes]" cid=18ac218d373 delta=15.824852594s username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="C: DONE\r\n" pkg=imapserver cid=18ac218d372 delta=29.267376ms username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="S: 55.1843 OK IDLE done\r\n" pkg=imapserver cid=18ac218d372 delta="78.481µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=33.30181633s cid=18ac218d372 delta="64.721µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="C: 56.1843 FETCH 8:12 (INTERNALDATE UID RFC822.SIZE FLAGS BODY.PEEK[HEADER.FIELDS (date subject from to cc message-id in-reply-to references content-type x-priority x-uniform-type-identifier x-universally-unique-identifier list-id list-unsubscribe x-spam-status x-spam-flag received-spf X-Forefront-Antispam-Report)])\r\n" pkg=imapserver cid=18ac218d372 delta=28.013567ms username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="S: * 8 FETCH (UID 320 INTERNALDATE \"23-Sep-2023 07:30:02 +0000\" RFC822.SIZE 80604 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe X-Spam-Status X-Spam-Flag Received-Spf X-Forefront-Antispam-Report)] {744}\r\n" pkg=imapserver cid=18ac218d372 delta=1.083528ms username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="184.681µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="S:  FLAGS (junk))\r\n* 9 FETCH (UID 321 INTERNALDATE \"22-Sep-2023 16:33:43 +0000\" RFC822.SIZE 70719 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe X-Spam-Status X-Spam-Flag Received-Spf X-Forefront-Antispam-Report)] {731}\r\n" pkg=imapserver cid=18ac218d372 delta="470.924µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="134.401µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="S:  FLAGS (junk))\r\n* 10 FETCH (UID 322 INTERNALDATE \"22-Sep-2023 17:41:20 +0000\" RFC822.SIZE 21088 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe X-Spam-Status X-Spam-Flag Received-Spf X-Forefront-Antispam-Report)] {640}\r\n" pkg=imapserver cid=18ac218d372 delta="248.402µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="38.84µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="S:  FLAGS (junk))\r\n* 11 FETCH (UID 323 INTERNALDATE \"22-Sep-2023 18:47:14 +0000\" RFC822.SIZE 146116 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe X-Spam-Status X-Spam-Flag Received-Spf X-Forefront-Antispam-Report)] {1147}\r\n" pkg=imapserver cid=18ac218d372 delta="218.122µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="36.72µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="S:  FLAGS (junk))\r\n* 12 FETCH (UID 324 INTERNALDATE \"23-Sep-2023 00:40:10 +0000\" RFC822.SIZE 20826 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe X-Spam-Status X-Spam-Flag Received-Spf X-Forefront-Antispam-Report)] {810}\r\n" pkg=imapserver cid=18ac218d372 delta="187.801µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="33.921µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="S:  FLAGS (junk))\r\n56.1843 OK FETCH done\r\n" pkg=imapserver cid=18ac218d372 delta=1.089928ms username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd=fetch duration=3.695467ms cid=18ac218d372 delta="37.32µs" username=user@domain.com
Sep 23 13:05:29 mail mox[3638]: l=trace m="C: 57.1843 UID COPY 320:324 Junk\r\n" pkg=imapserver cid=18ac218d372 delta=130.169884ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="updating junk filter" pkg=imapserver untrain=false untrainjunk=false train=true trainjunk=true cid=18ac218d372 delta=4.686715ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="updating junk filter" pkg=imapserver untrain=false untrainjunk=false train=true trainjunk=true cid=18ac218d372 delta=6.939172ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="updating junk filter" pkg=imapserver untrain=false untrainjunk=false train=true trainjunk=true cid=18ac218d372 delta=5.864403ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="updating junk filter" pkg=imapserver untrain=false untrainjunk=false train=true trainjunk=true cid=18ac218d372 delta=1.194169ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="updating junk filter" pkg=imapserver untrain=false untrainjunk=false train=true trainjunk=true cid=18ac218d372 delta=4.454273ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: DONE\r\n" pkg=imapserver cid=18ac218d38f delta=216.046721ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: 52.8 OK IDLE done\r\n" pkg=imapserver cid=18ac218d38f delta="97.961µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=19.302700436s cid=18ac218d38f delta="113.2µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 70.12 IDLE\r\n" pkg=imapserver cid=18ac218d395 delta=216.890247ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: + waiting\r\n" pkg=imapserver cid=18ac218d395 delta="97.36µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="inserting words in junkfilter db" pkg=imapserver words=844 cid=18ac218d372 delta=2.263497ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=4 uid=123 modseq=1547 keywords=[junk];mailboxid=4 uid=124 modseq=1547 keywords=[junk];mailboxid=4 uid=125 modseq=1547 keywords=[junk];mailboxid=4 uid=126 modseq=1547 keywords=[junk];mailboxid=4 uid=127 modseq=1547 keywords=[junk];13 total, 0 deleted, 12 unread, 12 unseen, size 763853 bytes]" cid=18ac218d372 delta=11.862287ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=123 modseq=1547 keywords=[junk];mailboxid=4 uid=124 modseq=1547 keywords=[junk];mailboxid=4 uid=125 modseq=1547 keywords=[junk];mailboxid=4 uid=126 modseq=1547 keywords=[junk];mailboxid=4 uid=127 modseq=1547 keywords=[junk];13 total, 0 deleted, 12 unread, 12 unseen, size 763853 bytes]" cid=18ac218d395 delta=12.07429ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * 13 EXISTS\r\n* 9 FETCH (UID 123 FLAGS ($Junk junk) MODSEQ (1547))\r\n* 10 FETCH (UID 124 FLAGS ($Junk junk) MODSEQ (1547))\r\n* 11 FETCH (UID 125 FLAGS ($Junk junk) MODSEQ (1547))\r\n* 12 FETCH (UID 126 FLAGS ($Junk junk) MODSEQ (1547))\r\n* 13 FETCH (UID 127 FLAGS ($Junk junk) MODSEQ (1547))\r\n" pkg=imapserver cid=18ac218d395 delta="64.2µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=123 modseq=1547 keywords=[junk];mailboxid=4 uid=124 modseq=1547 keywords=[junk];mailboxid=4 uid=125 modseq=1547 keywords=[junk];mailboxid=4 uid=126 modseq=1547 keywords=[junk];mailboxid=4 uid=127 modseq=1547 keywords=[junk];13 total, 0 deleted, 12 unread, 12 unseen, size 763853 bytes]" cid=18ac218d373 delta=229.051777ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * 13 EXISTS\r\n* 9 FETCH (UID 123 FLAGS ($Junk junk) MODSEQ (1547))\r\n* 10 FETCH (UID 124 FLAGS ($Junk junk) MODSEQ (1547))\r\n* 11 FETCH (UID 125 FLAGS ($Junk junk) MODSEQ (1547))\r\n* 12 FETCH (UID 126 FLAGS ($Junk junk) MODSEQ (1547))\r\n* 13 FETCH (UID 127 FLAGS ($Junk junk) MODSEQ (1547))\r\n" pkg=imapserver cid=18ac218d373 delta="70.24µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: 57.1843 OK [COPYUID 847374170 320:324 123:127] copied\r\n" pkg=imapserver cid=18ac218d372 delta="234.762µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid copy" duration=37.84464ms cid=18ac218d372 delta="407.563µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 58.1843 UID FETCH 321:324 (BODY.PEEK[] BODYSTRUCTURE)\r\n" pkg=imapserver cid=18ac218d372 delta=28.29633ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * 9 FETCH (UID 321 BODY[] {70719}\r\n" pkg=imapserver cid=18ac218d372 delta="587.324µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="213.082µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="344.282µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="124.801µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="65.081µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="89µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="64.961µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="406.243µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="125.081µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="46.12µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="33.76µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="31.561µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="27.28µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="30.16µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="66.721µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="38.52µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="32.8µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="34.48µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="64.881µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 1831 24)(\"TEXT\" \"HTML\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 66502 856) \"ALTERNATIVE\") MODSEQ (1546))\r\n* 10 FETCH (UID 322 BODY[] {21088}\r\n" pkg=imapserver cid=18ac218d372 delta="333.842µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="90.921µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="60.76µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="45.481µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="34.6µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="62.16µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="39.401µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"HTML\" (\"CHARSET\" \"utf-8\") NIL NIL \"BASE64\" 2116 31)(\"APPLICATION\" \"OCTET-STREAM\" (\"NAME\" \"Logo.png\") NIL NIL \"BASE64\" 14604) \"MIXED\") MODSEQ (1546))\r\n* 11 FETCH (UID 323 BODY[] {146116}\r\n" pkg=imapserver cid=18ac218d372 delta="470.603µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="445.844µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="90.64µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="68.881µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="39.08µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="28.32µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="27.12µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="25.961µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="58.96µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="42.64µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="26.561µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="100.92µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="41.121µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="42.88µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="62.08µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="39.081µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="35.08µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="28.76µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="56.961µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="44.68µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="32µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="31.08µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="61.761µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="33.24µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="32.08µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="24.361µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="32.76µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="32.32µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="28.16µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="28.56µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="24.601µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="22.88µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="27.92µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="27.48µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="35.6µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="27.681µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="25.12µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"UTF-8\") \"text-body\" NIL \"QUOTED-PRINTABLE\" 7861 150)(\"TEXT\" \"HTML\" (\"CHARSET\" \"UTF-8\") \"html-body\" NIL \"QUOTED-PRINTABLE\" 134330 2860) \"ALTERNATIVE\") MODSEQ (1546))\r\n* 12 FETCH (UID 324 BODY[] {20826}\r\n" pkg=imapserver cid=18ac218d372 delta="280.642µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="128.561µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="37.56µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="29.24µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="39.521µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="27.56µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="57.32µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"UTF-8\") NIL NIL \"QUOTED-PRINTABLE\" 2086 44)(\"TEXT\" \"HTML\" (\"CHARSET\" \"UTF-8\") NIL NIL \"QUOTED-PRINTABLE\" 16103 242) \"ALTERNATIVE\") MODSEQ (1546))\r\n58.1843 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d372 delta=1.32481ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=7.264333ms cid=18ac218d372 delta="45.2µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 59.1843 UID FETCH 320 (BODY.PEEK[] BODYSTRUCTURE)\r\n" pkg=imapserver cid=18ac218d372 delta=18.449417ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * 8 FETCH (UID 320 BODY[] {80604}\r\n" pkg=imapserver cid=18ac218d372 delta="568.404µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="193.562µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="41.72µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="114.441µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="155.761µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="65.321µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="143.761µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="207.681µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="96.521µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="104.241µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="104.16µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: DONE\r\n" pkg=imapserver cid=18ac218d373 delta=56.197057ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: 29.1844 OK IDLE done\r\n" pkg=imapserver cid=18ac218d373 delta="32.84µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=33.620106007s cid=18ac218d373 delta="64µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="559.845µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="42µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="75.56µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="56.241µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="28.72µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="152.961µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="58.881µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="147.961µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="62.08µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d372 delta="23.64µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 9493 197)(\"TEXT\" \"HTML\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 68146 1481) \"ALTERNATIVE\") MODSEQ (1546))\r\n59.1843 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d372 delta=5.438121ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=8.436222ms cid=18ac218d372 delta="105.2µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 30.1844 FETCH 9:13 (INTERNALDATE UID RFC822.SIZE FLAGS BODY.PEEK[HEADER.FIELDS (date subject from to cc message-id in-reply-to references content-type x-priority x-uniform-type-identifier x-universally-unique-identifier list-id list-unsubscribe x-spam-status x-spam-flag received-spf X-Forefront-Antispam-Report)])\r\n" pkg=imapserver cid=18ac218d373 delta=27.970328ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * 9 FETCH (UID 123 INTERNALDATE \"23-Sep-2023 07:30:02 +0000\" RFC822.SIZE 80604 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe X-Spam-Status X-Spam-Flag Received-Spf X-Forefront-Antispam-Report)] {744}\r\n" pkg=imapserver cid=18ac218d373 delta=1.864813ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="229.882µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  FLAGS ($Junk junk))\r\n* 10 FETCH (UID 124 INTERNALDATE \"22-Sep-2023 16:33:43 +0000\" RFC822.SIZE 70719 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe X-Spam-Status X-Spam-Flag Received-Spf X-Forefront-Antispam-Report)] {731}\r\n" pkg=imapserver cid=18ac218d373 delta="680.125µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="122.801µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  FLAGS ($Junk junk))\r\n* 11 FETCH (UID 125 INTERNALDATE \"22-Sep-2023 17:41:20 +0000\" RFC822.SIZE 21088 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe X-Spam-Status X-Spam-Flag Received-Spf X-Forefront-Antispam-Report)] {640}\r\n" pkg=imapserver cid=18ac218d373 delta="539.924µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="199.962µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  FLAGS ($Junk junk))\r\n* 12 FETCH (UID 126 INTERNALDATE \"22-Sep-2023 18:47:14 +0000\" RFC822.SIZE 146116 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe X-Spam-Status X-Spam-Flag Received-Spf X-Forefront-Antispam-Report)] {1147}\r\n" pkg=imapserver cid=18ac218d373 delta=2.448098ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="682.685µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  FLAGS ($Junk junk))\r\n* 13 FETCH (UID 127 INTERNALDATE \"23-Sep-2023 00:40:10 +0000\" RFC822.SIZE 20826 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe X-Spam-Status X-Spam-Flag Received-Spf X-Forefront-Antispam-Report)] {810}\r\n" pkg=imapserver cid=18ac218d373 delta=1.883414ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="68.68µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  FLAGS ($Junk junk))\r\n30.1844 OK FETCH done\r\n" pkg=imapserver cid=18ac218d373 delta=16.043959ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd=fetch duration=24.742063ms cid=18ac218d373 delta="113.321µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 60.1843 UID STORE 320:324 +FLAGS.SILENT (\\Deleted)\r\n" pkg=imapserver cid=18ac218d372 delta=77.480054ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=1 uid=320 modseq=1548 keywords=[junk];mailboxid=1 uid=321 modseq=1548 keywords=[junk];mailboxid=1 uid=322 modseq=1548 keywords=[junk];mailboxid=1 uid=323 modseq=1548 keywords=[junk];mailboxid=1 uid=324 modseq=1548 keywords=[junk];7 total, 5 deleted, 6 unread, 11 unseen, size 590313 bytes]" cid=18ac218d372 delta=3.514547ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * 8 FETCH (UID 320 MODSEQ (1548))\r\n* 9 FETCH (UID 321 MODSEQ (1548))\r\n* 10 FETCH (UID 322 MODSEQ (1548))\r\n* 11 FETCH (UID 323 MODSEQ (1548))\r\n* 12 FETCH (UID 324 MODSEQ (1548))\r\n60.1843 OK UID STORE done\r\n" pkg=imapserver cid=18ac218d372 delta="165.001µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid store" duration=3.699067ms cid=18ac218d372 delta="94µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uid=320 modseq=1548 keywords=[junk];mailboxid=1 uid=321 modseq=1548 keywords=[junk];mailboxid=1 uid=322 modseq=1548 keywords=[junk];mailboxid=1 uid=323 modseq=1548 keywords=[junk];mailboxid=1 uid=324 modseq=1548 keywords=[junk];7 total, 5 deleted, 6 unread, 11 unseen, size 590313 bytes]" cid=18ac218d395 delta=144.279549ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 31.1844 UID FETCH 124:127 (BODY.PEEK[] BODYSTRUCTURE)\r\n" pkg=imapserver cid=18ac218d373 delta=35.06542ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * 10 FETCH (UID 124 BODY[] {70719}\r\n" pkg=imapserver cid=18ac218d373 delta="496.363µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="167.322µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="73.8µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="75.481µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="78.8µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="96.081µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="85.481µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="84.72µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="69.081µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="48.72µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.4µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="37.401µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="37.48µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="33.4µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.48µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="33.841µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="38.88µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="93.361µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="42.6µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 1831 24)(\"TEXT\" \"HTML\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 66502 856) \"ALTERNATIVE\") MODSEQ (1547))\r\n* 11 FETCH (UID 125 BODY[] {21088}\r\n" pkg=imapserver cid=18ac218d373 delta="326.162µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="72.961µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="39.8µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.12µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="37.321µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="40.04µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="101.321µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"HTML\" (\"CHARSET\" \"utf-8\") NIL NIL \"BASE64\" 2116 31)(\"APPLICATION\" \"OCTET-STREAM\" (\"NAME\" \"Logo.png\") NIL NIL \"BASE64\" 14604) \"MIXED\") MODSEQ (1547))\r\n* 12 FETCH (UID 126 BODY[] {146116}\r\n" pkg=imapserver cid=18ac218d373 delta="239.322µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="60.72µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="38.24µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="38.361µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="38.28µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="26.84µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="28.44µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="28.761µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="30.36µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="39.76µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="30.68µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.12µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="29.081µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="59.76µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="33.76µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="28.601µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="33.24µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="29.8µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="34.96µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="35.681µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.72µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.84µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="49.88µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="30.201µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="32.32µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="43.92µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="30.84µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.081µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="29.56µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="33.4µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="26.64µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="23.841µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="27.4µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="30.12µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="37.4µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="28.84µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="29.641µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"UTF-8\") \"text-body\" NIL \"QUOTED-PRINTABLE\" 7861 150)(\"TEXT\" \"HTML\" (\"CHARSET\" \"UTF-8\") \"html-body\" NIL \"QUOTED-PRINTABLE\" 134330 2860) \"ALTERNATIVE\") MODSEQ (1547))\r\n* 13 FETCH (UID 127 BODY[] {20826}\r\n" pkg=imapserver cid=18ac218d373 delta="294.202µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="75.72µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="32.881µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.8µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="100.041µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="37.68µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="23.4µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uid=320 modseq=1548 keywords=[junk];mailboxid=1 uid=321 modseq=1548 keywords=[junk];mailboxid=1 uid=322 modseq=1548 keywords=[junk];mailboxid=1 uid=323 modseq=1548 keywords=[junk];mailboxid=1 uid=324 modseq=1548 keywords=[junk];7 total, 5 deleted, 6 unread, 11 unseen, size 590313 bytes]" cid=18ac218d373 delta="869.367µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"UTF-8\") NIL NIL \"QUOTED-PRINTABLE\" 2086 44)(\"TEXT\" \"HTML\" (\"CHARSET\" \"UTF-8\") NIL NIL \"QUOTED-PRINTABLE\" 16103 242) \"ALTERNATIVE\") MODSEQ (1547))\r\n31.1844 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d373 delta="56.72µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=5.285839ms cid=18ac218d373 delta="19.64µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 61.1843 UID EXPUNGE 320:324\r\n" pkg=imapserver cid=18ac218d372 delta=24.19034ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=1 uids=[320;321;322;323;324] modseq=1549;7 total, 0 deleted, 6 unread, 6 unseen, size 250960 bytes]" cid=18ac218d372 delta=6.441327ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * VANISHED 320:324\r\n61.1843 OK [HIGHESTMODSEQ 1549] expunged\r\n" pkg=imapserver cid=18ac218d372 delta="74.361µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 32.1844 UID FETCH 123 (BODY.PEEK[] BODYSTRUCTURE)\r\n" pkg=imapserver cid=18ac218d373 delta=25.244187ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid expunge" duration=6.586289ms cid=18ac218d372 delta="106.721µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uids=[320;321;322;323;324] modseq=1549;7 total, 0 deleted, 6 unread, 6 unseen, size 250960 bytes]" cid=18ac218d395 delta=30.747748ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * 9 FETCH (UID 123 BODY[] {80604}\r\n" pkg=imapserver cid=18ac218d373 delta="346.363µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="81.56µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="72.921µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="49µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="29.32µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="32.241µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.96µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="29.56µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.44µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.201µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="32.44µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="28.48µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="26.88µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="30.16µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="27.001µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.92µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="31.64µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="30.28µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="26.841µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="36.36µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d373 delta="23.68µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uids=[320;321;322;323;324] modseq=1549;7 total, 0 deleted, 6 unread, 6 unseen, size 250960 bytes]" cid=18ac218d373 delta="974.607µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 9493 197)(\"TEXT\" \"HTML\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 68146 1481) \"ALTERNATIVE\") MODSEQ (1547))\r\n32.1844 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d373 delta="42.641µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.053976ms cid=18ac218d373 delta="19.44µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 53.8 UID FETCH 1:319 (FLAGS UID) (CHANGEDSINCE 1541 VANISHED)\r\n" pkg=imapserver cid=18ac218d38f delta=206.303929ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=123 modseq=1547 keywords=[junk];mailboxid=4 uid=124 modseq=1547 keywords=[junk];mailboxid=4 uid=125 modseq=1547 keywords=[junk];mailboxid=4 uid=126 modseq=1547 keywords=[junk];mailboxid=4 uid=127 modseq=1547 keywords=[junk];13 total, 0 deleted, 12 unread, 12 unseen, size 763853 bytes;mailboxid=1 uid=320 modseq=1548 keywords=[junk];mailboxid=1 uid=321 modseq=1548 keywords=[junk];mailboxid=1 uid=322 modseq=1548 keywords=[junk];mailboxid=1 uid=323 modseq=1548 keywords=[junk];mailboxid=1 uid=324 modseq=1548 keywords=[junk];7 total, 5 deleted, 6 unread, 11 unseen, size 590313 bytes;mailboxid=1 uids=[320;321;322;323;324] modseq=1549;7 total, 0 deleted, 6 unread, 6 unseen, size 250960 bytes]" cid=18ac218d38f delta=1.40185ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * VANISHED (EARLIER) 320:324\r\n* 8 FETCH (UID 320 FLAGS (\\Deleted junk) MODSEQ (1548))\r\n* 9 FETCH (UID 321 FLAGS (\\Deleted junk) MODSEQ (1548))\r\n* 10 FETCH (UID 322 FLAGS (\\Deleted junk) MODSEQ (1548))\r\n* 11 FETCH (UID 323 FLAGS (\\Deleted junk) MODSEQ (1548))\r\n* 12 FETCH (UID 324 FLAGS (\\Deleted junk) MODSEQ (1548))\r\n* VANISHED 320:324\r\n53.8 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d38f delta="272.482µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=1.674573ms cid=18ac218d38f delta="63.801µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: DONE\r\n" pkg=imapserver cid=18ac218d395 delta=20.25511ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: 70.12 OK IDLE done\r\n" pkg=imapserver cid=18ac218d395 delta="30.8µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=207.480937ms cid=18ac218d395 delta="26.6µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 62.1843 IDLE\r\n" pkg=imapserver cid=18ac218d372 delta=25.290827ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: + waiting\r\n" pkg=imapserver cid=18ac218d372 delta="55.401µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 33.1844 IDLE\r\n" pkg=imapserver cid=18ac218d373 delta=81.348802ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: + waiting\r\n" pkg=imapserver cid=18ac218d373 delta="49.161µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 71.12 UID STORE 118:122 +FLAGS.SILENT (\\Deleted)\r\n" pkg=imapserver cid=18ac218d395 delta=208.630946ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=4 uid=118 modseq=1550 keywords=[junk];mailboxid=4 uid=119 modseq=1550 keywords=[junk];mailboxid=4 uid=120 modseq=1550 keywords=[junk];mailboxid=4 uid=121 modseq=1550 keywords=[junk];mailboxid=4 uid=122 modseq=1550 keywords=[junk];8 total, 5 deleted, 7 unread, 12 unseen, size 763853 bytes]" cid=18ac218d395 delta=5.138158ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * 4 FETCH (UID 118 MODSEQ (1550))\r\n* 5 FETCH (UID 119 MODSEQ (1550))\r\n* 6 FETCH (UID 120 MODSEQ (1550))\r\n* 7 FETCH (UID 121 MODSEQ (1550))\r\n* 8 FETCH (UID 122 MODSEQ (1550))\r\n71.12 OK UID STORE done\r\n" pkg=imapserver cid=18ac218d395 delta="134.681µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid store" duration=5.256999ms cid=18ac218d395 delta="58.321µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=118 modseq=1550 keywords=[junk];mailboxid=4 uid=119 modseq=1550 keywords=[junk];mailboxid=4 uid=120 modseq=1550 keywords=[junk];mailboxid=4 uid=121 modseq=1550 keywords=[junk];mailboxid=4 uid=122 modseq=1550 keywords=[junk];8 total, 5 deleted, 7 unread, 12 unseen, size 763853 bytes]" cid=18ac218d373 delta=150.924758ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * 4 FETCH (UID 118 FLAGS (\\Deleted $Junk junk) MODSEQ (1550))\r\n* 5 FETCH (UID 119 FLAGS (\\Deleted $Junk junk) MODSEQ (1550))\r\n* 6 FETCH (UID 120 FLAGS (\\Deleted $Junk junk) MODSEQ (1550))\r\n* 7 FETCH (UID 121 FLAGS (\\Deleted $Junk junk) MODSEQ (1550))\r\n* 8 FETCH (UID 122 FLAGS (\\Deleted $Junk junk) MODSEQ (1550))\r\n" pkg=imapserver cid=18ac218d373 delta="45.76µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=118 modseq=1550 keywords=[junk];mailboxid=4 uid=119 modseq=1550 keywords=[junk];mailboxid=4 uid=120 modseq=1550 keywords=[junk];mailboxid=4 uid=121 modseq=1550 keywords=[junk];mailboxid=4 uid=122 modseq=1550 keywords=[junk];8 total, 5 deleted, 7 unread, 12 unseen, size 763853 bytes]" cid=18ac218d372 delta=209.069028ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 54.8 IDLE\r\n" pkg=imapserver cid=18ac218d38f delta=214.224467ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: + waiting\r\n" pkg=imapserver cid=18ac218d38f delta="13.4µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uid=118 modseq=1550 keywords=[junk];mailboxid=4 uid=119 modseq=1550 keywords=[junk];mailboxid=4 uid=120 modseq=1550 keywords=[junk];mailboxid=4 uid=121 modseq=1550 keywords=[junk];mailboxid=4 uid=122 modseq=1550 keywords=[junk];8 total, 5 deleted, 7 unread, 12 unseen, size 763853 bytes]" cid=18ac218d38f delta="23.84µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 72.12 UID EXPUNGE 118:122\r\n" pkg=imapserver cid=18ac218d395 delta=205.027878ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="updating junk filter" pkg=imapserver untrain=true untrainjunk=true train=false trainjunk=false cid=18ac218d395 delta=3.347505ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="updating junk filter" pkg=imapserver untrain=true untrainjunk=true train=false trainjunk=false cid=18ac218d395 delta=5.921324ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="updating junk filter" pkg=imapserver untrain=true untrainjunk=true train=false trainjunk=false cid=18ac218d395 delta=6.123646ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="updating junk filter" pkg=imapserver untrain=true untrainjunk=true train=false trainjunk=false cid=18ac218d395 delta="649.724µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="updating junk filter" pkg=imapserver untrain=true untrainjunk=true train=false trainjunk=false cid=18ac218d395 delta=4.738435ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="inserting words in junkfilter db" pkg=imapserver words=844 cid=18ac218d395 delta=1.26141ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=4 uids=[118;119;120;121;122] modseq=1551;8 total, 0 deleted, 7 unread, 7 unseen, size 424500 bytes]" cid=18ac218d395 delta=13.648581ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * VANISHED 118:122\r\n72.12 OK [HIGHESTMODSEQ 1551] expunged\r\n" pkg=imapserver cid=18ac218d395 delta="174.641µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uids=[118;119;120;121;122] modseq=1551;8 total, 0 deleted, 7 unread, 7 unseen, size 424500 bytes]" cid=18ac218d373 delta=240.818704ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * VANISHED 118:122\r\n" pkg=imapserver cid=18ac218d373 delta="86.121µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid expunge" duration=35.940666ms cid=18ac218d395 delta="119.321µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uids=[118;119;120;121;122] modseq=1551;8 total, 0 deleted, 7 unread, 7 unseen, size 424500 bytes]" cid=18ac218d38f delta=240.858784ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=4 uids=[118;119;120;121;122] modseq=1551;8 total, 0 deleted, 7 unread, 7 unseen, size 424500 bytes]" cid=18ac218d372 delta=240.955786ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: DONE\r\n" pkg=imapserver cid=18ac218d38f delta=207.84306ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: 54.8 OK IDLE done\r\n" pkg=imapserver cid=18ac218d38f delta="71.841µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=448.850205ms cid=18ac218d38f delta="54µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="C: 73.12 FETCH 4:8 (INTERNALDATE UID RFC822.SIZE FLAGS BODY.PEEK[HEADER.FIELDS (date subject from to cc message-id in-reply-to references content-type x-priority x-uniform-type-identifier x-universally-unique-identifier list-id list-unsubscribe bimi-indicator bimi-location x-bimi-indicator-hash authentication-results dkim-signature)])\r\n" pkg=imapserver cid=18ac218d395 delta=213.133819ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S: * 4 FETCH (UID 123 INTERNALDATE \"23-Sep-2023 07:30:02 +0000\" RFC822.SIZE 80604 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe Bimi-Indicator Bimi-Location X-Bimi-Indicator-Hash Authentication-Results Dkim-Signature)] {1831}\r\n" pkg=imapserver cid=18ac218d395 delta="615.125µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="78.12µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  FLAGS ($Junk junk))\r\n* 5 FETCH (UID 124 INTERNALDATE \"22-Sep-2023 16:33:43 +0000\" RFC822.SIZE 70719 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe Bimi-Indicator Bimi-Location X-Bimi-Indicator-Hash Authentication-Results Dkim-Signature)] {1221}\r\n" pkg=imapserver cid=18ac218d395 delta="422.683µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="86.481µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  FLAGS ($Junk junk))\r\n* 6 FETCH (UID 125 INTERNALDATE \"22-Sep-2023 17:41:20 +0000\" RFC822.SIZE 21088 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe Bimi-Indicator Bimi-Location X-Bimi-Indicator-Hash Authentication-Results Dkim-Signature)] {1296}\r\n" pkg=imapserver cid=18ac218d395 delta="370.523µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="60.24µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  FLAGS ($Junk junk))\r\n* 7 FETCH (UID 126 INTERNALDATE \"22-Sep-2023 18:47:14 +0000\" RFC822.SIZE 146116 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe Bimi-Indicator Bimi-Location X-Bimi-Indicator-Hash Authentication-Results Dkim-Signature)] {2554}\r\n" pkg=imapserver cid=18ac218d395 delta="321.723µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="100.28µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  FLAGS ($Junk junk))\r\n* 8 FETCH (UID 127 INTERNALDATE \"23-Sep-2023 00:40:10 +0000\" RFC822.SIZE 20826 BODY[HEADER.FIELDS (Date Subject From To Cc Message-Id In-Reply-To References Content-Type X-Priority X-Uniform-Type-Identifier X-Universally-Unique-Identifier List-Id List-Unsubscribe Bimi-Indicator Bimi-Location X-Bimi-Indicator-Hash Authentication-Results Dkim-Signature)] {1251}\r\n" pkg=imapserver cid=18ac218d395 delta="324.123µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="43.64µs" username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=trace m="S:  FLAGS ($Junk junk))\r\n73.12 OK FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta=1.28617ms username=user@domain.com
Sep 23 13:05:30 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd=fetch duration=3.677107ms cid=18ac218d395 delta="41.76µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="C: 55.8 UID STORE 320:324 +FLAGS.SILENT ($NotJunk NotJunk)\r\n" pkg=imapserver cid=18ac218d38f delta=207.101855ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S: 55.8 OK UID STORE done\r\n" pkg=imapserver cid=18ac218d38f delta=1.943374ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid store" duration=1.946695ms cid=18ac218d38f delta="107.001µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="C: 74.12 IDLE\r\n" pkg=imapserver cid=18ac218d395 delta=383.407561ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S: + waiting\r\n" pkg=imapserver cid=18ac218d395 delta="78.76µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="C: 56.8 UID STORE 320:324 -FLAGS.SILENT ($Junk Junk)\r\n" pkg=imapserver cid=18ac218d38f delta=206.077327ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S: 56.8 OK UID STORE done\r\n" pkg=imapserver cid=18ac218d38f delta=1.34129ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid store" duration=1.39873ms cid=18ac218d38f delta="117.4µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="C: DONE\r\n" pkg=imapserver cid=18ac218d395 delta=206.754492ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S: 74.12 OK IDLE done\r\n" pkg=imapserver cid=18ac218d395 delta="85.601µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd=idle duration=206.914253ms cid=18ac218d395 delta="70.4µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="C: 57.8 IDLE\r\n" pkg=imapserver cid=18ac218d38f delta=208.099222ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S: + waiting\r\n" pkg=imapserver cid=18ac218d38f delta="58.081µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="C: 75.12 UID FETCH 123:124,126 (BODYSTRUCTURE BODY.PEEK[HEADER])\r\n" pkg=imapserver cid=18ac218d395 delta=206.589891ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S: * 4 FETCH (UID 123 BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 9493 197)(\"TEXT\" \"HTML\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 68146 1481) \"ALTERNATIVE\") BODY[HEADER] {2680}\r\n" pkg=imapserver cid=18ac218d395 delta=1.305729ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="86.241µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n* 5 FETCH (UID 124 BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 1831 24)(\"TEXT\" \"HTML\" (\"CHARSET\" \"utf-8\") NIL NIL \"QUOTED-PRINTABLE\" 66502 856) \"ALTERNATIVE\") BODY[HEADER] {2038}\r\n" pkg=imapserver cid=18ac218d395 delta="467.003µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="93.521µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n* 7 FETCH (UID 126 BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"UTF-8\") \"text-body\" NIL \"QUOTED-PRINTABLE\" 7861 150)(\"TEXT\" \"HTML\" (\"CHARSET\" \"UTF-8\") \"html-body\" NIL \"QUOTED-PRINTABLE\" 134330 2860) \"ALTERNATIVE\") BODY[HEADER] {3557}\r\n" pkg=imapserver cid=18ac218d395 delta="394.363µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="185.801µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n75.12 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta=1.596532ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=4.07899ms cid=18ac218d395 delta="127.041µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="C: 76.12 UID FETCH 125,127 (BODY.PEEK[] BODYSTRUCTURE)\r\n" pkg=imapserver cid=18ac218d395 delta=158.614055ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S: * 6 FETCH (UID 125 BODY[] {21088}\r\n" pkg=imapserver cid=18ac218d395 delta="377.363µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="232.522µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="73.28µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="31.681µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="61.32µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="49.16µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="50.401µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"HTML\" (\"CHARSET\" \"utf-8\") NIL NIL \"BASE64\" 2116 31)(\"APPLICATION\" \"OCTET-STREAM\" (\"NAME\" \"Logo.png\") NIL NIL \"BASE64\" 14604) \"MIXED\") MODSEQ (1547))\r\n* 8 FETCH (UID 127 BODY[] {20826}\r\n" pkg=imapserver cid=18ac218d395 delta="351.042µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="114.201µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="56.361µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="53.68µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="30.48µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="26.96µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="34.681µs" username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=trace m="S:  BODYSTRUCTURE ((\"TEXT\" \"PLAIN\" (\"CHARSET\" \"UTF-8\") NIL NIL \"QUOTED-PRINTABLE\" 2086 44)(\"TEXT\" \"HTML\" (\"CHARSET\" \"UTF-8\") NIL NIL \"QUOTED-PRINTABLE\" 16103 242) \"ALTERNATIVE\") MODSEQ (1547))\r\n76.12 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta=1.197329ms username=user@domain.com
Sep 23 13:05:31 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.7477ms cid=18ac218d395 delta="85.84µs" username=user@domain.com
Sep 23 13:05:32 mail mox[3638]: l=trace m="C: 77.12 UID FETCH 126 BODY.PEEK[TEXT]<0.62107>\r\n" pkg=imapserver cid=18ac218d395 delta=403.144067ms username=user@domain.com
Sep 23 13:05:32 mail mox[3638]: l=trace m="S: * 7 FETCH (UID 126 BODY[TEXT]<0> {62107}\r\n" pkg=imapserver cid=18ac218d395 delta="860.126µs" username=user@domain.com
Sep 23 13:05:32 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="119.041µs" username=user@domain.com
Sep 23 13:05:32 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n77.12 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta=1.37033ms username=user@domain.com
Sep 23 13:05:32 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=162.651205ms cid=18ac218d395 delta=160.409949ms username=user@domain.com
Sep 23 13:05:32 mail mox[3638]: l=trace m="C: 78.12 UID FETCH 126 BODY.PEEK[TEXT]<62107.80060>\r\n" pkg=imapserver cid=18ac218d395 delta=306.014627ms username=user@domain.com
Sep 23 13:05:32 mail mox[3638]: l=trace m="S: * 7 FETCH (UID 126 BODY[TEXT]<62107> {80060}\r\n" pkg=imapserver cid=18ac218d395 delta="627.405µs" username=user@domain.com
Sep 23 13:05:32 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="64.6µs" username=user@domain.com
Sep 23 13:05:32 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n78.12 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta=1.492971ms username=user@domain.com
Sep 23 13:05:32 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.194657ms cid=18ac218d395 delta="54.881µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="C: 79.12 UID FETCH 123 BODY.PEEK[TEXT]<0.35996>\r\n" pkg=imapserver cid=18ac218d395 delta=430.449869ms username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S: * 4 FETCH (UID 123 BODY[TEXT]<0> {35996}\r\n" pkg=imapserver cid=18ac218d395 delta="706.485µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="71.761µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n79.12 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta=1.547211ms username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.336977ms cid=18ac218d395 delta="59.521µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="C: 80.12 UID FETCH 126 BODY.PEEK[TEXT]<142167.3949>\r\n" pkg=imapserver cid=18ac218d395 delta=159.922504ms username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S: * 7 FETCH (UID 126 BODY[TEXT]<142167> {390}\r\n" pkg=imapserver cid=18ac218d395 delta="923.807µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="75.361µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n80.12 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta=1.258449ms username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.242577ms cid=18ac218d395 delta="82.041µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="C: 81.12 UID FETCH 124 BODY.PEEK[TEXT]\r\n" pkg=imapserver cid=18ac218d395 delta="32.08µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S: * 5 FETCH (UID 124 BODY[TEXT] {68679}\r\n" pkg=imapserver cid=18ac218d395 delta="539.564µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="83.361µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n81.12 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta=4.470433ms username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=5.169318ms cid=18ac218d395 delta="96.12µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="C: 82.12 UID FETCH 123 BODY.PEEK[TEXT]<35996.44608>\r\n" pkg=imapserver cid=18ac218d395 delta=399.016077ms username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S: * 4 FETCH (UID 123 BODY[TEXT]<35996> {41928}\r\n" pkg=imapserver cid=18ac218d395 delta="567.924µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m=... pkg=imapserver cid=18ac218d395 delta="104.961µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n82.12 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta=1.267969ms username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=1.935774ms cid=18ac218d395 delta="55.48µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="C: 83.12 UID FETCH 126 BODY.PEEK[TEXT]<142557.3559>\r\n" pkg=imapserver cid=18ac218d395 delta=160.231348ms username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S: * 7 FETCH (UID 126 BODY[TEXT]<142557> {0}\r\n" pkg=imapserver cid=18ac218d395 delta="865.286µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n83.12 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta=1.239169ms username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.117656ms cid=18ac218d395 delta="76.481µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="C: 84.12 UID FETCH 124 BODY.PEEK[TEXT]<68679.2040>\r\n" pkg=imapserver cid=18ac218d395 delta="33.56µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S: * 5 FETCH (UID 124 BODY[TEXT]<68679> {0}\r\n" pkg=imapserver cid=18ac218d395 delta="498.604µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n84.12 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta="901.366µs" username=user@domain.com
Sep 23 13:05:33 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=1.451571ms cid=18ac218d395 delta="71.601µs" username=user@domain.com
Sep 23 13:05:34 mail mox[3638]: l=trace m="C: 85.12 UID FETCH 123 BODY.PEEK[TEXT]<77924.2680>\r\n" pkg=imapserver cid=18ac218d395 delta=252.501231ms username=user@domain.com
Sep 23 13:05:34 mail mox[3638]: l=trace m="S: * 4 FETCH (UID 123 BODY[TEXT]<77924> {0}\r\n" pkg=imapserver cid=18ac218d395 delta=1.021247ms username=user@domain.com
Sep 23 13:05:34 mail mox[3638]: l=trace m="S:  MODSEQ (1547))\r\n85.12 OK UID FETCH done\r\n" pkg=imapserver cid=18ac218d395 delta=1.007248ms username=user@domain.com
Sep 23 13:05:34 mail mox[3638]: l=debug m="imap command done" pkg=imapserver cmd="uid fetch" duration=2.039375ms cid=18ac218d395 delta="64.68µs" username=user@domain.com
Sep 23 13:05:34 mail mox[3638]: l=trace m="C: 86.12 IDLE\r\n" pkg=imapserver cid=18ac218d395 delta=254.074482ms username=user@domain.com
Sep 23 13:05:34 mail mox[3638]: l=trace m="S: + waiting\r\n" pkg=imapserver cid=18ac218d395 delta="61.521µs" username=user@domain.com

To confirm the issue was unrelated to the mail client, I tried the same operation in mox's webmail with the same unsuccessful result.

mjl- commented 1 year ago

Very helpful, thanks!

You mentioned that moving messages is not successful. And I wondered about an error message. But I suspect there may be no error message, but you're just not seeing the messages moved? Because that's what it looks like from the transcript.

Sep 23 13:05:29 mail mox[3638]: l=trace m="C: 69.12 UID COPY 118:122 INBOX\r\n" pkg=imapserver cid=18ac218d395 delta=207.295735ms username=user@domain.com Sep 23 13:05:29 mail mox[3638]: l=trace m="S: 69.12 OK [COPYUID 847374170 118:122 320:324] copied\r\n" pkg=imapserver cid=18ac218d395 delta="89.24µs" username=user@domain.com Sep 23 13:05:29 mail mox[3638]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=1 uid=320 modseq=1546 keywords=[junk];mailboxid=1 uid=321 modseq=1546 keywords=[junk];mailboxid=1 uid=322 modseq=1546 keywords=[junk];mailboxid=1 uid=323 modseq=1546 keywords=[junk];mailboxid=1 uid=324 modseq=1546 keywords=[junk];12 total, 0 deleted, 11 unread, 11 unseen, size 590313 bytes]" cid=18ac218d395 delta=9.869314ms username=user@domain.com Sep 23 13:05:29 mail mox[3638]: l=debug m="applying changes" pkg=imapserver changes="[mailboxid=1 uid=320 modseq=1546 keywords=[junk];mailboxid=1 uid=321 modseq=1546 keywords=[junk];mailboxid=1 uid=322 modseq=1546 keywords=[junk];mailboxid=1 uid=323 modseq=1546 keywords=[junk];mailboxid=1 uid=324 modseq=1546 keywords=[junk];12 total, 0 deleted, 11 unread, 11 unseen, size 590313 bytes]" cid=18ac218d38f delta=15.824773473s username=user@domain.com Sep 23 13:05:29 mail mox[3638]: l=trace m="S: 12 EXISTS\r\n 8 FETCH (UID 320 FLAGS (junk) MODSEQ (1546))\r\n 9 FETCH (UID 321 FLAGS (junk) MODSEQ (1546))\r\n 10 FETCH (UID 322 FLAGS (junk) MODSEQ (1546))\r\n 11 FETCH (UID 323 FLAGS (junk) MODSEQ (1546))\r\n 12 FETCH (UID 324 FLAGS (junk) MODSEQ (1546))\r\n" pkg=imapserver cid=18ac218d372 delta="36.481µs" username=user@domain.com [...]

This appears to be the copy from Junk to Inbox. UIDs 118:122 from Junk were copied, and arrived as 320:324 in Inbox (last parameter of COPYUID).

As an aside, I would expect a "MOVE" command, but some clients do a COPY and DELETE, so that's not really an issue.

You can see the changes being broadcasted to other connections. Each log line with "applying changes" (there are multiple) is a connection for which the changes may be relevant and for which some IMAP updates will be sent.

Anyway, here's the important part. Pretty much immediately below, I'm seeing:

Sep 23 13:05:29 mail mox[3638]: l=trace m="C: 57.1843 UID COPY 320:324 Junk\r\n" pkg=imapserver cid=18ac218d372 delta=130.169884ms username=user@domain.com

So this is copying the messages that arrived in the Inbox (UIDs 320:324) back to the Junk folder!

Note that the "cid" is different in the two UID COPY commands, so different IMAP connections, and possibly different mail clients. You could try to identify the mail client that is doing the copying by looking in the logs for the entire trace of cid=18ac218d372. It may be sending an "ID" command that identifies its user agent.

I suspect this is a mail client with a rule like "Place everything with the 'junk' tag in the Junk folder.". Because I noticed the "junk" keyword in the "broadcast changes" line:

Sep 23 13:05:29 mail mox[3638]: l=debug m="broadcast changes" pkg=imapserver changes="[mailboxid=1 uid=320 modseq=1546 keywords=[junk];mailboxid=1 uid=321 modseq=1546 keywords=[junk];mailboxid=1 uid=322 modseq=1546 keywords=[junk];mailboxid=1 uid=323 modseq=1546 keywords=[junk];mailboxid=1 uid=324 modseq=1546 keywords=[junk];12 total, 0 deleted, 11 unread, 11 unseen, size 590313 bytes]" cid=18ac218d395 delta=9.869314ms username=user@domain.com

In this case, "junk" is a keyword. Those are "custom", non-standard message flags. There are standard flags called \Junk and \Notjunk to use for indicating (non)junk of messages. I think I have an account where Thunderbird has applied those non-standard, custom message keywords "junk" and "nonjunk" to messages (the backslash is significant). Perhaps if I let Thunderbird manage junk filtering, it may be moving messages back too. But I'm letting mox do the junk classification now, and I have it disabled in Thunderbird.

You could try removing the "junk" keywords from the messages before moving. But for a long-term solution I would look for the mail client that appears to be moving the messages back to the Junk folder.

x8x commented 1 year ago

I restricted all traffic to the mail server, keeping only port 443 open, thus isolating any IMAP clients. This allowed me to successfully move messages via webmail!

You hit the nail on the head! I initially thought that clients pulled updates at intervals, but your comment about broadcasting led me to discover the IDLE command. The instant reversal of the move initially had me puzzled, but now it's clear it could be a user's macOS Mail.app with an active in-app junk filter.

Thank you!