Control: clone -1 -2 Control: reassign -2 sendmail Control: severity -2 normal Control: retitle -2 sendmail: milter expansion of "$b" macro is unreliable Control: found -2 8.15.2-14~deb10u1
The underlying bug appears to be in sendmail. But I'm keeping the
spamass-milter bug open since the use of the "$b" macro there make this
a major problem.
The bug is that sendmail returns sendmail process start time instead of
current time when milters request the "$b" macro ("The current date in
RFC822 format"). This happens often, but not on every milter excution.
Sometimes the correct current time is returned. I do not know the exact
trigger...
The bug is easily reproduced using this simple noop python milter:
import Milter
import time
class DbgMilter(Milter.Base):
@Milter.noreply
def envrcpt(self, to, *str):
print("envrcpt() expanded 'b' to '", self.getsymval("b"), "' at ",
time.strftime("%Y-%m-%d %H:%M:%S"))
return Milter.CONTINUE
if __name__ == "__main__":
Milter.factory = DbgMilter
Milter.runmilter("dbgmilter", "/tmp/dbgmilter", 600)
configured as
INPUT_MAIL_FILTER(`dbg', `S=local:/tmp/dbgmilter, F=, T=S:4m;R:30m;E:40m')dnl
define(`confMILTER_MACROS_ENVRCPT', `{rcpt_mailer}, {rcpt_host}, {rcpt_addr},
{auth_type}, b, i, j, r, v, Z, _, {greylist}')dnl
Running this milter for a while I get:
bjorn@canardo:~/scripts/bjorn-scripts$ python3 pymilter-dbg.py
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
13:50:56
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:51:02 +0100 ' at 2020-01-20
13:51:02
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
13:52:17
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
13:52:23
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
13:52:28
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:52:51 +0100 ' at 2020-01-20
13:52:52
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:53:05 +0100 ' at 2020-01-20
13:53:06
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:53:25 +0100 ' at 2020-01-20
13:53:28
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:54:48 +0100 ' at 2020-01-20
13:54:48
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:55:36 +0100 ' at 2020-01-20
13:55:36
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:57:07 +0100 ' at 2020-01-20
13:57:07
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:57:12 +0100 ' at 2020-01-20
13:57:12
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 14:00:05 +0100 ' at 2020-01-20
14:00:05
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 14:00:50 +0100 ' at 2020-01-20
14:00:50
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
14:01:22
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 14:02:02 +0100 ' at 2020-01-20
14:02:02
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 14:03:14 +0100 ' at 2020-01-20
14:03:17
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 14:06:48 +0100 ' at 2020-01-20
14:06:49
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
14:07:00
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
14:07:11
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
14:07:22
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
14:07:30
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
14:07:41
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
14:07:43
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
14:07:54
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
14:07:55
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
14:08:03
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 14:13:24 +0100 ' at 2020-01-20
14:13:25
envrcpt() expanded 'b' to ' Mon, 20 Jan 2020 13:22:50 +0100 ' at 2020-01-20
14:13:36
As you can see, a significant number of requests get "13:22:50" instead
of the actual current. This is the time sendmail was started:
bjorn@canardo:~$ ls --full-time /proc/$(pidof "sendmail: MTA: accepting
connections")/cmdline
-r--r--r-- 1 root root 0 2020-01-20 13:22:50.429438748 +0100 /proc/25911/cmdline
-- Package-specific info:
Output of /usr/share/bug/sendmail/script:
ls -alR /etc/mail:
/etc/mail:
total 464
drwxr-sr-x 10 smmta smmsp 4096 Jan 20 13:22 .
drwxr-xr-x 212 root root 24576 Jan 20 06:53 ..
drwxr-xr-x 2 root smmsp 4096 Jan 13 18:59 CVS
-rwxr-xr-- 1 root smmsp 12980 Jan 20 13:22 Makefile
drwxr-sr-x 2 root smmsp 4096 Sep 6 2005 OLD
-rw-r--r-- 1 root root 4437 Jan 13 18:59 access
-rw-r----- 1 smmta smmsp 12288 Jan 13 18:59 access.db
-rw-r--r-- 1 root root 281 Sep 21 2004 address.resolve
-rw-r--r-- 1 root root 1758 Dec 6 11:45 aliases
-rw-r--r-- 1 smmta smmsp 12288 Dec 6 11:45 aliases.db
-rw-r--r-- 1 root smmsp 3735 Jan 20 13:22 databases
-rw-r----- 1 smmta smmsp 31 Apr 30 2001 default-auth-info
-r--r--r-- 1 daemon daemon 5659 Dec 8 2016 helpfile
-rw-r--r-- 1 root root 323 Dec 6 11:45 local-host-names
-rw-r--r-- 1 root root 1706 Sep 16 2003 local_virtusertable
drwxr-sr-x 2 smmta smmsp 4096 Sep 8 11:10 m4
-rw-r--r-- 1 root smmsp 185 Nov 24 2006 mailertable
-rw-r----- 1 root smmsp 12288 Sep 8 11:10 mailertable.db
-rw-r--r-- 1 smmta smmsp 5083 Aug 14 12:57 mailman.aliases
-rw-r--r-- 1 smmta smmsp 12288 Dec 6 11:45 mailman.aliases.db
drwxr-xr-x 2 root root 4096 Sep 8 11:10 peers
-rw-r--r-- 1 root root 72 Apr 7 2003 relay-domains
drwxr-xr-x 3 smmta smmsp 4096 Feb 11 2009 sasl
-rw-r--r-- 1 root smmsp 63926 Jan 20 13:22 sendmail.cf
-rw-r--r-- 1 root root 63629 Sep 8 11:10 sendmail.cf.old
-rw-r--r-- 1 root root 12219 Sep 8 11:10 sendmail.conf
-rw-r--r-- 1 root smmsp 2732 Jan 20 13:22 sendmail.mc
-rw-r--r-- 1 root root 148 Sep 16 2018 service.switch
-rw-r--r-- 1 root root 179 Sep 16 2018 service.switch-nodns
-rw-r--r-- 1 root smmsp 489 Sep 19 18:16 smarttable
-rw-r----- 1 smmta smmsp 12288 Sep 19 15:14 smarttable.db
drwxr-sr-x 2 smmta smmsp 4096 May 19 2008 smrsh
drwxr-sr-x 2 root smmsp 4096 May 3 2007 spamass.sock
lrwxrwxrwx 1 root root 15 Feb 13 2008 spamassassin -> ../spamassassin
-rw-r--r-- 1 root smmsp 102 Jul 13 2017 srssecret
-rw-r--r-- 1 root smmsp 42828 Sep 8 11:10 submit.cf
-rw-r--r-- 1 root root 42780 Sep 8 11:10 submit.cf.old
-rw-r--r-- 1 root smmsp 423 Sep 8 11:10 submit.mc
drwxr-xr-x 3 smmta smmsp 4096 Jul 4 2019 tls
-rw-r--r-- 1 root root 74 Aug 29 2014 trusted-users
-rw-r--r-- 1 root smmsp 262 Dec 6 11:45 virtusertable
-rw-r----- 1 root smmsp 12288 Dec 6 11:45 virtusertable.db
/etc/mail/CVS:
total 20
drwxr-xr-x 2 root smmsp 4096 Jan 13 18:59 .
drwxr-sr-x 10 smmta smmsp 4096 Jan 20 13:22 ..
-rw-r--r-- 1 root root 508 Jan 13 18:59 Entries
-rw-r--r-- 1 root smmsp 17 Apr 2 2003 Repository
-rw-r--r-- 1 root smmsp 19 Apr 2 2003 Root
/etc/mail/OLD:
total 12
drwxr-sr-x 2 root smmsp 4096 Sep 6 2005 .
drwxr-sr-x 10 smmta smmsp 4096 Jan 20 13:22 ..
-rw-r--r-- 1 root root 683 Mar 27 2001 sasl.mc
/etc/mail/m4:
total 24
drwxr-sr-x 2 smmta smmsp 4096 Sep 8 11:10 .
drwxr-sr-x 10 smmta smmsp 4096 Jan 20 13:22 ..
-rw-r--r-- 1 root root 790 Jan 30 2017 clamav-milter.m4
-rw-r----- 1 root smmsp 795 Sep 14 2007 dialup.m4
-rw-r--r-- 1 root root 107 Jul 3 2016 opendkim.m4
-rw-r----- 1 root smmsp 0 Oct 23 2002 provider.m4
-rw-r--r-- 1 root smmsp 2463 Jul 25 2004 smarttable.m4
/etc/mail/peers:
total 12
drwxr-xr-x 2 root root 4096 Sep 8 11:10 .
drwxr-sr-x 10 smmta smmsp 4096 Jan 20 13:22 ..
-rw-r--r-- 1 root root 328 Jul 18 2001 provider
/etc/mail/sasl:
total 24
drwxr-xr-x 3 smmta smmsp 4096 Feb 11 2009 .
drwxr-sr-x 10 smmta smmsp 4096 Jan 20 13:22 ..
drwxr-xr-x 2 root root 4096 Feb 11 2009 CVS
-rw-r----- 1 smmta smmsp 701 Feb 11 2009 Sendmail.conf.2
-rw-r----- 1 smmta smmsp 610 Mar 4 2003 Sendmail.conf.2.OLD
-rwxr--r-- 1 root root 3653 Sep 8 11:10 sasl.m4
/etc/mail/sasl/CVS:
total 20
drwxr-xr-x 2 root root 4096 Feb 11 2009 .
drwxr-xr-x 3 smmta smmsp 4096 Feb 11 2009 ..
-rw-r--r-- 1 root root 50 Feb 11 2009 Entries
-rw-r--r-- 1 root root 22 Feb 11 2009 Repository
-rw-r--r-- 1 root root 19 Feb 11 2009 Root
/etc/mail/smrsh:
total 8
drwxr-sr-x 2 smmta smmsp 4096 May 19 2008 .
drwxr-sr-x 10 smmta smmsp 4096 Jan 20 13:22 ..
lrwxrwxrwx 1 root root 26 Feb 13 2008 mail.local ->
/usr/lib/sm.bin/mail.local
lrwxrwxrwx 1 root root 17 Feb 13 2008 procmail -> /usr/bin/procmail
lrwxrwxrwx 1 root smmsp 17 May 19 2008 vacation -> /usr/bin/vacation
/etc/mail/spamass.sock:
total 8
drwxr-sr-x 2 root smmsp 4096 May 3 2007 .
drwxr-sr-x 10 smmta smmsp 4096 Jan 20 13:22 ..
/etc/mail/tls:
total 24
drwxr-xr-x 3 smmta smmsp 4096 Jul 4 2019 .
drwxr-sr-x 10 smmta smmsp 4096 Jan 20 13:22 ..
drwxr-xr-x 2 root root 4096 Sep 9 16:37 CVS
-rw-r--r-- 1 root root 7 Mar 4 2003 no_prompt
lrwxrwxrwx 1 root root 38 Jun 12 2017 sendmail-client.crt ->
/etc/ssl/acme/live/canardo.mork.no.crt
lrwxrwxrwx 1 root root 32 Jun 17 2015 sendmail-common.key ->
/etc/ssl/private/canardo-key.pem
lrwxrwxrwx 1 root root 24 Jun 17 2015 sendmail-common.prm ->
/etc/ssl/CA/dhparams.pem
lrwxrwxrwx 1 root root 42 Oct 20 2017 sendmail-intermediate-ca.crt ->
/etc/ssl/acme/certs/canardo.mork.no/ca.cer
lrwxrwxrwx 1 root root 38 Jun 12 2017 sendmail-server.crt ->
/etc/ssl/acme/live/canardo.mork.no.crt
-rwxr-xr-x 1 root root 3256 Sep 9 16:37 starttls.m4
-rw-r--r-- 1 smmta smmsp 2109 Mar 3 2003 starttls.m4.OLD
/etc/mail/tls/CVS:
total 20
drwxr-xr-x 2 root root 4096 Sep 9 16:37 .
drwxr-xr-x 3 smmta smmsp 4096 Jul 4 2019 ..
-rw-r--r-- 1 root root 46 Sep 9 16:37 Entries
-rw-r--r-- 1 root root 21 Jul 4 2019 Repository
-rw-r--r-- 1 root root 19 Jul 4 2019 Root
sendmail.conf:
DAEMON_NETMODE="Static";
DAEMON_NETIF="eth0";
DAEMON_MODE="Daemon";
DAEMON_PARMS="";
DAEMON_HOSTSTATS="Yes";
DAEMON_MAILSTATS="Yes";
QUEUE_MODE="${DAEMON_MODE}";
QUEUE_INTERVAL="5m";
QUEUE_PARMS="";
MSP_MODE="Cron";
MSP_INTERVAL="5m";
MSP_PARMS="";
MSP_MAILSTATS="Yes";
MISC_PARMS="";
CRON_MAILTO="root";
CRON_PARMS="";
LOG_CMDS="No";
HANDS_OFF="No";
AGE_DATA="";
DAEMON_RUNASUSER="No";
DAEMON_STATS="${DAEMON_MAILSTATS}";
MSP_STATS="${MSP_MAILSTATS}";
sendmail.mc:
define(`_USE_ETC_MAIL_')dnl
include(`/usr/share/sendmail/cf/m4/cf.m4')dnl
include(`/etc/mail/tls/starttls.m4')dnl
include(`/etc/mail/sasl/sasl.m4')dnl
VERSIONID(`$Id: sendmail.mc,v 1.58 2019/12/17 09:57:17 bjorn Exp $')
OSTYPE(`debian')dnl
DOMAIN(`debian-mta')dnl
define(`confSMTP_LOGIN_MSG', `$j Sendmail $v/$Z; $b')dnl
undefine(`confCF_VERSION')dnl
undefine(`confTLS_SRV_OPTIONS')dnl # enabling client cert vrfy to allow TLS
based relaying
FEATURE(`nouucp', `nospecial')dnl
FEATURE(`always_add_domain')dnl
FEATURE(`relay_entire_domain')dnl
FEATURE(`use_cw_file')dnl
FEATURE(`use_ct_file')dnl
FEATURE(`virtusertable')dnl
FEATURE(`access_db')dnl
FEATURE(`local_procmail')dnl
FEATURE(`delay_checks')dnl
FEATURE(`mailertable')dnl
include(`/etc/mail/m4/smarttable.m4')dnl
INPUT_MAIL_FILTER(`opendkim', `S=local:/run/opendkim/opendkim.sock')dnl
INPUT_MAIL_FILTER(`spamassassin', `S=local:/run/spamass/spamass.sock, F=,
T=S:4m;R:30m;E:40m')dnl
INPUT_MAIL_FILTER(`dbg', `S=local:/tmp/dbgmilter, F=, T=S:4m;R:30m;E:40m')dnl
include(`/etc/mail/m4/clamav-milter.m4')dnl
define(`confMILTER_MACROS_CONNECT',`t, b, j, _, {daemon_name}, {if_name},
{if_addr}, {daemon_port}')dnl
define(`confMILTER_MACROS_HELO',`s, {tls_version}, {cipher}, {cipher_bits},
{cert_subject}, {cert_issuer}, {verify}')dnl
define(`confMILTER_MACROS_ENVRCPT', `{rcpt_mailer}, {rcpt_host}, {rcpt_addr},
{auth_type}, b, i, j, r, v, Z, _, {greylist}')dnl
define(`confMIN_QUEUE_AGE', `10m')dnl
define(`confLOG_LEVEL', `10')dnl # - attempting to get useful AUTH logging
(default is 9)
define(`confMILTER_LOG_LEVEL',`9')dnl # ...without creating unnecessary milter
noise
define(`RELAY_MAILER_ARGS',`TCP $h 1025')dnl
define(`LOCAL_MAILER_FLAGS',`SPfhn8')dnl
define(`ALIAS_FILE',
`MAIL_SETTINGS_DIR`'aliases,`'MAIL_SETTINGS_DIR`'mailman.aliases')dnl
define(`confCACERT', `/etc/mail/tls/sendmail-server.crt')dnl
FEATURE(`no_default_msa')dnl # need this to avoid port collision with the
redefined IPv6 MSP-v6 below
DAEMON_OPTIONS(`Family=inet6, Name=MTA, Port=smtp')dnl
DAEMON_OPTIONS(`Family=inet6, Name=MSA, Port=submission, M=Ea')dnl
CLIENT_OPTIONS(`Family=inet, Address=148.122.252.1')dnl
CLIENT_OPTIONS(`Family=inet6, Address=2001:4641::1')dnl
MAILER(local)dnl
MAILER(smtp)dnl
submit.mc...
define(`_USE_ETC_MAIL_')dnl
include(`/usr/share/sendmail/cf/m4/cf.m4')dnl
VERSIONID(`$Id: submit.mc,v 1.16 2017/10/20 09:57:06 bjorn Exp $')
OSTYPE(`debian')dnl
DOMAIN(`debian-msp')dnl
FEATURE(`use_ct_file')dnl
FEATURE(`msp', `[IPv6:::1]', `25')dnl
include(`/etc/mail/tls/starttls.m4')dnl
define(`confCACERT', `/etc/mail/tls/sendmail-server.crt')dnl
-- System Information:
Debian Release: 10.2
APT prefers stable
APT policy: (990, 'stable'), (500, 'stable-updates')
Architecture: amd64 (x86_64)
Kernel: Linux 4.19.0-6-amd64 (SMP w/8 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8),
LANGUAGE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
Versions of packages sendmail depends on:
ii sendmail-base 8.15.2-14~deb10u1
ii sendmail-bin 8.15.2-14~deb10u1
ii sendmail-cf 8.15.2-14~deb10u1
ii sensible-mda 8.15.2-14~deb10u1
sendmail recommends no packages.
Versions of packages sendmail suggests:
ii rmail 8.15.2-14~deb10u1
pn sendmail-doc <none>
Versions of packages sensible-mda depends on:
ii libc6 2.28-10
ii procmail 3.22-26
ii sendmail-bin [mail-transport-agent] 8.15.2-14~deb10u1
Versions of packages rmail depends on:
ii libc6 2.28-10
ii libldap-2.4-2 2.4.47+dfsg-3+deb10u1
ii sendmail-bin [mail-transport-agent] 8.15.2-14~deb10u1
Versions of packages libmilter1.0.1 depends on:
ii libc6 2.28-10
Versions of packages sendmail-bin depends on:
ii debconf 1.5.71
ii libc6 2.28-10
ii libdb5.3 5.3.28+dfsg1-0.5
ii libldap-2.4-2 2.4.47+dfsg-3+deb10u1
ii liblockfile1 1.14-1.1
ii libsasl2-2 2.1.27+dfsg-1+deb10u1
ii libssl1.1 1.1.1d-0+deb10u2
ii libwrap0 7.6.q-28
ii lsb-base 10.2019051400
ii procps 2:3.3.15-2
ii sendmail-base 8.15.2-14~deb10u1
ii sendmail-cf 8.15.2-14~deb10u1
Versions of packages sendmail-bin suggests:
ii libsasl2-modules 2.1.27+dfsg-1+deb10u1
ii openssl 1.1.1d-0+deb10u2
ii sasl2-bin 2.1.27+dfsg-1+deb10u1
pn sendmail-doc <none>
-- no debconf information
signature.asc
Description: PGP signature
