Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Multiple issues with admin/domains page since v2.35.3 - no longer functions correctly and produces broken config. #1513

Closed
cybern0id opened this issue Mar 23, 2024 · 18 comments
Labels
bug Something isn't working enhancement New feature or request external Issue is outside our code workaround

Comments

@cybern0id
Copy link

Version 2.35.3 and 2.35.4 have issues with the admin/domains page. Clicking already configured domains to change the domain settings does not result in the settings pop-up window appearing at all and so domain settings can not be changed.
Also, it is no longer possible to deselect or disable each domain by clearing the check mark in the box next to the domain, nor is it possible to delete the domain.
Attempting to add a new domain does result in the domain settings pop-up window appearing however, it produces a broken and non-functional configuration.

When attempting to add a new domain, after entering the correct settings and clicking the 'Test' button, the test passes as shown by the tabs turning green however, the snappymail debug log shows "Failed authentication" and my mail server log shows that during the snappymail smtp test, the authentication is attempted using only the username part of the full email address whereas it should attempt using the full email address including domain, which my mail server requires, i.e. it requires myname@mailserver.co.uk for the auth username for example.

Version 2.35.2 does not suffer from these problems.

I'm wondering whether this might be related to recent changes for internationalisation of domain names? All my domains are .co.uk domains.

Steps to reproduce the behavior:

  1. Go to '?admin/domains'
  2. Click on 'any already configured domain'
  3. Nothing happens

Expected behavior
The domain settings pop-up window should appear and produce functioning domain configuration files.

Please complete the following information:

  • Browser: macOS Sonoma 14.4: Firefox 124.0.1 and Chromium 122.0.6261.111
  • IMAP daemon: dovecot
  • PHP version: 8.2.17
  • SnappyMail Version: 2.35.3 and 2.35.4
  • Mode: standalone
@the-djmaze the-djmaze added the bug Something isn't working label Mar 24, 2024
@cybern0id
Copy link
Author

Thanks for looking into this issue. I just cherry-picked this patch and added it to my 2.35.4 install but all of the issues I reported still exist:
It is still not possible to click on already configured domains to either edit, disable or delete them. Trying to create a new domain config results in a broken config file.

I've also discovered that when trying to add a new domain, the generated config file has no filename, and it only has a .json file extension. For example, if I attempt to create mailserver.co.uk domain, and I put 'mailserver.co.uk' in the 'Name' box of the form, the resultant file after saving is snappymail-data/_data_/_default_/domains/.json whereas snappymail-data/_data_/_default_/domains/mailserver.co.uk.json is expected.

I will attempt to capture a debug log and mail server auth log to post here however, the debug log only reports issues with generating the new domain config when saving the settings. It doesn't show anything relating to the domain settings editor pop-up window not showing.

Perhaps I should be posting separate issues for each problem?

@cybern0id
Copy link
Author

Here is the Snappymail debug log when trying to disable domain. When clicking the check box in the admins/domains UI, the box briefly clears and then quickly reverts back to being enabled:

[2024-03-24 14:19:18.151][12747528] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:98549][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 14:19:18.151][12747528] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:98549][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 14:19:18.152][12747528] JSON[INFO]: Action: DoAdminDomainDisable
[2024-03-24 14:19:18.152][12747528] POST[INFO]: {"name":"maildomain.co.uk","disabled":1,"Action":"AdminDomainDisable"}
[2024-03-24 14:19:18.153][12747528] JSON[INFO]: {"Action":"AdminDomainDisable","Result":true,"epoch":1711289958}
[2024-03-24 14:19:18.153][12747528] [INFO]: Memory peak usage: 2MB
[2024-03-24 14:19:18.153][12747528] [INFO]: Time delta: 0.0053770542144775
[2024-03-24 14:19:18.196][ea7755fa] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:13799][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 14:19:18.197][ea7755fa] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:13799][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 14:19:18.197][ea7755fa] JSON[INFO]: Action: DoAdminDomainList
[2024-03-24 14:19:18.197][ea7755fa] POST[INFO]: {"includeAliases":1,"Action":"AdminDomainList"}
[2024-03-24 14:19:18.198][ea7755fa] JSON[INFO]: {"Action":"AdminDomainList","Result":[{"name":"maildomain.co.uk","disabled":false,"alias":false},{"name":"maildomain3.me.uk","disabled":false,"alias":false},{"name":"maildomain2.uk","disabled":false,"alias":false},{"name":"*","disabled":false,"alias":false}],"epoch":1711289958}
[2024-03-24 14:19:18.198][ea7755fa] [INFO]: Memory peak usage: 2MB
[2024-03-24 14:19:18.198][ea7755fa] [INFO]: Time delta: 0.0053071975708008

