Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

The ImapClient is currently busy processing a command in another thread #613

Closed
Ceus opened this issue Dec 30, 2017 · 31 comments
Closed

The ImapClient is currently busy processing a command in another thread #613

Ceus opened this issue Dec 30, 2017 · 31 comments
Labels
question A question about how to do something

Comments

@Ceus
Copy link

Ceus commented Dec 30, 2017

  • What were you trying to do?
    Previously in 1.22.0, I was successfully able to listen for notifications without using IDLE and just NoOp. When an event is triggered, I would search the Inbox for any unseen items (if there were any) and if there were new items, it would parse the new messages.

  • What happened?
    After updating to 2.0.0
    When attempting to Fetch the items in the Inbox, I am getting the following message

The ImapClient is currently busy processing a command in another thread. Lock the SyncRoot property to properly synchronize your threads.

This message occurs at the following commands under the EventHandler.

public static async void OnMessageFlagsChanged(object sender, MessageFlagsChangedEventArgs e)
{
        var folder = (ImapFolder)sender;
            
        IList<IMessageSummary> summaries;
        var query = SearchQuery.SubjectContains("New message").And(SearchQuery.NotSeen);
        var uids = await folder.SearchAsync(query); // <-- This is where it breaks

Oddly enough, I downgraded back to 1.22.0, and my issue went away, and everything works as I had expected.

Connected to imaps://outlook.office365.com:993/
S: * OK The Microsoft Exchange IMAP4 service is ready. [RABNADUAUABSADIAMQBDAEEAMAAwADIAMgAuAG4AYQBtAHAAcgBkADIAMQAuAHAAcgBvAGQALgBvAHUAdABsAG8AbwBrAC4AYwBvAG0A]
C: A00000000 CAPABILITY
S: * CAPABILITY IMAP4 IMAP4rev1 AUTH=PLAIN AUTH=XOAUTH2 SASL-IR UIDPLUS ID UNSELECT CHILDREN IDLE NAMESPACE LITERAL+
S: A00000000 OK CAPABILITY completed.
C: A00000001 AUTHENTICATE PLAIN AGpmZWxwc0BpbnRlZ3JpdGVsLnVzXHRyYW5zY3JpYmUAQjV1elU5cmU=
S: A00000001 NO AUTHENTICATE failed.
C: A00000002 LOGIN [INFO REMOVED]
S: A00000002 OK LOGIN completed.
C: A00000003 CAPABILITY
S: * CAPABILITY IMAP4 IMAP4rev1 AUTH=PLAIN AUTH=XOAUTH2 SASL-IR UIDPLUS MOVE ID UNSELECT CLIENTACCESSRULES CLIENTNETWORKPRESENCELOCATION BACKENDAUTHENTICATE CHILDREN IDLE NAMESPACE LITERAL+
S: A00000003 OK CAPABILITY completed.
C: A00000004 NAMESPACE
S: * NAMESPACE (("" "/")) NIL NIL
S: A00000004 OK NAMESPACE completed.
C: A00000005 LIST "" "INBOX"
S: * LIST (\Marked \HasNoChildren) "/" INBOX
S: A00000005 OK LIST completed.
C: A00000006 SELECT INBOX
S: * 16 EXISTS
S: * 0 RECENT
S: * FLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)
S: * OK [PERMANENTFLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)] Permanent flags
S: * OK [UIDVALIDITY 14] UIDVALIDITY value
S: * OK [UIDNEXT 114] The next unique identifier value
S: A00000006 OK [READ-WRITE] SELECT completed.
C: A00000007 UID SEARCH SUBJECT "New message" UNSEEN
S: * SEARCH
S: A00000007 OK SEARCH completed.
C: A00000008 FETCH 1:* (UID FLAGS INTERNALDATE RFC822.SIZE ENVELOPE BODY)
S: * 1 FETCH (UID 65 FLAGS (\Seen) INTERNALDATE "19-Dec-2017 15:55:05 +0000" [INFO REMOVED]
S: A00000008 OK FETCH completed.
C: A00000009 NOOP
S: A00000009 OK NOOP completed.
C: A00000010 NOOP
S: * 16 FETCH (FLAGS ())
S: A00000010 OK NOOP completed.

" at MailKit.Net.Imap.ImapEngine.QueueCommand(ImapCommand ic)
at MailKit.Net.Imap.ImapFolder.d__323.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
at Voicemail_Transcription.EventHandlers.d__1.MoveNext() in C:\Users\jfelps\Documents\Visual Studio 2017\Projects\Voicemail Transcription\Voicemail Transcription\EventHandlers.cs:line 29"

Exception thrown: 'System.InvalidOperationException' in mscorlib.dll
The ImapClient is currently busy processing a command in another thread. Lock the SyncRoot property to properly synchronize your threads.

Please let me know if there is anything more that I need to provide. I have no problem providing my code through email preferably.

@jstedfast
Copy link
Owner

I think you just got lucky with 1.22.

The problem is that the ImapClient is not re-entrant. In other words, you cannot send another command while an existing command is currently being processed.

In your case, the NOOP command is still being processed when the event is triggered.

MailKit does not wait for the entire server response to be read before it begins parsing the response and emitting events. Instead, it processes the response as it receives it.

The Good:

  1. You get events in real-time.
  2. The client doesn't need to read a potentially massive amount of data into RAM first, before processing (thereby taking up huge amounts of resources).

The Bad:

  1. Can't send more commands in an event handler.

The Solution:

In your event handlers, queue your next command(s) to be executed once the existing command completes.

@jstedfast
Copy link
Owner

jstedfast commented Dec 30, 2017

Ah, wait, the reason it worked in 1.22 was because 1.22 used Task.Run() and locked the SyncRoot itself in the Async() methods.

Now that 2.0 is fully async, I can't easily do locking around the sync call like in 1.22.

@jstedfast jstedfast added the question A question about how to do something label Dec 30, 2017
@jstedfast
Copy link
Owner

In other words, this is what 1.22 does:

public Task<T> DoSomethingAsync ()
{
    return Task.Run (() => {
        lock (SyncRoot) {
            return DoSomething ();
        }
    });
}

@jstedfast
Copy link
Owner

I might have a solution...

@jstedfast
Copy link
Owner

Nope, that won't work... :(

@jstedfast
Copy link
Owner

I would love for this to work, but I don't think it's possible without moving the ImapEngine's runloop into another thread which I really don't want to do (because it makes things a lot more complex).

@Ceus
Copy link
Author

Ceus commented Jan 7, 2018

Dang! So, my next update will need to be to Queue the commands that are being called during the Event Handler? I don't have a problem with doing this, I am just unsure about how to go about doing this. Any insight you can give me here?

I am sorry I am just now seeing this. I don't think I got a notification. Thank you for your assistance!

@jstedfast
Copy link
Owner

MailKit doesn't provide a command queue that you can use, you'll have to do that yourself.

What you could do is have a ConcurrentQueue<Action> or something which your main program's main loop will pop and execute.

@jstedfast
Copy link
Owner

Another option is to do something like this:

void OnMessageFlagsChanged (object sender, MessageFlagsChangedEventArgs e)
{
    this.flags_changed = true;
}

And then, in your NOOP logic:

await client.NoOpAsync ();
if (this.flags_changed) {
    var query = SearchQuery.SubjectContains("New message").And(SearchQuery.NotSeen);
    var uids = await folder.SearchAsync(query);
}

That said, I'm not sure why you're using the MessageFlagsChanged event for checking for new mail... MessageFlagsChanged is only emitted when the flags on an existing message change.

You want CountChanged if you expect it to mean the potential for new mail to have arrived.

@Ceus
Copy link
Author

Ceus commented Jan 7, 2018

Thank you! I will give your second option a try. I feel like that will do what I need. I will let you know how that goes. :) 👍

