Hi Ellie, thanks and sorry for the long delay.
Hi Frank,On Mon, 11 Apr 2022, at 11:36 PM, Frank Richter wrote:I'm still hunting some strange IMAP bugs with Horde Webmail. Users get messages like 'Mailbox structure on server has changed.'This is in code handling UIDVALIDITY (as I understood it) – it's here:https://github.com/horde/imp/blob/8d19f07d87a6320df5de6b293ec05a49502005ff/lib/Mailbox.php#L672 <https://github.com/horde/imp/blob/8d19f07d87a6320df5de6b293ec05a49502005ff/lib/Mailbox.php#L672>If I'm reading this code correctly (someone who actually knows PHP can correct me if I'm not), it looks like it's doing something like:* get the cached uidvalidity* if there was no cached uidvalidity, set a flag to indicate that this is the first time we're caching it * if the cached uidvalidity does not match the uidvalidity from the server (including by not having been previously cached), update the cache to match* if we've updated the cache, and it wasn't the first time, throw the error So, any time UIDVALIDITY changes, Horde will throw this error.
I read the same :-) Instead of throwing an error I logged the uidvalidity values in Horde:2022-05-09T14:47:50 NOTICE: HORDE: [imp] Mailbox structure on server has changed: INBOX 944678882 [pid 71298 on line 682 of "/var/www/html/horde/imp/lib/Mailbox.php"] 2022-05-09T14:47:50 NOTICE: HORDE: [imp] Mailbox structure on server has changed: INBOX 1647543093 [pid 71298 on line 682 of "/var/www/html/horde/imp/lib/Mailbox.php"] 2022-05-09T14:47:50 NOTICE: HORDE: [imp] Mailbox structure on server has changed: INBOX 944678882 [pid 71298 on line 682 of "/var/www/html/horde/imp/lib/Mailbox.php"]
This is a telemetry log I catched during a "remove attachment" in Horde Webmail – it is done by storing a new message (APPEND) and delete the original message:
Frontend server:
<1652100470<7 APPEND INBOX (\seen) "9-May-2022 11:52:13 +0200" CATENATE (URL
/INBOX;UIDVALIDITY=944678882/;UID=294303/;SECTION=HEADER TEXT {31}
1652100470>+ i am an optimist
<1652100470<
--=_Jh9_M3APoyC6UIOy-C96gGX
<1652100470< URL /INBOX;UIDVALIDITY=944678882/;UID=294303/;SECTION=1.MIME URL
/INBOX;UIDVALIDITY=944678882/;UID=294303/;SECTION=1 TEXT {31}
1652100470>+ i am an optimist
<1652100470<
--=_Jh9_M3APoyC6UIOy-C96gGX
<1652100470< TEXT {162}
1652100470>+ i am an optimist
<1652100470<Content-Type: text/plain; charset=utf-8
Content-Disposition: attachment
[Anhang entfernt: Ehemaliger Anhangstyp: application/pkcs7-signature, Name:
smime.p7s]<1652100470< TEXT {33}
1652100470>+ i am an optimist
<1652100470< --=_Jh9_M3APoyC6UIOy-C96gGX-- <1652100470<)
1652100470>7 OK [APPENDUID *944678882* 294323] Completed
<1652100470<9 STATUS INBOX (UIDVALIDITY)
1652100470>* STATUS INBOX (*UIDVALIDITY 1647543093*) <<<--- Here the unchanged Horde Webmail throws an error
9 OK Completed <1652100470<10 SELECT INBOX (QRESYNC (*944678882* 478464 294303))
1652100470>* 180 EXISTS
* 1 RECENT
* FLAGS (\Answered \Flagged \Draft \Deleted \Seen NonJunk Junk $Forwarded
$Label1 $Label2 $Label3 $Label4 $Label5 $MDNSent)
* OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen NonJunk Junk
$Forwarded $Label1 $Label2 $Label3 $Label4 $Label5 $MDNSent \*)] Ok
* OK [UNSEEN 76] Ok
* OK [UIDVALIDITY 944678882] Ok
* OK [UIDNEXT 294324] Ok
* OK [HIGHESTMODSEQ 478465] Ok
* OK [URLMECH INTERNAL] Ok
* OK [ANNOTATIONS 65536] Ok
10 OK [READ-WRITE] Completed
<1652100470<11 UID STORE 294303 +FLAGS \deleted
Backend:
<1652100470<7 Localappend {5+}
INBOX "" (\seen) "9-May-2022 11:52:13 +0200" CATENATE (URL
/INBOX;UIDVALIDITY=944678882/;UID=294303/;SECTION=HEADER TEXT {31+}
--=_Jh9_M3APoyC6UIOy-C96gGX
URL /INBOX;UIDVALIDITY=944678882/;UID=294303/;SECTION=1.MIME URL
/INBOX;UIDVALIDITY=944678882/;UID=294303/;SECTION=1 TEXT {31+}
--=_Jh9_M3APoyC6UIOy-C96gGX
TEXT {162+}
Content-Type: text/plain; charset=utf-8
Content-Disposition: attachment
[Anhang entfernt: Ehemaliger Anhangstyp: application/pkcs7-signature, Name:
smime.p7s] TEXT {33+}
--=_Jh9_M3APoyC6UIOy-C96gGX--
)
1652100470>7 OK [APPENDUID *944678882* 294323] Completed
<1652100470<N01 NOOP
1652100470>N01 OK Completed
<1652100470<9 Status {5+}
INBOX (UIDVALIDITY)
1652100470>* STATUS INBOX (UIDVALIDITY *1647543093*)
9 OK Completed <1652100470<N01 NOOP
1652100470>N01 OK Completed
<1652100470<PROXY1 Enable Qresync
1652100470>PROXY1 OK Completed
<1652100470<10 Select {5+}
INBOX (QRESYNC (*944678882* 478464 294303))
1652100470>* 180 EXISTS
* 1 RECENT * FLAGS (\Answered \Flagged \Draft \Deleted \Seen NonJunk Junk $Forwarded $Label1 $Label2 $Label3 $Label4 $Label5 $MDNSent) * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen NonJunk Junk $Forwarded $Label1 $Label2 $Label3 $Label4 $Label5 $MDNSent \*)] Ok * OK [UNSEEN 76] Ok * OK [UIDVALIDITY 944678882] Ok * OK [UIDNEXT 294324] Ok * OK [HIGHESTMODSEQ 478465] Ok * OK [URLMECH INTERNAL] Ok * OK [ANNOTATIONS 65536] Ok 10 OK [READ-WRITE] CompletedI just don't understand why the UIDVALIDITY changes to 164754309, than back to the old value 944678882.
mbexamine says: … UIDValidity: 944678882 Last UID: 294323 Frank
UIDVALIDITY is /supposed/ to change, from time to time (ideally as rarely as possible). Message UIDs try to be persistent, so clients can cache them. UIDVALIDITY stays the same as long as the message UIDs remain the same, but changes if the UIDs change. The hypothetical client caches message UIDs along with the UIDVALIDITY, and if it ever gets a /different/ UIDVALIDITY back from the server, it then knows that its cached UIDs are no longer valid, and discards them. The server tries to keep message UIDs the same, but if it ever needs to renumber them for whatever reason, it bumps UIDVALIDITY to indicate it has done so.This is all normal IMAP behaviour.It's strange that Horde would throw this error up to the user, who probably has no idea what it means. IMO they should just discard any now-invalid cached UIDs, and carry on as usual.It's not clear to me whether Horde actually discards its cached UIDs on UIDVALIDITY change, like it's supposed to, or whether it just complains to the user.Either way, there's no indication that Cyrus is doing anything wrong in this case. Whatever shape this problem ends up being, it looks like a Horde problem.Cheers, ellie*Cyrus <https://cyrus.topicbox.com/latest>* / Info / see discussions <https://cyrus.topicbox.com/groups/info> + participants <https://cyrus.topicbox.com/groups/info/members> + delivery options <https://cyrus.topicbox.com/groups/info/subscription> Permalink <https://cyrus.topicbox.com/groups/info/T25c7531b76d23ba0-M2027d1f75cb88e5ba37c020e>
smime.p7s
Description: S/MIME Cryptographic Signature
