Unable to configure SMTP Server, context deadline exceeded

Troubleshooting
1

I am unable to setup the SMTP Server connection for Mattermost. I tried the docker setup with version 7.8.1 and 7.7.0 and currently tried the Ubuntu Omnibus installation (Mattermost Version: 7.8.0, Database Schema Version: 101), and I always get the same error.

Here is the Mattermost log, where I initially used port 465 with TLS, saved settings, and tested twice, then I changed the port to 25 and 587 both with STARTTLS and tested once each:

{"timestamp":"2023-03-08 06:09:28.749 Z","level":"info","msg":"SimpleWorker: Job is complete","caller":"jobs/base_workers.go:96","worker":"ProductNotices","job_id":"7qesrw671bb49nc9k1mps8breo"}
{"timestamp":"2023-03-08 06:49:42.842 Z","level":"warn","msg":"Unrecognized config permissions tag value.","caller":"api4/config.go:426","tag_value":"sysconsole_write_*_read"}
{"timestamp":"2023-03-08 06:49:42.897 Z","level":"warn","msg":"plugin configured with a nil SecureConfig","caller":"plugin/hclog_adapter.go:72","plugin_id":"com.mattermost.apps"}
{"timestamp":"2023-03-08 06:49:43.084 Z","level":"warn","msg":"plugin configured with a nil SecureConfig","caller":"plugin/hclog_adapter.go:72","plugin_id":"playbooks"}
{"timestamp":"2023-03-08 06:49:43.099 Z","level":"info","msg":"plugin process exited","caller":"plugin/hclog_adapter.go:61","plugin_id":"com.mattermost.apps","wrapped_extras":"pathplugins/com.mattermost.apps/server/dist/plugin-linux-amd64pid7666"}
{"timestamp":"2023-03-08 06:49:43.099 Z","level":"error","msg":"Unable to activate plugin","caller":"app/plugin.go:166","plugin_id":"com.mattermost.apps","error":"failed to ensure bot account: failed to set profile image: SetProfileImage: Couldn't upload profile image., "}
{"timestamp":"2023-03-08 06:49:43.224 Z","level":"info","msg":"plugin process exited","caller":"plugin/hclog_adapter.go:61","plugin_id":"playbooks","wrapped_extras":"pathplugins/playbooks/server/dist/plugin-linux-amd64pid7672"}
{"timestamp":"2023-03-08 06:49:43.224 Z","level":"error","msg":"Unable to activate plugin","caller":"app/plugin.go:166","plugin_id":"playbooks","error":"failed to ensure bot: failed to set profile image: SetProfileImage: Couldn't upload profile image."}
{"timestamp":"2023-03-08 06:49:48.713 Z","level":"warn","msg":"Error decoding the config","caller":"api4/system.go:202","path":"/api/v4/email/test","request_id":"144fatyu1bn4td11gihyubcujh","ip_addr":"127.0.0.1","user_id":"19kkfbshnfr3x85hfe8roagjka","method":"POST","error":"EOF"}
{"timestamp":"2023-03-08 06:49:58.714 Z","level":"error","msg":"Connection unsuccessful: unable to connect to the SMTP server through TLS: context deadline exceeded","caller":"web/context.go:117","path":"/api/v4/email/test","request_id":"144fatyu1bn4td11gihyubcujh","ip_addr":"127.0.0.1","user_id":"19kkfbshnfr3x85hfe8roagjka","method":"POST","err_where":"testEmail","http_code":500,"error":"testEmail: Connection unsuccessful: unable to connect to the SMTP server through TLS: context deadline exceeded"}
{"timestamp":"2023-03-08 07:08:05.275 Z","level":"warn","msg":"Error decoding the config","caller":"api4/system.go:202","path":"/api/v4/email/test","request_id":"ukunea7d47dsixa1nowezfsjrh","ip_addr":"127.0.0.1","user_id":"19kkfbshnfr3x85hfe8roagjka","method":"POST","error":"EOF"}
{"timestamp":"2023-03-08 07:08:15.277 Z","level":"error","msg":"Connection unsuccessful: unable to connect to the SMTP server through TLS: context deadline exceeded","caller":"web/context.go:117","path":"/api/v4/email/test","request_id":"ukunea7d47dsixa1nowezfsjrh","ip_addr":"127.0.0.1","user_id":"19kkfbshnfr3x85hfe8roagjka","method":"POST","err_where":"testEmail","http_code":500,"error":"testEmail: Connection unsuccessful: unable to connect to the SMTP server through TLS: context deadline exceeded"}