@Ceus
Copy link
Author

Ceus commented Jan 7, 2018

It appears that this resolved my issue. And I apologize, I didn't see the last bit of your message.

I am building a transcription service and I wanted the ability to mark an email as unread and for the email to act as normal. I don't actually care about how many messages are in the inbox or anything, just what happens to the new messages that come in or messages that I mark as unread.

@jstedfast
Copy link
Owner

Ah, ok. FWIW, the MessageFlagsChangedEventArgs argument provides information about the index of the message (sadly not the UID since the server does not provide that info) as well as what the new flags for the message are.

Using that info to keep track of state would be cheaper than doing a Search().

For example:

class MyMessageInfo
{
    public UniqueId UniqueId;
    public MessageFlags Flags;

    public MyMessageInfo (UniqueId uid, MessageFLags flags)
    {
        UniqueId = uid;
        Flags = flags;
    }
}
// after connecting and opening the folder you are interested in tracking, connect to some events so we can track the state of the server:
folder.CountChanged += OnCountChanged;
folder.MessageExpunged += OnMessageExpunged;
folder.MessageFlagsChanged += OnMessageFlagsChanged;

// now collect the list of message UIDs and their associated Flags:
this.messages = folder.Fetch (0, -1, MessageSummaryItems.UniqueId | MessageSummaryItems.Flags | OtherItemsYouCareAbout).Select (x => new MyMessageInfo (x.UniqueId, x.Flags).ToList ();

// .. some time passes, invoke NoOp:
client.NoOp ();

if (this.new_messages) {
    this.new_messages = false;

    var new_messages = folder.Fetch (this.messages.Count, -1, MessageSummaryItems.UniqueId | MessageSummaryItems.Flags | OtherItemsYouCareAbout).Select (x => new MyMessageInfo (x.UniqueId, x.Flags);

    this.messages.AddRange (new_messages);
}

Then, in your event handlers, you might have code that looks like this:

void OnMessageExpunged (object sender, MessageEventArgs e)
{
    // update our list of messages by removing the index of the message that just got expunged
    this.messages.RemoveAt (e.Index);
}

void OnMessageFLagsChanged (object sender, MessageFlagsChangedEventArgs e)
{
    // update the flags for the message at the specified index
    this.messages[e.Index].Flags = e.Flags;
}

void OnCountChanged (object sender, EventArgs e)
{
    var folder = (ImapFolder) sender;

    // folder.Count will either be exactly the same as this.messages.Count
    // -or-
    // it will be larger if new messages have arrived
    this.new_messages = folder.Count > messages.Count;
}

Now you can stay in sync with the server and not have to constantly re-Search.

@dorin7bogdan
Copy link

dorin7bogdan commented Mar 20, 2019

Hi,

From time to time, while trying to disconnect the ImapClient, I get the following exception:

[InvalidOperationException:The ImapClient is currently busy processing a command in another thread. Lock the SyncRoot property to properly synchronize your threads.]<br/> MailKit.Net.Imap.&lt;IterateAsync&gt;d__170.MoveNext() + 435<br/> System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) + 144<br/> System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) + 84<br/> MailKit.Net.Imap.&lt;RunAsync&gt;d__171.MoveNext() + 530<br/> System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) + 144<br/> System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) + 84<br/> MailKit.Net.Imap.&lt;DisconnectAsync&gt;d__95.MoveNext() + 676<br/> System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) + 144<br/> System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) + 84<br/> MailKit.Net.Imap.ImapClient.Disconnect(Boolean quit,CancellationToken cancellationToken) + 501<br/> HS.WinService.Configuration.CustomerEmailAccount.LogoutAndDisconnect() + 182

