FolderNotOpenException

[siberianguy]

I have an app that is requesting emails from a folder every 1 second.

public MailRepository(string mailServer, int port, bool ssl, string login, string password)
       {
           var client = new ImapClient();
           client.Disconnected += (sender, args) => Connect(mailServer, port, ssl, login, password, client);
           Connect(mailServer, port, ssl, login, password, client);
       }

       private void Connect(string mailServer, int port, bool ssl, string login, string password, ImapClient client)
       {
           client.Connect(mailServer, port, ssl);

           // Note: since we don't have an OAuth2 token, disable
           // the XOAUTH2 authentication mechanism.
           client.AuthenticationMechanisms.Remove("XOAUTH2");

           client.Authenticate(login, password);
           
           var inbox = client.GetFolder("TradingView");
               
           inbox.Open(FolderAccess.ReadWrite);

           _inbox = inbox;
       }

       public List<string> GetEmail()
       {
          ....
       }
}

Despite having reconnecting on disconnection, I tend to receive FolderNotOpenException after the program has been working for about 10 hours. Could you hint me how a folder could be closed without disconnect? Any other hint how to handle this situation would be highly appreciated

[jstedfast]

Are you re-opening the folder when you reconnect? That would be my first suspect.

If that's not the problem, are you opening any other folders? IMAP can only have 1 folder open at a time, so if you open a second folder, the the previous folder automatically gets closed.

[siberianguy]

I'm opening the folder as part of reconnect (you can see the Connect method is called as part of OnDisconnected handler) and don't open any other folders. My wild guess is that somehow a folder gets closed without disconnection

[jstedfast]

I can't think of any reason MailKit would randomly close a folder.

[jstedfast]

Okay, did some digging, the problem is probably that ImapClient.Disconnected event is probably not safe to reconnect inside of.

I would recommend against doing that and instead have the event set a flag that you need to reconnect after your command finishes or reconnect before sending your next command.

[jstedfast]

I'll need more specifics as to when exactly this happens (what command were you sending? did the server respond with * BYE to the previous command? What command was the previous command? etc) to even attempt trying ot make this safe to do.

[jstedfast]

I might be able to figure out what is going on based on just a protocol log, but I'm not sure. All the info you can get would be helpful.

[siberianguy]

I've implemented a workaround that "fixed" the problem for me:

        public List<string> GetEmail()
        {
            try
            {
               ...
            }
            catch (FolderNotOpenException ex)
            {
               Log.Logger.Error("Folder was not open - reopening");
                _inbox.Open(FolderAccess.ReadWrite);
                throw;
            }
        }

I would provide a protocol log if there's a chance it will help you.

[jstedfast]

Yea, if you could do that, I might be able to figure out what is going wrong. Ideally, it would be possible to reconnect inside of the Disconnected event handler.

