Bug 366498 - InvalidResponseCode due to a 64bit UIDNEXT
Summary: InvalidResponseCode due to a 64bit UIDNEXT
Status: RESOLVED UPSTREAM
Alias: None
Product: trojita
Classification: Unmaintained
Component: IMAP (show other bugs)
Version: unspecified
Platform: Slackware Linux
: NOR critical
Target Milestone: ---
Assignee: Trojita default assignee
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2016-08-07 17:36 UTC by Paul D Mallett
Modified: 2016-11-24 10:54 UTC (History)
1 user (show)

See Also:
Latest Commit:
Version Fixed In:
Sentry Crash Report:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Paul D Mallett 2016-08-07 17:36:16 UTC
The IMAP server sent us a reply which we could not parse. This might either mean that there's a bug in Trojitá's code, or that the IMAP server you are connected to is broken. Please report this as a bug anyway. Here are the details:
InvalidResponseCode: InvalidResponseCode
* OK [UIDVALIDITY 42036101441452023] UIDs valid
Comment 1 Paul D Mallett 2016-08-07 17:39:58 UTC
O/S Proteus running on USB stick. Email providor usa.net . Folders retrieved with numeric count but no email.
Comment 2 paalsteek 2016-08-08 15:44:41 UTC
Could you please provide the IMAP-Log? (IMAP->Debugging->Log into ... or IMAP->Debugging->Show IMAP protocol log, check that you provide the most current log containing the error, which should be the last tab)
Also notice that the log might contain sensitive information (the password is never logged though). You can also send the log directly via mail.
Comment 3 Paul D Mallett 2016-08-08 19:35:05 UTC
Log as requested
19:03:15.627 <<< * OK [UIDVALIDITY 22036101441452023] UIDs valid␍␊
19:03:15.627 <<< * OK [UIDVALIDITY 22036101441452023] UIDs valid␍␊* OK [UNSEEN 0]␍␊
19:03:15.627 <<< * OK [UIDVALIDITY 22036101441452023] UIDs valid␍␊* OK [UNSEEN 0]␍␊* OK [UIDNEXT 1]␍␊
19:03:15.627 <<< * OK [UIDVALIDITY 22036101441452023] UIDs valid␍␊* OK [UNSEEN 0]␍␊* OK [UIDNEXT 1]␍␊y17 OK [READ-WRITE] SELECT completed for Draft␍␊
19:03:15.628 InvalidResponseCode InvalidResponseCode␊* OK [UIDVALIDITY 22036101441452023] UIDs valid␍␊␊                                     ^ here
19:03:15.628 Imap::Mailbox::KeepMailboxOpenTask attached to Draft Failed: Asked to die
19:03:15.628 Imap::Mailbox::ObtainSynchronizedMailboxTask STATE_SELECTING Draft Failed: Asked to die
19:03:15.630 *** Connection killed.
Comment 4 Thomas Lübking 2016-08-08 20:50:06 UTC
Can you please provide more log data, ideally all, but at least starting w/ the matching SELECT call (ie ">>> y17" in *this* case, could be a differet tag in another try)
The reply looks incomplete (at least FLAGS, EXISTS, and RECENT should be in there), but that could also just be a capped log.


The main problem here though will be that UIDVALIDITY "slightly" exceeds 32 bits.
At least I read https://tools.ietf.org/html/rfc3501#section-2.3.1.1 as 32bit "UIDVALIDITY"  + 32bit UID 