I apologize for missing the protocol details, since the problem occurs in the release version.

Before trying to disconnect, we try to stop the idling thread.

        public void LogoutAndDisconnect()
        {
            try
            {
                if (IsAuthenticated)
                    StopIdling();

                if (IsConnected)
                    _client.Disconnect(true);
                _client = null;
                _inboxFolder = _processedFolder = _unprocessedFolder = null;
            }
            catch (Exception ex)
            {
                EventLogManager.Instance.WriteEntry(EventLogType.Error, ex, string.Format(UNEXPECTED_ERROR, MethodBase.GetCurrentMethod().Name, ChannelCode, InboxFolderName, ex.Message));
            }
        }
        public void ConnectAndLogin()
        {
            if (_client == null)
            {
#if DEBUG
                _client = new ImapClient(new ProtocolLogger(Console.OpenStandardError()));
#else
                _client = new ImapClient();
#endif
                _client.ServerCertificateValidationCallback = delegate { return true; };
            }

            try
            {
                var ok = TryConnectAndLogin();
                if (!ok)
                {
                    EventLogManager.Instance.WriteEntry(EventLogType.Error, string.Format(LOGIN_FAILED, Username, ChannelCode));
                    LogoutAndDisconnect();
                }
            }
            catch (Exception ex)
            {
                var err = string.Format(UNEXPECTED_ERROR, MethodBase.GetCurrentMethod().Name, ChannelCode, InboxFolderName, ex.Message);
                EventLogManager.Instance.WriteEntry(EventLogType.Error, ex, err);
                LogoutAndDisconnect();
            }
        }
        public void StopIdling()
        {
            lock (_syncRoot)
            {
                try
                {
                    if (_isIdle && _done?.IsCancellationRequested != true)
                    {
                        _done.Cancel();
                        _done.Dispose();
                    }
                    // if the thread doesn't end in 30 seconds, then abort it
                    _thread?.Join(30 * 100);
                    if (_thread?.IsAlive == true)
                        _thread.Abort();
                    _thread = null;
                }
                catch (Exception ex)
                {
                    EventLogManager.Instance.WriteEntry(EventLogType.Error, ex, string.Format(UNEXPECTED_ERROR, MethodBase.GetCurrentMethod().Name, ChannelCode, InboxFolderName, ex.Message));
                }
            }
        }
        public void StartIdling(bool connectAndLogin = true)
        {
            lock (_syncRoot)
            {
                if (connectAndLogin)
                    ConnectAndLogin();
                if (IsConnected && IsAuthenticated && !_isIdle)
                {
                    if (InboxFolder == null) // we check the property here, not the field, in order to initialize it if necessary !
                        return;

                    if (!_inboxFolder.IsOpen)
                    {
                        _inboxFolder.CountChanged -= Folder_CountChanged;
                        _inboxFolder.Open(FolderAccess.ReadWrite);
                        _inboxFolder.CountChanged += Folder_CountChanged;
                    }

                    _done = new CancellationTokenSource();
                    _thread = new Thread(IdleLoop);
                    _thread.Start(new IdleState(_client, _done.Token));

                    // the server should answer with "IDLE accepted, awaiting DONE command", so we give it max 10 seconds for safety 
                    SpinWait.SpinUntil(() => _isIdle, 10 * 1000);
                }
            }
        }

