0 votes
by (120 points)

I have application in which we read/send Mails and show in our application
We use Office365 accounts and user credentials to get mails. Recently Microsoft stopped Basic auth, so we switched to OAuth. Its able to read mails but it works for 1st two attempts and start failing from that. I am attaching the part of log file. Please check

2022-03-15 21:30:11.863 DEBUG Imap(1)[5] Info: State changed from 'Reading' to 'Ready'.
2022-03-15 21:30:17.833 DEBUG Imap(1)[36] Info: State changed from 'Ready' to 'Sending'.
2022-03-15 21:30:17.833 INFO Imap(1)[36] Command: R0003D LIST "" Inbox
2022-03-15 21:30:17.833 DEBUG Imap(1)[36] Info: State changed from 'Sending' to 'Reading'.
2022-03-15 21:30:18.113 INFO Imap(1)[36] Response: * LIST (\Marked \HasNoChildren) "/" INBOX
2022-03-15 21:30:18.113 INFO Imap(1)[36] Response: R0003D OK LIST completed.
2022-03-15 21:30:18.113 DEBUG Imap(1)[36] Info: State changed from 'Reading' to 'Ready'.
2022-03-15 21:30:18.127 DEBUG Imap(1)[36] Info: State changed from 'Ready' to 'Sending'.
2022-03-15 21:30:18.127 INFO Imap(1)[36] Command: R0003E STATUS Inbox (UNSEEN)
2022-03-15 21:30:18.127 DEBUG Imap(1)[36] Info: State changed from 'Sending' to 'Reading'.
2022-03-15 21:30:18.404 INFO Imap(1)[36] Response: * STATUS INBOX (UNSEEN 2)
2022-03-15 21:30:18.404 INFO Imap(1)[36] Response: R0003E OK STATUS completed.
2022-03-15 21:30:18.404 DEBUG Imap(1)[36] Info: State changed from 'Reading' to 'Ready'.
2022-03-15 21:30:18.408 DEBUG Imap(1)[36] Info: State changed from 'Ready' to 'Sending'.
2022-03-15 21:30:18.408 INFO Imap(1)[36] Command: R0003F SELECT Inbox
2022-03-15 21:30:18.408 DEBUG Imap(1)[36] Info: State changed from 'Sending' to 'Reading'.
2022-03-15 21:30:18.689 INFO Imap(1)[36] Response: * 3 EXISTS
2022-03-15 21:30:18.689 INFO Imap(1)[36] Response: * 0 RECENT
2022-03-15 21:30:18.689 INFO Imap(1)[36] Response: * FLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)
2022-03-15 21:30:18.689 INFO Imap(1)[36] Response: * OK [PERMANENTFLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)] Permanent flags
2022-03-15 21:30:18.689 INFO Imap(1)[36] Response: * OK [UNSEEN 1] Is the first unseen message
2022-03-15 21:30:18.689 INFO Imap(1)[36] Response: * OK [UIDVALIDITY 14] UIDVALIDITY value
2022-03-15 21:30:18.689 INFO Imap(1)[36] Response: * OK [UIDNEXT 30] The next unique identifier value
2022-03-15 21:30:18.689 INFO Imap(1)[36] Response: R0003F OK [READ-WRITE] SELECT completed.
2022-03-15 21:30:18.689 DEBUG Imap(1)[36] Info: State changed from 'Reading' to 'Ready'.
2022-03-15 21:30:18.690 DEBUG Imap(1)[36] Info: State changed from 'Ready' to 'Sending'.
2022-03-15 21:30:18.690 INFO Imap(1)[36] Command: R00040 UID SEARCH 1:3 ALL
2022-03-15 21:30:18.690 DEBUG Imap(1)[36] Info: State changed from 'Sending' to 'Reading'.
2022-03-15 21:30:18.965 INFO Imap(1)[36] Response: * SEARCH 5 26 28
2022-03-15 21:30:18.965 INFO Imap(1)[36] Response: R00040 OK SEARCH completed.
2022-03-15 21:30:18.965 DEBUG Imap(1)[36] Info: State changed from 'Reading' to 'Ready'.
2022-03-15 21:30:18.972 DEBUG Imap(1)[36] Info: State changed from 'Ready' to 'Sending'.
2022-03-15 21:30:18.972 INFO Imap(1)[36] Command: R00041 UID FETCH 5,26,28 (UID RFC822.SIZE FLAGS INTERNALDATE BODY.PEEK[HEADER] BODY)
2022-03-15 21:30:18.972 DEBUG Imap(1)[36] Info: State changed from 'Sending' to 'Reading'.
2022-03-15 21:30:19.268 INFO Imap(1)[36] Response: * 1 FETCH (UID 5 RFC822.SIZE 165057 FLAGS () INTERNALDATE "14-Mar-2022 00:17:01 -0400" BODY[HEADER] {8148}
2022-03-15 21:30:19.268 INFO Imap(1)[36] Response: ...8148 bytes...
2022-03-15 21:30:19.268 INFO Imap(1)[36] Response: BODY (("text" "plain" ("charset" "utf-8") NIL NIL "quoted-printable" 1851 55)("text" "html" ("charset" "utf-8") NIL NIL "quoted-printable" 67592 1584) "alternative"))
2022-03-15 21:30:19.268 INFO Imap(1)[36] Response: * 2 FETCH (UID 26 RFC822.SIZE 25331 FLAGS (\Seen) INTERNALDATE "15-Mar-2022 04:54:04 -0400" BODY[HEADER] {2244}
2022-03-15 21:30:19.295 INFO Imap(1)[36] Response: ...2244 bytes...
2022-03-15 21:30:19.295 INFO Imap(1)[36] Response: BODY ("text" "html" ("charset" "iso-8859-1") NIL NIL "quoted-printable" 0 0))
2022-03-15 21:30:19.295 INFO Imap(1)[36] Response: * 3 FETCH (UID 28 RFC822.SIZE 655211 FLAGS () INTERNALDATE "15-Mar-2022 06:40:12 -0400" BODY[HEADER] {7740}
2022-03-15 21:30:19.295 INFO Imap(1)[36] Response: ...7740 bytes...
2022-03-15 21:30:19.295 INFO Imap(1)[36] Response: BODY ((("text" "plain" ("charset" "utf-8") NIL NIL "quoted-printable" 2980 84)("text" "html" ("charset" "utf-8") NIL NIL "quoted-printable" 76087 1702) "alternative")("application" "octet-stream" ("name" "122290150921360.pdf") NIL NIL "base64" 614646) "mixed"))
2022-03-15 21:30:19.520 INFO Imap(1)[36] Response: R00041 OK FETCH completed.
2022-03-15 21:30:19.520 DEBUG Imap(1)[36] Info: State changed from 'Reading' to 'Ready'.
2022-03-15 21:37:09.811 DEBUG Imap(1)[26] Info: State changed from 'Ready' to 'Sending'.
2022-03-15 21:37:09.811 INFO Imap(1)[26] Command: R00042 LIST "" Inbox
2022-03-15 21:37:09.811 DEBUG Imap(1)[26] Info: State changed from 'Sending' to 'Reading'.
2022-03-15 21:37:29.084 DEBUG Imap(1)[26] TLS: TLS socket error, 0 bytes of data were received.
2022-03-15 21:37:29.087 DEBUG Imap(1)[26] TLS: TLS socket was closed: System.Net.Sockets.SocketException (0x80004005): An existing connection was forcibly closed by the remote host
at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
at Rebex.Net.ProxySocket.Receive(Byte[] buffer, Int32 offset, Int32 count, SocketFlags socketFlags)
at gjgit.hyowb.pcjrr(Int32 p0)
at gjgit.hyowb.nknsl()
at gjgit.hyowb.kotmb()
2022-03-15 21:37:29.091 INFO Imap(1)[26] TLS: Fatal Alert:InternalError was sent.
2022-03-15 21:37:29.096 ERROR Imap(1)[26] Info: Rebex.Net.TlsException: Connection was closed by the remote connection end. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
at Rebex.Net.ProxySocket.Receive(Byte[] buffer, Int32 offset, Int32 count, SocketFlags socketFlags)
at gjgit.hyowb.pcjrr(Int32 p0)
at gjgit.hyowb.nknsl()
at gjgit.hyowb.kotmb()
--- End of inner exception stack trace ---
at gjgit.hyowb.kotmb()
at gjgit.slguj.Poll(Int32 microSeconds, SocketSelectMode mode)
at Rebex.Net.TlsSocket.Poll(Int32 microSeconds, SocketSelectMode mode)
at gjgit.ilbpy.oguyl(Byte[] p0, Int32 p1, Int32 p2)
at gjgit.ilbpy.nudjq()
at gjgit.ilbpy.rzitx(Int32& p0)
at Rebex.Net.Imap.uggea()
at Rebex.Net.Imap.bffrq(String p0, ArrayList p1)
at Rebex.Net.Imap.caafd(String p0, ypnpr p1, String p2, Boolean p3, Func`3 p4)
at Rebex.Net.Imap.xaflj(Boolean p0, String p1, Object[] p2)
at Rebex.Net.Imap.vseow(String p0, Boolean p1)
at Rebex.Net.Imap.buhgb(String p0)
2022-03-15 21:46:28.427 ERROR Imap(1)[53] Info: System.InvalidOperationException: Cannot send command to the server because the response for previous one was not received.
at Rebex.Net.Imap.xctcz(String p0, String p1, Object[] p2)
at Rebex.Net.Imap.xaflj(Boolean p0, String p1, Object[] p2)
at Rebex.Net.Imap.vseow(String p0, Boolean p1)
at Rebex.Net.Imap.buhgb(String p0)

Applies to: Rebex Secure Mail

1 Answer

0 votes
by (144k points)
According to the log, this looks like the failure occurred after a successful authentication, and the reason seems to be connectivity issue - "An existing connection was forcibly closed by the remote host" error that indicates the connection has been lost. It doesn't seem to be related to OAuth authentication. If you are getting these errors at random, check your Internet connectivity. If there seems to be some pattern in them, we would like to see more logs to determine what is going on. But either way, this does not seem to be a client-side issue (or OAuth issue).
by (144k points)
By the way, I can't find your e-mail address or company in our licensing system. To ensure continued support, please contact us at support@rebex.net so we can sort this out. Thanks!
by (120 points)
edited by
ok, will check further, by the way is their any specific error status to know the oAuth token is expired ?. currently i see AUTHENTICATE failed (NO) at client.Login(token, ImapAuthentication.OAuth20); even for invalid token. is there any specific error status to know determine the error if so please share thanks
by (120 points)
Regd license the web we using is taken from another company, we don't have licensing details or credentials and version we have is 1.0.4086 , in which oAuth is not supported, so downloaded the latest version trail and started working. If this works out we will buy license . Thanks
by (144k points)
No, there is no specific error, unfortunately. Office365's IMAP just returns "NO AUTHENTICATE failed" when the token expires. Instead, consider tracking the token age in the application, and get a new one before it expires.
...