Here is the server log for first testing with port 465 TLS and then 25 STARTTLS:

Mar  8 08:21:35 mail-02 postfix/smtps/smtpd[2343378]: connect from <ptr_record>[<mattermost_public_ip>]
Mar  8 08:21:35 mail-02 postfix/smtps/smtpd[2343378]: SSL_accept error from <ptr_record>[<mattermost_public_ip>]: lost connection
Mar  8 08:21:35 mail-02 postfix/smtps/smtpd[2343378]: lost connection after CONNECT from <ptr_record>[<mattermost_public_ip>]
Mar  8 08:21:35 mail-02 postfix/smtps/smtpd[2343378]: disconnect from <ptr_record>[<mattermost_public_ip>] commands=0/0

Mar  8 08:22:02 mail-02 postfix/postscreen[2343612]: CONNECT from [<mattermost_public_ip>]:60569 to [<mail_server_private_ip>]:25
Mar  8 08:22:02 mail-02 postfix/postscreen[2343612]: PASS OLD [<mattermost_public_ip>]:60569
Mar  8 08:22:12 mail-02 postfix/smtpd[2343613]: connect from <ptr_record>[<mattermost_public_ip>]
Mar  8 08:22:12 mail-02 postfix/smtpd[2343613]: lost connection after CONNECT from <ptr_record>[<mattermost_public_ip>]
Mar  8 08:22:12 mail-02 postfix/smtpd[2343613]: disconnect from <ptr_record>[<mattermost_public_ip>] commands=0/0

I have verified that I can access the mail server from the Mattermost server bash:

root@mattermost:/usr/bin# telnet mail.mydomain.com 25
Trying <mailserver_ip>...
Connected to mail.mydomain.com.
Escape character is '^]'.
HELO morpheus@mydomain.com
220 mail-02.mydomain.com ESMTP Postfix
250 mail-02.mydomain.com
QUIT
221 2.0.0 Bye
Connection closed by foreign host.
root@mattermost:/usr/bin# telnet mail.mydomain.com 465
Trying <mailserver_ip>...
Connected to mail.mydomain.com.
Escape character is '^]'.
Connection closed by foreign host.
root@mattermost:/usr/bin# telnet mail.mydomain.com 587
Trying <mailserver_ip>...
Connected to mail.mydomain.com.
Escape character is '^]'.
220 mail-02.mydomain.com ESMTP Postfix
HELO morpheus@mydomain.com
250 mail-02.mydomain.com
QUIT
221 2.0.0 Bye
Connection closed by foreign host.
root@mattermost:/usr/bin#

I am at a loss where the problem could be. I can send mails from thunderbird using these server settings without a problem.

2

Since the error log stated something about Error decoding the config I tried setting the SMTP settings via environment variables and this works! I used the same settings I put into the system console, so there seems to be something broken. I will create a GitHub issue.

3

Hi @Morpheus and welcome to the Mattermost forums!

I’m not sure if this is an issue with the server, let’s check a few more things, please.

With regards to the first error you’re seeing:

{"timestamp":"2023-03-08 06:49:48.713 Z","level":"warn","msg":"Error decoding the config","caller":"api4/system.go:202","path":"/api/v4/email/test","request_id":"144fatyu1bn4td11gihyubcujh","ip_addr":"127.0.0.1","user_id":"19kkfbshnfr3x85hfe8roagjka","method":"POST","error":"EOF"}

Can you please post the output of:

jq .EmailSettings /opt/mattermost/config/config.json

On my demo system, it looks like this:

