Unable to parse message

kransom

Member
Aug 22, 2023
29
1
8
Not sure if this is a coincidence but I updated PMG this past Tuesday and I have a user reporting they're not receiving mail.

pmgversion
pmg-api/9.0.4/f3ea3fa12b03 (running kernel: 6.17.4-2-pve)

Some logs
Code:
*** outgoing mail server logs ***
Feb  4 11:00:00 outgoingmailserver.edu postfix/smtpd[1393939]: connect from cdsmailserver.edu [x.x.x.x]
Feb  4 11:00:00 outgoingmailserver.edu dovecot: auth-worker(1393940): Warning: userdb passwd: Move templates args to override_fields setting
Feb  4 11:00:00 outgoingmailserver.edu postfix/smtpd[1393939]: 5737B91: client=cdsmailserver.edu[x.x.x.x], sasl_method=PLAIN, sasl_username=cds-alerts
Feb  4 11:00:00 outgoingmailserver.edu postfix/cleanup[1393941]: 5737B91: message-id=<>
Feb  4 11:00:00 outgoingmailserver.edu postfix/qmgr[899854]: 5737B91: from=<duser@email.edu>, size=286, nrcpt=1 (queue active)
Feb  4 11:00:00 outgoingmailserver.edu postfix/smtpd[1393939]: disconnect from cdsmailserver.edu[x.x.x.x] ehlo=2 starttls=1 auth=1 mail=1 rcpt=1 data=1 quit=1 commands=8
Feb  4 11:00:00 outgoingmailserver.edu postfix/smtp[1393942]: 5737B91: to=<duser@email.edu>, relay=pmg[x.x.x.x]:26, delay=0.19, delays=0.09/0.01/0.01/0.08, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 6A9CB2E0CA7)
Feb  4 11:00:00 outgoingmailserver.edu postfix/qmgr[899854]: 5737B91: removed
Feb  4 11:01:55 outgoingmailserver.edu postfix/anvil[1393800]: statistics: max connection rate 3/60s for (smtp:x.x.x.x) at Feb  4 10:55:08

*** pmg logs ***
2026-02-04T11:00:00.429031-08:00 pmg postfix/smtpd[22156]: connect from outgoingmailserver.edu[x.x.x.x]
2026-02-04T11:00:00.429641-08:00 pmg systemd[1]: Starting pmg-hourly.service - Hourly Proxmox Mail Gateway activities...
2026-02-04T11:00:00.436880-08:00 pmg postfix/smtpd[22156]: 6A9CB2E0CA7: client=outgoingmailserver.edu[x.x.x.x]
2026-02-04T11:00:00.437694-08:00 pmg postfix/cleanup[22158]: 6A9CB2E0CA7: message-id=<>
2026-02-04T11:00:00.511836-08:00 pmg postfix/smtpd[22156]: disconnect from outgoingmailserver.edu[x.x.x.x] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
2026-02-04T11:00:00.512379-08:00 pmg postfix/qmgr[896]: 6A9CB2E0CA7: from=<duser@email.edu>, size=507, nrcpt=1 (queue active)
2026-02-04T11:00:00.529911-08:00 pmg pmg-smtp-filter[22092]: 2026/02/04-11:00:00 CONNECT TCP Peer: "[127.0.0.1]:53658" Local: "[127.0.0.1]:10023"
2026-02-04T11:00:00.576432-08:00 pmg pmg-smtp-filter[22092]: 2E0CFB698397308B946: unable to parse message -    unexpected end of header
2026-02-04T11:00:00.576879-08:00 pmg pmg-smtp-filter[22092]: fast exit because of errors (free 275673088 bytes)
2026-02-04T11:00:00.577916-08:00 pmg pmg-smtp-filter[16893]: Starting "1" children
2026-02-04T11:00:00.631662-08:00 pmg postfix/lmtp[22159]: 6A9CB2E0CA7: to=<duser@email.edu>, relay=127.0.0.1[127.0.0.1]:10023, delay=0.15, delays=0.08/0.02/0.04/0.01, dsn=4.4.0, status=deferred (host 127.0.0.1[127.0.0.1] said: 451 4.4.0 detected undelivered mail to <duser@email.edu> (in reply to end of DATA command))
 
Similar as in that post?

 
Similar as in that post?


This was reported by my user today.

good news, my problem is solved. The emails from my python alarms program which continued to successfully go through the outgoing mail server yesterday had message strings which started with an letter, the ones which stopped working Tuesday morning had message strings which started with a number ("13:0" for 1pm for example). Yesterday at 16:14 I restarted the alarms code, changing the hourly keepalive email messages to start with a letter (e.g. "keepalive 20:0 P3”) and the hourly emails have successfully gone through bepex to PMG from that time onwards.

So my current theory is that the PMG upgrade Tuesday morning changed the message parser somehow to not permit messages send by python via the otugoing mail server which start with a number.

There is no need to investigate this further, the work around is perfectly fine.