We use the IdleState and IdleLoop taken from your sample ImapIdle.sln:

        #region - IdleState and IdleLoop
        private class IdleState
        {
            readonly object mutex = new object();
            CancellationTokenSource timeout;

            /// <summary>
            /// Get the cancellation token.
            /// </summary>
            /// <remarks>
            /// <para>The cancellation token is the brute-force approach to cancelling the IDLE and/or NOOP command.</para>
            /// <para>Using the cancellation token will typically drop the connection to the server and so should
            /// not be used unless the client is in the process of shutting down or otherwise needs to
            /// immediately abort communication with the server.</para>
            /// </remarks>
            /// <value>The cancellation token.</value>
            public CancellationToken CancellationToken { get; private set; }

            /// <summary>
            /// Get the done token.
            /// </summary>
            /// <remarks>
            /// <para>The done token tells the <see cref="Program.IdleLoop"/> that the user has requested to end the loop.</para>
            /// <para>When the done token is cancelled, the <see cref="Program.IdleLoop"/> will gracefully come to an end by
            /// cancelling the timeout and then breaking out of the loop.</para>
            /// </remarks>
            /// <value>The done token.</value>
            public CancellationToken DoneToken { get; private set; }

            /// <summary>
            /// Get the IMAP client.
            /// </summary>
            /// <value>The IMAP client.</value>
            public ImapClient Client { get; private set; }

            /// <summary>
            /// Check whether or not either of the CancellationToken's have been cancelled.
            /// </summary>
            /// <value><c>true</c> if cancellation was requested; otherwise, <c>false</c>.</value>
            public bool IsCancellationRequested
            {
                get
                {
                    return CancellationToken.IsCancellationRequested || DoneToken.IsCancellationRequested;
                }
            }

            /// <summary>
            /// Initializes a new instance of the <see cref="IdleState"/> class.
            /// </summary>
            /// <param name="client">The IMAP client.</param>
            /// <param name="doneToken">The user-controlled 'done' token.</param>
            /// <param name="cancellationToken">The brute-force cancellation token.</param>
            public IdleState(ImapClient client, CancellationToken doneToken, CancellationToken cancellationToken = default(CancellationToken))
            {
                CancellationToken = cancellationToken;
                DoneToken = doneToken;
                Client = client;

                // When the user hits a key, end the current timeout as well
                doneToken.Register(CancelTimeout);
            }

            /// <summary>
            /// Cancel the timeout token source, forcing ImapClient.Idle() to gracefully exit.
            /// </summary>
            void CancelTimeout()
            {
                lock (mutex)
                {
                    if (timeout != null)
                        timeout.Cancel();
                }
            }

            /// <summary>
            /// Set the timeout source.
            /// </summary>
            /// <param name="source">The timeout source.</param>
            public void SetTimeoutSource(CancellationTokenSource source)
            {
                lock (mutex)
                {
                    timeout = source;

                    if (timeout != null && IsCancellationRequested)
                        timeout.Cancel();
                }
            }
        }

        private static void IdleLoop(object state)
        {
            var idle = (IdleState)state;

            lock (idle.Client.SyncRoot)
            {
                // Note: since the IMAP server will drop the connection after 30 minutes, we must loop sending IDLE commands that
                // last ~29 minutes or until the user has requested that they do not want to IDLE anymore.
                // 
                // For GMail, we use a 9 minute interval because they do not seem to keep the connection alive for more than ~10 minutes.
                while (!idle.IsCancellationRequested)
                {
                    using (var timeout = new CancellationTokenSource(new TimeSpan(0, 0, CustomerEmailsConfig.NoopIssueTimeout)))
                    {
                        try
                        {
                            // We set the timeout source so that if the idle.DoneToken is cancelled, it can cancel the timeout
                            idle.SetTimeoutSource(timeout);

                            if (idle.Client.Capabilities.HasFlag(ImapCapabilities.Idle))
                            {
                                // The Idle() method will not return until the timeout has elapsed or idle.CancellationToken is cancelled
                                idle.Client.Idle(timeout.Token, idle.CancellationToken);
                            }
                            else
                            {
                                // The IMAP server does not support IDLE, so send a NOOP command instead
                                idle.Client.NoOp(idle.CancellationToken);

                                // Wait for the timeout to elapse or the cancellation token to be cancelled
                                WaitHandle.WaitAny(new[] { timeout.Token.WaitHandle, idle.CancellationToken.WaitHandle });
                            }
                        }
                        catch (OperationCanceledException ex)
                        {
                            // This means that idle.CancellationToken was cancelled, not the DoneToken nor the timeout.
                            EventLogManager.Instance.WriteEntry(EventLogType.Error, ex);
                            break;
                        }
                        catch (ImapProtocolException ex)
                        {
                            // The IMAP server sent garbage in a response and the ImapClient was unable to deal with it.
                            // This should never happen in practice, but it's probably still a good idea to handle it.
                            // 
                            // Note: an ImapProtocolException almost always results in the ImapClient getting disconnected.
                            EventLogManager.Instance.WriteEntry(EventLogType.Error, ex);
                            break;
                        }
                        catch (ImapCommandException ex)
                        {
                            // The IMAP server responded with "NO" or "BAD" to either the IDLE command or the NOOP command.
                            // This should never happen... but again, we're catching it for the sake of completeness.
                            EventLogManager.Instance.WriteEntry(EventLogType.Error, ex);
                            break;
                        }
                        catch (IOException ex)
                        {
                            EventLogManager.Instance.WriteEntry(EventLogType.Error, ex);
                            break;
                        }
                        catch (Exception ex)
                        {
                            EventLogManager.Instance.WriteEntry(EventLogType.Error, ex);
                            break;
                        }
                        finally
                        {
                            // We're about to Dispose() the timeout source, so set it to null.
                            idle.SetTimeoutSource(null);
                        }
                    }
                }
            }
        }
        #endregion

