Wrong timestamp added by sendmail in Received: header?

Andreas Haumer <[email protected]> Mon, 24 Mar 2025 15:19:40 +0100
Newsgroups	gmane.mail.spam.spamassassin.general
Organization	xS+S
Message-ID	<[email protected]>
Hi!

Recently I noticed a (at least for me) very strange problem
with a mailserver running sendmail + SpamAssassin: sometimes
(not always!) the Received: header inserted by sendmail is completely wrong,
triggering SpamAssassin rules like "T_DATE_IN_FUTURE_96_Q"

More details: this is an internet-facing mail MX, currently running Debian 10
with sendmail 8.15.2 and spamass-milter 0.4.0

This server is the primary MX for some domains and thus receives almost
all mail for that domains. For spam filtering purposes, it connects
to a SpamAssassin server using spamass-milter. Mails above a given
spam score are rejected, all other mail is forwarded to some internal
mail server for further processing.

The system also uses milters for DKIM, SPF and DMARC functionality,
resulting in the following sendmail config:

INPUT_MAIL_FILTER(`opendkim', `S=local:/var/run/opendkim/opendkim.sock')
INPUT_MAIL_FILTER(`pyspf-milter', `S=local:/run/pyspf-milter/pyspf-milter.sock')dnl
INPUT_MAIL_FILTER(`opendmarc', `S=local:/var/run/opendmarc/opendmarc.sock')dnl
INPUT_MAIL_FILTER(`spamassassin', `S=local:/var/run/spamass/spamass.sock, F=, T=C:15m;S:4m;R:4m;E:10m')dnl

define(`confMILTER_MACROS_CONNECT',`t, b, j, _, {daemon_name}, {if_name}, {if_addr}')dnl
define(`confMILTER_MACROS_HELO',`s, {tls_version}, {cipher}, {cipher_bits}, {cert_subject}, {cert_issuer}')dnl
define(`confMILTER_MACROS_ENVRCPT',`r, v, Z, b, {auth_type}')dnl


When mail is received, sendmail adds a Received: header before the mail is transferred to SpamAssassin.

This header usually looks like that (example, actual spam mail from today):

X-Envelope-From: <[email protected]>
X-Envelope-To: <[email protected]>
Received: from s1159236.srvape.com (s1159236.srvape.com [91.184.249.155] (may be forged))
	by bernhard.xss.co.at (8.15.2/8.15.2/Debian-14~deb10u3) with ESMTP id 52O6Kmpe022819
	Mon, 24 Mar 2025 07:20:48 +0100
	(envelope-from <[email protected]>);
[...]

All is fine with that. The timestamp is correct, as verified by the mailserver logfile:

Mar 24 07:20:48 bernhard pyspf-milter[451]: connect from [91.184.249.155] at ('91.184.249.155', 53264) EXTERNAL
Mar 24 07:20:49 bernhard pyspf-milter[451]: prepend Authentication-Results: bernhard.xss.co.at; spf=none (no SPF record) smtp.mailfrom=qmt-india.com (client-ip=91.184.249.155; helo=[91.184.249.155]; [email protected]; receiver=<UNKNOWN>)
Mar 24 07:20:49 bernhard sm-mta[22819]: 52O6Kmpe022819: from=<[email protected]>, size=2673, class=0, nrcpts=1, msgid=<[email protected]>, proto=ESMTP, daemon=MTA-v4, relay=s1159236.srvape.com [91.184.249.155] (may be forged)
Mar 24 07:20:49 bernhard sm-mta[22819]: 52O6Kmpe022819: Milter insert (0): header: Authentication-Results: bernhard.xss.co.at; spf=none (no SPF record) \n   smtp.mailfrom=qmt-india.com (client-ip=91.184.249.155; \n   helo=[91.184.249.155]; [email protected]; \n   receiver=<UNKNOWN>)
Mar 24 07:20:50 bernhard opendmarc[544]: 52O6Kmpe022819: qmt-india.com none
Mar 24 07:20:50 bernhard sm-mta[22819]: 52O6Kmpe022819: Milter insert (1): header: Authentication-Results: bernhard.xss.co.at; dmarc=none (p=none dis=none) header.from=qmt-india.com
Mar 24 07:20:56 bernhard sm-mta[22819]: 52O6Kmpe022819: Milter add: header: X-Spam-Flag: YES
Mar 24 07:20:56 bernhard sm-mta[22819]: 52O6Kmpe022819: Milter add: header: X-Spam-Status: Yes, score=12.3 required=5.0 tests=BAYES_50,HTML_MESSAGE,\n\tKAM_DMARC_STATUS,KAM_LAZY_DOMAIN_SECURITY,MAY_BE_FORGED,MIME_HTML_ONLY,\n\tRCVD_IN_SBL_CSS,SPF_HELO_NONE,SPF_NONE,T_KAM_HTML_FONT_INVALID,\n\tURIBL_ABUSE_SURBL,URIBL_BLACK,URIBL_DBL_PHISH shortcircuit=no\n\tautolearn=no autolearn_force=no version=3.4.6
Mar 24 07:20:56 bernhard sm-mta[22819]: 52O6Kmpe022819: Milter add: header: X-Spam-Level: ************
Mar 24 07:20:56 bernhard sm-mta[22819]: 52O6Kmpe022819: Milter add: header: X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on\n\tmaxwell.intern.xss.co.at
Mar 24 07:20:56 bernhard sm-mta[22819]: 52O6Kmpe022819: Milter change: header Subject: from  Important account Notification to *****SPAM(12.3)***** Important account Notification
Mar 24 07:20:56 bernhard sm-mta[22819]: 52O6Kmpe022819: Milter change: header Content-Type: from  text/html to multipart/mixed; boundary="----------=_67E0F9C8.E98AFB69"
Mar 24 07:20:56 bernhard sm-mta[22819]: 52O6Kmpe022819: Milter message: body replaced

But sometimes, the Received: header added by sendmail looks like this (example from today):

X-Envelope-From: <[email protected]>
X-Envelope-To: <[email protected]>
Received: from careers.traumwege.shop (careers.traumwege.shop [188.165.26.27])
	by bernhard.xss.co.at (8.15.2/8.15.2/Debian-14~deb10u3) with ESMTPS id 52O8RTLZ025442
	Fri, 13 Dec 2024 10:41:57 +0100
	(envelope-from <[email protected]>);
[...]

This mail was actually received today at 09:27:30, according to the mailserver logfile:

Mar 24 09:27:29 bernhard pyspf-milter[451]: connect from careers.traumwege.shop at ('188.165.26.27', 37939) EXTERNAL
Mar 24 09:27:30 bernhard sm-mta[25442]: STARTTLS=server, relay=careers.traumwege.shop [188.165.26.27], version=TLSv1.2, verify=NOT, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256
Mar 24 09:27:30 bernhard pyspf-milter[451]: prepend Authentication-Results: bernhard.xss.co.at; spf=pass (sender SPF authorized) smtp.mailfrom=careers.traumwege.shop (client-ip=188.165.26.27; helo=careers.traumwege.shop; [email protected]; receiver=<UNKNOWN>)
Mar 24 09:27:30 bernhard sm-mta[25442]: 52O8RTLZ025442: from=<[email protected]>, size=7971, class=0, nrcpts=1, msgid=<szpGnAQ.14378.702.buT-YW5kcmVhc0B4c3MuY28uYXQ=@3460.vt83Gog6vBA-careers.traumwege.shop>, proto=ESMTPS, daemon=MTA-v4, relay=careers.traumwege.shop [188.165.26.27]
Mar 24 09:27:30 bernhard opendkim[579]: 52O8RTLZ025442: s=mail d=careers.traumwege.shop SSL
Mar 24 09:27:30 bernhard sm-mta[25442]: 52O8RTLZ025442: Milter insert (1): header: Authentication-Results:  bernhard.xss.co.at;\n\tdkim=pass (1024-bit key; unprotected) header.d=careers.traumwege.shop [email protected] header.b="ZX/EgtIq";\n\tdkim-atps=neutral
Mar 24 09:27:30 bernhard sm-mta[25442]: 52O8RTLZ025442: Milter insert (0): header: Authentication-Results: bernhard.xss.co.at; spf=pass (sender SPF \n   authorized) smtp.mailfrom=careers.traumwege.shop \n   (client-ip=188.165.26.27; helo=careers.traumwege.shop; \n   [email protected]; \n   receiver=<UNKNOWN>)
Mar 24 09:27:31 bernhard opendmarc[544]: 52O8RTLZ025442: careers.traumwege.shop pass
Mar 24 09:27:31 bernhard sm-mta[25442]: 52O8RTLZ025442: Milter insert (1): header: Authentication-Results: bernhard.xss.co.at; dmarc=pass (p=reject dis=none) header.from=careers.traumwege.shop
Mar 24 09:27:37 bernhard sm-mta[25442]: 52O8RTLZ025442: Milter add: header: X-Spam-Flag: YES
Mar 24 09:27:37 bernhard sm-mta[25442]: 52O8RTLZ025442: Milter add: header: X-Spam-Status: Yes, score=14.9 required=5.0 tests=BAYES_50,DCC_REPUT_00_12,\n\tDKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,GB_S3_HTM,HTML_FONT_LOW_CONTRAST,\n\tHTML_MESSAGE,KAM_EU,KAM_SOMETLD_ARE_BAD_TLD,LOCAL_SUSPECT_FROM_TLD,\n\tSPF_HELO_PASS,SPF_PASS,T_DATE_IN_FUTURE_96_Q,T_REMOTE_IMAGE,\n\tT_TVD_FUZZY_SECTOR shortcircuit=no autolearn=no autolearn_force=no\n\tversion=3.4.6
Mar 24 09:27:37 bernhard sm-mta[25442]: 52O8RTLZ025442: Milter add: header: X-Spam-Level: **************
Mar 24 09:27:37 bernhard sm-mta[25442]: 52O8RTLZ025442: Milter add: header: X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on\n\tmaxwell.intern.xss.co.at
Mar 24 09:27:37 bernhard sm-mta[25442]: 52O8RTLZ025442: Milter change: header Subject: from  =?UTF-8?B?8J+alyBTaWNoZXJoZWl0IHp1ZXJzdCDigJMgbWl0IEdlc2NoZW5r?= to *****SPAM(14.9)***** =?UTF-8?B?8J+alyBTaWNoZXJoZWl0IHp1ZXJzdCDigJMgbWl0IEdlc2NoZW5r?=
Mar 24 09:27:37 bernhard sm-mta[25442]: 52O8RTLZ025442: Milter change: header Content-Type: from  multipart/alternative; boundary="_=_H2pYaEquwJUY9pCkkzUeXSAQhnIqp2oTMNwMo1SH2I_=_";charset=UTF-8 to multipart/mixed; boundary="----------=_67E11779.AA2E28C1"
Mar 24 09:27:37 bernhard sm-mta[25442]: 52O8RTLZ025442: Milter message: body replaced

But this time sendmail added the timestamp "Fri, 13 Dec 2024 10:41:57 +0100" to the
Received: header, which then triggered the T_DATE_IN_FUTURE_96_Q rule.

In this case the mail was obvious spam anyway, but there are cases the T_DATE_IN_FUTURE*
rule lifted the spam score a tiny bit above the 5.0 limit, resulting in a FalsePositive,
which of course is a bad thing...

Now: "Fri, 13 Dec 2024 10:41:57 +0100" is actually the exact timestamp the machine was last rebooted!

root@bernhard:~# last reboot
reboot   system boot  4.19.0-27-amd64  Fri Dec 13 10:41   still running

So it looks like sendmail(really?) sometimes(why?) doesn't add the current timestamp
(as one would expect), but the timestamp the process was started to the Received: header.
This really puzzles me. I haven't found an explanation for that behaviour, much less a
rule, under which circumstances it happens.

This server setup is in use for some time now, but I noticed this problem only recently.
Usually, security updates require servers to be rebooted from time to time. But this
particular server now is running since last December and SpamAssassin recently started
to trigger the T_DATE_IN_FUTURE_96_Q rule, resulting in more and more FalsePositives,
so I investigated and found this problem.

Of course I could restart sendmail, or even disable the T_DATE_IN_FUTURE_* rules,
but I'd rather find out what is going on here and fix the real problem.

I'm not sure if this has anything to do with SpamAssassin at all, so this might be
the wrong place to report. But if anyone on this list has any clue of what is going
on here I'd be happy if he or she could give me a hint.

Thanks!

- andreas

-- 
Andreas Haumer
*x Software + Systeme              | mailto:[email protected]
Karmarschgasse 51/2/20             | https://www.xss.co.at/
A-1100 Vienna, Austria             | Tel: +43-1-6060114
OpenPGP_signature.asc (application/pgp-signature, 203 B)