2nd try: Thunderbird "Empty Trash" causes inconsistent IMAP session state?

[awl1]

Hello Aki,

do you have any news on this issue in the meantime?

Thanks & best regards
Andreas


Am 07.06.2017 um 22:30 schrieb awl1:
>
> Sorry, just one more thing I've just noticed now from looking at the 
> IMAP session IDs:
>
> Dovecot seems to map the steps as outlined below to four different 
> IMAP session IDs all related to the exact same Thunderbird client 
> instance:
>
>   * <yH0lKWRRpNHAqOh5> session for the folder copy of folder "Dilbert"
>     with 317 messages
>   * <VcMlLWRRqNHAqOh5> session for the deletion of folder "Dilbert"
>     into Trash
>   * </qSFLWRRqtHAqOh5> session from which the empty Trash seems to be
>     run and which ends up in "inconsistent state"
>   * <HHmhLWRRrNHAqOh5> another session seemingly accessing the Trash
>     folder for which I am unable to determine its exact purpose
>
> Maybe the issue is that the fourth session should not even exist or at 
> least has a race condition with the third one?
>
> Thanks again & best regards
> Andreas
>
>
> Am 07.06.2017 um 22:19 schrieb awl1:
>> Hello Aki,
>>
>> please find attached the debug log from another incident, this time 
>> with IMAP session ID (<yH0lKWRRpNHAqOh5>) in the logs and with 
>> "mail_debug=yes" in dovecot.conf.
>>
>> I can consistently reproduce the "inconsistent state" error message 
>> by the following steps from the most recent Thunderbird version 
>> (52.1.1, on 64-bit Linux Ubuntu 16.04.02 LTS):
>>
>>  * copy a folder (in the sample log: named "Dilbert") with several mail
>>    messages from my mail provider remote IMAP account into my local
>>    Dovecot archive account
>>  * delete this folder from the Dovecot archive account into the Trash
>>    folder
>>  * empty the Trash folder from Thunderbird
>>  * immediately, the message about "inconsistent IMAP session state"
>>    appears in the dovecot-info.log
>>
>> In case the log even with mail_debug=yes again is no real help (which 
>> I fear to be the case, as to me, the log looks very similar to the 
>> previous log), would you be able to insert some additional debug log 
>> statements into Dovecot code at some appropriate places, and let me 
>> try again with such an additional debug version?
>>
>> Many thanks & best regards
>> Andreas
>>
>>
>> Am 07.06.2017 um 07:57 schrieb Aki Tuomi:
>>> That log didn't do much help, can you try enabling mail_debug=yes 
>>> for a moment and see if it gives any more insight? Aki On 05.06.2017 
>>> 15:13, awl1 wrote:
>>>> Hello again,
>>>>
>>>> here you are (log excerpt from May 29 00:06:02 until May 29 01:17:49):
>>>>
>>>> May 29 00:12:05 imap(xxx at xxx.org): Info: IMAP session state is
>>>> inconsistent, please relogin. in=1369 out=222662
>>>> May 29 00:12:05 imap(xxx at xxx.org): Info: IMAP session state is
>>>> inconsistent, please relogin. in=204 out=1504
>>>> May 29 00:40:29 imap(xxx at xxx.org): Info: IMAP session state is
>>>> inconsistent, please relogin. in=1213 out=6414
>>>> May 29 00:40:30 imap(xxx at xxx.org): Info: IMAP session state is
>>>> inconsistent, please relogin. in=227 out=1430
>>>>
>>>>
>>>> I'd still be interested anyway in what I'd have t do in order to add
>>>> the session ID to my future log files. Is this documented anywhere?
>>>>
>>>> https://wiki.dovecot.org/Variables does not help enough with regards
>>>> to how to apply it to logfile settings in dovecot.conf... :-(
>>>>
>>>>
>>>> Thanks again & best regards
>>>> Andreas
>>>>
>>>>
>>>> Am 05.06.2017 um 13:50 schrieb Aki Tuomi:
>>>>> Yes, that would help too.
>>>>>
>>>>> Aki
>>>>>
>>>>>
>>>>> On 05.06.2017 14:35, awl1 wrote:
>>>>>> Hello Aki,
>>>>>>
>>>>>> sorry, but I am still a newbie to Dovecot:
>>>>>>
>>>>>> Hmm - I don't seem to have IMAP session IDs in every line of my
>>>>>> dovecot-info.log. that could be used to extract IMAP session-related
>>>>>> info.
>>>>>>
>>>>>> I assume that I have to set up logging in a specific way to add and
>>>>>> then find the IMAP session ID in my logs. Could you please point 
>>>>>> me to
>>>>>> the docs about how to configure this for the future?
>>>>>>
>>>>>> What I can offer now from my old logs is to provide log file 
>>>>>> excerpts
>>>>>> from some minutes/seconds before the "Empty Trash" action caused the
>>>>>> "inconsistent IMPA state" message until shortly after - would that
>>>>>> help as well!?
>>>>>>
>>>>>> Best regards & apologies
>>>>>> Andreas
>>>>>>
>>>>>>
>>>>>> Am 05.06.2017 um 13:13 schrieb Aki Tuomi:
>>>>>>> Can you provide full logs for the imap session? Basically you 
>>>>>>> can do
>>>>>>> grep session-id logfile.
>>>>>>>
>>>>>>> Aki
>>>>
>>
>