User auth fails for IMAP and SMTP AUTH on fresh install of Rocky 8 and 9

swimboy · July 6, 2023, 3:43pm

SYSTEM INFORMATION
OS type and version	Rocky 8 and 9
Virtualmin version	7.7

I’ve tried several times with fresh installs of the latest Rocky 8 and Rocky 9, and experience the same problems. I get the following error during the installation after configuring Fail2BanFirewall:

Use of uninitialized value $backend in concatenation (.) or string at /usr/share/perl5/vendor_perl/Virtualmin/Config/Plugin/Fail2banFirewalld.pm line 90.

After setting up a domain and a user, I get authentication failures when trying to log in via IMAP or SMTP AUTH. If I try logging in to Usermin, the password works, but fails when trying to display the inbox with an IMAP authentication error.

Joe · July 6, 2023, 4:17pm

These two things are unrelated.

The Fail2banFirewalld error is a known issue and will be fixed in a virtualmin-config update. It is a cosmetic issue.

We need to see the maillog (or journal for the relevant service) entries when you try to authenticate with IMAP or SMTP.

swimboy · July 7, 2023, 1:29pm

OK, I was able to resolve the IMAP authentication issue, but still can’t get SMTP AUTH to work. Here are the relevant log entries:

/var/log/maillog:

Jul  7 13:22:39 localhost postfix/smtpd[104251]: warning: SASL authentication failure: Password verification failed
Jul  7 13:22:39 localhost postfix/smtpd[104251]: warning: d4-50-154-112.nap.wideopenwest.com[50.4.112.154]: SASL PLAIN authentication failed: authentication failure
Jul  7 13:22:41 localhost postfix/smtpd[104251]: warning: SASL authentication failure: Password verification failed
Jul  7 13:22:41 localhost postfix/smtpd[104251]: warning: d4-50-154-112.nap.wideopenwest.com[50.4.112.154]: SASL PLAIN authentication failed: authentication failure
Jul  7 13:22:43 localhost postfix/smtpd[104251]: warning: d4-50-154-112.nap.wideopenwest.com[50.4.112.154]: SASL LOGIN authentication failed: authentication failure
Jul  7 13:22:45 localhost postfix/smtpd[104251]: warning: d4-50-154-112.nap.wideopenwest.com[50.4.112.154]: SASL LOGIN authentication failed: authentication failure
Jul  7 13:22:45 localhost postfix/smtpd[104251]: disconnect from d4-50-154-112.nap.wideopenwest.com[50.4.112.154] ehlo=2 starttls=1 auth=0/4 quit=1 commands=4/8
Jul  7 13:25:34 localhost postfix/anvil[99750]: statistics: max connection rate 2/60s for (submission:50.4.112.154) at Jul  7 13:18:22
Jul  7 13:25:34 localhost postfix/anvil[99750]: statistics: max connection count 1 for (submission:50.4.112.154) at Jul  7 13:15:34
Jul  7 13:25:34 localhost postfix/anvil[99750]: statistics: max cache size 2 at Jul  7 13:20:16

and /var/log/secure:

Jul  7 13:22:37 localhost saslauthd[20261]: pam_unix(smtp:auth): check pass; user unknown
Jul  7 13:22:37 localhost saslauthd[20261]: pam_unix(smtp:auth): authentication failure; logname= uid=0 euid=0 tty= ruser= rhost=
Jul  7 13:22:39 localhost saslauthd[20263]: pam_unix(smtp:auth): check pass; user unknown
Jul  7 13:22:39 localhost saslauthd[20263]: pam_unix(smtp:auth): authentication failure; logname= uid=0 euid=0 tty= ruser= rhost=
Jul  7 13:22:41 localhost saslauthd[20264]: pam_unix(smtp:auth): check pass; user unknown
Jul  7 13:22:41 localhost saslauthd[20264]: pam_unix(smtp:auth): authentication failure; logname= uid=0 euid=0 tty= ruser= rhost=
Jul  7 13:22:44 localhost saslauthd[20265]: pam_unix(smtp:auth): check pass; user unknown
Jul  7 13:22:44 localhost saslauthd[20265]: pam_unix(smtp:auth): authentication failure; logname= uid=0 euid=0 tty= ruser= rhost=

and here’s the SMTP trace from the client:

INITIATING CONNECTION Jul 07 09:22:36.515 host:hawk.tagcomp.com -- port:587 -- socket:0x0 -- thread:0x6000003e4400

