Forum OpenACS Development: Sending emails through acs_mail_lite::smtp

Request notifications

Hi there,

It seems acs_mail_lite::smtp wraps the email differently, then emails get rejected by the SMTP service provider.

Postfix logs show the following messages for valid emails (i.e. using mail command) and rejected emails (i.e. using OpenACS ad_proc acs_mail_lite::send)

acs_mail_lite SMTP pkg parameters are all blank. Plus I've assigned mailhost within ns-config.tcl accordingly.
I've followed the execution of ad_proc acs_mail_lite::send, and I added many ns_log Notice's along the code. The very last command is:

"smtp::sendmessage ::mime::43 -originator mailto:nevessouza@iurix.com -header {From mailto:nevessouza@iurix.com} -header {Reply-To mailto:nevessouza@iurix.com} -header {To mailto:iuri_sampaio@hotmail.com} -servers iurix.com -ports 25"

It's within acs_mail_lite::smtp, line 162.

...
if {[catch $cmd errorMsg]} {
ns_log Error "acs-mail-lite::smtp: error $errorMsg while executing\n$cmd"
error $errorMsg
}
...

However, I haven't found a way to go depper within [smtp::sendmessage]. How would I debug this execution?
/api-doc/proc-view?proc=acs_mail_lite::smtp&source_p=1

Why do emails using OpenACS get rejected while emails using "mail" command work successfully? I've assigned the parameter EmailDeliveryMode
to "log". See the entire log bellow

#1. Valid email
Nov 29 21:43:07 iurix postfix/pickup[15402]: 376674C872: uid=1002 from=mailto:iurix@iurix.com >
Nov 29 21:43:07 iurix postfix/cleanup[15420]: 376674C872: message-id=mailto:20181129214307.376674C872@mail.iurix.com >
Nov 29 21:43:07 iurix postfix/qmgr[15403]: 376674C872: from=mailto:iurix@iurix.com >, size=355, nrcpt=1 (queue active)
Nov 29 21:43:07 iurix postfix/smtp[15421]: 376674C872: to=mailto:iuri.sampaio@gmail.com >, relay=smtpout.secureserver.net[68.178.252.101]:465, delay=0.43, delays=0.03/0/0.31/0.1, dsn=2.0.0, status=sent (250 SU5TgNDSXROT0 mail accepted for delivery)
Nov 29 21:43:07 iurix postfix/qmgr[15403]: 376674C872: removed

#2. Reject Email
Nov 29 21:42:45 iurix postfix/smtpd[15410]: connect from iurix.com[192.199.241.135]
Nov 29 21:42:45 iurix postfix/smtpd[15410]: NOQUEUE: reject: RCPT from iurix.com[192.199.241.135]: 454 4.7.1 mailto:iuri.sampaio@gmail.com >: Relay access denied; from=mailto:nevessouza@iurix.com> to=mailto:iuri.sampaio@gmail.com > proto=ESMTP helo=< iurix.com >
Nov 29 21:42:45 iurix postfix/smtpd[15410]: disconnect from iurix.com[192.199.241.135] ehlo=1 mail=1 rcpt=0/1 rset=1 quit=1 commands=4/5

[29/Nov/2018:22:06:03][12309.7f09d2dbf700][-conn:iurix:0:892-] Notice: SEND EMAIL to_addr mailto:iuri_sampaio@hotmail.com
[29/Nov/2018:22:06:03][12309.7f09d2dbf700][-conn:iurix:0:892-] Notice: acs-mail-lite::send: logging email instead of sending

**********
Envelope sender: mailto:bounce-879-E694D573CFEF49F86ADE2FAF3E8C5B7B192C6EEF-282@iurix.com