@cybern0id
Copy link
Author

And here is the Snappymail debug log when trying to delete the same domain. Again, the UI shows the 'Are you sure?' button when clicking the trash can but nothing happens when clicking 'Are you sure?'.

[2024-03-24 14:52:25.522][127beddb] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:98549][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 14:52:25.522][127beddb] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:98549][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 14:52:25.523][127beddb] JSON[INFO]: Action: DoAdminDomainDelete
[2024-03-24 14:52:25.523][127beddb] POST[INFO]: {"name":"maildomain.co.uk","Action":"AdminDomainDelete"}
[2024-03-24 14:52:25.523][127beddb] JSON[INFO]: {"Action":"AdminDomainDelete","Result":true,"epoch":1711291945}
[2024-03-24 14:52:25.523][127beddb] [INFO]: Memory peak usage: 2MB
[2024-03-24 14:52:25.523][127beddb] [INFO]: Time delta: 0.0052030086517334
[2024-03-24 14:52:25.577][694106fb] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:13799][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 14:52:25.578][694106fb] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:13799][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 14:52:25.578][694106fb] JSON[INFO]: Action: DoAdminDomainList
[2024-03-24 14:52:25.578][694106fb] POST[INFO]: {"includeAliases":1,"Action":"AdminDomainList"}
[2024-03-24 14:52:25.579][694106fb] JSON[INFO]: {"Action":"AdminDomainList","Result":[{"name":"maildomain.co.uk","disabled":false,"alias":false},{"name":"maildomain3.me.uk","disabled":false,"alias":false},{"name":"maildomain2.uk","disabled":false,"alias":false},{"name":"*","disabled":false,"alias":false}],"epoch":1711291945}
[2024-03-24 14:52:25.579][694106fb] [INFO]: Memory peak usage: 2MB
[2024-03-24 14:52:25.579][694106fb] [INFO]: Time delta: 0.004957914352417

It looks like the Json queries are empty. Is something filtering them? Is the fault with my web server config or a bug in the Snappymail code? I run haproxy in front of httpd, with php-fpm 8.2 ......

@cybern0id
Copy link
Author

And here are logs showing an attempt to add a new domain.
First is my mail server log showing only the user part of the email address rather than full email address being used as authentication username.
Second is the Snappymail debug log.

