Noticed that getaltnames() can log the SANs as they are parsed, so I
yanked up the log level and registered an outlook.com address to test
against:
2024-10-29T09:29:30.283537+00:00 dilbert sm-mta[1697002]: STARTTLS=client, init=1
2024-10-29T09:29:30.283681+00:00 dilbert sm-mta[1697002]: engine=(null), path=(null), ispre=0, pre=0, initialized=0
2024-10-29T09:29:30.356523+00:00 dilbert sm-mta[1697002]: tls_clt_features=sts=secure;servername=hostname, relay=outlook-com.olc.protection.outlook.com [52.101.40.30]
2024-10-29T09:29:30.356694+00:00 dilbert sm-mta[1697002]: tls_clt_features=parsed, sts=secure, relay=outlook-com.olc.protection.outlook.com [52.101.40.30]
2024-10-29T09:29:30.356941+00:00 dilbert sm-mta[1697002]: tls_clt_features=parsed, servername=hostname, relay=outlook-com.olc.protection.outlook.com [52.101.40.30]
2024-10-29T09:29:30.510779+00:00 dilbert sm-mta[1697002]: STARTTLS=client, start=ok
2024-10-29T09:29:30.511540+00:00 dilbert sm-mta[1697002]: STARTTLS=client, info: fds=9/4, err=2
2024-10-29T09:29:30.668666+00:00 dilbert sm-mta[1697002]: STARTTLS=client, info: fds=9/4, err=2
2024-10-29T09:29:30.836892+00:00 dilbert sm-mta[1697002]: STARTTLS: TLS cert verify: depth=0 /C=US/ST=Washington/L=Redmond/O=Microsoft Corporation/CN=mail.protection.outlook.com, state=1, reason=ok
2024-10-29T09:29:30.841735+00:00 dilbert sm-mta[1697002]: STARTTLS=client, get_verify: 0 get_peer: 0x55e6b9c7f290
2024-10-29T09:29:30.842307+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=mail.protection.outlook.com
2024-10-29T09:29:30.842615+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.mail.eo.outlook.com
2024-10-29T09:29:30.842825+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.mail.protection.outlook.com
2024-10-29T09:29:30.843017+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=mail.messaging.microsoft.com
2024-10-29T09:29:30.843226+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=outlook.com
2024-10-29T09:29:30.843430+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.olc.protection.outlook.com
2024-10-29T09:29:30.843659+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.pamx1.hotmail.com
2024-10-29T09:29:30.843864+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.mail.protection.outlook.de
2024-10-29T09:29:30.844063+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.mx.microsoft
2024-10-29T09:29:30.844125+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.k-v1.mx.microsoft
2024-10-29T09:29:30.844325+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.n-v1.mx.microsoft
2024-10-29T09:29:30.844424+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.q-v1.mx.microsoft
2024-10-29T09:29:30.844669+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.y-v1.mx.microsoft
2024-10-29T09:29:30.844778+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.d-v1.mx.microsoft
2024-10-29T09:29:30.844949+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.e-v1.mx.microsoft
2024-10-29T09:29:30.845107+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.a-v1.mx.microsoft
2024-10-29T09:29:30.845309+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.r-v1.mx.microsoft
2024-10-29T09:29:30.845370+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.w-v1.mx.microsoft
2024-10-29T09:29:30.845555+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.p-v1.mx.microsoft
2024-10-29T09:29:30.845606+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.x-v1.mx.microsoft
2024-10-29T09:29:30.845794+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.j-v1.mx.microsoft
2024-10-29T09:29:30.845849+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.s-v1.mx.microsoft
2024-10-29T09:29:30.846090+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.c-v1.mx.microsoft
2024-10-29T09:29:30.846178+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.b-v1.mx.microsoft
2024-10-29T09:29:30.846382+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.f-v1.mx.microsoft
2024-10-29T09:29:30.846576+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.i-v1.mx.microsoft
2024-10-29T09:29:30.846664+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.t-v1.mx.microsoft
2024-10-29T09:29:30.846758+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.m-v1.mx.microsoft
2024-10-29T09:29:30.846853+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.o-v1.mx.microsoft
2024-10-29T09:29:30.846913+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.g-v1.mx.microsoft
2024-10-29T09:29:30.846973+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.v-v1.mx.microsoft
2024-10-29T09:29:30.847045+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.h-v1.mx.microsoft
2024-10-29T09:29:30.847123+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.l-v1.mx.microsoft
2024-10-29T09:29:30.847223+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., AltName=*.u-v1.mx.microsoft
2024-10-29T09:29:30.847297+00:00 dilbert sm-mta[1697002]: STARTTLS=client, relay=outlook-com.olc.protection.outlook.com., version=TLSv1.3, verify=OK, cipher=TLS_AES_256_GCM_SHA384, bits=256/256
2024-10-29T09:29:30.847368+00:00 dilbert sm-mta[1697002]: STARTTLS=client, cert-subject=/C=US/ST=Washington/L=Redmond/O=Microsoft+20Corporation/CN=mail.protection.outlook.com, cert-issuer=/C=US/O=DigiCert+20Inc/CN=DigiCert+20Cloud+20Services+20CA-1, verifymsg=ok
2024-10-29T09:29:30.847428+00:00 dilbert sm-mta[1697002]: STARTTLS=read, info: fds=9/4, err=2
2024-10-29T09:29:30.996568+00:00 dilbert sm-mta[1697002]: STARTTLS=read, info: fds=9/4, err=2
2024-10-29T09:29:31.193337+00:00 dilbert sm-mta[1697002]: STARTTLS=read, info: fds=9/4, err=2
2024-10-29T09:29:31.350226+00:00 dilbert sm-mta[1697002]: 49T9TSAv1697000: --- 450 4.7.0 <***@outlook.com>... outlook-com.olc.protection.outlook.com not listed in SANs (hold)
2024-10-29T09:29:31.350353+00:00 dilbert sm-mta[1697002]: 49T9TSAv1697000: ruleset=tls_rcpt, arg1=***@outlook.com, relay=outlook-com.olc.protection.outlook.com., reject=450 4.7.0 <***@outlook.com>... outlook-com.olc.protection.outlook.com not listed in SANs
2024-10-29T09:29:31.350462+00:00 dilbert sm-mta[1697002]: 49T9TSAv1697000: --- 050 <***@outlook.com>... Deferred
2024-10-29T09:29:31.350545+00:00 dilbert sm-mta[1697002]: 49T9TSAv1697000: to=<***@outlook.com>, delay=00:00:02, xdelay=00:00:02, mailer=esmtp, pri=31187, relay=outlook-com.olc.protection.outlook.com. [52.101.40.30], dsn=4.2.0, stat=Deferred
2024-10-29T09:29:31.350631+00:00 dilbert sm-mta[1697002]: STARTTLS=read, info: fds=9/4, err=2
2024-10-29T09:29:31.508147+00:00 dilbert sm-mta[1697002]: NOQUEUE: --- 050 Closing connection to outlook-com.olc.protection.outlook.com.
2024-10-29T09:29:31.508386+00:00 dilbert sm-mta[1697002]: STARTTLS=read, info: fds=9/4, err=2
2024-10-29T09:29:31.662726+00:00 dilbert sm-mta[1697002]: STARTTLS=client, SSL_shutdown failed: -1
The SAN parsing looks fine to me, so I believe this points to a bug in
the m4 matching.
For reference, this is a similar test log against google:
2024-10-29T09:29:57.965992+00:00 dilbert sm-mta[1697008]: STARTTLS=client, init=1
2024-10-29T09:29:57.966067+00:00 dilbert sm-mta[1697008]: engine=(null), path=(null), ispre=0, pre=0, initialized=0
2024-10-29T09:29:57.970146+00:00 dilbert sm-mta[1697008]: tls_clt_features=sts=secure;servername=hostname, relay=gmail-smtp-in.l.google.com [IPv6:2a00:1450:4010:c05:0:0:0:1b]
2024-10-29T09:29:57.970286+00:00 dilbert sm-mta[1697008]: tls_clt_features=parsed, sts=secure, relay=gmail-smtp-in.l.google.com [IPv6:2a00:1450:4010:c05:0:0:0:1b]
2024-10-29T09:29:57.970406+00:00 dilbert sm-mta[1697008]: tls_clt_features=parsed, servername=hostname, relay=gmail-smtp-in.l.google.com [IPv6:2a00:1450:4010:c05:0:0:0:1b]
2024-10-29T09:29:57.974133+00:00 dilbert sm-mta[1697008]: STARTTLS=client, start=ok
2024-10-29T09:29:57.974858+00:00 dilbert sm-mta[1697008]: STARTTLS=client, info: fds=9/4, err=2
2024-10-29T09:29:57.981578+00:00 dilbert sm-mta[1697008]: STARTTLS: TLS cert verify: depth=0 /CN=mx.google.com, state=1, reason=ok
2024-10-29T09:29:57.982254+00:00 dilbert sm-mta[1697008]: STARTTLS=client, get_verify: 0 get_peer: 0x55e6b9c7d3d0
2024-10-29T09:29:57.982433+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=mx.google.com
2024-10-29T09:29:57.982779+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=smtp.google.com
2024-10-29T09:29:57.983537+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=aspmx.l.google.com
2024-10-29T09:29:57.983614+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt1.aspmx.l.google.com
2024-10-29T09:29:57.983671+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt2.aspmx.l.google.com
2024-10-29T09:29:57.984115+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt3.aspmx.l.google.com
2024-10-29T09:29:57.984576+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt4.aspmx.l.google.com
2024-10-29T09:29:57.984677+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=gmail-smtp-in.l.google.com
2024-10-29T09:29:57.984879+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt1.gmail-smtp-in.l.google.com
2024-10-29T09:29:57.984970+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt2.gmail-smtp-in.l.google.com
2024-10-29T09:29:57.985155+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt3.gmail-smtp-in.l.google.com
2024-10-29T09:29:57.985310+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt4.gmail-smtp-in.l.google.com
2024-10-29T09:29:57.985400+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=gmr-smtp-in.l.google.com
2024-10-29T09:29:57.985608+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt1.gmr-smtp-in.l.google.com
2024-10-29T09:29:57.985780+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt2.gmr-smtp-in.l.google.com
2024-10-29T09:29:57.985842+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt3.gmr-smtp-in.l.google.com
2024-10-29T09:29:57.985890+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=alt4.gmr-smtp-in.l.google.com
2024-10-29T09:29:57.986130+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=mx1.smtp.goog
2024-10-29T09:29:57.986191+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=mx2.smtp.goog
2024-10-29T09:29:57.986379+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=mx3.smtp.goog
2024-10-29T09:29:57.986450+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=mx4.smtp.goog
2024-10-29T09:29:57.986644+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=aspmx2.googlemail.com
2024-10-29T09:29:57.986705+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=aspmx3.googlemail.com
2024-10-29T09:29:57.986917+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=aspmx4.googlemail.com
2024-10-29T09:29:57.986982+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=aspmx5.googlemail.com
2024-10-29T09:29:57.987174+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., AltName=gmr-mx.google.com
2024-10-29T09:29:57.987232+00:00 dilbert sm-mta[1697008]: STARTTLS=client, relay=gmail-smtp-in.l.google.com., version=TLSv1.3, verify=OK, cipher=TLS_AES_256_GCM_SHA384, bits=256/256
2024-10-29T09:29:57.987423+00:00 dilbert sm-mta[1697008]: STARTTLS=client, cert-subject=/CN=mx.google.com, cert-issuer=/C=US/O=Google+20Trust+20Services/CN=WR2, verifymsg=ok
2024-10-29T09:29:57.987482+00:00 dilbert sm-mta[1697008]: STARTTLS=read, info: fds=9/4, err=2
2024-10-29T09:29:57.994383+00:00 dilbert sm-mta[1697008]: STARTTLS=read, info: fds=9/4, err=2
2024-10-29T09:29:58.000405+00:00 dilbert sm-mta[1697008]: STARTTLS=read, info: fds=9/4, err=2
2024-10-29T09:29:58.162462+00:00 dilbert sm-mta[1697008]: STARTTLS=read, info: fds=9/4, err=2
2024-10-29T09:29:58.163402+00:00 dilbert sm-mta[1697008]: STARTTLS=read, info: fds=9/4, err=2
2024-10-29T09:29:58.366636+00:00 dilbert sm-mta[1697008]: 49T9Tu0F1697006: --- 050 <***@gmail.com>... Sent (OK 1730194198 38308e7fff4ca-2fcb45e2a01si27180301fa.310 - gsmtp)
2024-10-29T09:29:58.366769+00:00 dilbert sm-mta[1697008]: 49T9Tu0F1697006: to=<***@gmail.com>, delay=00:00:01, xdelay=00:00:01, mailer=esmtp, pri=31200, relay=gmail-smtp-in.l.google.com. [IPv6:2a00:1450:4010:c05:0:0:0:1b], dsn=2.0.0, stat=Sent (OK 1730194198 38308e7fff4ca-2fcb45e2a01si27180301fa.310 - gsmtp)
2024-10-29T09:29:58.369046+00:00 dilbert sm-mta[1697008]: 49T9Tu0F1697006: done; delay=00:00:01, ntries=1
2024-10-29T09:29:58.369260+00:00 dilbert sm-mta[1697008]: NOQUEUE: --- 050 Closing connection to gmail-smtp-in.l.google.com.
2024-10-29T09:29:58.370012+00:00 dilbert sm-mta[1697008]: STARTTLS=read, info: fds=9/4, err=2
2024-10-29T09:29:58.373981+00:00 dilbert sm-mta[1697008]: STARTTLS=client, SSL_shutdown failed: -1
Bjørn