Below is a link to an extract from my Postfix server's mail log, showing one successful SMTP transaction. Is it possible to configure Postfix to add a unique ID tag to all log entries involving the same transaction, from start to finish? Similar to how Rspamd does it.

Alternatively, I'd like to come up with a way to parse the entries and add specific details about a mail transaction to a MySQL database. Can anyone point me in the right direction?

Log Extract

Nov  1 03:43:54 alpha postfix/smtpd[18981]: connect from mail-am6eur05olkn2036.outbound.protection.outlook.com[40.92.91.36]
Nov  1 03:43:55 alpha postfix/smtpd[18981]: Untrusted TLS connection established from mail-am6eur05olkn2036.outbound.protection.outlook.com[40.92.91.36]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Nov  1 03:43:55 alpha policyd-spf[22060]: prepend Received-SPF: Pass (mailfrom) identity=mailfrom; client-ip=40.92.91.36; helo=eur05-am6-obe.outbound.protection.outlook.com; envelope-from=****@hotmail.com; receiver=<UNKNOWN>
Nov  1 03:43:55 alpha postgrey[2891]: action=pass, reason=client whitelist, client_name=mail-am6eur05olkn2036.outbound.protection.outlook.com, client_address=40.92.91.36, sender=****@hotmail.com, recipient=****@****.**
Nov  1 03:43:55 alpha postfix/smtpd[18981]: 8F5623040B2E: client=mail-am6eur05olkn2036.outbound.protection.outlook.com[40.92.91.36]
Nov  1 03:43:55 alpha postfix/cleanup[22062]: 8F5623040B2E: message-id=<DBBPR08MB62652E5C80C2C00403606971D8130@DBBPR08MB6265.eurprd08.prod.outlook.com>
Nov  1 03:43:55 alpha opendkim[2874]: 8F5623040B2E: s=selector1 d=hotmail.com SSL
Nov  1 03:43:56 alpha postfix/qmgr[8571]: 8F5623040B2E: from=<****@hotmail.com>, size=6118, nrcpt=1 (queue active)
Nov  1 03:43:56 alpha postfix/smtpd[18981]: disconnect from mail-am6eur05olkn2036.outbound.protection.outlook.com[40.92.91.36] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
Nov  1 03:43:57 alpha postfix/smtpd[22072]: connect from localhost[127.0.0.1]
Nov  1 03:43:57 alpha postfix/smtpd[22072]: 26A0C3040B83: client=localhost[127.0.0.1]
Nov  1 03:43:57 alpha postfix/cleanup[22062]: 26A0C3040B83: message-id=<DBBPR08MB62652E5C80C2C00403606971D8130@DBBPR08MB6265.eurprd08.prod.outlook.com>
Nov  1 03:43:57 alpha postfix/smtpd[22072]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Nov  1 03:43:57 alpha postfix/qmgr[8571]: 26A0C3040B83: from=<****@hotmail.com>, size=7044, nrcpt=1 (queue active)
Nov  1 03:43:57 alpha amavis[8143]: (08143-17) Passed CLEAN {RelayedInbound}, [40.92.91.36]:24161 [40.92.91.36] <****@hotmail.com> -> <****@****.**>, Queue-ID: 8F5623040B2E, Message-ID: <DBBPR08MB62652E5C80C2C00403606971D8130@dbbpr08mb6265.eurprd08.prod.outlook.com>, mail_id: oshjPfmSfjIQ, Hits: 1.711, size: 6238, queued_as: 26A0C3040B83, dkim_sd=selector1:hotmail.com, 1124 ms
Nov  1 03:43:57 alpha postfix/smtp[22067]: 8F5623040B2E: to=<****@****.**>, relay=127.0.0.1[127.0.0.1]:10024, delay=2.1, delays=0.99/0.02/0/1.1, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 26A0C3040B83)
Nov  1 03:43:57 alpha postfix/qmgr[8571]: 8F5623040B2E: removed
Nov  1 03:43:57 alpha postfix/pickup[18099]: 439EE3040B85: uid=2000 from=<****@hotmail.com>
Nov  1 03:43:57 alpha postfix/cleanup[22062]: 439EE3040B85: message-id=<DBBPR08MB62652E5C80C2C00403606971D8130@DBBPR08MB6265.eurprd08.prod.outlook.com>
Nov  1 03:43:57 alpha postfix/qmgr[8571]: 439EE3040B85: from=<****@hotmail.com>, size=7294, nrcpt=1 (queue active)
Nov  1 03:43:57 alpha postfix/srs/smtpd[22082]: connect from localhost[127.0.0.1]
Nov  1 03:43:57 alpha postfix/pipe[22075]: 26A0C3040B83: to=<****@****.**>, relay=dovecot, delay=0.23, delays=0.04/0.01/0/0.19, dsn=2.0.0, status=sent (delivered via dovecot service)
Nov  1 03:43:57 alpha postfix/qmgr[8571]: 26A0C3040B83: removed
Nov  1 03:43:57 alpha postfix/srs/smtpd[22082]: 5F56B3040B2E: client=localhost[127.0.0.1]
Nov  1 03:43:57 alpha postsrsd[22091]: srs_forward: <****@hotmail.com> rewritten as <SRS0=w4eH=EH=hotmail.com=****@alpha.****.***>
Nov  1 03:43:57 alpha postfix/srs/cleanup[22087]: 5F56B3040B2E: message-id=<DBBPR08MB62652E5C80C2C00403606971D8130@DBBPR08MB6265.eurprd08.prod.outlook.com>
Nov  1 03:43:57 alpha postfix/srs/smtpd[22082]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Nov  1 03:43:57 alpha postfix/smtp[22079]: 439EE3040B85: to=<****@****.***>, relay=127.0.0.1[127.0.0.1]:10027, delay=0.2, delays=0.08/0.03/0.02/0.07, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5F56B3040B2E)
Nov  1 03:43:57 alpha postfix/qmgr[8571]: 5F56B3040B2E: from=<SRS0=w4eH=EH=hotmail.com=****@alpha.****.***>, size=7484, nrcpt=1 (queue active)
Nov  1 03:43:57 alpha postfix/qmgr[8571]: 439EE3040B85: removed
Nov  1 03:43:57 alpha postfix/smtp[22079]: Untrusted TLS connection established to aspmx.l.google.com[108.177.15.27]:25: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)
Nov  1 03:43:58 alpha postfix/smtp[22079]: 5F56B3040B2E: to=<****@****.***>, relay=ASPMX.L.GOOGLE.COM[108.177.15.27]:25, delay=0.81, delays=0.07/0/0.31/0.43, dsn=2.0.0, status=sent (250 2.0.0 OK  1604202238 c2si11327805wrm.385 - gsmtp)
Nov  1 03:43:58 alpha postfix/qmgr[8571]: 5F56B3040B2E: removed

Solution 1:

The log entries already have what you are looking for. The 12 hex digits are a message ID that is the same for every Postfix log entry relating to a given message.

Note that since you are passing messages through milters, the same message gets a different ID when it returns back to Postfix for further processing.

The process ID of the various Postfix components that handled a message is also shown. This can help you associate log entries without a message ID to the relevant messages.