The vanishing outgoing e-mail

mbyrd777 · July 15, 2014, 4:14pm

So I have a Virtualmin setup with many domains. The mail is fast and works amazingly well. Thank everyone for the GPL version.

Now for the problem child… I have a single domain who can send to everyone besides 1 specific domain. That other domain can send back to the virtualmin server perfectly fine.

So…
Domain 1 can send to domain 2 and it disappears.
Domain 2 can send to domain 1 and it works great.
Domain 1 can send to anyone else in the world without issue.
Domain 2 can send to anyone else in the world without issue.

I’m setup with postfix and I’m just needing some tips as far as hunting down the mail in the logs.

I have administrative access to domain 2’s e-mail server (exchange) and full access to the virtualmin root.

Any help is greatly appreciated! A beer will be provided to anyone who can help me fix this!

Eric · July 15, 2014, 5:36pm

Howdy,

Hmm, in this particular case, does domain2 have a website hosted on your Virtualmin server?

If so, one possible cause is that the “Mail for Domain” feature may be enabled in Edit Virtual Server -> Enabled Features. If Mail for Domain is enabled, any email destined for that domain would be delivered locally on the Virtualmin server, rather than to the remote Exchange server.

You could verify that by reviewing the email logs in /var/log/maillog or /var/log/mail.log.

Even if that’s not the case, the above email logs would likely offer some hints as to what’s going on regarding this issue.

-Eric

mbyrd777 · July 15, 2014, 5:47pm

They don’t have a domain hosted there. It is completely seperate.

Jul 15 17:17:21 mx00 postfix/local[21527]: B22FB7338: to=user-domain2.com@mx.domain1.com, orig_to=user@domain2.com, relay=local, delay=0.99, delays=0.09/0/0/0.9, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)

Jul 15 17:17:21 mx00 postfix/qmgr[2495]: B22FB7338: removed

I see this in the log and it looks to me as if it is sent.

Eric · July 15, 2014, 7:35pm

Whenever it shows an email being delivered to the command “/usr/bin/procmail-wrapper”, that means it is being delivered locally, and not to a remote server.

Is there any other output above that particular log message? The other output may help us understand what exactly is going on there.

-Eric

mbyrd777 · July 15, 2014, 7:52pm


