K-9 Mail sync hangs when Dovecot reports "corrupted record in index cache file"

cketti · December 16, 2021, 6:42am

It’s still not clear to me what exactly caused the behavior you were seeing. Without being able to reproduce the issue it’s very hard to fix the problem. I’d be guessing. And since you’ve fixed your server, you wouldn’t be able to test potential fixes either. So for now this will remain unfixed.

If this was caused by the server sending improper IMAP responses, I don’t expect many people to run into this.

puterboy · December 16, 2021, 3:10pm

I could test potential fixes since I saved the corrupted dovecot server files and caches.

Are you able to share with me (or point me to) the portion of the code that is relevant so I can take a look and see if maybe I can figure out where/why it is hanging. Not that I am a code expert but sometimes a second set of eyes can help.

cketti · December 16, 2021, 4:43pm

The FETCH command is sent here:

github.com

k9mail/k-9/blob/b425ec527416c9e0b427d11696df76385b2de0eb/mail/protocols/imap/src/main/java/com/fsck/k9/mail/store/imap/RealImapFolder.kt#L573

    
      
          
          
val spaceSeparatedFetchFields = ImapUtility.join(" ", fetchFields)
          var windowStart = 0
          while (windowStart < messages.size) {
              val windowEnd = min(windowStart + FETCH_WINDOW_SIZE, messages.size)
              val uidWindow = uids.subList(windowStart, windowEnd)
          
          
    try {
                  val commaSeparatedUids = ImapUtility.join(",", uidWindow)
                  val command = String.format("UID FETCH %s (%s)", commaSeparatedUids, spaceSeparatedFetchFields)
                  connection!!.sendCommand(command, false)
          
          
        var messageNumber = 0
                  var callback: ImapResponseCallback? = null
                  if (fetchProfile.contains(FetchProfile.Item.BODY) ||
                      fetchProfile.contains(FetchProfile.Item.BODY_SANE)
                  ) {
                      callback = FetchBodyCallback(messageMap)
                  }
          
          
        var response: ImapResponse

The responses are read here (and since there’s no log output of a complete response line being read, the app most likely hangs when calling this method for the first time):

github.com

k9mail/k-9/blob/b425ec527416c9e0b427d11696df76385b2de0eb/mail/protocols/imap/src/main/java/com/fsck/k9/mail/store/imap/RealImapFolder.kt#L585

    
      
          var messageNumber = 0
          var callback: ImapResponseCallback? = null
          if (fetchProfile.contains(FetchProfile.Item.BODY) ||
              fetchProfile.contains(FetchProfile.Item.BODY_SANE)
          ) {
              callback = FetchBodyCallback(messageMap)
          }
          
          
var response: ImapResponse
          do {
              response = connection!!.readResponse(callback)
              if (response.tag == null && ImapResponseParser.equalsIgnoreCase(response[1], "FETCH")) {
                  val fetchList = response.getKeyedValue("FETCH") as ImapList
                  val uid = fetchList.getKeyedString("UID")
          
          
        val message = messageMap[uid]
                  if (message == null) {
                      if (K9MailLib.isDebug()) {
                          Timber.d("Do not have message in messageMap for UID %s for %s", uid, logId)
                      }
                      handleUntaggedResponse(response)

If you’re up for building the app yourself, I’m happy to jump on a video call to walk you through debugging this issue.

puterboy · December 22, 2021, 8:29am

I spun up a virtual machine to play around with the corrupted imap messages on my server.
This allowed me to reliably reproduce the error on the K9 app as well as to see the errors generated on my dovecot server logs

myserver dovecot: imap(username): Error: Corrupted record in index cache file /home/username/mail-imap/.imap/Sent/dovecot.index.cache: UID 112: Broken physical size in mailbox Sent: read(/home/username/mail-imap/Sent) failed: Cached message size smaller than expected (32262 < 32619, box=Sent, UID=112)

myserver dovecot: imap(username): Error: read(/home/username/mail-imap/Sent) failed: Cached message size smaller than expected (32262 < 32619, box=Sent, UID=112) (FETCH BODY for mailbox Sent UID 112)

I capture the response to the following dovecot fetch command and sent it to you via private email.

UID FETCH 112 BODY.PEEK)

The message concludes with a text/html base64 encoded MIME attachment that is cut off midstream, ending in ‘—’ without any concluding ‘)’
The final 3 characters ‘—’ are illegal base64 characters and the absence of a closing parentheses implies that the fetch command return is never properly terminated… Presumably, this confuses/freezes K9 from receiving (or sending) further IMAP commands to the affected server (or indeed any other listed IMAP server).

Note that the corruption on this one email server prevents K9 from loading new emails from this and ANY OTHER email server that K9 polls/pushes. And when I do try to poll a server manually, the wheel just spins for awhile until it presumably timesout.

However, I can still:

Navigate among K9 screens and features on the app itself (so the app is not frozen)
Scroll and read messages that were previously downloaded
Compose and seemingly send messages but they get STUCK in the
outbox

Restarting the app (even without clearing the cache) causes the app to
resume fetching mail properly and posts the mails that were stuck in
the outbox.

I should add that my VM will allow me to test or debug any new
versions of K9 mail against this corrupted email.

puterboy · January 1, 2022, 10:46pm

Did you get the email I sent you (privately) with an attachment containing the broken dovecot imap folder that you can use to replicate the problem?

puterboy · January 2, 2022, 2:46am

OK - I just replied again to your email but not sure if it is getting to you. If not can you share with me an email address that does work (the one I have says: noreply@forum.k9mail.app)

cketti · January 2, 2022, 3:04am

The email address is debugging@cketti.de

puterboy · January 14, 2022, 8:09am

Did you get the emails i sent to debugging@cketti.de?

cketti · January 14, 2022, 3:47pm

Yes. Unfortunately, I don’t think the emails contain enough information for me to reproduce the issue.

But currently this issue is also not a priority for me. It seems very unlikely that a lot of people will run into a similar problem.

dfskoll · May 14, 2023, 12:35pm

FWIW, I just hit this problem too, with the latest K-9 mail.