MIME-Version: 1.0
Content-ID: mailto:12309.1543529163.55@iurix.com >
message-id: mailto:12309.1543529163.52@iurix.com >
date: Thu, 29 Nov 2018 22:06:03 +0000
Subject: =?UTF-8?Q?Email_sample_from_oacs?=
From: mailto:nevessouza@iurix.com
Reply-To: mailto:nevessouza@iurix.com
To: mailto:iuri.sampaio@gmail.com
Content-Type: multipart/alternative;
boundary="----- =_RDQxNjQ4M0Q2MDc3MkU1RTJGNDkzMDZFQUE4RUE4Mjg="

------- =_RDQxNjQ4M0Q2MDc3MkU1RTJGNDkzMDZFQUE4RUE4Mjg=
MIME-Version: 1.0
Content-ID: mailto:12309.1543529163.54@iurix.com >
Content-Type: text/plain;
charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

This is a test body. The persrverance is super
------- =_RDQxNjQ4M0Q2MDc3MkU1RTJGNDkzMDZFQUE4RUE4Mjg=
MIME-Version: 1.0
Content-ID: mailto:12309.1543529163.53@iurix.com >
Content-Type: text/html;
charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

This is a test body. The persrverance is super
------- =_RDQxNjQ4M0Q2MDc3MkU1RTJGNDkzMDZFQUE4RUE4Mjg=--

**********

Collapse
Posted by Iuri Sampaio on
I found a solution but the cause is still unknown to myself. Amending mailhost parameter, within ns-config.tcl, allowed a different content, wraped in the email source. It seems ad_proc acs_mail_lite::smtp connects correctly to Postfix now. Emails from OpenACS work properly now.

Why assiging the domain would be a cause, if hostname was properly configured in the server (i.e. OS settings) ?

[30/Nov/2018:00:28:46][17022.7f44632ce700][-conn:iurix:1:5-] Notice: SEND EMAIL to_addr mailto:iuri_sampaio@hotmail.com
[30/Nov/2018:00:28:46][17022.7f44632ce700][-conn:iurix:1:5-] Notice: -multi_token ::mime::13
-headers {From mailto:nevessouza@iurix.com} {Reply-To mailto:nevessouza@iurix.com} {To mailto:iuri.sampaio@gmail.com}
-originator mailto:bounce-879-2663A53C9FB1055B413E8067C1C985EAB0B85CC7-282@iurix.com
[30/Nov/2018:00:28:46][17022.7f44632ce700][-conn:iurix:1:5-] Notice: ORIGINATOR mailto:bounce-879-2663A53C9FB1055B413E8067C1C985EAB0B85CC7-282@iurix.com
[30/Nov/2018:00:28:46][17022.7f44632ce700][-conn:iurix:1:5-] Notice: send cmd: smtp::sendmessage ::mime::13 -originator mailto:nevessouza@iurix.com -header {From mailto:nevessouza@iurix.com} -header {Reply-To mailto:nevessouza@iurix.com} -header {To mailto:iuri.sampaio@gmail.com} -servers localhost -ports 25

Nov 30 00:28:46 iurix postfix/smtpd[17012]: connect from localhost[127.0.0.1]
Nov 30 00:28:46 iurix postfix/smtpd[17012]: 34DF04C93E: client=localhost[127.0.0.1]
Nov 30 00:28:46 iurix postfix/cleanup[17016]: 34DF04C93E: message-id=mailto:17022.1543537726.8@iurix.com >
Nov 30 00:28:46 iurix postfix/smtpd[17012]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Nov 30 00:28:46 iurix postfix/qmgr[16715]: 34DF04C93E: from=mailto:nevessouza@iurix.com >, size=1176, nrcpt=1 (queue active)
Nov 30 00:28:46 iurix postfix/smtp[17017]: 34DF04C93E: to=mailto:iuri.sampaio@gmail.com >, relay=smtpout.secureserver.net[173.201.192.229]:25, delay=0.44, delays=0.06/0/0.26/0.11, dsn=2.0.0, status=sent (250 SWfmg0lQwGkjo mail accepted for delivery)