Jul 15 12:51:22 mx00 spamd[19068]: spamd: setuid to user@domain2.com succeeded
Jul 15 12:51:22 mx00 spamd[19068]: spamd: processing message <1feb4b304f5d0312d50b85857b9f7ff9@domain1.com> for user@domain2.com:595
Jul 15 12:51:23 mx00 spamd[19068]: spamd: clean message (-1.1/5.0) for user@domain2.com:595 in 0.3 seconds, 40678 bytes.
Jul 15 12:51:23 mx00 spamd[19068]: spamd: result: . -1 - ALL_TRUSTED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,URIBL_BLOCKED scantime=0.3,size=40678,user=user@domain2.com,uid=595,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=53894,mid=<1feb4b304f5d0312d50b85857b9f7ff9@domain1.com>,autolearn=ham
Jul 15 12:51:23 mx00 postfix/local[31632]: 3489C7322: to=, orig_to=, relay=local, delay=1, delays=0.1/0.01/0/0.89, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)
Jul 15 14:36:40 mx00 spamd[6944]: spamd: setuid to user@domain2.com succeeded
Jul 15 14:36:40 mx00 spamd[6944]: spamd: processing message <53e507680e9cfdcc5fb2f65578481a3a@domain1.com> for user@domain2.com:595
Jul 15 14:36:44 mx00 spamd[6944]: spamd: clean message (-1.1/5.0) for user@domain2.com:595 in 4.1 seconds, 1530 bytes.
Jul 15 14:36:44 mx00 spamd[6944]: spamd: result: . -1 - ALL_TRUSTED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,URIBL_BLOCKED scantime=4.1,size=1530,user=user@domain2.com,uid=595,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=54658,mid=<53e507680e9cfdcc5fb2f65578481a3a@domain1.com>,autolearn=ham
Jul 15 14:36:44 mx00 postfix/local[7759]: D90377431: to=, orig_to=, relay=local, delay=7.6, delays=0.08/0.01/0/7.5, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)
Jul 15 14:42:37 mx00 spamd[6944]: spamd: setuid to user@domain2.com succeeded
Jul 15 14:42:37 mx00 spamd[6944]: spamd: processing message <0acd45234006d5a5c7b93a01bbbc3971@domain1.com> for user@domain2.com:595
Jul 15 14:42:37 mx00 spamd[6944]: spamd: clean message (-1.1/5.0) for user@domain2.com:595 in 0.7 seconds, 1505 bytes.
Jul 15 14:42:37 mx00 spamd[6944]: spamd: result: . -1 - ALL_TRUSTED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,URIBL_BLOCKED scantime=0.7,size=1505,user=user@domain2.com,uid=595,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=54715,mid=<0acd45234006d5a5c7b93a01bbbc3971@domain1.com>,autolearn=ham
Jul 15 14:42:37 mx00 postfix/local[8279]: 78E8D7322: to=, orig_to=, relay=local, delay=1.3, delays=0.1/0.01/0/1.2, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)
Jul 15 14:57:33 mx00 spamd[6944]: spamd: setuid to user@domain2.com succeeded
Jul 15 14:57:33 mx00 spamd[6944]: spamd: processing message <40f8cf55c599a3f9d73d157447eab0be@domain1.com> for user@domain2.com:595
Jul 15 14:57:34 mx00 spamd[6944]: spamd: clean message (-1.1/5.0) for user@domain2.com:595 in 0.9 seconds, 1539 bytes.
Jul 15 14:57:34 mx00 spamd[6944]: spamd: result: . -1 - ALL_TRUSTED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,URIBL_BLOCKED scantime=0.9,size=1539,user=user@domain2.com,uid=595,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=54836,mid=<40f8cf55c599a3f9d73d157447eab0be@domain1.com>,autolearn=ham
Jul 15 14:57:34 mx00 postfix/local[9641]: 307467322: to=, orig_to=, relay=local, delay=1.4, delays=0.08/0/0/1.3, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)
Jul 15 15:23:49 mx00 postgrey[2410]: action=pass, reason=client AWL, client_name=173-163-208-213-westflorida.hfc.comcastbusiness.net, client_address=173.163.208.213, sender=user@domain2.com, recipient=user1@domain1.com
Jul 15 15:23:50 mx00 postfix/qmgr[2495]: DF6CC7322: from=, size=93620, nrcpt=1 (queue active)
Jul 15 15:43:50 mx00 spamd[6944]: spamd: setuid to user@domain2.com succeeded
Jul 15 15:43:50 mx00 spamd[6944]: spamd: processing message <516a1118e00bbd68f7325c390ada358d@domain1.com> for user@domain2.com:595
Jul 15 15:43:54 mx00 spamd[6944]: spamd: clean message (-1.1/5.0) for user@domain2.com:595 in 4.1 seconds, 2143 bytes.
Jul 15 15:43:54 mx00 spamd[6944]: spamd: result: . -1 - ALL_TRUSTED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,URIBL_BLOCKED scantime=4.1,size=2143,user=user@domain2.com,uid=595,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=55338,mid=<516a1118e00bbd68f7325c390ada358d@domain1.com>,autolearn=ham
Jul 15 15:43:54 mx00 postfix/local[13673]: 890A07322: to=, orig_to=, relay=local, delay=4.6, delays=0.05/0/0/4.6, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)
Jul 15 15:50:55 mx00 postgrey[2410]: action=pass, reason=client AWL, client_name=173-163-208-213-westflorida.hfc.comcastbusiness.net, client_address=173.163.208.213, sender=user@domain2.com, recipient=user1@domain1.com
Jul 15 15:50:55 mx00 postfix/qmgr[2495]: 81C897322: from=, size=2217, nrcpt=1 (queue active)
Jul 15 17:17:21 mx00 spamd[6944]: spamd: setuid to user@domain2.com succeeded
Jul 15 17:17:21 mx00 spamd[6944]: spamd: processing message <258de33957e1066a95d4f3b89b8ec009@domain1.com> for user@domain2.com:595
Jul 15 17:17:21 mx00 spamd[6944]: spamd: clean message (-1.1/5.0) for user@domain2.com:595 in 0.4 seconds, 1518 bytes.
Jul 15 17:17:21 mx00 spamd[6944]: spamd: result: . -1 - ALL_TRUSTED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,URIBL_BLOCKED scantime=0.4,size=1518,user=user@domain2.com,uid=595,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=56187,mid=<258de33957e1066a95d4f3b89b8ec009@domain1.com>,autolearn=ham
Jul 15 17:17:21 mx00 postfix/local[21527]: B22FB7338: to=, orig_to=, relay=local, delay=0.99, delays=0.09/0/0/0.9, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)
Jul 15 18:13:57 mx00 spamd[6944]: spamd: setuid to user@domain2.com succeeded
Jul 15 18:13:57 mx00 spamd[6944]: spamd: processing message <6c73fc2900a8c14934feb5d8d0938fd9@domain1.com> for user@domain2.com:595
Jul 15 18:14:01 mx00 spamd[6944]: spamd: clean message (-1.1/5.0) for user@domain2.com:595 in 4.1 seconds, 2723 bytes.
Jul 15 18:14:01 mx00 spamd[6944]: spamd: result: . -1 - ALL_TRUSTED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,URIBL_BLOCKED scantime=4.1,size=2723,user=user@domain2.com,uid=595,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=56669,mid=<6c73fc2900a8c14934feb5d8d0938fd9@domain1.com>,autolearn=ham
Jul 15 18:14:01 mx00 postfix/local[27174]: 3AEFE7322: to=, orig_to=, relay=local, delay=4.6, delays=0.04/0/0/4.6, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)

Eric · July 15, 2014, 8:08pm

Howdy,

Hmm, it appears that domain2.com is actually setup on your Virtualmin server.

If it wasn’t setup via Virtualmin, it may have been manually setup outside of Virtualmin.

However, according to those log messages, not only does Postfix think domain2.com is local, when the SpamAssassin process changes it’s userid to match the recipient, it’s able to change to “user@domain2.com”.

That means that domain2.com has actually been setup on your server, and there is at least one user that’s part of that domain.

Can you double-check that in Virtualmin, it wasn’t accidentally added? You can check that by looking in the drop-down list on the top-left.

-Eric

mbyrd777 · July 15, 2014, 8:46pm

sigh

that’s what I get for having shared root access… yes the domain2 was added.

thanks for your help!

and how can I send you beer$?

Eric · July 15, 2014, 9:38pm

Glad you got it working!

No need to send any money, I’m just happy that’s working properly now

Have a good one!

-Eric