Can receive mails but can't send

wjurry · March 5, 2022, 11:11am

I am using Axigen Mail Server and I am happy with it’s numerous options and features.

I am able to receive emails, but can’t send. Here is the queue log:

2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Shepherd thread received signal for processing
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> state to RECEIVED
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set mail state to PROCESSING
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Start processing mail
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> state to PROCESSING
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Start filter smtp routing
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Processing started
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Shepherd thread finished processing signal
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: No certificate loaded; disabling STARTTLS
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Local connection
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set remote delivery to auth
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set max data size to 10240 KB
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set max received headers to 30
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Maximum recipient count set to 1000
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Wait for processing response at least 10 seconds
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: STARTTLS extension allowed
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: 8BIT MIME accepted
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: BINARY DATA extension allowed
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: PIPELINING extension allowed
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set local delivery to all
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: DSN extension denied
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Greylist enabled
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: session from [127.0.0.1] authenticated by <support@weblabs.app>
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Created new queue item with id 000FEE87
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Auto-generate SPF result for MAIL FROM <support@weblabs.app@weblabs.app> issued from EHLO domain <weblabs.app> connected from <127.0.0.1>: Pass (spfHeader = ''; spfExplanation = 'null')
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Greylist disabled
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: DomainKeys verification result: no signature
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: DKIM verification result: no signature
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: New mail <1646477542754609231@weblabs.app> received from weblabs.app (127.0.0.1) with envelope from <support@weblabs.app>, authenticated as <support@weblabs.app>, recipients=1 (jurrywajdi@yahoo.com), size=2102, enqueued with id 0FEE87 (orgid=32FDDF)
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> state to FILTER DISCARD
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> state to PROCESSING
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> data version to 1
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:000FEE87: Set mail state to REMOVED
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Finished filtering mail object 32FDDF with filter: smtp routing
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> state to PROCESSING
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Start filter AV:Tnef of type socket filter from server
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Filter AXI-TNEF(127.0.0.1:8888):[PASS]: pass - no changes
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Finished filtering mail object 32FDDF with filter: AV:Tnef of type socket filter from server
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> data version to 2
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> state to PROCESSING
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Start filter text appender
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Finished filtering mail object 32FDDF with filter: text appender
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> data version to 3
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> state to PROCESSING
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Start filter onProcessing event
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: The message has been signed using DomainKeys
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Finished filtering mail object 32FDDF with filter: onProcessing event
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> data version to 4
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> state to PROCESSING
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set recipient <jurrywajdi@yahoo.com> state to PROCESSED - RELAY
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set mail state to PROCESSED
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Processing finished
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Shepherd thread received signal for delivery
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Shepherd thread finished delivery signal
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Start mail delivery
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set mail state to SENDING
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Start remote delivery for 1 recipients in domain yahoo.com
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set remote smtp host to <[hidden]>
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Set remote smtp port to 993
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Use SSL connection
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: STARTTLS extension allowed
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Allowed ssl versions set to: tls11 tls12 tls13 
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Relay mail using filter specified host: <[hidden]:993>
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Relay mail: add host <hidden> with priority 0
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Use <hidden> to relay mail 32FDDF for domain yahoo.com
2022-03-05 13:52:25 +0300 04 127.0.0.1 PROCESSING:0032FDDF: 1 temporary failed recipients; compose temporary NDR

I have couple of questions here:

Why is the domain name (@weblabs.app) duplicated?
Why spfHeader is empty?

Auto-generate SPF result for MAIL FROM <support@weblabs.app@weblabs.app> issued from EHLO domain <weblabs.app> connected from <127.0.0.1>: Pass (spfHeader = ''; spfExplanation = 'null')

I have configured the DNS records and enabled DMARC and SPF, here are the records:

TXT    _dmarc    v=DMARC1; p=quarantine; rua=mailto:x@b.com"
TXT           weblabs.app     v=spf1 mx a include:weblabs.app -all

