MS 365 IMAP oAuth2 seems to be broken since upgrade to 6.4.2

Moderator: crythias

Post Reply
gob
Znuny newbie
Posts: 47
Joined: 18 Jan 2011, 15:45
Znuny Version: 3.0.4

MS 365 IMAP oAuth2 seems to be broken since upgrade to 6.4.2

Post by gob »

Hi

I have been building / testing a new Znuny server on the feature branch with a view to switching over some time in the near future.

I first built this when v6.1 was new so it's been a long time in testing. :lol:
I previously configured oAuth to collect and send email from an IMAP/TLS mailbox on our company Microsoft 365 tenant.
It was working perfectly but since upgrading to v6.4.2 it has stopped receiving emails.
It seems that sending does work OK.

I read a previous post regarding and error with POP and oAuth which pointed to an issue with an outdated module - IO::Socket::SSL
I updated that module as suggested and the znuny server connected once successfully to retrieve the messages in the mailbox. This may have been coincidental as since that one time it will not retrieve emails again.

I don't know if this is coincidental, but it seems that the oAuth token now expires around 90 minutes after it is renewed. I seem to recollect that was much longer in the future that it renews? :

Renewed on 22/08/2022 at 17:25

Code: Select all

Token is valid until 22/08/2022 18:45 (Europe/London).	| Refresh token is valid (without expiration date). | valid
If I check for mail from the CLI with debug option I get the following:

Code: Select all

/opt/otrs/bin/otrs.Console.pl Maint::PostMaster::MailAccountFetch --debug
Error: The terminal encoding should be set to 'utf-8', but is 'ansi_x3.4-1968'. Some characters might not be displayed correctly.

Spawning child process to fetch incoming messages from mail accounts...

outlook.office.com (IMAPTLS)...
IMAPTLS: Connection to outlook.office.com closed.