Mar 24 15:32:33 mailhost smtpd[42497]: a7501379091b30e5 smtp connected address=127.0.0.1 host=localhost
Mar 24 15:32:33 mailhost smtpd[42497]: a7501379091b30e5 smtp tls ciphers=TLSv1.3:TLS_AES_256_GCM_SHA384:256
Mar 24 15:32:33 mailhost smtpd[42497]: a7501379091b30e5 smtp authentication user=useremail@ result=permfail
Mar 24 15:32:33 mailhost smtpd[83200]: authdenied: failed authentication from user=fail address=127.0.0.1 host=localhost
Mar 24 15:32:33 mailhost smtpd[42497]: a7501379091b30e5 smtp failed-command command="AUTH PLAIN (...)" result="535 Authentication failed"
Mar 24 15:32:33 mailhost dovecot: imap-login: Disconnected: Connection closed (auth failed, 1 attempts in 2 secs): user=<useremail@>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, TLS, session=<2nLzw2kUXGp/AAAB>
Mar 24 15:32:33 mailhost smtpd[42497]: a7501379091b30e5 smtp disconnected reason=quit
[2024-03-24 15:31:51.836][53877017] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:98549][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][GET https://mail.mailserver.co.uk/?admin]
[2024-03-24 15:31:51.837][53877017] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:98549][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][GET https://mail.mailserver.co.uk/?admin]
[2024-03-24 15:31:51.841][53877017] [INFO]: Memory peak usage: 2MB
[2024-03-24 15:31:51.841][53877017] [INFO]: Time delta: 0.010114908218384
[2024-03-24 15:31:51.921][33f04f62] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:13799][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][GET https://mail.mailserver.co.uk/?/AdminAppData/0/3844731656646335/]
[2024-03-24 15:31:51.927][33f04f62] APPDATA[INFO]: {"Auth":true,"title":"Mailserver Webmail","loadingDescription":"Webmail","Plugins":[],"System":{"version":"2.35.4","token":"85a95f09584dd947a020271119660dde17a858f9","languages":["ar-SA","bg-BG","cs-CZ","da-DK","de-DE","el-GR","en","en-GB","eo","es-ES","et-EE","eu","fa-IR","fi-FI","fr-FR","hu-HU","id-ID","is-IS","it-IT","ja-JP","ko-KR","lt-LT","lv-LV","nb-NO","nl-NL","pl-PL","pt","pt-BR","pt-PT","ro-RO","ru-RU","sk-SK","sl-SI","sv-SE","tr-TR","uk-UA","vi-VN","zh-CN","zh-TW"],"webPath":"\/","webVersionPath":"\/snappymail\/v\/2.35.4\/","themes":["Default","A","BlackWood","Blurred","BlurredDark","DarkShine","Linen","Love","LoveDark","NextcloudV25+","NightShine","Snow","SnowDarkV1","Squares","SquaresDark","Stripes","StripesDark","Wood","Xv","Clear"]},"allowLanguagesOnLogin":true,"Admin":{"host":false,"path":"admin","allowed":true,"language":"en","languages":["cs-CZ","da-DK","de-DE","en","en-GB","es-ES","eu","fa-IR","fi-FI","fr-FR","hu-HU","id-ID","it-IT","ja-JP","lt-LT","nb-NO","nl-NL","pl-PL","pt","pt-BR","pt-PT","ru-RU","sk-SK","sl-SI","sv-SE","vi-VN","zh-CN"],"clientLanguage":"en-GB"},"adminLogin":"jcrladmin","adminTOTP":"","pluginsEnable":false,"loginDefaultDomain":"","determineUserLanguage":true,"determineUserDomain":false,"supportedPdoDrivers":["mysql","sqlite"],"contactsEnable":true,"contactsSync":false,"contactsPdoType":"sqlite","contactsPdoDsn":"host=127.0.0.1;port=3306;dbname=snappymail","contactsPdoUser":"root","contactsPdoPassword":"********","contactsMySQLSSLCA":"","contactsMySQLSSLVerify":true,"contactsMySQLSSLCiphers":"","contactsSQLiteGlobal":true,"contactsSuggestionsLimit":30,"faviconUrl":"","weakPassword":false,"useLocalProxyForExternalImages":true,"autoVerifySignatures":false,"allowLanguagesOnSettings":true,"Capa":{"AdditionalAccounts":true,"AttachmentThumbnails":true,"AttachmentsActions":true,"Contacts":true,"DangerousActions":true,"GnuPG":false,"Identities":true,"OpenPGP":false,"Sieve":true,"Themes":true,"UserBackground":false,"Kolab":false},"attachmentLimit":2097152,"phpUploadSizes":{"upload_max_filesize":"2M","post_max_size":"8M"},"Theme":"Default","language":"en-GB","clientLanguage":"en-GB","PluginsLink":"","StaticLibsJs":"\/snappymail\/v\/2.35.4\/static\/js\/libs.js"}
[2024-03-24 15:31:51.927][33f04f62] [INFO]: Memory peak usage: 2MB
[2024-03-24 15:31:51.927][33f04f62] [INFO]: Time delta: 0.0093889236450195
[2024-03-24 15:31:51.992][ead179be] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:98549][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 15:31:51.993][ead179be] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:98549][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 15:31:51.993][ead179be] JSON[INFO]: Action: DoAdminDomainList
[2024-03-24 15:31:51.993][ead179be] POST[INFO]: {"includeAliases":1,"Action":"AdminDomainList"}
[2024-03-24 15:31:51.994][ead179be] JSON[INFO]: {"Action":"AdminDomainList","Result":[{"name":"maildomain.co.uk","disabled":false,"alias":false},{"name":"maildomain3.me.uk","disabled":false,"alias":false},{"name":"maildomain2.uk","disabled":false,"alias":false},{"name":"*","disabled":false,"alias":false}],"epoch":1711294311}
[2024-03-24 15:31:51.994][ead179be] [INFO]: Memory peak usage: 2MB
[2024-03-24 15:31:51.994][ead179be] [INFO]: Time delta: 0.0058300495147705
[2024-03-24 15:32:31.871][b2943b47] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:13799][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 15:32:31.871][b2943b47] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:13799][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 15:32:31.872][b2943b47] JSON[INFO]: Action: DoAdminDomainTest
[2024-03-24 15:32:31.872][b2943b47] POST[INFO]: {"name":"mailserver.co.uk","IMAP":{"host":"127.0.0.1","port":993,"secure":1,"timeout":300,"shortLogin":false,"lowerLogin":true,"ssl":{"verify_peer":false,"verify_peer_name":false,"allow_self_signed":false},"disabled_capabilities":["METADATA","PREVIEW","STATUS=SIZE"],"folder_list_limit":200,"message_list_limit":10000},"SMTP":{"host":"127.0.0.1","port":465,"secure":1,"timeout":60,"shortLogin":false,"lowerLogin":true,"ssl":{"verify_peer":false,"verify_peer_name":false,"allow_self_signed":false},"setSender":false,"authPlainLine":false,"useAuth":true,"usePhpMail":false},"Sieve":{"enabled":false,"host":"","port":4190,"secure":0,"timeout":10,"shortLogin":false,"lowerLogin":true,"ssl":{"verify_peer":false,"verify_peer_name":false,"allow_self_signed":false}},"whiteList":"","auth":{"user":"useremail@mailserver.co.uk","pass":"FlUi4k4Aju5laZ9CIWve"},"Action":"AdminDomainTest"}
[2024-03-24 15:32:31.873][b2943b47] IMAP[INFO]: Start connection to "ssl://127.0.0.1:993"
[2024-03-24 15:32:31.894][b2943b47] IMAP[INFO]: Connect (success)
[2024-03-24 15:32:31.894][b2943b47] IMAP[DEBUG]: 0.020479202270508 (raw connection)
[2024-03-24 15:32:31.896][b2943b47] IMAP[INFO]: < * OK [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE IDLE LITERAL+ AUTH=PLAIN] Dovecot ready.\r\n
[2024-03-24 15:32:31.896][b2943b47] IMAP[DEBUG]: 0.022620916366577 (*)
[2024-03-24 15:32:31.896][b2943b47] IMAP[INFO]: > TAG1 AUTHENTICATE PLAIN *******\r\n
[2024-03-24 15:32:33.439][b2943b47] IMAP[INFO]: < TAG1 NO [AUTHENTICATIONFAILED] Authentication failed.\r\n
[2024-03-24 15:32:33.439][b2943b47] IMAP[DEBUG]: 1.5423710346222 (TAG1)
[2024-03-24 15:32:33.439][b2943b47] IMAP[WARNING]: MailSo\Imap\Exceptions\NegativeResponseException: AUTHENTICATIONFAILED Authentication failed. in /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Imap/ResponseCollection.php:46
Stack trace:
#0 /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Imap/ImapClient.php(525): MailSo\Imap\ResponseCollection->validate()
#1 /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Imap/ImapClient.php(166): MailSo\Imap\ImapClient->getResponse()
#2 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Actions/AdminDomains.php(121): MailSo\Imap\ImapClient->Login()
#3 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/ServiceActions.php(134): RainLoop\ActionsAdmin->DoAdminDomainTest()
#4 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(132): RainLoop\ServiceActions->ServiceJson()
#5 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(14): RainLoop\Service::RunResult()
#6 /www/SM/snappymail/v/2.35.4/include.php(135): RainLoop\Service::Handle()
#7 /www/SM/index.php(11): include('...')
#8 {main}
[2024-03-24 15:32:33.440][b2943b47] IMAP[NOTICE]: MailSo\Imap\Exceptions\NegativeResponseException: AUTHENTICATIONFAILED Authentication failed. in /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Imap/ResponseCollection.php:46
Stack trace:
#0 /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Imap/ImapClient.php(525): MailSo\Imap\ResponseCollection->validate()
#1 /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Imap/ImapClient.php(166): MailSo\Imap\ImapClient->getResponse()
#2 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Actions/AdminDomains.php(121): MailSo\Imap\ImapClient->Login()
#3 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/ServiceActions.php(134): RainLoop\ActionsAdmin->DoAdminDomainTest()
#4 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(132): RainLoop\ServiceActions->ServiceJson()
#5 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(14): RainLoop\Service::RunResult()
#6 /www/SM/snappymail/v/2.35.4/include.php(135): RainLoop\Service::Handle()
#7 /www/SM/index.php(11): include('...')
#8 {main}