I suspect that sometimes the idle thread cannot be terminated so that the Disconnect fails to be done.
In this case how to abort the idle thread?

Please advise.

@jstedfast
Copy link
Owner

The Idle/IdleAsync methods take 2 CancellationToken arguments: doneToken and cancellationToken

What I would do is, after cancelling doneToken (using your _done token source as you are already doing), if the thread doesn't end after your time limit, then try calling Cancel() on your cancellationToken source and giving it a few more seconds to join.

This may still fail currently, but I've been working toward making cancel even more solid. I've made changes to SmtpClient so far and once I know that approach works for sure, I'll be adding it to ImapClient and Pop3Client.

@dorin7bogdan
Copy link

dorin7bogdan commented Mar 20, 2019

Hi Jstedfast,
Thank you for the quick answer.
I defined:
private CancellationTokenSource _cancel
I also fixed the time to join from 30 * 100 to 30 * 1000 to really be 30 seconds, as intended initially.
Please let me know if this version of StartIdling / StopIdling should be better:

public void StopIdling()
{
	lock (_syncRoot)
	{
		try
		{
			if (_isIdle && _done?.IsCancellationRequested != true)
			{
				_done.Cancel();
				_done.Dispose();
			}
			// if the thread doesn't end in 30 seconds, then use the cancelation token 
			_thread?.Join(30 * 1000);
			if (_thread?.IsAlive == true)
			{
				_cancel?.Cancel();
				_thread?.Join(30 * 1000);
				// if the thread doesn't end in 30 seconds, then abort it
				if (_thread?.IsAlive == true)
					_thread.Abort();
			}
			_thread = null;
		}
		catch (Exception ex)
		{
			EventLogManager.Instance.WriteEntry(EventLogType.Error, ex, string.Format(UNEXPECTED_ERROR, MethodBase.GetCurrentMethod().Name, ChannelCode, InboxFolderName, ex.Message));
		}
	}
}
public void StartIdling(bool connectAndLogin = true)
{
	lock (_syncRoot)
	{
		if (connectAndLogin)
			ConnectAndLogin();
		if (IsConnected && IsAuthenticated && !_isIdle)
		{
			if (InboxFolder == null) // we check the property here, not the field, in order to initialize it if necessary !
				return;

			if (!_inboxFolder.IsOpen)
			{
				_inboxFolder.CountChanged -= Folder_CountChanged;
				_inboxFolder.Open(FolderAccess.ReadWrite);
				_inboxFolder.CountChanged += Folder_CountChanged;
			}

			_done = new CancellationTokenSource();
			_cancel = new CancellationTokenSource();
			_thread = new Thread(IdleLoop);
			_thread.Start(new IdleState(_client, _done.Token, _cancel.Token));

			// the server should answer with "IDLE accepted, awaiting DONE command", so we give it max 10 seconds for safety 
			SpinWait.SpinUntil(() => _isIdle, 10 * 1000);
		}
	}
}