CONNECTED Jul 07 09:22:36.553 [kCFStreamSocketSecurityLevelNone] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400

READ Jul 07 09:22:36.604 [kCFStreamSocketSecurityLevelNone] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
220 hawk.tagcomp.com ESMTP Postfix

WROTE Jul 07 09:22:36.604 [kCFStreamSocketSecurityLevelNone] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
EHLO smtpclient.apple

READ Jul 07 09:22:36.645 [kCFStreamSocketSecurityLevelNone] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
250-hawk.tagcomp.com
250-PIPELINING
250-SIZE 10240000
250-VRFY
250-ETRN
250-STARTTLS
250-AUTH PLAIN LOGIN
250-AUTH=PLAIN LOGIN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250-DSN
250-SMTPUTF8
250 CHUNKING

WROTE Jul 07 09:22:36.645 [kCFStreamSocketSecurityLevelNone] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
STARTTLS

READ Jul 07 09:22:36.680 [kCFStreamSocketSecurityLevelNone] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
220 2.0.0 Ready to start TLS

WROTE Jul 07 09:22:36.870 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
EHLO smtpclient.apple

READ Jul 07 09:22:36.914 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
250-hawk.tagcomp.com
250-PIPELINING
250-SIZE 10240000
250-VRFY
250-ETRN
250-AUTH PLAIN LOGIN
250-AUTH=PLAIN LOGIN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250-DSN
250-SMTPUTF8
250 CHUNKING

WROTE Jul 07 09:22:36.915 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
AUTH PLAIN  (*** 56 bytes hidden ***)

READ Jul 07 09:22:39.163 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
535 5.7.8 Error: authentication failed: authentication failure

WROTE Jul 07 09:22:39.163 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
AUTH PLAIN  (*** 36 bytes hidden ***)

READ Jul 07 09:22:41.347 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
535 5.7.8 Error: authentication failed: authentication failure

WROTE Jul 07 09:22:41.348 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
AUTH LOGIN

READ Jul 07 09:22:41.384 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
334 VXNlcm5hbWU6

WROTE Jul 07 09:22:41.384 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
amVmZi1tYi1yMTI5LmNvbQ==

READ Jul 07 09:22:41.422 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
334 UGFzc3dvcmQ6

WROTE Jul 07 09:22:41.422 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
************

READ Jul 07 09:22:43.892 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
535 5.7.8 Error: authentication failed: authentication failure

WROTE Jul 07 09:22:43.893 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
AUTH LOGIN

READ Jul 07 09:22:43.929 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
334 VXNlcm5hbWU6

WROTE Jul 07 09:22:43.929 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
amVmZi1tYi1yMTI5LmNvbQ==

READ Jul 07 09:22:43.968 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
334 UGFzc3dvcmQ6

WROTE Jul 07 09:22:43.968 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
************

READ Jul 07 09:22:45.508 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
535 5.7.8 Error: authentication failed: authentication failure

WROTE Jul 07 09:22:45.509 [kCFStreamSocketSecurityLevelTLSv1_2] -- host:hawk.tagcomp.com -- port:587 -- socket:0x600003c366a0 -- thread:0x6000003e4400
QUIT

stefan1959 · July 7, 2023, 9:02pm

are you using the email address as username?

swimboy · July 7, 2023, 9:06pm

Yes, I am, for both IMAP and SMTP. It’s working for IMAP, but not SMTP.

stefan1959 · July 7, 2023, 9:25pm

by the log its not sending a username as its blank. What options have you set for smtp? Looks like a apple device and I’m not familiar with them.

found this may help testing

swimboy · July 8, 2023, 2:31pm

I also noticed the blank username in the logs, which was curious. In the SMTP trace from the client, you can see the username being transmitted in base64 (I decoded it to make sure it was the correct username). I’ve even tried manually telnetting into port 587 and sending the authentication information by hand and still get the same entries in the log.

(I tried the SMTP test tool, but it’s down right now due to a DDOS attack. )

swimboy · July 10, 2023, 12:04pm

SMTP test tool is back up, here are the results:

Connected to smtp://hawk.tagcomp.com:587/?starttls=when-available
<< 220 hawk.tagcomp.com ESMTP Postfix
>> EHLO [172.31.11.248]
<< 250-hawk.tagcomp.com
<< 250-PIPELINING
<< 250-SIZE 10240000
<< 250-VRFY
<< 250-ETRN
<< 250-STARTTLS
<< 250-AUTH PLAIN LOGIN
<< 250-AUTH=PLAIN LOGIN
<< 250-ENHANCEDSTATUSCODES
<< 250-8BITMIME
<< 250-DSN
<< 250-SMTPUTF8
<< 250 CHUNKING
>> STARTTLS
<< 220 2.0.0 Ready to start TLS
>> EHLO [172.31.11.248]
<< 250-hawk.tagcomp.com
<< 250-PIPELINING
<< 250-SIZE 10240000
<< 250-VRFY
<< 250-ETRN
<< 250-AUTH PLAIN LOGIN
<< 250-AUTH=PLAIN LOGIN
<< 250-ENHANCEDSTATUSCODES
<< 250-8BITMIME
<< 250-DSN
<< 250-SMTPUTF8
<< 250 CHUNKING
>> AUTH PLAIN AGplZmZAbWItcjEyO****************==
<< 535 5.7.8 Error: authentication failed: authentication failure
>> AUTH LOGIN
<< 334 VXNlcm5hbWU6
>> amVmZkBtYi1yMTI5LmNvbQ==
<< 334 UGFzc3dvcmQ6
>> *************==
<< 535 5.7.8 Error: authentication failed: authentication failure
ERROR: 535: 5.7.8 Error: authentication failed: authentication failure

The username and password are definitely getting transmitted, but the log still says “user unknown” and “ruser=”

swimboy · July 11, 2023, 2:37pm

I have found the cause of the issue! I installed a minimal install of Rocky 9.2, manually installed wget and perl, then downloaded and ran the virtualmin 7.7 installer. After getting Virtualmin up and running, I experienced the symptoms above, no ability to authenticate via SMTP. (The IMAP authentication fails at the very beginning, but clears up on its own after a few minutes?!?!)

However, when I ran the “dnf groupinstall Server” command, a few hundred more packages were installed. I rebooted the server and, VOILA!, the SMTP authentication began working as expected.

Evidently, there’s some dependency that’s not being addressed in the installer. I’m not sure how to identify it, but I’m happy to work with the developers to track this down.

stefan1959 · July 11, 2023, 10:13pm

hmm ok, I would of thought the install scripts would of installed all necessary packages for the system to work or at least have a complaint that something was missing. Not sure if this is a bug.

Joe · July 17, 2023, 6:30pm

The only way that would happen is if you’ve configured dnf to not install default packages when performing a group install (and only installing mandatory packages).

github.com

virtualmin/virtualmin-yum-groups/blob/a472f059ca4e18112e2b3a51283b12a59879330b/virtualmin-comps.xml#L41


      
          <packagereq type="mandatory">zip</packagereq>
          <packagereq type="default">awscli</packagereq>
          <packagereq type="default">awstats</packagereq>
          <packagereq type="default">bzip2</packagereq>
          <packagereq type="default">certbot</packagereq>
          <packagereq type="default">mod_http2</packagereq>
          <packagereq type="default">clamav</packagereq>
          <packagereq type="default">clamav-update</packagereq>
          <packagereq type="default">clamd</packagereq>
          <packagereq type="default">cronie</packagereq>
          <packagereq type="default">cyrus-sasl</packagereq>
          <packagereq type="default">cyrus-sasl-gssapi</packagereq>
          <packagereq type="default">cyrus-sasl-plain</packagereq>
          <packagereq type="default">dovecot</packagereq>
          <packagereq type="default">etckeeper</packagereq>
          <packagereq type="default">fail2ban-firewalld</packagereq>
          <packagereq type="default">fail2ban-server</packagereq>
          <packagereq type="default">fcgiwrap</packagereq>
          <packagereq type="default">firewalld</packagereq>
          <packagereq type="default">jailkit</packagereq>
          <packagereq type="default">logrotate</packagereq>

Joe · July 17, 2023, 6:32pm

To be clear, you shouldn’t need to install the whole Server group. Just leaving dnf configured to install default packages in a group when running the virtualmin-install.sh should do the job (that is the default on a freshly installed Rocky, for both 8 and 9).

I can’t think of any other package that would be involved, and I can’t think of any other way for installing the Server group to have fixed it; I’m not saying there isn’t some other explanation, as it’s a complicated system with a lot of moving parts, I just can’t think of any.

system · September 15, 2023, 6:33pm

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.