Next MailSo\Imap\Exceptions\LoginBadCredentialsException: AUTHENTICATIONFAILED Authentication failed. in /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Imap/ImapClient.php:229
Stack trace:
#0 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Actions/AdminDomains.php(121): MailSo\Imap\ImapClient->Login()
#1 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/ServiceActions.php(134): RainLoop\ActionsAdmin->DoAdminDomainTest()
#2 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(132): RainLoop\ServiceActions->ServiceJson()
#3 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(14): RainLoop\Service::RunResult()
#4 /www/SM/snappymail/v/2.35.4/include.php(135): RainLoop\Service::Handle()
#5 /www/SM/index.php(11): include('...')
#6 {main}
[2024-03-24 15:32:33.440][b2943b47] SMTP[INFO]: Start connection to "ssl://127.0.0.1:465"
[2024-03-24 15:32:33.449][b2943b47] SMTP[INFO]: Connect (success)
[2024-03-24 15:32:33.449][b2943b47] SMTP[DEBUG]: 0.0095250606536865 (raw connection)
[2024-03-24 15:32:33.450][b2943b47] SMTP[INFO]: < 220 mail.mailserver.co.uk ESMTP OpenSMTPD\r\n
[2024-03-24 15:32:33.450][b2943b47] SMTP[INFO]: > EHLO mail.mailserver.co.uk\r\n
[2024-03-24 15:32:33.450][b2943b47] SMTP[INFO]: < 250-mail.mailserver.co.uk Hello mail.mailserver.co.uk [127.0.0.1], pleased to meet you\r\n
[2024-03-24 15:32:33.450][b2943b47] SMTP[INFO]: < 250-8BITMIME\r\n
[2024-03-24 15:32:33.450][b2943b47] SMTP[INFO]: < 250-ENHANCEDSTATUSCODES\r\n
[2024-03-24 15:32:33.450][b2943b47] SMTP[INFO]: < 250-SIZE 36700160\r\n
[2024-03-24 15:32:33.450][b2943b47] SMTP[INFO]: < 250-DSN\r\n
[2024-03-24 15:32:33.451][b2943b47] SMTP[INFO]: < 250-AUTH PLAIN LOGIN\r\n
[2024-03-24 15:32:33.451][b2943b47] SMTP[INFO]: < 250 HELP\r\n
[2024-03-24 15:32:33.451][b2943b47] SMTP[INFO]: > AUTH PLAIN\r\n
[2024-03-24 15:32:33.451][b2943b47] SMTP[INFO]: < 334 \r\n
[2024-03-24 15:32:33.451][b2943b47] SMTP[INFO]: > ********\r\n
[2024-03-24 15:32:33.548][b2943b47] SMTP[INFO]: < 535 Authentication failed\r\n
[2024-03-24 15:32:33.549][b2943b47] SMTP[ERROR]: MailSo\Smtp\Exceptions\NegativeResponseException: 535 Authentication failed in /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Smtp/SmtpClient.php:596
Stack trace:
#0 /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Smtp/SmtpClient.php(504): MailSo\Smtp\SmtpClient->validateResponse()
#1 /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Smtp/SmtpClient.php(192): MailSo\Smtp\SmtpClient->sendRequestWithCheck()
#2 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Actions/AdminDomains.php(166): MailSo\Smtp\SmtpClient->Login()
#3 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/ServiceActions.php(134): RainLoop\ActionsAdmin->DoAdminDomainTest()
#4 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(132): RainLoop\ServiceActions->ServiceJson()
#5 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(14): RainLoop\Service::RunResult()
#6 /www/SM/snappymail/v/2.35.4/include.php(135): RainLoop\Service::Handle()
#7 /www/SM/index.php(11): include('...')
#8 {main}
[2024-03-24 15:32:33.549][b2943b47] SMTP[NOTICE]: MailSo\Smtp\Exceptions\NegativeResponseException: 535 Authentication failed in /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Smtp/SmtpClient.php:596
Stack trace:
#0 /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Smtp/SmtpClient.php(504): MailSo\Smtp\SmtpClient->validateResponse()
#1 /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Smtp/SmtpClient.php(192): MailSo\Smtp\SmtpClient->sendRequestWithCheck()
#2 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Actions/AdminDomains.php(166): MailSo\Smtp\SmtpClient->Login()
#3 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/ServiceActions.php(134): RainLoop\ActionsAdmin->DoAdminDomainTest()
#4 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(132): RainLoop\ServiceActions->ServiceJson()
#5 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(14): RainLoop\Service::RunResult()
#6 /www/SM/snappymail/v/2.35.4/include.php(135): RainLoop\Service::Handle()
#7 /www/SM/index.php(11): include('...')
#8 {main}

