I changed from local SMTP server and now I’m unable to send mail with the mail plugin (latest version).
My mailserver is postfix and configured to allow local relay when authentication is used. The IP of the pimatic machine is whitelisted as a sending client.

  • Pimatic is not running on the same ip / machine as postfix
  • Pimatic is running in the same subnet as postfix
  • I can send email directly from the prompt of the pimatic server using telnet and the same credentials (this rules out any connectivity and authentication issues).
  • When sending mail everything looks ok, but the plugin simply stops doing its work, after a while postifx kills the connection due to timeout
Oct 24 21:06:02 mail postfix/postscreen[21353]: CONNECT from [192.168.2.121]:43858 to [192.168.2.234]:25
Oct 24 21:06:02 mail postfix/postscreen[21353]: WHITELISTED [192.168.2.121]:43858
Oct 24 21:06:02 mail postfix/smtpd[21356]: connect from unknown[192.168.2.121]
Oct 24 21:06:03 mail dovecot: auth: Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Oct 24 21:06:03 mail dovecot: auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so
Oct 24 21:06:03 mail dovecot: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat
Oct 24 21:06:03 mail dovecot: auth: Debug: auth client connected (pid=0)
Oct 24 21:06:04 mail postfix/smtpd[21356]: Anonymous TLS connection established from unknown[192.168.2.121]: TLSv1.2 with cipher ECDHE-RSA-AES256-SHA (256/256 bits)
Oct 24 21:06:04 mail dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=smtp#011nologin#011lip=192.168.2.234#011rip=192.168.2.121#011secured#011resp=secret stuff= (previous base64 data may contain sensitive data)
Oct 24 21:06:04 mail dovecot: auth-worker(21358): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Oct 24 21:06:04 mail dovecot: auth-worker(21358): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so
Oct 24 21:06:04 mail dovecot: auth-worker(21358): Debug: sql(backup@domain.tld,192.168.2.121): query: SELECT username AS user, domain, password FROM accounts WHERE
username = 'backup' AND domain = 'domain.tld' and enabled = true;
Oct 24 21:06:04 mail dovecot: auth-worker(21358): Debug: sql(backup@domain.tld,192.168.2.121): username changed backup@domain.tld -> backup
Oct 24 21:06:04 mail dovecot: auth-worker(21358): Debug: sql(backup,192.168.2.121): username changed backup -> backup@domain.tld
Oct 24 21:06:04 mail dovecot: auth: Debug: sql(backup@domain.tld,192.168.2.121): username changed backup@domain.tld -> backup
Oct 24 21:06:05 mail dovecot: auth: Debug: sql(backup,192.168.2.121): username changed backup -> backup@domain.tld
Oct 24 21:06:05 mail dovecot: auth: Debug: client passdb out: OK#0111#011user=backup@domain.tld
Oct 24 21:06:05 mail postfix/smtpd[21356]: 881AA22336: client=unknown[192.168.2.121], sasl_method=PLAIN, sasl_username=backup@domain.tld
Oct 24 21:06:05 mail postfix/cleanup[21360]: 881AA22336: message-id=<1258678a5527aadedf426171d8a915@pimaticvm>

Eventually postfix will give up and send a timeout response to pimatic:

Oct 24 21:11:06 mail postfix/smtpd[21356]: timeout after DATA (90326 bytes) from unknown[192.168.2.121]
Oct 24 21:11:06 mail postfix/smtpd[21356]: disconnect from unknown[192.168.2.121] ehlo=2 starttls=1 auth=1 mail=1 rcpt=1 data=0/1 commands=6/7

Strange enough, the connection from pimatic mail plugin was open all that time:

error [pimatic]: Error on evaluation of rule condition of rule mail-config-on-request: 421 4.4.2 mail.domain.tld Error: timeout exceeded
21:11:05error [pimatic]: rule mail-config-on-request error executing an action: 421 4.4.2 mail.domain.tld Error: timeout exceeded

Previously, with a other brand SMTP server, I could send mails to local accounts witouth any issues.
I’m pulling my hair but can’t figure out what;s going wrong.