Re: Move mails between folders on different backend servers

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] 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
> *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> 
>

This is a multi-part message in MIME format...

------------=_1652102116-220731-1--