{
  "EnableSignUpWithEmail": true,
  "EnableSignInWithEmail": true,
  "EnableSignInWithUsername": true,
  "SendEmailNotifications": true,
  "UseChannelInEmailNotifications": false,
  "RequireEmailVerification": false,
  "FeedbackName": "",
  "FeedbackEmail": "test@example.com",
  "ReplyToAddress": "test@example.com",
  "FeedbackOrganization": "",
  "EnableSMTPAuth": false,
  "SMTPUsername": "",
  "SMTPPassword": "",
  "SMTPServer": "localhost",
  "SMTPPort": "10025",
  "SMTPServerTimeout": 10,
  "ConnectionSecurity": "",
  "SendPushNotifications": false,
  "PushNotificationServer": "",
  "PushNotificationContents": "full",
  "PushNotificationBuffer": 1000,
  "EnableEmailBatching": false,
  "EmailBatchingBufferSize": 256,
  "EmailBatchingInterval": 30,
  "EnablePreviewModeBanner": true,
  "SkipServerCertificateVerification": false,
  "EmailNotificationContentsType": "full",
  "LoginButtonColor": "#0000",
  "LoginButtonBorderColor": "#2389D7",
  "LoginButtonTextColor": "#2389D7",
  "EnableInactivityEmail": true
}

The following errors indicate that there are timeouts when trying to connect to the SMTP service, which could have multiple reasons:

Mar  8 08:21:35 mail-02 postfix/smtps/smtpd[2343378]: lost connection after CONNECT from <ptr_record>[<mattermost_public_ip>]
{"timestamp":"2023-03-08 07:08:15.277 Z","level":"error","msg":"Connection unsuccessful: unable to connect to the SMTP server through TLS: context deadline

What server name did you use for the SMTP server? If it’s mail.mydomain.com as mentioned in your example, are we perfectly sure that the routing works and that you’re able to access the service on the public IP directly from the server (not sure if the public IP is online on your server and if there’s some NAT in place).
You redacted the hostnames in your example (all but the one in the first line, you might want to fix this one also) so I’m not 100% sure, but the context deadline exceeded message definitely means that there’s a timeout happening.

I tried to connect to your mailserver and do only get a protocol error and now I’m blocked and cannot try again - is there maybe some kind of rate-limiting or blacklisting active that would have kicked out your Mattermost application server?

4

Hi, I do not have a config.json file, only config.defaults.json. Using the Omnibus install seems to not use a config file.

[Unit]
Description=Mattermost
After=network.target
After=postgresql.service
Requires=postgresql.service

[Service]
Type=notify
ExecStart=/opt/mattermost/bin/mattermost
TimeoutStartSec=3600
Restart=always
RestartSec=10
WorkingDirectory=/opt/mattermost
User=mattermost
Group=mattermost
LimitNOFILE=49152

EnvironmentFile=/etc/mattermost/mmomni.mattermost.env

[Install]
WantedBy=postgresql.service

The env file doesn’t link to any config file.

I restarted my mail server about an hour ago, that might be why you had problems connecting. There is no aggressive blocking enabled. No idea about the protocol error, as I stated in my update, after setting the SMTP Server via env vars I had no problem sending the test mail.

I think the context deadline exceeded error is because there is an internal error with Mattermost because the SMTP settings aren’t saved correctly.

5

For the omnibus setup, the config is stored in the database. You can get it by running the following command:

# mmctl --local config get EmailSettings
{
  "EnableSignUpWithEmail": true,
  "EnableSignInWithEmail": true,
  "EnableSignInWithUsername": true,
  "SendEmailNotifications": true,
  "UseChannelInEmailNotifications": false,
  "RequireEmailVerification": false,
  "FeedbackName": "MMTest2",
  "FeedbackEmail": "root@mmtest2.anexia.dev",
  "ReplyToAddress": "root@mmtest2.anexia.dev",
  "FeedbackOrganization": "",
  "EnableSMTPAuth": false,
  "SMTPUsername": "",
  "SMTPPassword": "",
  "SMTPServer": "localhost",
  "SMTPPort": "25",
  "SMTPServerTimeout": 10,
  "ConnectionSecurity": "",
  "SendPushNotifications": false,
  "PushNotificationServer": "",
  "PushNotificationContents": "full",
  "PushNotificationBuffer": 1000,
  "EnableEmailBatching": false,
  "EmailBatchingBufferSize": 256,
  "EmailBatchingInterval": 30,
  "EnablePreviewModeBanner": false,
  "SkipServerCertificateVerification": false,
  "EmailNotificationContentsType": "full",
  "LoginButtonColor": "#0000",
  "LoginButtonBorderColor": "#2389D7",
  "LoginButtonTextColor": "#2389D7",
  "EnableInactivityEmail": true
}
6

Ok, this is my current working config, set via env vars:

{
  "EnableSignUpWithEmail": true,
  "EnableSignInWithEmail": true,
  "EnableSignInWithUsername": true,
  "SendEmailNotifications": true,
  "UseChannelInEmailNotifications": false,
  "RequireEmailVerification": false,
  "FeedbackName": "Hub",
  "FeedbackEmail": "hub@mydomain.com",
  "ReplyToAddress": "",
  "FeedbackOrganization": "",
  "EnableSMTPAuth": true,
  "SMTPUsername": "hub@mydomain.com",
  "SMTPPassword": "********************************",
  "SMTPServer": "mail.mydomain.com",
  "SMTPPort": "465",
  "SMTPServerTimeout": 30,
  "ConnectionSecurity": "TLS",
  "SendPushNotifications": false,
  "PushNotificationServer": "",
  "PushNotificationContents": "full",
  "PushNotificationBuffer": 1000,
  "EnableEmailBatching": true,
  "EmailBatchingBufferSize": 256,
  "EmailBatchingInterval": 30,
  "EnablePreviewModeBanner": false,
  "SkipServerCertificateVerification": false,
  "EmailNotificationContentsType": "full",
  "LoginButtonColor": "#0000",
  "LoginButtonBorderColor": "#2389D7",
  "LoginButtonTextColor": "#2389D7",
  "EnableInactivityEmail": true
}

Since this is working, i don’t want to break it again. Here is the config from a new Docker install where I set the same settings in the system console and where i get the context deadline exceeded error:

{
  "EnableSignUpWithEmail": true,
  "EnableSignInWithEmail": true,
  "EnableSignInWithUsername": true,
  "SendEmailNotifications": true,
  "UseChannelInEmailNotifications": false,
  "RequireEmailVerification": false,
  "FeedbackName": "Hub Test",
  "FeedbackEmail": "hub@mydomain.com",
  "ReplyToAddress": "",
  "FeedbackOrganization": "",
  "EnableSMTPAuth": true,
  "SMTPUsername": "hub@mydomain.com",
  "SMTPPassword": "********************************",
  "SMTPServer": "mail.mydomain.com",
  "SMTPPort": "465",
  "SMTPServerTimeout": 10,
  "ConnectionSecurity": "TLS",
  "SendPushNotifications": true,
  "PushNotificationServer": "https://push-test.mattermost.com",
  "PushNotificationContents": "full",
  "PushNotificationBuffer": 1000,
  "EnableEmailBatching": false,
  "EmailBatchingBufferSize": 256,
  "EmailBatchingInterval": 30,
  "EnablePreviewModeBanner": false,
  "SkipServerCertificateVerification": false,
  "EmailNotificationContentsType": "full",
  "LoginButtonColor": "#0000",
  "LoginButtonBorderColor": "#2389D7",
  "LoginButtonTextColor": "#2389D7",
  "EnableInactivityEmail": true
}

I don’t see any significant differences that would cause any issues. My idea would be that there is an issue with password parsing, as I stated in the GitHub issue I created: Unable to set SMTP Server settings via system console · Issue #22456 · mattermost/mattermost-server · GitHub

7

Thanks, I tried to reproduce that on one of my systems but so far, I was unable to.
In your docker setup, when you’re in the SMTP server setting page and after you saved the settings and click on test connection, do you also get a timeout there?

This is what I tried and I got the “authentication failed” message, just want to make sure this is also what you’re seeing and if it’s possible to reproduce it this way:

grafik
grafik508×1288 46.5 KB