Next MailSo\Smtp\Exceptions\LoginBadCredentialsException: 535 Authentication failed in /www/SM/snappymail/v/2.35.4/app/libraries/MailSo/Smtp/SmtpClient.php:214
Stack trace:
#0 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Actions/AdminDomains.php(166): MailSo\Smtp\SmtpClient->Login()
#1 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/ServiceActions.php(134): RainLoop\ActionsAdmin->DoAdminDomainTest()
#2 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(132): RainLoop\ServiceActions->ServiceJson()
#3 /www/SM/snappymail/v/2.35.4/app/libraries/RainLoop/Service.php(14): RainLoop\Service::RunResult()
#4 /www/SM/snappymail/v/2.35.4/include.php(135): RainLoop\Service::Handle()
#5 /www/SM/index.php(11): include('...')
#6 {main}
[2024-03-24 15:32:33.550][b2943b47] IMAP[INFO]: Disconnected from "ssl://127.0.0.1:993" (success)
[2024-03-24 15:32:33.550][b2943b47] IMAP[DEBUG]: 1.6768519878387 (net session)
[2024-03-24 15:32:33.551][b2943b47] SMTP[INFO]: > QUIT\r\n
[2024-03-24 15:32:33.551][b2943b47] SMTP[INFO]: < 221 2.0.0 Bye\r\n
[2024-03-24 15:32:33.552][b2943b47] SMTP[INFO]: Disconnected from "ssl://127.0.0.1:465" (success)
[2024-03-24 15:32:33.552][b2943b47] SMTP[DEBUG]: 0.11207103729248 (net session)
[2024-03-24 15:32:33.552][b2943b47] JSON[INFO]: {"Action":"AdminDomainTest","Result":{"Imap":true,"Smtp":true,"Sieve":true,"ImapResult":{"connectCapa":["IMAP4REV1","SASL-IR","LOGIN-REFERRALS","ID","ENABLE","IDLE","LITERAL+","AUTH=PLAIN"]},"SmtpResult":{"connectCapa":["MAIL.mailserver.co.uk","8BITMIME","ENHANCEDSTATUSCODES","SIZE","DSN","AUTH","HE...
[2024-03-24 15:32:33.552][b2943b47] [INFO]: Memory peak usage: 2MB
[2024-03-24 15:32:33.552][b2943b47] [INFO]: Time delta: 1.6847529411316
[2024-03-24 15:33:06.365][82c9ada9] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:98549][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 15:33:06.366][82c9ada9] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:98549][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 15:33:06.367][82c9ada9] JSON[INFO]: Action: DoAdminDomainSave
[2024-03-24 15:33:06.367][82c9ada9] POST[INFO]: {"name":"mailserver.co.uk","IMAP":{"host":"127.0.0.1","port":993,"secure":1,"timeout":300,"shortLogin":false,"lowerLogin":true,"ssl":{"verify_peer":false,"verify_peer_name":false,"allow_self_signed":false},"disabled_capabilities":["METADATA","PREVIEW","STATUS=SIZE"],"folder_list_limit":200,"message_list_limit":10000},"SMTP":{"host":"127.0.0.1","port":465,"secure":1,"timeout":60,"shortLogin":false,"lowerLogin":true,"ssl":{"verify_peer":false,"verify_peer_name":false,"allow_self_signed":false},"setSender":false,"authPlainLine":false,"useAuth":true,"usePhpMail":false},"Sieve":{"enabled":false,"host":"","port":4190,"secure":0,"timeout":10,"shortLogin":false,"lowerLogin":true,"ssl":{"verify_peer":false,"verify_peer_name":false,"allow_self_signed":false}},"whiteList":"","create":1,"Action":"AdminDomainSave"}
[2024-03-24 15:33:06.369][82c9ada9] JSON[INFO]: {"Action":"AdminDomainSave","Result":true,"epoch":1711294386}
[2024-03-24 15:33:06.369][82c9ada9] [INFO]: Memory peak usage: 2MB
[2024-03-24 15:33:06.369][82c9ada9] [INFO]: Time delta: 0.0074670314788818
[2024-03-24 15:33:06.417][129c6076] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:13799][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 15:33:06.418][129c6076] [INFO]: [SM:2.35.4][IP:127.0.0.1][PID:13799][OpenBSD httpd][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3][POST https://mail.mailserver.co.uk/?admin/Json/&q[]=/0/]
[2024-03-24 15:33:06.418][129c6076] JSON[INFO]: Action: DoAdminDomainList
[2024-03-24 15:33:06.418][129c6076] POST[INFO]: {"includeAliases":1,"Action":"AdminDomainList"}
[2024-03-24 15:33:06.419][129c6076] JSON[INFO]: {"Action":"AdminDomainList","Result":[{"name":"","disabled":true,"alias":false},{"name":"maildomain.co.uk","disabled":false,"alias":false},{"name":"maildomain3.me.uk","disabled":false,"alias":false},{"name":"maildomain2.uk","disabled":false,"alias":false},{"name":"*","disabled":false,"alias":false}],"epoch":171...
[2024-03-24 15:33:06.419][129c6076] [INFO]: Memory peak usage: 2MB
[2024-03-24 15:33:06.419][129c6076] [INFO]: Time delta: 0.005385160446167

@cybern0id
Copy link
Author

And finally, here is the domains directory listing showing the generated .json without mailserver.co.uk filename and the generated contents of that file.

mailhost# ls -lah /www/SM/snappymail-data/_data_/_default_/domains/

drwxr-xr-x  2 www  www   512B Mar 24 15:33 .
drwxr-xr-x  9 www  www   512B Mar 24 13:57 ..
-rw-------  1 www  www   2.3K Mar 24 15:33 .json
-rw-r--r--  1 www  www   321B Aug 22  2022 default.ini
-rw-------  1 www  www    28B Mar 23 17:12 disabled

mailhost# cat /www/SM/snappymail-data/_data_/_default_/domains/.json
{
    "IMAP": {
        "host": "127.0.0.1",
        "port": 993,
        "type": 1,
        "timeout": 300,
        "shortLogin": false,
        "lowerLogin": true,
        "stripLogin": "",
        "sasl": [
            "SCRAM-SHA3-512",
            "SCRAM-SHA-512",
            "SCRAM-SHA-256",
            "SCRAM-SHA-1",
            "PLAIN",
            "LOGIN"
        ],
        "ssl": {
            "verify_peer": false,
            "verify_peer_name": false,
            "allow_self_signed": false,
            "SNI_enabled": true,
            "disable_compression": true,
            "security_level": 1
        },
        "use_expunge_all_on_delete": false,
        "fast_simple_search": true,
        "force_select": false,
        "message_all_headers": false,
        "message_list_limit": 10000,
        "search_filter": "",
        "disabled_capabilities": [
            "METADATA",
            "PREVIEW",
            "STATUS=SIZE"
        ]
    },
    "SMTP": {
        "host": "127.0.0.1",
        "port": 465,
        "type": 1,
        "timeout": 60,
        "shortLogin": false,
        "lowerLogin": true,
        "stripLogin": "",
        "sasl": [
            "SCRAM-SHA3-512",
            "SCRAM-SHA-512",
            "SCRAM-SHA-256",
            "SCRAM-SHA-1",
            "PLAIN",
            "LOGIN"
        ],
        "ssl": {
            "verify_peer": false,
            "verify_peer_name": false,
            "allow_self_signed": false,
            "SNI_enabled": true,
            "disable_compression": true,
            "security_level": 1
        },
        "useAuth": true,
        "setSender": false,
        "usePhpMail": false,
        "authPlainLine": false
    },
    "Sieve": {
        "host": "",
        "port": 4190,
        "type": 0,
        "timeout": 10,
        "shortLogin": false,
        "lowerLogin": true,
        "stripLogin": "",
        "sasl": [
            "SCRAM-SHA3-512",
            "SCRAM-SHA-512",
            "SCRAM-SHA-256",
            "SCRAM-SHA-1",
            "PLAIN",
            "LOGIN"
        ],
        "ssl": {
            "verify_peer": false,
            "verify_peer_name": false,
            "allow_self_signed": false,
            "SNI_enabled": true,
            "disable_compression": true,
            "security_level": 1
        },
        "enabled": false
    },
    "whiteList": ""

@the-djmaze
Copy link
Owner

the-djmaze commented Mar 24, 2024

Something must be wrong with your server.

JSON[INFO]: Action: DoAdminDomainDisable
POST[INFO]: {"name":"maildomain.co.uk","disabled":1,"Action":"AdminDomainDisable"}
JSON[INFO]: {"Action":"AdminDomainDisable","Result":true,"epoch":1711289958}

Here it says the change is made and the domain is disabled.

JSON[INFO]: Action: DoAdminDomainList
POST[INFO]: {"includeAliases":1,"Action":"AdminDomainList"}
JSON[INFO]: {"Action":"AdminDomainList","Result":[{"name":"maildomain.co.uk","disabled":false,"alias":false},{"name":"maildomain3.me.uk","disabled":false,"alias":false},{"name":"maildomain2.uk","disabled":false,"alias":false},{"name":"*","disabled":false,"alias":false}],"epoch":1711289958}

Here it does not say it is. So saving the disabled failed.

I've changed the code a bit to return "false" when it fails

@cybern0id
Copy link
Author

Exactly! This is what I am reporting - the admins/domains web UI doesn't work correctly and so disabling, deleting or editing doesn't work. I'll try this change and report findings.

These issues only started happening since 2.35.3 - my mail server configuration hasn't changed.

I don't understand why the admins/domains settings editor window doesn't pop up when clicking one of the listed domains.

@the-djmaze
Copy link
Owner

the-djmaze commented Mar 24, 2024

I don't understand why the admins/domains settings editor window doesn't pop up when clicking one of the listed domains.

Check your logs
https://github.com/the-djmaze/snappymail/wiki/FAQ#how-do-i-enable-logging

@cybern0id
Copy link
Author

Nothing in error logs. Access logs shows "POST /?admin/Json/&q[]=/0/ HTTP/1.1" 200 0 "" whenever I reload /?admin#/domains or click on an already configured and listed domain.

Does this imply that the JSON query is not working correctly?

@the-djmaze
Copy link
Owner

Access logs shows "POST /?admin/Json/&q[]=/0/ HTTP/1.1" 200 0 ""

That is the Apache log. Not the PHP nor SnappyMail log

@cybern0id
Copy link
Author

cybern0id commented Mar 24, 2024

Yes. The php-fpm debug log does not show anything. The Snappymail logs are already posted in this ticket. In Snappymail config I had already set debug log = on + json javascript + css and log level = 7 = debug in the logging section.

@the-djmaze
Copy link
Owner

Then, when empty it could be an issue with PHP Intl extension returning incorrect value for idn_to_ascii.

Just wait for next release

@cybern0id
Copy link
Author

Ah! I had an issue with PHP-intl on another site recently and it was due to changes in PHP. I will try running an older version of PHP to see if that works.

Thanks for giving your time to help me and help troubleshoot, much appreciated.

I have a little extra information - I enabled developer console in my browser and I see this when loading the domains page:

Request for font "Hiragino Kaku Gothic ProN" blocked at visibility level 2 (requires 3)
admin.js:1101:61
Request for font "STIX Two Math" blocked at visibility level 2 (requires 3)
admin.js:1101:61
Source map error: NetworkError when attempting to fetch resource.
Resource URL: moz-extension://2713e7f8-6a45-407f-bdf1-e51d888c0801/model/static/DOMPurify/purify.min.js
Source Map URL: purify.min.js.map

DOMPurify is part of Squire isn't it? Is the fact that Firefox can't find it important?

@the-djmaze
Copy link
Owner

Those errors are because of Firefox extensions trying to load inside SnappyMail.
SnappyMail does not allow things for security reasons.
moz-extension://UUID is unique to your instance. We can't know which extension causes it.

@cybern0id
Copy link
Author

cybern0id commented Mar 24, 2024

Interesting! I tried using a Firefox private browsing window that is supposed to disable all extensions yet I still get the error about purify.min.js. However, with a clean Firefox profile, that has zero extensions installed, the error doesn't appear - but.... the admin/domains page still doesn't work.

I will leave you alone now and wait for the next release 🙂
... and will let you know if older PHP fixes it.

Thanks again for your help

[Edit] It is the Firefox Translations add-on - firefox-translations-addon @ mozilla.org

@cybern0id
Copy link
Author

Web browser debugger shows this JSON request and response when clicking on a domain in the list to edit it:

Request: {"name":"mailserver.co.uk","Action":"AdminDomainLoad"}
Reponse: {"Action":"AdminDomainLoad","Result":false,"ErrorCode":0,"ErrorMessage":"","epoch":1711308588}

In Snappymail 2.35.2 the JSON response contains the domain's configuration settings as expected.

Changing PHP version has no effect. I tried php-8.0 and php-8.1 before reverting back to php-8.2.

@cybern0id
Copy link
Author

cybern0id commented Mar 24, 2024

The problem does indeed lie with my web server.

I'd like to apologise for bombarding you with messages today and wasting your time.

It has taken me all day to troubleshoot and get to the bottom of it. Your hint about PHP Intl module and idn_to_ascii being the issue was very helpful!

I'll explain the solution in the hope that it might help other Snappymail and OpenBSD users in future:

I discovered that even though the php-intl module was loaded, attempting to use the idn_to_ascii function resulted in an error, but only while using it via php-fpm and not via php cli. This got me thinking about file permissions, locations and chroots.....

I created a small idn-test.php file:

<?php
    echo idn_to_ascii('mailserver.co.uk');
?>

and enabled intl error messages in my php.ini:

intl.error_level = E_WARNING
display_errors = On

and the only output was the resultant error failed to open UIDNA instance

Checking file locations and OS packages relating to ICU and I discovered the icu4c-wwwdata-73.2v0 package for OpenBSD. The package description states ICU data file for use with /var/www chroot jails and it provides /var/www/usr/local/share/icu/73.2/icudt73l.dat.

My web server doesn't run with the default OpenBSD chroot so I copied that file to the relative path under my chroot and now everything works!!

@the-djmaze
Copy link
Owner

the-djmaze commented Mar 25, 2024

Great that you find the problem!

SnappyMail does have a polyfill when php-intl is not installed.
So removing php-intl was also an option (but the code will be slower then native).
The changes in v2.35 are mostly because of using the native (when available).

@the-djmaze the-djmaze added external Issue is outside our code enhancement New feature or request workaround bug Something isn't working and removed bug Something isn't working labels Mar 25, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working enhancement New feature or request external Issue is outside our code workaround
Projects
None yet
Development

No branches or pull requests

2 participants