Jan will know for sure and might reply next week or by the end of the month.
Comment 5 Paul D Mallett 2016-08-09 21:12:10 UTC
Guess what, if I scroll back we get a lot more. Sorry about that.........
20:49:25.673 Imap::Mailbox::OpenConnectionTask OpenConnectionTask:  Activated
20:49:25.723 *** Looking up imap.postoffice.net...
20:49:25.723 conn Resolving hostname...
20:49:26.082 *** Connecting to imap.postoffice.net:143...
20:49:26.082 conn Connecting to the IMAP server...
20:49:26.225 *** Connection established
20:49:26.225 *** Connected
20:49:26.225 conn Checking capabilities...
20:49:26.365 <<< * OK IMAP4rev1 ca22 7134 1bdeuYz031 server ready␍␊
20:49:26.365 conn Waiting for encryption...
20:49:26.366 >>> y0 CAPABILITY␍␊
20:49:26.512 <<< * CAPABILITY IMAP4REV1 STARTTLS NAMESPACE CHILDREN UIDPLUS IDLE␍␊
20:49:26.512 <<< y0 OK CAPABILITY completed␍␊
20:49:26.512 conn Asking for encryption...
20:49:26.513 >>> y1 STARTTLS␍␊
20:49:26.655 *** STARTTLS
20:49:26.656 <<< y1 OK Begin TLS negotiation now␍␊
20:49:26.656 conn Starting encryption (STARTTLS)...
20:49:27.144 *** [Socket is encrypted now; 1 errors: The root certificate of the certificate chain is self-signed, and untrusted (CN: Entrust Root Certification Authority) ]
20:49:27.144 conn Checking certificates (STARTTLS)...
20:49:27.148 conn Checking capabilities (after STARTTLS)...
20:49:27.148 >>> y2 CAPABILITY␍␊
20:49:27.293 <<< * OK IMAP4rev1 ca22 7134 1bdeuYz031 server ready␍␊
20:49:27.472 <<< * CAPABILITY IMAP4REV1 NAMESPACE CHILDREN UIDPLUS IDLE␍␊
20:49:27.473 <<< y2 OK CAPABILITY completed␍␊
20:49:27.473 conn Logging in...
20:49:39.432 >>> [LOGIN command goes here]
20:49:39.590 <<< y3 OK LOGIN completed␍␊
20:49:39.590 conn Checking capabilities (after login)...
20:49:39.591 >>> y4 CAPABILITY␍␊
20:49:39.738 <<< * CAPABILITY IMAP4REV1 NAMESPACE CHILDREN UIDPLUS IDLE␍␊
20:49:39.738 <<< y4 OK CAPABILITY completed␍␊
20:49:39.738 conn Logged in.
20:49:39.739 Imap::Mailbox::OpenConnectionTask OpenConnectionTask: Logged in. Completed
20:49:39.739 Imap::Mailbox::GetAnyConnectionTask Activated
20:49:39.740 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:39.740 Imap::Mailbox::ListChildMailboxesTask Listing stuff below mailbox  Activated
20:49:39.741 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:39.741 Imap::Mailbox::NumberOfMessagesTask attached to INBOX Activated
20:49:39.742 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:39.742 Imap::Mailbox::NumberOfMessagesTask attached to Draft Activated
20:49:39.742 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:39.743 Imap::Mailbox::NumberOfMessagesTask attached to Junk Mail Activated
20:49:39.743 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:39.744 Imap::Mailbox::NumberOfMessagesTask attached to Sent Activated
20:49:39.744 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:39.744 Imap::Mailbox::NumberOfMessagesTask attached to Trash Activated
20:49:39.745 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:39.745 Imap::Mailbox::ListChildMailboxesTask Listing stuff below mailbox  Activated
20:49:39.746 >>> y5 LIST "" "%"␍␊
20:49:39.746 >>> y6 STATUS INBOX (MESSAGES UNSEEN RECENT)␍␊
20:49:39.746 >>> y7 STATUS Draft (MESSAGES UNSEEN RECENT)␍␊
20:49:39.746 >>> y8 STATUS "Junk Mail" (MESSAGES UNSEEN RECENT)␍␊
20:49:39.746 >>> y9 STATUS Sent (MESSAGES UNSEEN RECENT)␍␊
20:49:39.746 >>> y10 STATUS Trash (MESSAGES UNSEEN RECENT)␍␊
20:49:39.746 >>> y11 LIST "" "%"␍␊
20:49:39.894 <<< * LIST (\HasNoChildren) "/" "Draft"␍␊
20:49:39.895 <<< * LIST (\HasNoChildren) "/" "Inbox"␍␊
20:49:39.895 <<< * LIST (\HasNoChildren) "/" "Junk Mail"␍␊
20:49:39.895 <<< * LIST (\HasNoChildren) "/" "Sent"␍␊
20:49:39.895 <<< * LIST (\HasNoChildren) "/" "Trash"␍␊
20:49:40.025 <<< y5 OK LIST completed␍␊
20:49:40.025 <<< * STATUS "Inbox" (MESSAGES 140 RECENT 11 UNSEEN 138)␍␊
20:49:40.025 <<< y6 OK STATUS completed␍␊
20:49:40.025 <<< * STATUS "Draft" (MESSAGES 0 RECENT 0 UNSEEN 0)␍␊
20:49:40.025 <<< y7 OK STATUS completed␍␊
20:49:40.026 <<< * STATUS "Junk Mail" (MESSAGES 2 RECENT 2 UNSEEN 2)␍␊
20:49:40.026 <<< y8 OK STATUS completed␍␊
20:49:40.026 <<< * STATUS "Sent" (MESSAGES 0 RECENT 0 UNSEEN 0)␍␊
20:49:40.026 <<< y9 OK STATUS completed␍␊
20:49:40.027 Imap::Mailbox::ListChildMailboxesTask Listing stuff below mailbox  Completed
20:49:40.027 Imap::Mailbox::NumberOfMessagesTask [invalid mailboxIndex] Completed
20:49:40.028 Imap::Mailbox::NumberOfMessagesTask [invalid mailboxIndex] Completed
20:49:40.028 Imap::Mailbox::NumberOfMessagesTask [invalid mailboxIndex] Completed
20:49:40.028 Imap::Mailbox::NumberOfMessagesTask [invalid mailboxIndex] Completed
20:49:40.032 Imap::Mailbox::GetAnyConnectionTask Activated
20:49:40.033 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:40.033 Imap::Mailbox::NumberOfMessagesTask attached to INBOX Activated
20:49:40.035 Imap::Mailbox::GetAnyConnectionTask Activated
20:49:40.036 Imap::Mailbox::GetAnyConnectionTask Activated
20:49:40.037 Imap::Mailbox::GetAnyConnectionTask Activated
20:49:40.038 Imap::Mailbox::GetAnyConnectionTask Activated
20:49:40.040 >>> y12 STATUS INBOX (MESSAGES UNSEEN RECENT)␍␊
20:49:40.040 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:40.041 Imap::Mailbox::NumberOfMessagesTask attached to Draft Activated
20:49:40.041 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:40.041 Imap::Mailbox::NumberOfMessagesTask attached to Junk Mail Activated
20:49:40.042 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:40.042 Imap::Mailbox::NumberOfMessagesTask attached to Sent Activated
20:49:40.042 Imap::Mailbox::GetAnyConnectionTask Completed
20:49:40.043 Imap::Mailbox::NumberOfMessagesTask attached to Trash Activated
20:49:40.044 >>> y13 STATUS Draft (MESSAGES UNSEEN RECENT)␍␊
20:49:40.044 >>> y14 STATUS "Junk Mail" (MESSAGES UNSEEN RECENT)␍␊
20:49:40.044 >>> y15 STATUS Sent (MESSAGES UNSEEN RECENT)␍␊
20:49:40.044 >>> y16 STATUS Trash (MESSAGES UNSEEN RECENT)␍␊
20:49:40.076 <<< * STATUS "Trash" (MESSAGES 22 RECENT 22 UNSEEN 22)␍␊
20:49:40.076 <<< y10 OK STATUS completed␍␊
20:49:40.076 <<< * LIST (\HasNoChildren) "/" "Draft"␍␊
20:49:40.076 <<< * LIST (\HasNoChildren) "/" "Inbox"␍␊
20:49:40.076 <<< * LIST (\HasNoChildren) "/" "Junk Mail"␍␊
20:49:40.076 <<< * LIST (\HasNoChildren) "/" "Sent"␍␊
20:49:40.076 <<< * LIST (\HasNoChildren) "/" "Trash"␍␊
20:49:40.076 <<< y11 OK LIST completed␍␊
20:49:40.076 Imap::Mailbox::NumberOfMessagesTask [invalid mailboxIndex] Completed
20:49:40.077 Imap::Mailbox::ListChildMailboxesTask Listing stuff below mailbox  Completed
20:49:40.256 <<< * STATUS "Inbox" (MESSAGES 140 RECENT 11 UNSEEN 138)␍␊
20:49:40.256 <<< y12 OK STATUS completed␍␊
20:49:40.256 Imap::Mailbox::NumberOfMessagesTask [invalid mailboxIndex] Completed
20:49:40.396 <<< * STATUS "Draft" (MESSAGES 0 RECENT 0 UNSEEN 0)␍␊
20:49:40.396 <<< y13 OK STATUS completed␍␊
20:49:40.396 <<< * STATUS "Junk Mail" (MESSAGES 2 RECENT 2 UNSEEN 2)␍␊
20:49:40.397 <<< y14 OK STATUS completed␍␊
20:49:40.397 Imap::Mailbox::NumberOfMessagesTask [invalid mailboxIndex] Completed
20:49:40.397 Imap::Mailbox::NumberOfMessagesTask [invalid mailboxIndex] Completed
20:49:40.537 <<< * STATUS "Sent" (MESSAGES 0 RECENT 0 UNSEEN 0)␍␊
20:49:40.537 <<< y15 OK STATUS completed␍␊
20:49:40.537 <<< * STATUS "Trash" (MESSAGES 22 RECENT 22 UNSEEN 22)␍␊
20:49:40.537 <<< y16 OK STATUS completed␍␊
20:49:40.537 Imap::Mailbox::NumberOfMessagesTask [invalid mailboxIndex] Completed
20:49:40.538 Imap::Mailbox::NumberOfMessagesTask [invalid mailboxIndex] Completed
20:49:46.544 Imap::Mailbox::ObtainSynchronizedMailboxTask STATE_WAIT_FOR_CONN INBOX Activated
20:49:46.545 Imap::Mailbox::ObtainSynchronizedMailboxTask STATE_SELECTING INBOX Synchronizing mailbox
20:49:46.547 >>> y17 SELECT INBOX␍␊
20:49:46.798 <<< * FLAGS (\Answered \Flagged \Deleted \Seen \Draft)␍␊
20:49:46.939 <<< * 140 EXISTS␍␊
20:49:46.939 <<< * 11 RECENT␍␊
20:49:46.939 <<< * OK [UIDVALIDITY 42036101441452023] UIDs valid␍␊
20:49:46.940 <<< * OK [UIDVALIDITY 42036101441452023] UIDs valid␍␊* OK [UNSEEN 1]␍␊
20:49:46.940 <<< * OK [UIDVALIDITY 42036101441452023] UIDs valid␍␊* OK [UNSEEN 1]␍␊* OK [UIDNEXT 150]␍␊
20:49:46.940 <<< * OK [UIDVALIDITY 42036101441452023] UIDs valid␍␊* OK [UNSEEN 1]␍␊* OK [UIDNEXT 150]␍␊y17 OK [READ-WRITE] SELECT completed for Inbox␍␊
20:49:46.940 InvalidResponseCode InvalidResponseCode␊* OK [UIDVALIDITY 42036101441452023] UIDs valid␍␊␊                                     ^ here
20:49:46.940 Imap::Mailbox::KeepMailboxOpenTask attached to INBOX Failed: Asked to die
20:49:46.940 Imap::Mailbox::ObtainSynchronizedMailboxTask STATE_SELECTING INBOX Failed: Asked to die
20:49:46.943 *** Connection killed.
Comment 6 Jan Kundrát 2016-08-12 09:30:50 UTC
(In reply to Thomas Lübking from comment #4)
> The main problem here though will be that UIDVALIDITY "slightly" exceeds 32 bits.

Yes, the IMAP server is violating the IMAP protocol specification in a pretty basic aspect. The best we could do is treating this as if UIDVALIDITY was not present at all which would mean that Trojita will re-download everything over and over again anytime a mailbox gets opened.

I do not think that this is worth our time, but patches are welcome if someone cares enough.
Comment 7 Paul D Mallett 2016-08-12 10:12:35 UTC
Thanks for the answer, would usa.net be able to draw the same conclusion from my log file? I was going to have ago at them about this, if as you say this is a standard protocol they should comply? Well I can try.
Comment 8 Jan Kundrát 2016-08-12 10:42:19 UTC
Yes, telling them that the following line violates https://tools.ietf.org/html/rfc3501#section-2.3.1.1 might help them fix their software.

  * OK [UIDVALIDITY 42036101441452023] UIDs valid␍␊
Comment 9 Paul D Mallett 2016-08-15 20:54:49 UTC
   Jan

   Just to complete this one; usa.net got back to me....

   "Good Day, we already received an answer from our Systems Engineer and
   they already created a "Jira Ticket - HCMS-699" meaning that this is a
   known issue and they already on the process of fixing this specific
   issue."

   No time scale but good news, once again thanks for your help.

   Paul

   Paul D. Mallett
   Sandbach, Seale Lane, Seale, Farnham, Surrey. GU10 1PR
   United Kingdom
   PHN:  +44 (0)1252 782084
   MBL:  +44 (0)7836 273377
   SKP:   pauldmallett
   NET:         pauldmallett@usa.net [1]   

   On 12/08/16 11:42, Jan Kundrát via KDE Bugzilla wrote:

     https://bugs.kde.org/show_bug.cgi?id=366498          
     --- Comment #8 from Jan Kundrát      <jkt@kde.org> [2]      ---
     Yes, telling them that the following line violates     https://tools.ietf.org/html/rfc3501#section-2.3.1.1      might help them fix their
     software.
     
       * OK [UIDVALIDITY 42036101441452023] UIDs valid␍␊


   


   1. mailto:pauldmallett@usa.net
   2. mailto:jkt@kde.org
Comment 10 Jan Kundrát 2016-11-24 09:35:01 UTC
Somebody else's bug -> closing.
Comment 11 Paul D Mallett 2016-11-24 10:54:22 UTC
Thank you for closing this bug. This is a problem with the IMAP server not the software I should have reported back as soon as I established where the problem lay.