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
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:
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"]
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] Completed
I 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
Attachment:
smime.p7s
Description: S/MIME Cryptographic Signature
