0

During that day sender sent four other emails after this one. All of them were delivered as usual.
These are the lines of maillog corresponding to that email that was not delivered to recipient.

Mar 22 06:36:19 host postfix/smtpd[10898]: connect from mail-eopbgr20115.outbound.protection.outlook.com[40.107.X.X]

Mar 22 06:36:20 host postfix/smtpd[10898]: setting up TLS connection from mail-eopbgr20115.outbound.protection.outlook.com[40.107.X.X]

Mar 22 06:36:20 host postfix/smtpd[10898]: Anonymous TLS connection established from mail-eopbgr20115.outbound.protection.outlook.com[40.107.X.X]: TLSv1.2 with cipher AES256-SHA256 (256/256 bits)

Mar 22 06:36:20 host postgrey[2424]: action=pass, reason=client whitelist, client_name=mail-eopbgr20115.outbound.protection.outlook.com, client_address=40.107.X.X, sender=sender@sender, recipient=rec@rec.com

Mar 22 06:36:20 host postfix/smtpd[10898]: D6D441CA09A0: client=mail-eopbgr20115.outbound.protection.outlook.com[40.107.X.X]

Mar 22 06:36:21 host postfix/cleanup[12463]: D6D441CA09A0: message-id=< VI1PR01MB4271639DA076BEED2736C9BBA3430@VI1PR01MB4271.eurprd01.prod.exchangelabs.com>

Mar 22 06:36:21 host postfix/cleanup[12463]: D6D441CA09A0: discard: header x-microsoft-antispam-message-info:? 5rSUbtg9a+8v7qvflcvdu8ODNNDgy6QCo+jk8ASeowDSfUDlGtYCfDanPZJMgeVPyAkrokaTR/GTVXYWmsdxNjKqfXtMFFV5oeBuVMt16oe4C6HjA720zoIc55J2J/Mgzz9DS6vIKQ3BUcbQjjryRvMopmcnkloE8rBr from mail-eopbgr20115.outbound.protection.outlook.com[40.107.X.X]; from=< sender@sender> to=< rec@rec.com> proto=ESMTP helo=< EUR02-VE1-obe.outbound.protection.outlook.com>

Mar 22 06:36:21 host postfix/smtpd[10898]: disconnect from mail-eopbgr20115.outbound.protection.outlook.com[40.107.X.X]

Spamassassin is running but Procmail is set to deliver normally.

These lines are also from maillog of one of the delivered ones.

Mar 22 12:44:03 host postfix/smtpd[2197]: connect from mail-eopbgr00132.outbound.protection.outlook.com[40.107.X.X]

Mar 22 12:44:03 host postfix/smtpd[2197]: setting up TLS connection from mail-eopbgr00132.outbound.protection.outlook.com[40.107.X.X]

Mar 22 12:44:03 host postfix/smtpd[2197]: Anonymous TLS connection established from mail-eopbgr00132.outbound.protection.outlook.com[40.107.X.X]: TLSv1.2 with cipher AES256-SHA256 (256/256 bits)

Mar 22 12:44:03 host postgrey[2424]: action=pass, reason=client whitelist, client_name=mail-eopbgr00132.outbound.protection.outlook.com, client_address=40.107.X.X, sender=sender@sender, recipient=rec@rec

Mar 22 12:44:03 host postfix/smtpd[2197]: BB5741CA09A0: client=mail-eopbgr00132.outbound.protection.outlook.com[40.107.X.X]

Mar 22 12:44:03 host postfix/cleanup[3184]: BB5741CA09A0: message-id=< VI1PR01MB4271B2A2EA25E7D9246BB185A3430@VI1PR01MB4271.eurprd01.prod.exchangelabs.com>

Mar 22 12:44:04 host opendkim[2109]: BB5741CA09A0: mail-eopbgr00132.outbound.protection.outlook.com [40.107.X.X] not internal

Mar 22 12:44:04 host opendkim[2109]: BB5741CA09A0: not authenticated

Mar 22 12:44:04 host opendkim[2109]: BB5741CA09A0: failed to parse authentication-results: header field

Mar 22 12:44:04 host opendkim[2109]: BB5741CA09A0: DKIM verification successful

Mar 22 12:44:04 host postfix/qmgr[2515]: BB5741CA09A0: from=< sender@sender>, size=12328, nrcpt=1 (queue active)

Mar 22 12:44:04 host postfix/pickup[1223]: 362C71CA0B4D: uid=584 from=< rec>

Mar 22 12:44:04 host postfix/cleanup[3184]: 362C71CA0B4D: message-id=< VI1PR01MB4271B2A2EA25E7D9246BB185A3430@VI1PR01MB4271.eurprd01.prod.exchangelabs.com>