Additionally, do you recommend to do something in the catch block or to add a finally block? (in the StopIdling method). For example to abort the _thread if still alive.

@dorin7bogdan
Copy link

Also, do you think it's better to declare the IdleLoop method as instance method (instead of static)?
I'm asking this because we connect multiple clients (to different mailboxes) and they might rise concurrency issues.
In other words, there are several instances of the class containing the ImapClient _client field running and idling in parallel.
Thank you in advance.

@jstedfast
Copy link
Owner

Your new StopIdling() method looks exactly how I was recommending.

As far as adding a finally goes, I've got a few thoughts:

  1. _done.Cancel () has been recently fixed to catch all exceptions inside MailKit, so they should never bubble up to your code.
  2. I'm not as sure about _cancel.Cancel(), I'm pretty sure that should only cause exceptions on the thread that is actually running the IMAP query, but not 100% confident. If any situations are found that do cause _cancel.Cancel() to throw from within MailKit, I would consider that a bug in MailKit.

That leaves your _thread.Join()'s as potential sources of exceptions which I don't think will be a realistic issue in your code.

The only potential problem I see in your StopIdling method right now is that _done is only Disposed in 1 code path (only if you are idling and the token hasn't already been cancelled). It might be worth moving the Dispose() to a finally clause:

} finally {
    if (_done != null)
        _done.Dispose ();
}

