Error sending messages between accounts on self-hosted chatmail

Hi all,

I set up a new chatmail instance on my own domain, using the instructions from the chatmail repository.

It seems to work, all services up, website reachable etc. I can make new accounts on it, either automatically with the qr-code, or using a 9-letter username I choose myself.

Now, I have two accounts on the same server, on 2 different devices, and am trying to send a message from one to the other.
It fails. In the chat GUI, I see this message:

Sent: 2024.02.16 09:39:22 by Me (sender@myownchatdomain)
State: Failed
Error: Permanent SMTP error: permanent: Error: (SMTPSenderRefused) (451, b'4.7.1 Service unavailable - try again later', 'sender@myownchatdomain')
Message-ID: Mr.ZVBZPJVbN_9.2e--S7K2fjv@myownchatdomain

No Hop Info

My server is running debian 11, as someone here recommended, on arm64 hardware.
On my server, I see the following in /var/log/mail.info

Feb 16 09:39:23 debian-chat-arm postfix/smtps/smtpd[2400]: warning: hostname ns.kvikna.com does not resolve to address 178.19.52.249: Name or service not known
Feb 16 09:39:23 debian-chat-arm postfix/smtps/smtpd[2400]: connect from unknow249]
Feb 16 09:39:23 debian-chat-arm postfix/smtps/smtpd[2400]: NOQUEUE: client=unknown[178.19.52.249], sasl_method=PLAIN, sasl_username=desktop00@myownchatdomain
Feb 16 09:39:23 debian-chat-arm postfix/reinject/smtpd[2405]: warning: Invalid TLS protocol list ">=TLSv1.2": disabling TLS support
Feb 16 09:39:23 debian-chat-arm postfix/reinject/smtpd[2405]: connect from localhost[127.0.0.1]
Feb 16 09:39:23 debian-chat-arm postfix/reinject/smtpd[2405]: warning: connect to Milter service unix:opendkim/opendkim.sock: Permission denied
Feb 16 09:39:23 debian-chat-arm postfix/reinject/smtpd[2405]: NOQUEUE: milter-reject: CONNECT from localhost[127.0.0.1]: 451 4.7.1 Service unavailable - try again later; proto=SMTP
Feb 16 09:39:23 debian-chat-arm postfix/reinject/smtpd[2405]: NOQUEUE: milter-reject: EHLO from localhost[127.0.0.1]: 451 4.7.1 Service unavailable - try again later; proto=SMTP helo=<[127.0.1.1]>
Feb 16 09:39:23 debian-chat-arm postfix/reinject/smtpd[2405]: NOQUEUE: milter-reject: MAIL from localhost[127.0.0.1]: 451 4.7.1 Service unavailable - try again later; from=<desktop00@myownchatdomain> proto=ESMTP helo=<[127.0.1.1]>
Feb 16 09:39:23 debian-chat-arm postfix/reinject/smtpd[2405]: lost connection after RSET from localhost[127.0.0.1]
Feb 16 09:39:23 debian-chat-arm postfix/reinject/smtpd[2405]: disconnect from localhost[127.0.0.1] ehlo=1 mail=0/1 rset=1 commands=2/3
Feb 16 09:39:23 debian-chat-arm postfix/smtps/smtpd[2400]: proxy-reject: END-OF-MESSAGE: 500 Error: (SMTPSenderRefused) (451, b'4.7.1 Service unavailable - try again later', 'desktop00@myownchatdomain'); from=<desktop00@myownchatdomain> to=<indridi00@myownchatdomain> proto=ESMTP helo=<[127.0.0.1]> sasl_username=<desktop00@myownchatdomain>
Feb 16 09:39:23 debian-chat-arm postfix/smtps/smtpd[2400]: disconnect from unknown[178.19.52.249] ehlo=1 auth=1 mail=1 rcpt=2 data=0/1 quit=1 commands=6/7
Feb 16 09:40:37 debian-chat-arm postfix/anvil[1886]: statistics: max connection rate 2/60s for (smtps:178.19.52.249) at Feb 16 09:37:08
Feb 16 09:40:37 debian-chat-arm postfix/anvil[1886]: statistics: max connection count 1 for (smtps:157.157.114.224) at Feb 16 09:30:37
Feb 16 09:40:37 debian-chat-arm postfix/anvil[1886]: statistics: max cache size 2 at Feb 16 09:36:32n[178.19.52.

Please note that I have removed the actual mail addresses and replaced with fictious ones.

I must admit that I’m have little knowledge of running mail servers, so I’m not really capable of interpreting these logs.

Does someone have a hint about what might be going wrong?

Greetings,
IndriĂ°i

I think it’s intentional, in the sense that you can’t send emails unless they’re encrypted.

Now, of course the first time you send an email to an address, the mail server doesn’t know if there’s a Chatmail server or something else on the other side, so to get two email addresses from Chatmail systems to talk for the first time, you need to necessarily use QR codes.

But someone from deltachat crew will respond you better than me, because maybe I’m wrong :sweat_smile:

Thanks -
I tried sending by first scanning the qr code.
But I suppose this has something to do with my DNS setup.
At first, the cmdeploy dns ran with an error : my MX record wasn’t there, and the script didn’t correctly parse what came out of the request.

My DNS records were not correct before. The dns checker in cmdeploy dns choked on my non-existin MX record, and stopped, so I didn’t get the very helpful instructions. I poked around the the source code to get around it, and have now set up all the dns records, I hope. At least the dns-checking script doesn’t complain anymore.

Currently - I get the following message in the logs (and btw - I also switched to a debian 12 machine):

Feb 16 17:20:30 debian-chat-arm postfix/smtps/smtpd[1327]: connect from mobile-out-114-224.siminn.is[157.157.114.224]
Feb 16 17:20:30 debian-chat-arm doveauth[779]: WARNING:root:request had no answer: 'H3\t2\t0\t\tauth'
Feb 16 17:20:30 debian-chat-arm postfix/smtps/smtpd[1327]: NOQUEUE: client=mobile-out-114-224.siminn.is[157.157.114.224], sasl_method=PLAIN, sasl_username=indridi00@mychatdomain
Feb 16 17:20:30 debian-chat-arm postfix/reinject/smtpd[1333]: connect from localhost[::1]
Feb 16 17:20:30 debian-chat-arm postfix/reinject/smtpd[1333]: warning: connect to Milter service unix:opendkim/opendkim.sock: Permission denied
Feb 16 17:20:30 debian-chat-arm postfix/reinject/smtpd[1333]: NOQUEUE: milter-reject: CONNECT from localhost[::1]: 451 4.7.1 Service unavailable - try again later; proto=SMTP
Feb 16 17:20:30 debian-chat-arm postfix/reinject/smtpd[1333]: NOQUEUE: milter-reject: EHLO from localhost[::1]: 451 4.7.1 Service unavailable - try again later; proto=SMTP helo=<[127.0.1.1]>
Feb 16 17:20:30 debian-chat-arm postfix/reinject/smtpd[1333]: NOQUEUE: milter-reject: MAIL from localhost[::1]: 451 4.7.1 Service unavailable - try again later; from=<indridi00@mychatdomain> proto=ESMTP helo=<[127.0.1.1]>
Feb 16 17:20:30 debian-chat-arm filtermail[788]: ERROR:mail.log:('127.0.0.1', 43476) SMTP session exception
Feb 16 17:20:30 debian-chat-arm filtermail[788]: Traceback (most recent call last):
Feb 16 17:20:30 debian-chat-arm filtermail[788]:   File "/usr/local/lib/chatmaild/venv/lib/python3.11/site-packages/aiosmtpd/smtp.py", line 741, in _handle_client
Feb 16 17:20:30 debian-chat-arm filtermail[788]:     await method(arg)
Feb 16 17:20:30 debian-chat-arm filtermail[788]:   File "/usr/local/lib/chatmaild/venv/lib/python3.11/site-packages/aiosmtpd/smtp.py", line 1460, in smtp_DATA
Feb 16 17:20:30 debian-chat-arm filtermail[788]:     status = await self._call_handler_hook('DATA')
Feb 16 17:20:30 debian-chat-arm filtermail[788]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Feb 16 17:20:30 debian-chat-arm filtermail[788]:   File "/usr/local/lib/chatmaild/venv/lib/python3.11/site-packages/aiosmtpd/smtp.py", line 473, in _call_handler_hook
Feb 16 17:20:30 debian-chat-arm filtermail[788]:     status = await hook(self, self.session, self.envelope, *args)
Feb 16 17:20:30 debian-chat-arm filtermail[788]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Feb 16 17:20:30 debian-chat-arm filtermail[788]:   File "/usr/local/lib/chatmaild/venv/lib/python3.11/site-packages/chatmaild/filtermail.py", line 96, in handle_DATA
Feb 16 17:20:30 debian-chat-arm filtermail[788]:     client.sendmail(envelope.mail_from, envelope.rcpt_tos, envelope.content)
Feb 16 17:20:30 debian-chat-arm filtermail[788]:   File "/usr/lib/python3.11/smtplib.py", line 887, in sendmail
Feb 16 17:20:30 debian-chat-arm filtermail[788]:     raise SMTPSenderRefused(code, resp, from_addr)
Feb 16 17:20:30 debian-chat-arm filtermail[788]: smtplib.SMTPSenderRefused: (451, b'4.7.1 Service unavailable - try again later', 'indridi00@mychatdomain')
Feb 16 17:20:30 debian-chat-arm postfix/smtps/smtpd[1327]: proxy-reject: END-OF-MESSAGE: 500 Error: (SMTPSenderRefused) (451, b'4.7.1 Service unavailable - try again later', 'indridi00@mychatdomain'); from=<indridi00@mychatdomain> to=<desktop00@mychatdomain> proto=ESMTP helo=<[127.0.0.1]> sasl_username=<indridi00@mychatdomain>
Feb 16 17:20:30 debian-chat-arm postfix/reinject/smtpd[1333]: lost connection after RSET from localhost[::1]
Feb 16 17:20:30 debian-chat-arm postfix/reinject/smtpd[1333]: disconnect from localhost[::1] ehlo=1 mail=0/1 rset=1 commands=2/3
Feb 16 17:20:31 debian-chat-arm postfix/smtps/smtpd[1327]: disconnect from mobile-out-114-224.siminn.is[157.157.114.224] ehlo=1 auth=1 mail=1 rcpt=2 data=0/1 quit=1 commands=6/7

Ok, it works now. If I add a new contact using the QR code, I can send a message, and the other account actually receives it.

It appears that the auto-generated config for postfix wasn’t correct. I added the following lines at the end of /etc/postfix/main.cf

smtpd_milters = inet:127.0.0.1:8891
non_smtpd_milters = $smtpd_milters
milter_default_action = accept

I have double checked - removing these lines, then restarting postfix and opendkim services results in message delivery failure as before.

Perhaps I should file an issue?

But nothing is even running on port 8891, so this smtpd_milters setting is not correct. Besides that, OpenDKIM milter should not be configured globally on all smtpd daemons, submission ports don’t need it as outgoing messages are signed by reinjecting proxy after filtermail. OpenDKIM is running on /var/spool/postfix/opendkim/opendkim.sock unix socket and is configured with smtpd_milters=unix:opendkim/opendkim.sock on smtpd daemons that need it.

I have tested, messages from chat.spliff-donk.de still do not seem to be delivered outside.

Maybe OpenDKIM is not running and you skip it with milter_default_action = accept? Could you try restarting it with systemctl restart opendkim? Default action is tempfail and with accept setting you ignore errors.

Thank you for your help.

You are right - the lines I added seem to have “fixed” things by ignoring dkim. I removed them again. The real problem was probably another one (found deep in some config files).
The postfix user needs to be a member of the opendkim user group - which is not the default on debian 12 install.

Added postfix to opendkim group, removed the line in the config - and I can send mails within the server (still problem with sending between servers, another thread for that).

Thank you,
IndriĂ°i

cmdeploy should have added postfix to opendkim group:

This did not work for you? Could be a simple cmdeploy run should have fixed it, but we definitely need to make it work on the first run.

I opened an issue on GitHub: `postfix` is not added to `opendkim` group on first install · Issue #217 · deltachat/chatmail · GitHub

I did run cmdeploy run.

There were some errors, my dns records wera lacking a lot when I first ran it. Regrettably, I can’t remember which errors, or even if it was perhaps not in run but in the cmdeploy dns command.

In any case, I had everything up and running: postfix, dovecot and chatmail deamon, visible in ps -AF and in service --status-all. However postfix user was reported as being solely member of postfix group and no others.

After adding the postfix user to the opendkim group, everything started working.

Greetings,
IndriĂ°i

1 Like