Mar 22 12:44:04 host postfix/local[3190]: BB5741CA09A0: to=< rec@XXhost>, orig_to=< rec@rec>, relay=local, delay=0.54, delays=0.46/0/0/0.08, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME)

Mar 22 12:44:04 host postfix/qmgr[2515]: BB5741CA09A0: removed

Mar 22 12:44:04 host opendkim[2109]: 362C71CA0B4D: no signing table match for 'sender@sender'

Mar 22 12:44:04 host opendkim[2109]: 362C71CA0B4D: failed to parse authentication-results: header field

Mar 22 12:44:04 host opendkim[2109]: 362C71CA0B4D: DKIM verification successful

Mar 22 12:44:04 host postfix/smtpd[2197]: warning: network_biopair_interop: error writing 69 bytes to the network: Connection reset by peer

Mar 22 12:44:04 host postfix/smtpd[2197]: warning: network_biopair_interop: error writing 69 bytes to the network: Broken pipe

Mar 22 12:44:04 host postfix/smtpd[2197]: disconnect from mail-eopbgr00132.outbound.protection.outlook.com[40.107.X.X]

EDIT (Answering some comments/questions)

Postfix Header and Body checks don't contain anything about "Microsoft-antispam" or something like that, only "/Republique du Benin/" and other known strings only are in spam headers/bodies.

Header checks: enter image description here
Body checks: enter image description here

cat /path-to-Mar22-procmail.log | grep sender's name

outputs the other 4 delivered messages, not the Mar 22 06:36: one
procmai.rc of this user only has a forward directive regarding sender's name

I understand that that Microsoft antispam header might be causing the issue but I don't get what happened.

EDIT 2:
Looking at the header of the second message sent and delivered it also contains MS antispam msg that wasn't explicity recorded in log file:

x-microsoft-antispam-message-info: Dgz3XVK6DEMeeorg2JFa7q8+XuAbKdJSYQ7Q90u5ByPqwwuvuoBx7bfKh4rWYzkdgu4EYFwgk6idK2YswaKyN8uwCuqVh41lQWVja0GMMiyIA3F2r4h0kHmk+E6aIhMoju4h7mNl6/4KaDYx20AAplVJk99gFq6TEm6I7z4GIu8OngM6FkH6UQj/vF89sa2NkI4edRaMidxoXSujy6umqUVl9qEn74mLttPfLxQkl4DDtV95Idt/hGAGuvYYzzkQc1LaxD/F9ICa6F3l6NHE1d9f2t0ZfAFa7tl3OGUJsMtHK5xL5X/vlWAcfdlqCsqOYIs0wJ+gCgjqYQ6GWZmmXIVAwQuyMwAtw7IxwItfod+bne1k9lMk0iZtooT8Kh6abJYGBemL9wGDtPL9JaArmau4h6rkAcjp2pSQmrD5o4o=

This is quite longer than the other one.

  • "discard: header x-microsoft-antispam-message-info:? " : Is there a filter if this header exists ? – Dom Mar 23 at 16:49
  • I don't see anything implicating Procmail; maybe edit out the procmail tag? Or else, if you have a relevant.procmalrc and log file, show it. – tripleee Mar 23 at 18:47
  • Check the contents of /etc/postfix/header_checks and /etc/postfix/body_checks (it's ok if the latter doesn't exist). – Michael Hampton Mar 23 at 18:49
  • I added some more info to the question – dstonek Mar 23 at 21:21
1

My guess is that your 'header_checks' regex /.icu/ is matching something in the full x-microsoft-antispam-message-info header. Postfix does not log all of very long headers and that's a very loose regex because you have the wildcard. Seems like a very risky pattern to me but do as you want with your own mail...

Note that "x-microsoft-antispam-message-info" is not documented, but it almost always contains >300 or <100 characters and most often is 428 characters.

  • I was suspicious about that .icu but because I didn't find this string in MS antispam header, but you say it is trimmed. Do they also contain dots? I added it a month ago because lots of spam from *.icu addresses. At least I shuould change it by .icu$ – dstonek Mar 24 at 22:35
  • 2
    . is a wildcard in regex. so '/.icu/' means any 4 characters ending in icu. To match a literal '.' you need to use '\.' – Bill Cole Mar 24 at 22:39
0

The main difference I see is that the outlook server where the message originated added a header, "x-microsoft-antispam-message-info", to the message that failed to deliver. Apparently, for whatever reason, outlook tagged the message as possible spam. I would look through all my mail config to see if that header triggers any special processing.

  • Sorry to say that this is not an answer – dstonek Mar 23 at 21:22

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.