As far as making IdleLoop an instance vs static, I'm not sure it really matters.

@dorin7bogdan
Copy link

dorin7bogdan commented Mar 21, 2019

Hi Jstedfast, thank you so much for the useful suggestions !!!

I just reproduced a scenario that might be the cause of the problems:

The StartIdling method is called on every minute, and as you can see its code from above, based on the _idle flag value it renews the tokens and starts the new _thread.
private bool _isIdle => _client?.IsIdle == true;

So it seems to be a concurrency issue, when the IdleLoop's timeout just expired (i.e. at 5 min) and at the same time the StartIdling was called.
I could see in the debugger that the _idle flag was false when entering the StartIdling method, and it became true in the middle of the method.
How could I synchronize the IdleLoop's while or using block with the StartIlding?

@jstedfast
Copy link
Owner

I would probably recommend avoiding the use of a boolean variable for this and use a ManualResentEvent instead.

@dorin7bogdan
Copy link

Hi Jeffrey,

I continue on this thread, even if it is not on the same subject.
While IDLE looping, sometimes (once a week?) we get a strange exception.
I tried to reproduce on DEV environment but didn't succeed yet.

Syntax error in response. Unexpected token: [atom: Server]

ImapProtocolException:Syntax error in response. Unexpected token: [atom: Server]]<br/> 
MailKit.Net.Imap.&lt;StepAsync&gt;d__79.MoveNext() + 9392<br/> 
System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) + 144<br/> 
System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) + 84<br/> 
System.Runtime.CompilerServices.ConfiguredTaskAwaiter.GetResult() + 49<br/> 
MailKit.Net.Imap.&lt;IterateAsync&gt;d__170.MoveNext() + 1878<br/> 
System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) + 144<br/> 
System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) + 84<br/> 
MailKit.Net.Imap.&lt;RunAsync&gt;d__171.MoveNext() + 530<br/> 
System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) + 144<br/> 
System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) + 84<br/> 
MailKit.Net.Imap.&lt;IdleAsync&gt;d__100.MoveNext() + 1227<br/> 
System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) + 144<br/> 
System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) + 84<br/> 
MailKit.Net.Imap.ImapClient.Idle(CancellationToken doneToken,CancellationToken cancellationToken) + 528<br/> 
HS.PiPWService.Configuration.CustomerEmailAccount.IdleLoop(Object state) + 391<br/> 

I know that you fixed similar issues in past.
The server is Microsoft Exchange IMAP4.
I can give you a DEV sample from starting the IDLE loop:

Connected to imaps://dag01.mailserver.local:993/
S: * OK The Microsoft Exchange IMAP4 service is ready.
C: A00000000 CAPABILITY
S: * CAPABILITY IMAP4 IMAP4rev1 AUTH=PLAIN AUTH=NTLM AUTH=GSSAPI UIDPLUS MOVE ID CHILDREN IDLE NAMESPACE LITERAL+
S: A00000000 OK CAPABILITY completed.
C: A00000001 AUTHENTICATE PLAIN
S: +
C: AFBMVU1CRURGT1JEXGNicxxxxxxxxx*****
S: A00000001 OK AUTHENTICATE completed.
C: A00000002 CAPABILITY
S: * CAPABILITY IMAP4 IMAP4rev1 AUTH=PLAIN AUTH=NTLM AUTH=GSSAPI UIDPLUS MOVE ID XPROXY3 CHILDREN IDLE NAMESPACE LITERAL+
S: A00000002 OK CAPABILITY completed.
C: A00000003 NAMESPACE
S: * NAMESPACE (("" "/")) NIL NIL
S: A00000003 OK NAMESPACE completed.
C: A00000004 LIST "" "INBOX"
S: * LIST (\Marked \HasNoChildren) "/" INBOX
S: A00000004 OK LIST completed.
C: A00000005 LIST "" DOrin
S: * LIST (\HasChildren) "/" Dorin
S: A00000005 OK LIST completed.
C: A00000006 LIST "" DOrinProcessed
S: * LIST (\HasNoChildren) "/" DorinProcessed
S: A00000006 OK LIST completed.
C: A00000007 LIST "" Unprocessed
S: * LIST (\HasNoChildren) "/" Unprocessed
S: A00000007 OK LIST completed.
C: A00000008 SELECT Dorin
S: * 0 EXISTS
S: * 0 RECENT
S: * FLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)
S: * OK [PERMANENTFLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)] Permanent flags
S: * OK [UIDVALIDITY 66] UIDVALIDITY value
S: * OK [UIDNEXT 90] The next unique identifier value
S: A00000008 OK [READ-WRITE] SELECT completed.
C: A00000009 UID SEARCH ALL
S: * SEARCH
S: A00000009 OK SEARCH completed.
C: A00000010 IDLE
S: + IDLE accepted, awaiting DONE command.