Started at Mon Aug 22 17:34:25 2022
Using Mail::IMAPClient version 3.42 on perl 5.028001
Connecting with IO::Socket::IP PeerAddr outlook.office.com PeerPort 143 Proto tcp Timeout 600 Debug 1
Connected to outlook.office.com
Read:   * OK The Microsoft Exchange IMAP4 service is ready. [[******************==]
Sending: 1 STARTTLS
Sent 12 bytes
Read:   1 OK Begin TLS negotiation now.
Sending: 2 AUTHENTICATE XOAUTH2
Sent 24 bytes
Read:   +
Sending: [Redact: Count=2 Showcredentials=OFF]
Sent 2950 bytes
Read:   2 OK AUTHENTICATE completed.
Sending: 3 SELECT INBOX
Sent 16 bytes
Read:   3 BAD User is authenticated but not connected.
ERROR: 3 BAD User is authenticated but not connected. at /usr/share/perl5/Mail/IMAPClient.pm line 1378.
        Mail::IMAPClient::__ANON__("3 BAD User is authenticated but not connected.\x{d}\x{a}") called at /usr/share/perl5/Mail/IMAPClient.pm line 1414
        Mail::IMAPClient::_get_response(Mail::IMAPClient=HASH(0x561b730379d0), 3, undef) called at /usr/share/perl5/Mail/IMAPClient.pm line 1340
        Mail::IMAPClient::_imap_command_do(Mail::IMAPClient=HASH(0x561b730379d0), "SELECT INBOX") called at /usr/share/perl5/Mail/IMAPClient.pm line 1238
        Mail::IMAPClient::_imap_command(Mail::IMAPClient=HASH(0x561b730379d0), "SELECT INBOX") called at /usr/share/perl5/Mail/IMAPClient.pm line 854
        Mail::IMAPClient::select(Mail::IMAPClient=HASH(0x561b730379d0), "INBOX") called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 301
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 305
        Kernel::System::MailAccount::IMAP::__ANON__("select", "INBOX") called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 331
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 345
        Kernel::System::MailAccount::IMAP::_Fetch(Kernel::System::MailAccount::IMAPTLS=HASH(0x561b720268f8), "AuthenticationType", "oauth2_token", "ChangeTime", "2022-08-22 13:23:44", "Type", "IMAPTLS", "Password", ...) called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 157
        Kernel::System::MailAccount::IMAP::Fetch(Kernel::System::MailAccount::IMAPTLS=HASH(0x561b720268f8), "DispatchingBy", "From", "ValidID", 1, "Debug", 1, "Host", ...) called at /opt/znuny-6.4.2/Kernel/System/MailAccount.pm line 649
        Kernel::System::MailAccount::MailAccountFetch(Kernel::System::MailAccount=HASH(0x561b71fcc188), "Comment", "", "CreateTime", "2021-08-13 22:12:44", "********ConfigID", 2, "AuthenticationType", ...) called at /opt/znuny-6.4.2/Kernel/System/Console/Command/Maint/PostMaster/MailAccountFetch.pm line 170
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/Console/Command/Maint/PostMaster/MailAccountFetch.pm line 162
        Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch::Run(Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch=HASH(0x561b6ecdf2d8)) called at /opt/znuny-6.4.2/Kernel/System/Console/BaseCommand.pm line 460
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/Console/BaseCommand.pm line 454
        Kernel::System::Console::BaseCommand::Execute(Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch=HASH(0x561b6ecdf2d8), "--debug") called at /opt/znuny-6.4.2/Kernel/System/Console/InterfaceConsole.pm line 81
        Kernel::System::Console::InterfaceConsole::Run(Kernel::System::Console::InterfaceConsole=HASH(0x561b71557a40), "Maint::PostMaster::MailAccountFetch", "--debug") called at /opt/otrs/bin/otrs.Console.pl line 37
ERROR: 3 BAD User is authenticated but not connected. at /usr/share/perl5/Mail/IMAPClient.pm line 1288.
        Mail::IMAPClient::_imap_command(Mail::IMAPClient=HASH(0x561b730379d0), "SELECT INBOX") called at /usr/share/perl5/Mail/IMAPClient.pm line 854
        Mail::IMAPClient::select(Mail::IMAPClient=HASH(0x561b730379d0), "INBOX") called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 301
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 305
        Kernel::System::MailAccount::IMAP::__ANON__("select", "INBOX") called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 331
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 345
        Kernel::System::MailAccount::IMAP::_Fetch(Kernel::System::MailAccount::IMAPTLS=HASH(0x561b720268f8), "AuthenticationType", "oauth2_token", "ChangeTime", "2022-08-22 13:23:44", "Type", "IMAPTLS", "Password", ...) called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 157
        Kernel::System::MailAccount::IMAP::Fetch(Kernel::System::MailAccount::IMAPTLS=HASH(0x561b720268f8), "DispatchingBy", "From", "ValidID", 1, "Debug", 1, "Host", ...) called at /opt/znuny-6.4.2/Kernel/System/MailAccount.pm line 649
        Kernel::System::MailAccount::MailAccountFetch(Kernel::System::MailAccount=HASH(0x561b71fcc188), "Comment", "", "CreateTime", "2021-08-13 22:12:44", "********ConfigID", 2, "AuthenticationType", ...) called at /opt/znuny-6.4.2/Kernel/System/Console/Command/Maint/PostMaster/MailAccountFetch.pm line 170
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/Console/Command/Maint/PostMaster/MailAccountFetch.pm line 162
        Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch::Run(Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch=HASH(0x561b6ecdf2d8)) called at /opt/znuny-6.4.2/Kernel/System/Console/BaseCommand.pm line 460
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/Console/BaseCommand.pm line 454
        Kernel::System::Console::BaseCommand::Execute(Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch=HASH(0x561b6ecdf2d8), "--debug") called at /opt/znuny-6.4.2/Kernel/System/Console/InterfaceConsole.pm line 81
        Kernel::System::Console::InterfaceConsole::Run(Kernel::System::Console::InterfaceConsole=HASH(0x561b71557a40), "Maint::PostMaster::MailAccountFetch", "--debug") called at /opt/otrs/bin/otrs.Console.pl line 37
ERROR: OTRS-otrs.Console.pl-Maint::PostMaster::MailAccountFetch-78 Perl: 5.28.1 OS: linux Time: Mon Aug 22 17:34:27 2022

 Message: Error while retrieving the messages 'IMAPTLS': Could not select: 


 Traceback (6175): 
   Module: Kernel::System::MailAccount::IMAP::_Fetch Line: 347
   Module: Kernel::System::MailAccount::IMAP::Fetch Line: 157
   Module: Kernel::System::MailAccount::MailAccountFetch Line: 649
   Module: (eval) Line: 170
   Module: Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch::Run Line: 162
   Module: (eval) Line: 460
   Module: Kernel::System::Console::BaseCommand::Execute Line: 454
   Module: Kernel::System::Console::InterfaceConsole::Run Line: 81
   Module: /opt/otrs/bin/otrs.Console.pl Line: 37

Sending: 4 CLOSE
Sent 9 bytes
Read:   4 BAD User is authenticated but not connected.
        * BYE Connection closed. 14
ERROR: 4 BAD User is authenticated but not connected. at /usr/share/perl5/Mail/IMAPClient.pm line 1378.
        Mail::IMAPClient::__ANON__("4 BAD User is authenticated but not connected.\x{d}\x{a}") called at /usr/share/perl5/Mail/IMAPClient.pm line 1414
        Mail::IMAPClient::_get_response(Mail::IMAPClient=HASH(0x561b730379d0), 4, undef) called at /usr/share/perl5/Mail/IMAPClient.pm line 1340
        Mail::IMAPClient::_imap_command_do(Mail::IMAPClient=HASH(0x561b730379d0), "CLOSE") called at /usr/share/perl5/Mail/IMAPClient.pm line 1238
        Mail::IMAPClient::_imap_command(Mail::IMAPClient=HASH(0x561b730379d0), "CLOSE") called at /usr/share/perl5/Mail/IMAPClient.pm line 2369
        Mail::IMAPClient::close(Mail::IMAPClient=HASH(0x561b730379d0)) called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 301
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 305
        Kernel::System::MailAccount::IMAP::__ANON__("close") called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 521
        Kernel::System::MailAccount::IMAP::_Fetch(Kernel::System::MailAccount::IMAPTLS=HASH(0x561b720268f8), "AuthenticationType", "oauth2_token", "ChangeTime", "2022-08-22 13:23:44", "Type", "IMAPTLS", "Password", ...) called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 157
        Kernel::System::MailAccount::IMAP::Fetch(Kernel::System::MailAccount::IMAPTLS=HASH(0x561b720268f8), "DispatchingBy", "From", "ValidID", 1, "Debug", 1, "Host", ...) called at /opt/znuny-6.4.2/Kernel/System/MailAccount.pm line 649
        Kernel::System::MailAccount::MailAccountFetch(Kernel::System::MailAccount=HASH(0x561b71fcc188), "Comment", "", "CreateTime", "2021-08-13 22:12:44", "********ConfigID", 2, "AuthenticationType", ...) called at /opt/znuny-6.4.2/Kernel/System/Console/Command/Maint/PostMaster/MailAccountFetch.pm line 170
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/Console/Command/Maint/PostMaster/MailAccountFetch.pm line 162
        Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch::Run(Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch=HASH(0x561b6ecdf2d8)) called at /opt/znuny-6.4.2/Kernel/System/Console/BaseCommand.pm line 460
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/Console/BaseCommand.pm line 454
        Kernel::System::Console::BaseCommand::Execute(Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch=HASH(0x561b6ecdf2d8), "--debug") called at /opt/znuny-6.4.2/Kernel/System/Console/InterfaceConsole.pm line 81
        Kernel::System::Console::InterfaceConsole::Run(Kernel::System::Console::InterfaceConsole=HASH(0x561b71557a40), "Maint::PostMaster::MailAccountFetch", "--debug") called at /opt/otrs/bin/otrs.Console.pl line 37
ERROR: * BYE Connection closed. 14 at /usr/share/perl5/Mail/IMAPClient.pm line 1429.
        Mail::IMAPClient::_get_response(Mail::IMAPClient=HASH(0x561b730379d0), 4, undef) called at /usr/share/perl5/Mail/IMAPClient.pm line 1340
        Mail::IMAPClient::_imap_command_do(Mail::IMAPClient=HASH(0x561b730379d0), "CLOSE") called at /usr/share/perl5/Mail/IMAPClient.pm line 1238
        Mail::IMAPClient::_imap_command(Mail::IMAPClient=HASH(0x561b730379d0), "CLOSE") called at /usr/share/perl5/Mail/IMAPClient.pm line 2369
        Mail::IMAPClient::close(Mail::IMAPClient=HASH(0x561b730379d0)) called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 301
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 305
        Kernel::System::MailAccount::IMAP::__ANON__("close") called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 521
        Kernel::System::MailAccount::IMAP::_Fetch(Kernel::System::MailAccount::IMAPTLS=HASH(0x561b720268f8), "AuthenticationType", "oauth2_token", "ChangeTime", "2022-08-22 13:23:44", "Type", "IMAPTLS", "Password", ...) called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 157
        Kernel::System::MailAccount::IMAP::Fetch(Kernel::System::MailAccount::IMAPTLS=HASH(0x561b720268f8), "DispatchingBy", "From", "ValidID", 1, "Debug", 1, "Host", ...) called at /opt/znuny-6.4.2/Kernel/System/MailAccount.pm line 649
        Kernel::System::MailAccount::MailAccountFetch(Kernel::System::MailAccount=HASH(0x561b71fcc188), "Comment", "", "CreateTime", "2021-08-13 22:12:44", "********ConfigID", 2, "AuthenticationType", ...) called at /opt/znuny-6.4.2/Kernel/System/Console/Command/Maint/PostMaster/MailAccountFetch.pm line 170
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/Console/Command/Maint/PostMaster/MailAccountFetch.pm line 162
        Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch::Run(Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch=HASH(0x561b6ecdf2d8)) called at /opt/znuny-6.4.2/Kernel/System/Console/BaseCommand.pm line 460
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/Console/BaseCommand.pm line 454
        Kernel::System::Console::BaseCommand::Execute(Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch=HASH(0x561b6ecdf2d8), "--debug") called at /opt/znuny-6.4.2/Kernel/System/Console/InterfaceConsole.pm line 81
        Kernel::System::Console::InterfaceConsole::Run(Kernel::System::Console::InterfaceConsole=HASH(0x561b71557a40), "Maint::PostMaster::MailAccountFetch", "--debug") called at /opt/otrs/bin/otrs.Console.pl line 37
ERROR: * BYE Connection closed. 14 at /usr/share/perl5/Mail/IMAPClient.pm line 1288.
        Mail::IMAPClient::_imap_command(Mail::IMAPClient=HASH(0x561b730379d0), "CLOSE") called at /usr/share/perl5/Mail/IMAPClient.pm line 2369
        Mail::IMAPClient::close(Mail::IMAPClient=HASH(0x561b730379d0)) called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 301
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 305
        Kernel::System::MailAccount::IMAP::__ANON__("close") called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 521
        Kernel::System::MailAccount::IMAP::_Fetch(Kernel::System::MailAccount::IMAPTLS=HASH(0x561b720268f8), "AuthenticationType", "oauth2_token", "ChangeTime", "2022-08-22 13:23:44", "Type", "IMAPTLS", "Password", ...) called at /opt/znuny-6.4.2/Kernel/System/MailAccount/IMAP.pm line 157
        Kernel::System::MailAccount::IMAP::Fetch(Kernel::System::MailAccount::IMAPTLS=HASH(0x561b720268f8), "DispatchingBy", "From", "ValidID", 1, "Debug", 1, "Host", ...) called at /opt/znuny-6.4.2/Kernel/System/MailAccount.pm line 649
        Kernel::System::MailAccount::MailAccountFetch(Kernel::System::MailAccount=HASH(0x561b71fcc188), "Comment", "", "CreateTime", "2021-08-13 22:12:44", "********ConfigID", 2, "AuthenticationType", ...) called at /opt/znuny-6.4.2/Kernel/System/Console/Command/Maint/PostMaster/MailAccountFetch.pm line 170
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/Console/Command/Maint/PostMaster/MailAccountFetch.pm line 162
        Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch::Run(Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch=HASH(0x561b6ecdf2d8)) called at /opt/znuny-6.4.2/Kernel/System/Console/BaseCommand.pm line 460
        eval {...} called at /opt/znuny-6.4.2/Kernel/System/Console/BaseCommand.pm line 454
        Kernel::System::Console::BaseCommand::Execute(Kernel::System::Console::Command::Maint::PostMaster::MailAccountFetch=HASH(0x561b6ecdf2d8), "--debug") called at /opt/znuny-6.4.2/Kernel/System/Console/InterfaceConsole.pm line 81
        Kernel::System::Console::InterfaceConsole::Run(Kernel::System::Console::InterfaceConsole=HASH(0x561b71557a40), "Maint::PostMaster::MailAccountFetch", "--debug") called at /opt/otrs/bin/otrs.Console.pl line 37
Done.
Any suggestions on what might be wrong or any further troubleshooting steps?

thanks!
root
Administrator
Posts: 3960
Joined: 18 Dec 2007, 12:23
Znuny Version: Znuny and Znuny LTS
Real Name: Roy Kaldung
Company: Znuny
Contact:

Re: MS 365 IMAP oAuth2 seems to be broken since upgrade to 6.4.2

Post by root »

Hi,

"3 BAD User is authenticated but not connected." usually indicates an issue with permissions or an expired application secret. What kind of mailbox is it? A regular one or a shared one? Does the user signed in on the OAuth consent screen still have sufficient permissions to the mailbox?

- Roy
Znuny and Znuny LTS running on CentOS / RHEL / Debian / SLES / MySQL / PostgreSQL / Oracle / OpenLDAP / Active Directory / SSO

Use a test system - always.

Do you need professional services? Check out https://www.znuny.com/

Do you want to contribute or want to know where it goes ?
gob
Znuny newbie
Posts: 47
Joined: 18 Jan 2011, 15:45
Znuny Version: 3.0.4

Re: MS 365 IMAP oAuth2 seems to be broken since upgrade to 6.4.2

Post by gob »

a-ha!
Good shout Roy.
I granted my account full access on the znuny mailbox and refreshed the token.
Seems to be working again now!

Hopefully that's it.

Thanks
Gordon
KevP
Znuny newbie
Posts: 20
Joined: 09 May 2023, 16:52
Znuny Version: 7.0
Real Name: Kevin Pattison

Re: MS 365 IMAP oAuth2 seems to be broken since upgrade to 6.4.2

Post by KevP »

I had the same problem setting it up. The resolution for me was that I needed to allow IMAP on my own user account through admin.microsoft.com and "email apps" setting on my user (as I had authenticated). Hope this helps someone.
Post Reply