(Note: currently this is just a theory, because I can't think of any other way this could happen)

[siberianguy]

I was finally able to reproduce this behaviour
imap.zip

[jstedfast]

I was hoping the log would show something useful, but I'm not even sure at what point you are getting the FolderNotOpenException. At the end of the log?

I noticed that GMail is throttling you... probably because you are pegging the server with Status (MessageStatusItems.Unseen) requests. You might want to back off on the polling a bit.

I'm not sure what the performance penalty of Status() is on GMail, but in general, it's slow because it has to open the folder, count the messages and then return. Since you already have the folder open, a more efficient way of being notified of new (unseen) messages is to simply use the NoOp() method and listen for the CountChanged event.

My guess is that for GMail, it probably doesn't matter... just a note for future reference.

[siberianguy]

Thanks for your feedback! Yeah, I definitely poll too much and I plan to rework my code similar to the Idle sample soon. Just wanted to share an unexpected behaviour

[jstedfast]

Are you using the standard/synchronous API, the Async() API, or a mix?

[siberianguy]

I'm usjng the syncronous Api in a background thread. Here's all I do once a second:

        public List<string> GetUnreadMailSubjects(bool firstRun)
        {
            try
            {
                var subjects = new List<string>();

                _inbox.Status(StatusItems.Unread);

                if (_inbox.Unread == 0) //no new messages
                    return new List<string>();

                var headers = new HashSet<HeaderId>(new[] {HeaderId.Subject});

                var index = Math.Max(_inbox.Count - _inbox.Unread, 0);

                var items = _inbox.Fetch(index, -1, MessageSummaryItems.UniqueId, headers);

                if (!firstRun) //on the first run we just mark all the signals we've missed as read
                {
                    foreach (var item in items)
                    {
                        if (_alreadReadUniqueIds.Contains(item.UniqueId))
                            continue;
                    
                        var subject = item.Headers[HeaderId.Subject];

                        subjects.Add(subject);
                    }
                }

                var uniqueIds = items.Select(x => x.UniqueId).ToList();
                _alreadReadUniqueIds.AddRange(uniqueIds);
                _inbox.AddFlags(uniqueIds, MessageFlags.Seen, true);

                return subjects;
            }
            catch (FolderNotOpenException ex)
            {
                Log.Logger.Error("Folder was not open - reopening");
                _inbox.Open(FolderAccess.ReadWrite);
                throw;
            }
        }

[jstedfast]

What about for your Connect/Authenticate/Open calls? Are those also sync? or are those Async?

BTW, something I noticed in your logs, is that your code continues to examine the same message over and over again because for some reason, GMail is telling you (UNSEEN 1) in every loop iteration and then you FETCH the exact same message as the previous loop and mark it as \Seen. Over and over and over again.

Somehow GMail is not properly recording that transaction between loops (probably because GMail's STATUS info is cached?).

To illustrate what I'm saying:

C: D00000006 STATUS TradingView (UNSEEN)
S: * STATUS "TradingView" (UNSEEN 1)
S: D00000006 OK Success [THROTTLED]
C: D00000007 FETCH 9677:* (UID BODY.PEEK[HEADER.FIELDS (SUBJECT)])
S: * 9677 FETCH (UID 12783 MODSEQ (26135634) BODY[HEADER.FIELDS (SUBJECT)] {43}
S: Subject: TradingView Alert: BUY EOS/USD
S: 
S: )
S: D00000007 OK Success [THROTTLED]
C: D00000008 UID STORE 12783 +FLAGS.SILENT (\Seen)
S: D00000008 OK Success [THROTTLED]
C: D00000009 STATUS TradingView (UNSEEN)
S: * STATUS "TradingView" (UNSEEN 1)
S: D00000009 OK Success [THROTTLED]
C: D00000010 FETCH 9677:* (UID BODY.PEEK[HEADER.FIELDS (SUBJECT)])
S: * 9677 FETCH (UID 12783 MODSEQ (26135634) BODY[HEADER.FIELDS (SUBJECT)] {43}
S: Subject: TradingView Alert: BUY EOS/USD
S: 
S: )
S: D00000010 OK Success [THROTTLED]
C: D00000011 UID STORE 12783 +FLAGS.SILENT (\Seen)
S: D00000011 OK Success [THROTTLED]
C: D00000012 STATUS TradingView (UNSEEN)
S: * STATUS "TradingView" (UNSEEN 1)
S: D00000012 OK Success [THROTTLED]

This just repeats over 6,000 times.

I would suggest this better alternative:

public List<string> GetUnreadMailSubjects(bool firstRun)
{
    try
    {
        var uids = _inbox.Search (SearchQuery.NotSeen);
        var subjects = new List<string> ();

        if (uids.Count == 0)
            return subjects;

        var headers = new HashSet<HeaderId> (new[] { HeaderId.Subject });
        var items = _inbox.Fetch (uids, MessageSummaryItems.UniqueId, headers);

        if (!firstRun) //on the first run we just mark all the signals we've missed as read
        {
            foreach (var item in items)
            {
                var subject = item.Headers[HeaderId.Subject];
                subjects.Add(subject);
            }
        }

        _inbox.AddFlags (uids, MessageFlags.Seen, true);

        return subjects;
    }
    catch (FolderNotOpenException ex)
    {
        Log.Logger.Error("Folder was not open - reopening");
        _inbox.Open(FolderAccess.ReadWrite);
        throw;
    }
}

[jstedfast]

Heh, FWIW, it took 16768 (or more) loops before GMail decided to throttle my connection. Just interesting info.

[siberianguy]

We did have a problem with that one mystical unread email. So the idea is that we read unread emails, mark them as read and then do it again every second (definitely worse than subscribing to an event). And there was one unread email somewhere in between that messed everything up. I will use the improvements you kindly shared for now but will rework to Idle when I have a chance

[jstedfast]

Oh, interesting. I wonder if GMail is just bugged out for that particular message, then?

[siberianguy]

I don't think so. Here's how, I think it happened:

1. We request an amount of unread emails and receive, let's say, 2
2. We read the two last emails
3. Right between step 1 and 2 another email arrived
4. We mark the first two emails as read but the third ghost-email is still unread and it will always stay unread as we read only UnSeen amount from the top

Just not a very good idea of processing new emails...

[jstedfast]

Oh, yea, that makes sense... my code snippet above will avoid that scenario fwiw.

[jstedfast]

All I can think of is that the Disconnected handler is running in a thread other than the thread your loop is running in and somehow the loop is accessing the folder before the Disconnected event handler finishes reconnecting/opening the folder.

I haven't been able to reproduce...

[jstedfast]

Never mind, I think I figured out your problem :)

Here's what I think is happening:

When the ImapEngine (where the core IMAP logic lives) gets disconnected, it emits its own Disconnected event. The ImapClient and the ImapFolder both have handlers for this event.

Depending on which order these handlers were added to the ImapEngine.Disconnected event, they would run in different orders.

The ImapClient's handler raises its own Disconnected event which is what you are using to re-connect the ImapClient and re-open the folder.

But... the ImapFolder's handler sets folder.Access = FolderAccess.None because when the server gets disconnected, obviously it's the same as getting closed.

When you are hitting this FolderNotOpenException case, it's because the ImapFolder event is running after you've reconnected and reopened the folder.

I actually just committed some changes to the ImapEngine Disconnect logic that should fix this and it occurred to me afterward that this is probably why I haven't been able to reproduce, lol.

Ok, well, I guess it's fixed now.

[siberianguy]

Interesting... I'm glad we both fixed some problems in our code :) Is there an updated Nuget with the new changes? If yes, I would try to remove the try-catch I had and deploy it to production to test it our

[jstedfast]

Not yet. I'm hoping to make a new release this coming weekend. I had planned on making a release this past weekend but got side-tracked with writing a bunch more unit tests (from 70.5% unit test coverage to 80.3% coverage).

I will likely spend the next few nights pumping out some more tests and hopefully hit 85% coverage, then I'll make a release.

Either way I'll make a release this weekend, even if I don't hit my 85% target.

[jstedfast]

I've just made a release of 2.0.7 with the fix that seemed to work for me. Hopefully it works for you as well :)

[siberianguy]

Thanks! I've upgraded the package, removed my reopening hack and deployed to the server. Will let you know if the problem manages to come back (hopefully not)

[siberianguy]

I found an interesting behaviour. So I've used the solution you offered above and currently what I see is that inbox.Search(NotSeen) returns zero elements despite there's an unread email. It doesn't happen at first (at launch the emails are read) but it happens later (I guess after a bunch of reconnects). There're no exception, the folder is seemingly open and just returns empty array of subjects. I'm not sure whether it's related to the last update or has to do with the way Search works in general. Unfortunately I've disabled the imap.log but I may enable it again if it might help

[jstedfast]

Re-enabling the imap.log would be the easiest way to figure out what is going wrong. If you could do that, that would be hugely helpful.