Also, I have configured DKIM record, to sign email envelop before sending:

TXT    s1._domainkey    v=DKIM1; k=rsa;  p=<public_key>

So, what did I do wrong ? Is there anything I missed in Axigen config ?

indreias · March 7, 2022, 12:28pm

Hello,

As you noticed from below logs:

2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Relay mail using filter specified host: <[hidden]:993>
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Relay mail: add host <hidden> with priority 0
2022-03-05 13:52:22 +0300 08 127.0.0.1 PROCESSING:0032FDDF: Use <hidden> to relay mail 32FDDF for domain yahoo.com

you seems to have configured a Smart Host relay in order to send your messages to external domains. This is nothing strange but the port used (993) which is the default for IMAP SSL protocol. Now, if you have double checked this setup with your Smart Host service than please post here the PROCESSING and SMTP-OUT Axigen log lines but only after you have set both of the on Protocol Communication log level.

HTH,
Ioan

wjurry · March 10, 2022, 5:31pm

Hi @indreias , I have the same issue. Here is the log:

2022-03-10 20:26:51 +0300 08 LocalMachine SMTP-OUT:00000005: Relay mail 043519: connecting to <hidden-ip>:993
2022-03-10 20:26:51 +0300 16 LocalMachine  SMTP-OUT:00000005: >> SSL: client hello, remote <hidden-ip>:993, version TLS 1.3 (0304)
2022-03-10 20:26:51 +0300 16 LocalMachine  SMTP-OUT:00000005: >> SSL: client hello, remote <hidden-ip>:993, session id cf53b3b94d87cca65fbb283e374d3cd361a3bbfcc2f4d029585d47392b57dc70
2022-03-10 20:26:51 +0300 16 LocalMachine  SMTP-OUT:00000005: >> SSL: client hello, remote <hidden-ip>:993, 31 cipher suites: 130213031301c02cc030009fcca9cca8ccaac02bc02f009ec024c028006bc023c0270067c00ac0140039c009c0130033009d009c003d003c0035002f00ff
2022-03-10 20:26:51 +0300 16 LocalMachine  SMTP-OUT:00000005: << SSL: server hello, remote <hidden-ip>:993, version TLS 1.3 (0304)
2022-03-10 20:26:51 +0300 16 LocalMachine  SMTP-OUT:00000005: << SSL: server hello, remote <hidden-ip>:993, cipher suite c030
2022-03-10 20:26:51 +0300 08 LocalMachine  SMTP-OUT:00000005: Relay mail 043519: connected to <hidden-ip>:993
2022-03-10 20:26:51 +0300 16 LocalMachine  SMTP-OUT:00000005: << * OK AXIGEN IMAP4rev1 service is ready
2022-03-10 20:26:51 +0300 08 LocalMachine  SMTP-OUT:00000005: Disconnected from <hidden-ip>
2022-03-10 20:26:51 +0300 08 LocalMachine  SMTP-OUT:00000005: Relay mail 043519: no more relays for gmail.com
2022-03-10 20:26:51 +0300 04 LocalMachine  SMTP-OUT:00000005: Delivery attempt completed for mail 043519; 1 recipients remaining; reschedule for delivery
2022-03-10 20:26:51 +0300 08 LocalMachine  SMTP-OUT:00000005: Set mail state to SEND FAILURE

indreias · March 10, 2022, 6:58pm

Hello @wjurry ,

From below log line

2022-03-10 20:26:51 +0300 16 LocalMachine  SMTP-OUT:00000005: << * OK AXIGEN IMAP4rev1 service is ready

it is clear that you are using a wrong Smart Host relay IP and port.

You may ask why and the answer is there, in front of you: you are conecting to an IMAP service (maybe it is your Axigen server?) and not to an SMTP relay service.

Please double check your setup as clearly something is not well done in terms of routing external email messages.

If you are unable to spot the problem please share your smtpFilters.script file (you should find it into filters folder from your Axigen working dir).

HTH,
Ioan