Please advise.

@jstedfast
Copy link
Owner

That log doesn't contain the word Server anywhere, so that can't be the correct log.

The exception you are getting is because the IMAP response parser is encountering the word Server where it doesn't make any sense syntactically.

@dorin7bogdan
Copy link

Hi Jeffrey,
Is there a way to enable the Imap protocol logging only for main info, without printing all email body / attachments details ?

@jstedfast
Copy link
Owner

No, there's no way to do that.

@dorin7bogdan
Copy link

Ok, thank you! Maybe in future versions :).

@jstedfast
Copy link
Owner

Actually... what you could do is write your own IProtocolLogger implementation that only writes the first line of the command and drops the rest of it.

@dorin7bogdan
Copy link

dorin7bogdan commented May 14, 2019

Interesting idea, but what do you think if derive from MailKit.ProtocolLogger and override the LogServer(byte[] buffer, int offset, int count) with call base.LogServer(buffer, offset, 100) inside?
Do you see any drawbacks here?

@jstedfast
Copy link
Owner

That won't work because MailKit will chunk the command to the logger, so the buffer does not necessarily contain the full command.

@dorin7bogdan
Copy link

Hi Jeffrey,
Sorry for disturbing you again....
In fact I need to skip logging the call FETCH BODY command details, since this gets the biggest amount of data.
And eventually print only the first and the last line.
S: * 1 FETCH (BODY[] {88166}
S: Received: from mailtest.local (...) by
S: mailtest.local (... ) with Microsoft SMTP Server
S: (TLS) id 15.0.1395.4 via Mailbox Transport; Wed, 15 May 2019 06:06:41 -0400
S: Received: from mailtest.local (...) by
. . . . .
. . . . .
S: nl7O1f3Rm7r9g5+PhWS/45fU+n88+/jznL1zZ19R1dPjPv7Y6w38479MdnjnPXjnb0w39MhF56d5
S: /V6y9UKax/qr/9k=
S:
S: ------=_NextPart_000_00D6_01D50B1F.1E45A4B0--
S: UID 8)
S: F00000014 OK FETCH completed.

The existing MailKit.ProtocolLogger code seems quite complex and I'm afraid to adjust it right now.
If it is possible in future versions, please take in account adding support for this feature.
Thank you so much.

@jstedfast
Copy link
Owner

All you need to do is buffer the data before it gets pushed to the underlying log stream:

When LogClient() gets called, append it to the client buffer. When LogServer() gets called, you know the client buffer is complete and then you can print just the first and last lines.

When LogServer() gets called, append it to the client buffer. When LogClient() gets called, you know the server buffer is complete and then you can print just the first and last lines.

@dorin7bogdan
Copy link

dorin7bogdan commented May 24, 2019

Hi Jeffrey,
A small question:
Is it possible to reset the protocol logger file without disconnecting the IMAP client?
I'd like to prevent it from growing too much.
Currently I cannot manually edit it from Notepad:

"The process cannot access the file because it is being used by another process."

Thank you.

@jstedfast
Copy link
Owner

Not using the one provided by MailKit, but you could write your own that does.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
question A question about how to do something
Projects
None yet
Development

No branches or pull requests

3 participants