IMAP in bad state. "[401] Invalid access token".

[jschwartzentruber]

Following is my log from hydroxide-imap running overnight with Thunderbird open and connected (unattended).

Nov 25 22:48:40 hydroxide[11625]: 2018/11/25 22:48:40 Synchronizing mailbox INBOX...
Nov 25 22:48:41 hydroxide[11625]: 2018/11/25 22:48:41 Synchronizing mailbox INBOX: done.
Nov 25 23:08:02 hydroxide[11625]: 2018/11/25 23:08:02 Synchronizing mailbox INBOX...
Nov 25 23:08:03 hydroxide[11625]: 2018/11/25 23:08:03 Synchronizing mailbox INBOX: done.
Nov 26 02:32:09 hydroxide[11625]: 2018/11/26 02:32:09 cannot receive event: [500] Internal server error
[snip ... same message every few seconds]
Nov 26 02:57:39 hydroxide[11625]: 2018/11/26 02:57:39 cannot receive event: [500] Internal server error
Nov 26 03:00:17 hydroxide[11625]: 2018/11/26 03:00:17 Synchronizing mailbox INBOX...
Nov 26 03:00:19 hydroxide[11625]: 2018/11/26 03:00:19 Synchronizing mailbox INBOX: done.
Nov 26 03:31:48 hydroxide[11625]: 2018/11/26 03:31:48 Received create event for message xyz==
Nov 26 06:54:47 hydroxide[11625]: 2018/11/26 06:54:47 Received update event for message xyz==
Nov 26 06:56:18 hydroxide[11625]: 2018/11/26 06:56:18 Received create event for message xyz==
Nov 26 07:41:18 hydroxide[11625]: 2018/11/26 07:41:18 Received create event for message xyz==
Nov 26 07:42:48 hydroxide[11625]: 2018/11/26 07:42:48 Received update event for message xyz==
Nov 26 07:43:47 hydroxide[11625]: 2018/11/26 07:43:47 Received update event for message xyz==
Nov 26 09:16:38 hydroxide[11625]: imap/server: 2018/11/26 09:16:38 cannot send response:  write tcp 127.0.0.1:7143->127.0.0.1:55100: write: broken pipe
Nov 26 09:16:51 hydroxide[11625]: 2018/11/26 09:16:51 Synchronizing mailbox INBOX...
Nov 26 09:16:52 hydroxide[11625]: 2018/11/26 09:16:52 Synchronizing mailbox INBOX: done.
Nov 26 09:17:51 hydroxide[11625]: 2018/11/26 09:17:51 cannot receive event: cannot re-authenticate: two factor authentication enabled, please login manually
Nov 26 09:17:51 hydroxide[11625]: 2018/11/26 09:17:51 cannot receive event: [401] Invalid access token
[snip ... same message multiple times per second]
Nov 26 10:21:04 hydroxide[11625]: 2018/11/26 10:21:04 cannot receive event: [401] Invalid access token
Nov 26 10:21:04 systemd[793]: Stopping Hydroxide IMAP proxy....
Nov 26 10:21:04 systemd[793]: Stopped Hydroxide IMAP proxy..
Nov 26 10:21:04 systemd[793]: Started Hydroxide IMAP proxy..
Nov 26 10:21:04 hydroxide[22743]: 2018/11/26 10:21:04 Starting IMAP server at 127.0.0.1:7143
Nov 26 10:21:20 hydroxide[22743]: 2018/11/26 10:21:20 Synchronizing mailbox INBOX...
Nov 26 10:21:21 hydroxide[22743]: 2018/11/26 10:21:21 Synchronizing mailbox INBOX: done.

So it thinks it needs to re-authenticate due to MFA, but restarting the service causes it to work again (without re-authentication).

The log also shows a period of 500 errors (I guess that is the PM server?), but hydroxide recovers from that.