danzuep / MailKitSimplified

Send and receive emails easily, fluently, with one line of code for each operation.
MIT License
79 stars 10 forks source link

IMAP server disconnected after 3 hours #72

Open danzuep opened 1 month ago

danzuep commented 1 month ago

All appeared fine in testing this morning - it processed a couple of emails sitting in the inbox, then a few more i sent over the next 10 mintes. However when I sent another email almost 3 hours later I got the exception seen below. I have included the last successful read and move at 11:53

2024-08-07 11:53:21.5670 [DEBUG] Caa.Api.Email.MailMonitor: Incoming testing 4 
2024-08-07 11:53:21.9330 [DEBUG] Caa.Api.Email.MailMonitor: After arrival move return uniqueId: 62 
2024-08-07 11:53:26.6315 [ INFO] MailKitSimplified.Receive: imap.gmail.com referencing-test@antisemitism.org INBOX message #68 departure processed. 
2024-08-07 14:43:47.8126 [ INFO] MailKitSimplified.Receive: IMAP protocol exception, checking connection. MailKit.Net.Imap.ImapProtocolException: The IMAP server has unexpectedly disconnected.
   at MailKit.Net.Imap.ImapStream.ReadAheadAsync(Int32 atleast, CancellationToken cancellationToken)
   at MailKit.Net.Imap.ImapStream.ReadTokenAsync(String specials, CancellationToken cancellationToken)
   at MailKit.Net.Imap.ImapCommand.StepAsync()
   at MailKit.Net.Imap.ImapEngine.IterateAsync()
   at MailKit.Net.Imap.ImapEngine.RunAsync(ImapCommand ic)
   at MailKit.Net.Imap.ImapClient.NoOpAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.ProcessMessagesArrivedAsync(Boolean firstConnection, CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.WaitForNewMessagesAsync(CancellationToken cancellationToken)
2024-08-07 14:43:48.4505 [DEBUG] MailKitSimplified.Receive: imap.gmail.com referencing-test@antisemitism.org INBOX message #69 arrived. 
2024-08-07 14:43:48.4928 [DEBUG] Caa.Api.Email.MailMonitor: Incoming test 5 
2024-08-07 14:43:48.6119 [ERROR] MailKitSimplified.Receive: Error occurred processing arrival queue item. imap.gmail.com referencing-test@antisemitism.org INBOX #69. MailKit.ServiceNotConnectedException: The ImapClient is not connected.
   at MailKit.Net.Imap.ImapFolder.CheckState(Boolean open, Boolean rw)
   at MailKit.Net.Imap.ImapFolder.GetEnumerator()+MoveNext()
   at Microsoft.Extensions.Logging.LogValuesFormatter.TryFormatArgumentIfNullOrEnumerable[T](T value, Object& stringValue)
   at Microsoft.Extensions.Logging.LogValuesFormatter.Format(Object[] values)
   at NLog.Extensions.Logging.NLogLogger.CreateLogEventInfo[TState](LogLevel nLogLogLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at NLog.Extensions.Logging.NLogLogger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.Logger.<Log>g__LoggerLog|14_0[TState](LogLevel logLevel, EventId eventId, ILogger logger, Exception exception, Func`3 formatter, List`1& exceptions, TState& state)

Originally posted by @alasdair-richardson in https://github.com/danzuep/MailKitSimplified/issues/70#issuecomment-2273531711

jstedfast commented 1 month ago

This may or may not be helpful (hopefully it is), but IMAP servers can drop client connections at any time for any reason.

It is possible that this is not a bug in your (existing) code but rather just a normal (but still "exceptional") circumstance that your library could potentially handle, much like HTTP "retry" libraries do.

I've been pondering trying to figure out a way to handle random server disconnects in MailKit itself, but it's "complicated".

(and gets even more complicated once you factor in OAuth2 access tokens which may have expired since the most recent successful login)

danzuep commented 1 month ago

Thanks Jeffrey! It's an honour to have your input here as the one who made all of this possible. Kudos.

danzuep commented 1 month ago

By the way @jstedfast , if you want to host this project on your site I'd be more than happy to transfer it accross as long as I can stay on as a maintainer.

danzuep commented 1 month ago

The catch statement that logged the exception already reconnects which is why the next email that arrived was added to the queue, and the message is added back to the queue right after that error message, so I'll change it to just be a warning. Alasdair, please close this issue if that email was processed successfully soon after.

alasdair-richardson commented 1 month ago

@danzuep As you can see from the log messages i posted I got the original Imap protocol exception, then less than a second later it started processing the message (message #69 arrived then my code said subject was 'test 5'). It was after that it got the ServiceNotConnected exception. So I processed the email but it did not get moved. When I tried just now to send another email, I got the Imap protocol exception again, then i saw your code receiving message #70, but my code was no longed called, so no attempt was made to process or move the email. log below

2024-08-07 17:26:55.1450 [ INFO] MailKitSimplified.Receive: IMAP protocol exception, checking connection. MailKit.Net.Imap.ImapProtocolException: The IMAP server has unexpectedly disconnected.
   at MailKit.Net.Imap.ImapStream.ReadAheadAsync(Int32 atleast, CancellationToken cancellationToken)
   at MailKit.Net.Imap.ImapStream.ReadTokenAsync(String specials, CancellationToken cancellationToken)
   at MailKit.Net.Imap.ImapCommand.StepAsync()
   at MailKit.Net.Imap.ImapEngine.IterateAsync()
   at MailKit.Net.Imap.ImapEngine.RunAsync(ImapCommand ic)
   at MailKit.Net.Imap.ImapClient.NoOpAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.ProcessMessagesArrivedAsync(Boolean firstConnection, CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.WaitForNewMessagesAsync(CancellationToken cancellationToken)
2024-08-07 17:26:55.9056 [DEBUG] MailKitSimplified.Receive: imap.gmail.com referencing-test@antisemitism.org INBOX message #70 arrived. 
alasdair-richardson commented 1 month ago

Sending a further message gets it to your code without a problem but my code is not being called

2024-08-07 17:38:51.9108 [DEBUG] MailKitSimplified.Receive: imap.gmail.com referencing-test@antisemitism.org INBOX message #71 arrived. 
jstedfast commented 1 month ago

FWIW, since you seem to be dealing with GMail:

https://developers.google.com/gmail/imap/imap-smtp

Session length limits

Gmail POP sessions are limited to about 7 days. Gmail IMAP sessions are limited to about 24 hours. If the session was authenticated using OAuth credentials, it's limited to about the validity period of the access token used (usually 1 hour). A session in this context is one continuous TCP connection.

When the time elapses and the session expires, Gmail closes the connection with a message saying that the session expired. After that, the client can reconnect, authenticate again, and continue. If using OAuth, make sure that the access token used is valid (if you try to use an access token older than 1 hour, it might be invalid).

(bold text added to draw attention)

alasdair-richardson commented 1 month ago

At the moment I am using Imap with user name and password.

danzuep commented 1 month ago

I added a retry to the arrival queue so you should be fine now. I've run one of these for over a year before, but it wasn't GMail and I had a local try-catch so I didn't need the service retry. Seems like it'll be useful for other people too though. Let me know next time you see that message, it should just come through as a warning now and carry on.

alasdair-richardson commented 1 month ago

I have updated and restarted this morning. I will send more emails during the day, and let you know what happens,

alasdair-richardson commented 1 month ago

@danzuep all appears to be working in terms of that reconnection. I had to put in a bit of extra logic to check if I had already stored the email - my process was store, move and if the move fails and I get the email again i don't want to store it again. This morning found the following exception in the log and the monitor has stopped

2024-08-10 06:43:46.4584 [ INFO] MailKitSimplified.Receive: IMAP I/O exception, reconnecting. 
2024-08-10 06:43:46.4694 [ERROR] MailKitSimplified.Receive: Idle client failed. System.Net.Sockets.SocketException (11001): No such host is known.
   at System.Net.NameResolutionPal.ProcessResult(SocketError errorCode, GetAddrInfoExContext* context)
   at System.Net.NameResolutionPal.GetAddressInfoExCallback(Int32 error, Int32 bytes, NativeOverlapped* overlapped)
--- End of stack trace from previous location ---
   at MailKit.Net.SocketUtils.ConnectAsync(String host, Int32 port, IPEndPoint localEndPoint, CancellationToken cancellationToken)
   at MailKit.Net.SocketUtils.ConnectAsync(String host, Int32 port, IPEndPoint localEndPoint, Int32 timeout, CancellationToken cancellationToken)
   at MailKit.MailService.ConnectNetworkAsync(String host, Int32 port, CancellationToken cancellationToken)
   at MailKit.Net.Imap.ImapClient.ConnectAsync(String host, Int32 port, SecureSocketOptions options, CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.ImapReceiver.ConnectImapClientAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.ImapReceiver.ConnectAuthenticatedImapClientAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.ReconnectAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.WaitForNewMessagesAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.IdleStartAsync(CancellationToken cancellationToken)

I assume I need to put a try catch block round the the Monitor function, though I am not sure if the exception propagated up ... Something like

while (true)
{
    try
    {
        await MonitorAsync();
    }
    catch (Exception e)
    {
        // Log it ...
    }
}

But there are a couple of questions. 1 Is this correct i.e. is there an exception to catch? 2 What the heck is No Such Host Known (imap.gmail.com)? 3 Should I catch any exception or just particular one(s)? 4 Should I also include the line in the try creating the DestinationFolder mailFolderClient.GetFolderAsync

alasdair-richardson commented 1 month ago

Or maybe I had some network/internet connection glitch this morning, and this is unlikely to happen once we start running this in Azure? But some kind of back-off/retry logic should be possible, e.g. put in a wait in the catch block above?

alasdair-richardson commented 1 month ago

Weirdly when I reconnected expecting to see the email I sent this morning get processed, it didn't. When I look at the gmail inbox the email I sent this morning does not appear in the inbox or the processed folder - but I see it on the All Mail tab. It does not appear anywhere else (including Bin).

danzuep commented 1 month ago

I've added a catch for the SocketException so you don't have to, but I don't expect it to be very common. See also.

alasdair-richardson commented 1 month ago

Thank you @danzuep once again. Unfortunately we are gong away for a few days and I need to test this at least overnight and preferably for longer. We will be back Friday and I will test over the weekend and let you know the results.

alasdair-richardson commented 1 month ago

Just getting round to starting testing. I saw 2 versions in nuget - 2.11.10-tags-v2-11-10-rc0001 (which is what I already installed) and 2.11.10-tags-v2-11-10-r-0001 (r-0001 rather than rc0001) which did seem to be slightly newer so I downloaded that.

alasdair-richardson commented 3 weeks ago

Well things seem to be fine now. Not sure what the different disconnects are (see below), and I don't know if any of them was caused by the 'No such host' exception I saw before, but it seems to be reconnecting fine. I think you can probably close this. And thanks again

2024-08-19 21:50:25.6619 [ INFO] MailKitSimplified.Receive: Session expired, please login again. Reconnecting and trying again. 
2024-08-19 23:20:38.9285 [ INFO] MailKitSimplified.Receive: The IMAP server has unexpectedly disconnected. Reconnecting and trying again. 
2024-08-19 23:30:45.7210 [ INFO] MailKitSimplified.Receive: The IMAP server has unexpectedly disconnected. Reconnecting and trying again. 
2024-08-20 00:58:39.3936 [ INFO] MailKitSimplified.Receive: The IMAP server has unexpectedly disconnected. Reconnecting and trying again. 
2024-08-20 12:01:11.9890 [ INFO] MailKitSimplified.Receive: System error Reconnecting and trying again. 
2024-08-20 12:53:59.4123 [ INFO] MailKitSimplified.Receive: System error Reconnecting and trying again. 
2024-08-20 13:59:35.4224 [ INFO] MailKitSimplified.Receive: The IMAP server has unexpectedly disconnected. Reconnecting and trying again. 
alasdair-richardson commented 3 weeks ago

Actually can I just ask one more thing? This message is now [DEBUG]

2024-08-20 13:59:36.1746 [DEBUG] MailKitSimplified.Receive: [imap.gmail.com](http://imap.gmail.com/) [referencing-test@antisemitism.org](mailto:referencing-test@antisemitism.org) INBOX message #89 arrived.

Could this onw become DEBUG too please?

2024-08-20 13:59:41.2478 [ INFO] MailKitSimplified.Receive: [imap.gmail.com](http://imap.gmail.com/) [referencing-test@antisemitism.org](mailto:referencing-test@antisemitism.org) INBOX message #89 departure processed.
danzuep commented 3 weeks ago

I've changed that message to DEBUG and removed the cancellation from Move so it doesn't end up in between folders again like last time. https://www.nuget.org/packages/MailKitSimplified.Receiver/2.11.10

alasdair-richardson commented 3 weeks ago

I'm afraid the no such host seems to have reared its head again. This morning I see the following in the log. I noticed when sending an email this afternoon and the monitor is not picking it up at all, seems not to be listening any more. No more messages in log from MailkitSimplified after 8.05m though the server is still running. On restarting the server it p[icked up the new emails ok.


2024-08-24 08:05:05.9133 [ INFO] MailKitSimplified.Receive: IMAP I/O exception, reconnecting. 
2024-08-24 08:05:06.0098 [ INFO] MailKitSimplified.Receive: IMAP socket exception during connection attempt #1. imap.gmail.com referencing-test@antisemitism.org INBOX. 
2024-08-24 08:05:06.0207 [ INFO] MailKitSimplified.Receive: IMAP socket exception during connection attempt #2, backing off for 100ms. imap.gmail.com referencing-test@antisemitism.org INBOX.
2024-08-24 08:05:06.1281 [ERROR] MailKitSimplified.Receive: IMAP socket exception during connection attempt #3, backing off for 100ms. imap.gmail.com referencing-test@antisemitism.org INBOX. System.Net.Sockets.SocketException (11001): No such host is known.
   at System.Net.NameResolutionPal.ProcessResult(SocketError errorCode, GetAddrInfoExContext* context)
   at System.Net.NameResolutionPal.GetAddressInfoExCallback(Int32 error, Int32 bytes, NativeOverlapped* overlapped)
--- End of stack trace from previous location ---
   at MailKit.Net.SocketUtils.ConnectAsync(String host, Int32 port, IPEndPoint localEndPoint, CancellationToken cancellationToken)
   at MailKit.Net.SocketUtils.ConnectAsync(String host, Int32 port, IPEndPoint localEndPoint, Int32 timeout, CancellationToken cancellationToken)
   at MailKit.MailService.ConnectNetworkAsync(String host, Int32 port, CancellationToken cancellationToken)
   at MailKit.Net.Imap.ImapClient.ConnectAsync(String host, Int32 port, SecureSocketOptions options, CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.ImapReceiver.ConnectImapClientAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.ImapReceiver.ConnectAuthenticatedImapClientAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.ReconnectAsync(CancellationToken cancellationToken)
2024-08-24 08:05:06.2480 [ INFO] MailKitSimplified.Receive: IMAP service not connected, reconnecting. 
2024-08-24 08:05:06.2577 [ INFO] MailKitSimplified.Receive: IMAP socket exception during connection attempt #1. imap.gmail.com referencing-test@antisemitism.org INBOX.
2024-08-24 08:05:06.2577 [ INFO] MailKitSimplified.Receive: IMAP socket exception during connection attempt #2, backing off for 100ms. imap.gmail.com referencing-test@antisemitism.org INBOX.
2024-08-24 08:05:06.3815 [ERROR] MailKitSimplified.Receive: IMAP socket exception during connection attempt #3, backing off for 100ms. imap.gmail.com referencing-test@antisemitism.org INBOX. System.Net.Sockets.SocketException (11001): No such host is known.
   at System.Net.NameResolutionPal.ProcessResult(SocketError errorCode, GetAddrInfoExContext* context)
   at System.Net.NameResolutionPal.GetAddressInfoExCallback(Int32 error, Int32 bytes, NativeOverlapped* overlapped)
--- End of stack trace from previous location ---
   at MailKit.Net.SocketUtils.ConnectAsync(String host, Int32 port, IPEndPoint localEndPoint, CancellationToken cancellationToken)
   at MailKit.Net.SocketUtils.ConnectAsync(String host, Int32 port, IPEndPoint localEndPoint, Int32 timeout, CancellationToken cancellationToken)
   at MailKit.MailService.ConnectNetworkAsync(String host, Int32 port, CancellationToken cancellationToken)
   at MailKit.Net.Imap.ImapClient.ConnectAsync(String host, Int32 port, SecureSocketOptions options, CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.ImapReceiver.ConnectImapClientAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.ImapReceiver.ConnectAuthenticatedImapClientAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.ReconnectAsync(CancellationToken cancellationToken)
2024-08-24 08:05:06.4968 [ INFO] MailKitSimplified.Receive: IMAP service not connected, reconnecting. 
2024-08-24 08:05:06.5041 [ INFO] MailKitSimplified.Receive: IMAP socket exception during connection attempt #1. imap.gmail.com referencing-test@antisemitism.org INBOX.
2024-08-24 08:05:06.5041 [ INFO] MailKitSimplified.Receive: IMAP socket exception during connection attempt #2, backing off for 100ms. imap.gmail.com referencing-test@antisemitism.org INBOX.
2024-08-24 08:05:06.6320 [ERROR] MailKitSimplified.Receive: IMAP socket exception during connection attempt #3, backing off for 100ms. imap.gmail.com referencing-test@antisemitism.org INBOX. System.Net.Sockets.SocketException (11001): No such host is known.
   at System.Net.NameResolutionPal.ProcessResult(SocketError errorCode, GetAddrInfoExContext* context)
   at System.Net.NameResolutionPal.GetAddressInfoExCallback(Int32 error, Int32 bytes, NativeOverlapped* overlapped)
--- End of stack trace from previous location ---
   at MailKit.Net.SocketUtils.ConnectAsync(String host, Int32 port, IPEndPoint localEndPoint, CancellationToken cancellationToken)
   at MailKit.Net.SocketUtils.ConnectAsync(String host, Int32 port, IPEndPoint localEndPoint, Int32 timeout, CancellationToken cancellationToken)
   at MailKit.MailService.ConnectNetworkAsync(String host, Int32 port, CancellationToken cancellationToken)
   at MailKit.Net.Imap.ImapClient.ConnectAsync(String host, Int32 port, SecureSocketOptions options, CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.ImapReceiver.ConnectImapClientAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.ImapReceiver.ConnectAuthenticatedImapClientAsync(CancellationToken cancellationToken)
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.ReconnectAsync(CancellationToken cancellationToken)
``

. 
alasdair-richardson commented 3 weeks ago

If I got a notification in my code I could back off for longer periods, perhaps extending the period etc (exponential backoff)

danzuep commented 3 weeks ago

I've added another pre-release that allows you to disable some of the built in idle client exception handling with a Boolean so that you can back off for longer periods or do whatever else you find works. I might change the usage before the next release though to make it fluent.

alasdair-richardson commented 3 weeks ago

Thank you. I assume that this only affects the disconnects happening on the listening socket, and the code to reconnect the Processed folder when moving the processed email is separate? It would help me if you could just point me at the actual reconnection code you have allowed us to disable so I can use that as a template for my replacement code.

danzuep commented 3 weeks ago

This works:

await _monitorFolder
    .SetMessageSummaryItems()
    .SetIgnoreExistingMailOnConnect()   
    .OnMessageArrival(ProcessMessage)
    .IdleAsync(cancellationToken, handleExceptions: false)
    .ContinueWith(t => _logger.LogError(t.Exception?.GetBaseException(),
        "Idle client failed."), TaskContinuationOptions.OnlyOnFaulted); // add retry error handling here

Alternatively, to catch all the exceptions mentioned in the error messages you posted above:

                try
                {
                // idle here
                }
                catch (IOException ex)
                {
                    _logger.LogError(ex, $"{_imapReceiver} IMAP I/O exception, reconnecting.");
                }
                catch (SocketException ex)
                {
                    _logger.LogError(ex, ($"{_imapReceiver} IMAP socket exception, reconnecting.");
                }
                catch (ServiceNotConnectedException ex)
                {
                    _logger.LogError(ex, ($"{_imapReceiver} IMAP service not connected, reconnecting.");
                }
alasdair-richardson commented 3 weeks ago

I have implemented some fallback/retry logic using a library called Polly. A bit of overkill for this purpose but it looks to be useful for other things too. Unfortunately the arrived messages are not being passed to my code. I think this may be due to the following code in MailFolderMonitor.IdleAsync

if (!handleExceptions)
        {
          taskArray = new Task[4]
          {
            mailFolderMonitor.IdleStartAsync(mailFolderMonitor._cancel.Token),
            mailFolderMonitor.ProcessDepartureQueueAsync(mailFolderMonitor._messageArrivalMethod, mailFolderMonitor._cancel.Token),
            mailFolderMonitor.ProcessDepartureQueueAsync(mailFolderMonitor._messageDepartureMethod, mailFolderMonitor._cancel.Token),
            mailFolderMonitor.ProcessFlagChangeQueueAsync(mailFolderMonitor._messageFlagsChangedMethod, mailFolderMonitor._cancel.Token)
          };
        }

Note that ProcessDepartureQueueAsync is being added twice rather than ProcessArrivalQueueAsync which is being added in the else section.

danzuep commented 3 weeks ago

Try https://www.nuget.org/packages/MailKitSimplified.Receiver/2.11.13-tags-v2-11-13-b0001

alasdair-richardson commented 2 weeks ago

Well it is calling my handling code now. I will let you know how it behaves over the next few days.

alasdair-richardson commented 1 week ago

Finally got an error which backed out into my error handling. Unfortunately it did not work - I suspect I have done something wrong - see exceptions below. Overnight this is what happened

2024-09-03 00:22:27.9247 [ INFO] ervices.MailFolderMonitor: The IMAP server has unexpectedly disconnected. IMAP protocol exception, reconnecting and trying again. 
2024-09-03 03:25:00.1697 [ INFO] ervices.MailFolderMonitor: imap.gmail.com referencing-test@antisemitism.org INBOX IMAP I/O exception, reconnecting. 
2024-09-03 03:25:00.1793 [ INFO] ervices.MailFolderMonitor: imap.gmail.com referencing-test@antisemitism.org INBOX IMAP socket exception during connection attempt #1. 
2024-09-03 03:25:00.1793 [ INFO] ervices.MailFolderMonitor: imap.gmail.com referencing-test@antisemitism.org INBOX IMAP socket exception during connection attempt #2, backing off for 501ms. 
2024-09-03 03:25:00.7711 [DEBUG] Caa.Api.Email.MailMonitor: Exception(SocketException): No such host is known. ... delaying for 2000ms 
2024-09-03 03:25:02.8458 [DEBUG] Caa.Api.Email.MailMonitor: Exception(SocketException): No such host is known. ... delaying for 4000ms 
2024-09-03 03:25:06.9153 [DEBUG] Caa.Api.Email.MailMonitor: Exception(SocketException): No such host is known. ... delaying for 8000ms 
2024-09-03 03:25:14.9691 [DEBUG] Caa.Api.Email.MailMonitor: Exception(SocketException): No such host is known. ... delaying for 16000ms 
2024-09-03 03:25:31.0363 [DEBUG] Caa.Api.Email.MailMonitor: Exception(SocketException): No such host is known. ... delaying for 32000ms 
2024-09-03 03:26:14.1735 [DEBUG] Caa.Api.Email.MailMonitor: Exception(SocketException): No such host is known. ... delaying for 64000ms 
2024-09-03 03:27:18.8094 [DEBUG] Caa.Api.Email.MailMonitor: Exception(ImapProtocolException): The IMAP server has unexpectedly disconnected. ... delaying for 128000ms 
2024-09-03 03:29:27.4969 [ INFO] ervices.MailFolderMonitor: imap.gmail.com referencing-test@antisemitism.org INBOX (0) idle monitor started, fetching existing emails. 
2024-09-03 03:29:27.4969 [ERROR] ervices.MailFolderMonitor: imap.gmail.com referencing-test@antisemitism.org INBOX IMAP client is being accessed by multiple threads. System.ObjectDisposedException: The CancellationTokenSource has been disposed.
   at System.Threading.CancellationTokenSource.get_Token()
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.WaitForNewMessagesAsync(CancellationToken cancellationToken)
2024-09-03 03:29:27.5032 [ INFO] ervices.MailFolderMonitor: imap.gmail.com referencing-test@antisemitism.org INBOX monitoring complete. 
2024-09-03 03:29:28.6271 [ INFO] ervices.MailFolderMonitor: imap.gmail.com referencing-test@antisemitism.org INBOX (0) idle monitor started, fetching existing emails. 
2024-09-03 03:29:28.6286 [ERROR] ervices.MailFolderMonitor: imap.gmail.com referencing-test@antisemitism.org INBOX IMAP client is being accessed by multiple threads. System.ObjectDisposedException: The CancellationTokenSource has been disposed.
   at System.Threading.CancellationTokenSource.get_Token()
   at MailKitSimplified.Receiver.Services.MailFolderMonitor.WaitForNewMessagesAsync(CancellationToken cancellationToken)
2024-09-03 03:29:28.6286 [ INFO] ervices.MailFolderMonitor: imap.gmail.com referencing-test@antisemitism.org INBOX monitoring complete. 

Those last 4 lines in the log are now repeating every second or so and seem to indicate that my code and the base code perhaps both accesing the imap client in deifferent threads or somehting (no idea really). I will add the code from my retry logic below

alasdair-richardson commented 1 week ago

Here is the code for my MonitorWithRetryAsync method. As I said before I am using the Polly library to do the retries, but that should not be causing the problem.

    private async Task MonitorWithRetryAsync(CancellationToken ct)
    {
        var strategy = new ResiliencePipelineBuilder().AddRetry(new()
        {
            ShouldHandle = new PredicateBuilder().Handle<Exception>(),
            MaxRetryAttempts = int.MaxValue,
            BackoffType = DelayBackoffType.Exponential,
            MaxDelay = new TimeSpan(0, 5, 0),
            OnRetry = args =>
            {
                var exception = args.Outcome.Exception!;
                var name = exception.GetType().Name;
                logger.LogDebug("Exception({Name}): {Message} ... delaying for {Time}ms", name,
                    exception.Message, args.RetryDelay.TotalMilliseconds);
                return default;
            }
        }).Build();

        var totalRequests = 0;
        while (!ct.IsCancellationRequested)
        {
            totalRequests++;
            try
            {
                await strategy.ExecuteAsync(async token => await MonitorAsync(token), ct);
            }
            catch (Exception e)
            {
                logger.LogError("Request {No} eventually failed with: {Message}", totalRequests, e.Message);
            }

            await Task.Delay(TimeSpan.FromSeconds(1), ct);
        }
    }

Note that as i have told the strategy to retry forever (but limited the maximum delay to 5 minutes) the code in the catch section above wshouldnever be called - I just left it in from the example in case ... I guess the main question is shoudl I do somethig in the OnRetry code in the strategy which might prevent the access from different threads problem? Particularly if the exception is IMAP server has unexpectedly disconnected.

danzuep commented 1 week ago

This looks like it might be more related to Gmail than anything else sorry. I've hopefully fixed the cancellation token disposed exception in the latest pre-release, sorry for the delay in getting back to you.