Re: Unexpected record type 'X'

[John Alex.]

In my case, a single alias was used that expands to 5000 or more addresses in a 
virtual_alias_maps table (after increasing virtual_alias_expansion_limit).


The error is reproduced both when sending an email to this alias address and when just 
checking with 'sendmail -bv'.


John

On 10/6/22 16:37, Wietse Venema wrote:

How was your Postfix queue file with 5000 recipients created?
- with Postfix virtual_alias_maps expansion,
- with Postfix alias_maps expansion (/etc/aliases),
- by submitting a message with 5000 recipients over SMTP?
- ??

Re: Unexpected record type 'X'

[Wietse Venema]

Wietse Venema:
> > So it seems this issue occurs whenever the mail queue total recipient count 
> > reaches 5000 
> > addresses.
> 
> Thanks, that is very useful. This appears to be a corner-case error,
> and that would explain why the problem was difficult to reproduce.

This reproduces 100% with the Postfix smtp-source test program and
a test system with empty Postfix queue.

Sending a test message over SMTP with 5000 or more recipients will
trigger the problem. It should also reproduce with virtual_alias_maps
expansion and with alias_maps expansion, because they all result
in similar queue file contents.

I'm going back to $WORK now, and will do further experiments later.

Wietse

Re: Unexpected record type 'X'

[Wietse Venema]

John Alex.:
> Hi, I encountered the same issue on two FreeBSD 13.1 + Postfix 3.7.2 
> installations. It 
> only occurs when trying to send an email with >4999 recipients (the mail 
> queue is 
> otherwise empty). This issue does not happen on another machine with FreeBSD 
> 13.0 + 
> Postfix 3.6.3.
> 
> After some search I found that it is caused by the following addition in 
> qmgr_message.c in 
> 3.7 (line 441):
> 
> if (strchr(expected_rec_types, rec_type) == 0) {
>  msg_warn("Unexpected record type '%c' at offset %ld",
>   rec_type, (long) curr_offset);
>  rec_type = REC_TYPE_ERROR;
>  break;
> }
> 
> in combination with the pre-existing (line 385):
> 
> /* Keep interrupt latency in check. */
> if (recipient_limit > 5000)
>  recipient_limit = 5000;
> 
> 
> If I remove the code that was introduced in 3.7, the mail is delivered 
> without issue. I 
> also tried changing 5000 to 10001 and the email was again succesfully 
> delivered to up to 
> 1 recipients.
> 
> So it seems this issue occurs whenever the mail queue total recipient count 
> reaches 5000 
> addresses.

Thanks, that is very useful. This appeats to be a corner-case error,
and that woiuld explain why the problem was difficult to reproduce.

How was your Postfix queue file with 5000 recipients created? 
- with Postfix virtual_alias_maps expansion,
- with Postfix alias_maps expansion (/etc/aliases),
- by submitting a message with 5000 recipients over SMTP?
- ??

I prefer not to remove the new sanity check, but instead fix the
corner-case error.

Wietse

Re: Unexpected record type 'X'

[John Alex.]

Hi, I encountered the same issue on two FreeBSD 13.1 + Postfix 3.7.2 installations. It 
only occurs when trying to send an email with >4999 recipients (the mail queue is 
otherwise empty). This issue does not happen on another machine with FreeBSD 13.0 + 
Postfix 3.6.3.


After some search I found that it is caused by the following addition in qmgr_message.c in 
3.7 (line 441):


if (strchr(expected_rec_types, rec_type) == 0) {
msg_warn("Unexpected record type '%c' at offset %ld",
 rec_type, (long) curr_offset);
rec_type = REC_TYPE_ERROR;
break;
}

in combination with the pre-existing (line 385):

/* Keep interrupt latency in check. */
if (recipient_limit > 5000)
recipient_limit = 5000;


If I remove the code that was introduced in 3.7, the mail is delivered without issue. I 
also tried changing 5000 to 10001 and the email was again succesfully delivered to up to 
1 recipients.


So it seems this issue occurs whenever the mail queue total recipient count reaches 5000 
addresses.


John

On 8/30/22 10:20, Frank Brendel wrote:

Hi,

sporadically I get the error
   Unexpected record type 'X' at offset ...
and the message is moved to the corrupt queue.

E.g.
postfix/smtpd[19574] 010EDD6443: client=unknown[1.2.3.4]
postfix/cleanup[98995] 010EDD6443: message-id=<>
postfix/qmgr[63719] 010EDD6443: from=,
size=14197, nrcpt=24 (queue active)
postfix/qmgr[63719] warning: Unexpected record type 'X' at offset 17542
postfix/qmgr[63719] warning: saving corrupt file "010EDD6443" from
queue "active" to queue "corrupt"

The message looks OK to me. It is multipart/mixed with multiple
recipients. The offset is always at the end of the message.

postcat -do 010EDD6443
...
17481  78 boundary_641_fc5671dc-1c1d-438e-a827-019b96ffe19b--
17538  78
17540  78
17542  88 *** HEADER EXTRACTED 010EDD6443 ***
17544  69 *** MESSAGE FILE END 010EDD6443 ***

Postfix version is 3.7.0 and runs on FreeBSD 12.3.

I have no idea what HEADER EXTRACTED means an why it appears or why it
shouldn't.
Messages were sent with different email clients.

So what could be wrong with the message?


Thanks
Frank


  Frank Brendel
Administrator Rechenzentrum

Telefon:  +49 811 9595-157
Telefax:  +49 811 9595-199
Internet: https://www.eurolog.com

EURO-LOG AG
Am Söldnermoos 17, D-85399 Hallbergmoos
Vorstand: Jörg Fürbacher
Aufsichtsratsvorsitzender: Markus Quicken
Registergericht: AG München HRB 140857
Steuer-Nr.: 115/118/10169
Ust-ID-Nr.: DE 811547361

Diese E-Mail könnte vertrauliche und/oder rechtlich geschützte Informationen 
enthalten. Wenn Sie nicht der richtige Adressat sind oder diese E-Mail 
irrtümlich erhalten haben, informieren Sie bitte sofort den Absender und 
vernichten Sie diese Mail. Das unerlaubte Kopieren sowie die unbefugte 
Weitergabe dieser Mail sind nicht gestattet. This e-mail may contain 
confidential and/or privileged information. If you are not the intended 
recipient (or have received this e-mail in error) please notify the sender 
immediately and destroy this e-mail. Any unauthorized copying, disclosure or 
distribution of the material in this e-mail is strictly forbidden.

Re: Unexpected record type 'X'

[J Doe]

On 2022-09-06 23:18, Viktor Dukhovni wrote:


On Tue, Sep 06, 2022 at 09:43:38PM -0400, J Doe wrote:


Out of curiosity ... why do queue files require the execute bit ?


That's how they're marked "complete".  A partially written queue file is
just read-write.  When a queue is committed it is marked executable and
synced to disk, at that point the SMTP server can tell the remote client
that the file is safely persisted in the queue.


Hi Viktor,

Ah, neat!  Thanks for satisfying my curiosity.

- J

Re: Unexpected record type 'X'

[Viktor Dukhovni]

On Tue, Sep 06, 2022 at 09:43:38PM -0400, J Doe wrote:

> Out of curiosity ... why do queue files require the execute bit ?

That's how they're marked "complete".  A partially written queue file is
just read-write.  When a queue is committed it is marked executable and
synced to disk, at that point the SMTP server can tell the remote client
that the file is safely persisted in the queue.

-- 
Viktor.

Re: Unexpected record type 'X'

[J Doe]

On 2022-08-30 10:35, Viktor Dukhovni wrote:

On Tue, Aug 30, 2022 at 02:25:20PM +, Frank Brendel wrote:


So I can try to reproduce it by simply putting that file into the
incoming queue?


Within the same filesystem, yes.


Our test system has FreeBSD 13.1 and Postfix 3.7.2 installed.  I'd try
to resend a mail via that system.


If you're copying queue files between systems, make sure to stop Postfix
on the target system, and run "postsuper -s" as root after copying the
queue file.  Queue file permissions need to be 0700 to make the message
deliverable, the owner needs to be the "$mail_owner" user (typically
"postfix").



Hi,

Out of curiosity ... why do queue files require the execute bit ?

Thanks,

- J

Re: Unexpected record type 'X'

[Frank Brendel]

You're so right. But sending files via SFTP would be too easy 

I think with recipient verification and queue/log monitoring I have a
lot stuff for improving the system.

Wietse, Viktor many thanks!

Frank


 Frank Brendel
Administrator Rechenzentrum

Telefon:  +49 811 9595-157
Telefax:  +49 811 9595-199
Internet: https://www.eurolog.com

EURO-LOG AG
Am Söldnermoos 17, D-85399 Hallbergmoos
Vorstand: Jörg Fürbacher
Aufsichtsratsvorsitzender: Markus Quicken
Registergericht: AG München HRB 140857
Steuer-Nr.: 115/118/10169
Ust-ID-Nr.: DE 811547361

Diese E-Mail könnte vertrauliche und/oder rechtlich geschützte Informationen 
enthalten. Wenn Sie nicht der richtige Adressat sind oder diese E-Mail 
irrtümlich erhalten haben, informieren Sie bitte sofort den Absender und 
vernichten Sie diese Mail. Das unerlaubte Kopieren sowie die unbefugte 
Weitergabe dieser Mail sind nicht gestattet. This e-mail may contain 
confidential and/or privileged information. If you are not the intended 
recipient (or have received this e-mail in error) please notify the sender 
immediately and destroy this e-mail. Any unauthorized copying, disclosure or 
distribution of the material in this e-mail is strictly forbidden.

Re: Unexpected record type 'X'

[Viktor Dukhovni]

On Wed, Aug 31, 2022 at 02:32:33PM +, Frank Brendel wrote:

> Monitoring the logs is on the list.
> 
> If I understand the Postfix architecture right all I have to do in case
> of failed recipients is to write something like
>   b...@recipient.com REJECT Mailbox full
> into a $smtpd_recipient_restriction table and wait for $max_use or
> $max_idle?

If the messages to the full mailbox are tempfailing at "RCPT TO:" rather
than ".", then Wietse's suggestion of recipient verification probes is
better (with a positive cache lifetime that's not too long).

> Regarding the tons of messages: it's a process which send these
> messages to a customer. Don't ask me why via SMTP of all things.
> The process doesn't see any problems on the receiver site because
> Postfix response is always OK. But if Postfix can block the process now
> because of broken recipients ... 

Well, Postfix would tempfail the delivery, so if the remote source has a
queue, the flood will ultimately resume.

You really need to have a chat about reasonable mail volume expectations
with customer in question.  Nobody reads 250,000 email messages in a
few days, and a machine-to-machine data stream is better handled by
other means.

At Morgan Stanley, we wrote a flood detector that quarantined high
volume repetitious mail from same sender to same recipients with similar
subjects.  After enough flood garbage, further messages landed in the
"hold" queue, and periodically a notice went to the ops team to look
into either deleting the junk or release it in rare cases.

The culprits were invariably naïve developers who thought that a new
email message for each unexpected error in their software was a good
monitoring design.

-- 
Viktor.

Re: Unexpected record type 'X'

[Wietse Venema]

Frank Brendel:
> > You really should do something about that, build a table of over-
> > quota
> > recipients, and tempfail new mail for such users when briefly over
> > quota, and ultimately reject if long-term over-quota.
> >
> but is that possible with remote mailboxes?

The Postfix reject_unverified_recipient feature can block mail for
unavailable remote and local mailboxes. This feature is typically
used to avoid forwarding mail for a non-existing address, but it
will work with all error conditions that a Postfix delivery agent
can detect without actually delivering mail.

Wietse

Re: Unexpected record type 'X'

[Frank Brendel]

Hi Viktor,

thank you for the hint.

Monitoring the logs is on the list.

If I understand the Postfix architecture right all I have to do in case
of failed recipients is to write something like
  b...@recipient.com REJECT Mailbox full
into a $smtpd_recipient_restriction table and wait for $max_use or
$max_idle?

Regarding the tons of messages: it's a process which send these
messages to a customer. Don't ask me why via SMTP of all things.
The process doesn't see any problems on the receiver site because
Postfix response is always OK. But if Postfix can block the process now
because of broken recipients ... 


Thank you
Frank




 Frank Brendel
Administrator Rechenzentrum

Telefon:  +49 811 9595-157
Telefax:  +49 811 9595-199
Internet: https://www.eurolog.com

EURO-LOG AG
Am Söldnermoos 17, D-85399 Hallbergmoos
Vorstand: Jörg Fürbacher
Aufsichtsratsvorsitzender: Markus Quicken
Registergericht: AG München HRB 140857
Steuer-Nr.: 115/118/10169
Ust-ID-Nr.: DE 811547361

Diese E-Mail könnte vertrauliche und/oder rechtlich geschützte Informationen 
enthalten. Wenn Sie nicht der richtige Adressat sind oder diese E-Mail 
irrtümlich erhalten haben, informieren Sie bitte sofort den Absender und 
vernichten Sie diese Mail. Das unerlaubte Kopieren sowie die unbefugte 
Weitergabe dieser Mail sind nicht gestattet. This e-mail may contain 
confidential and/or privileged information. If you are not the intended 
recipient (or have received this e-mail in error) please notify the sender 
immediately and destroy this e-mail. Any unauthorized copying, disclosure or 
distribution of the material in this e-mail is strictly forbidden. Am Mittwoch, 
dem 31.08.2022 um 09:11 -0400 schrieb Viktor Dukhovni:
> On Wed, Aug 31, 2022 at 09:56:49AM +, Frank Brendel wrote:
>
> > > You really should do something about that, build a table of over-
> > > quota recipients, and tempfail new mail for such users when
> > > briefly
> > > over quota, and ultimately reject if long-term over-quota.
> >
> > but is that possible with remote mailboxes?
>
> If this is outbound mail to a remote domain, then it is much harder
> to
> know that the mailbox is full, you'd need to monitor the logs or the
> content of the deferred queue for recipients deferred with an
> extended
> status code of 4.2.2  3.3>,
> and then you could attempt to propagate this upstream, by tempfailing
> further traffic to the destination until the backlog of deferred mail
> to that recipient falls below a low water mark.
>
> But if you managed in less that $max_queue_lifetime to accumulate
> 250,000 messages to the same mailbox, something is wrong on the
> sender
> end.  Whatever is generating the flood should be dealt with.
>

Re: Unexpected record type 'X'

[Viktor Dukhovni]

On Wed, Aug 31, 2022 at 09:56:49AM +, Frank Brendel wrote:

> > You really should do something about that, build a table of over-
> > quota recipients, and tempfail new mail for such users when briefly
> > over quota, and ultimately reject if long-term over-quota.
>
> but is that possible with remote mailboxes?

If this is outbound mail to a remote domain, then it is much harder to
know that the mailbox is full, you'd need to monitor the logs or the
content of the deferred queue for recipients deferred with an extended
status code of 4.2.2 ,
and then you could attempt to propagate this upstream, by tempfailing
further traffic to the destination until the backlog of deferred mail
to that recipient falls below a low water mark.

But if you managed in less that $max_queue_lifetime to accumulate
250,000 messages to the same mailbox, something is wrong on the sender
end.  Whatever is generating the flood should be dealt with.

-- 
Viktor.

Re: Unexpected record type 'X'

[Frank Brendel]

Hi Viktor,



 Frank Brendel
Administrator Rechenzentrum

Telefon:  +49 811 9595-157
Telefax:  +49 811 9595-199
Internet: https://www.eurolog.com

EURO-LOG AG
Am Söldnermoos 17, D-85399 Hallbergmoos
Vorstand: Jörg Fürbacher
Aufsichtsratsvorsitzender: Markus Quicken
Registergericht: AG München HRB 140857
Steuer-Nr.: 115/118/10169
Ust-ID-Nr.: DE 811547361

Diese E-Mail könnte vertrauliche und/oder rechtlich geschützte Informationen 
enthalten. Wenn Sie nicht der richtige Adressat sind oder diese E-Mail 
irrtümlich erhalten haben, informieren Sie bitte sofort den Absender und 
vernichten Sie diese Mail. Das unerlaubte Kopieren sowie die unbefugte 
Weitergabe dieser Mail sind nicht gestattet. This e-mail may contain 
confidential and/or privileged information. If you are not the intended 
recipient (or have received this e-mail in error) please notify the sender 
immediately and destroy this e-mail. Any unauthorized copying, disclosure or 
distribution of the material in this e-mail is strictly forbidden. Am Dienstag, 
dem 30.08.2022 um 10:08 -0400 schrieb Viktor Dukhovni:
> >
> > But regarding 'queue files' I have about 265.000 deferred mails
> > (recipients mailbox full).
>
> You really should do something about that, build a table of over-
> quota
> recipients, and tempfail new mail for such users when briefly over
> quota, and ultimately reject if long-term over-quota.
>
but is that possible with remote mailboxes?


Thank you
Frank

Re: Unexpected record type 'X'

[Frank Brendel]

Hi Wietse,

all pending 'corrupt' messages are sent now. No errors. 

I'll upgrade the system to FreeBSD 13.1 and Postfix 3.7.2
and keep an eye on the queue size.

Thank you for your help.

And thank you for Postfix, it makes a good job here since 2004! 


Kind regards
Frank




 Frank Brendel
Administrator Rechenzentrum

Telefon:  +49 811 9595-157
Telefax:  +49 811 9595-199
Internet: https://www.eurolog.com

EURO-LOG AG
Am Söldnermoos 17, D-85399 Hallbergmoos
Vorstand: Jörg Fürbacher
Aufsichtsratsvorsitzender: Markus Quicken
Registergericht: AG München HRB 140857
Steuer-Nr.: 115/118/10169
Ust-ID-Nr.: DE 811547361

Diese E-Mail könnte vertrauliche und/oder rechtlich geschützte Informationen 
enthalten. Wenn Sie nicht der richtige Adressat sind oder diese E-Mail 
irrtümlich erhalten haben, informieren Sie bitte sofort den Absender und 
vernichten Sie diese Mail. Das unerlaubte Kopieren sowie die unbefugte 
Weitergabe dieser Mail sind nicht gestattet. This e-mail may contain 
confidential and/or privileged information. If you are not the intended 
recipient (or have received this e-mail in error) please notify the sender 
immediately and destroy this e-mail. Any unauthorized copying, disclosure or 
distribution of the material in this e-mail is strictly forbidden. Am Dienstag, 
dem 30.08.2022 um 11:47 -0400 schrieb Wietse Venema:
>
> I can't come up with a 'reasonable' way to reproduce this error.
> For example, if the queue manager somehow read the wrong information
> from the message size record, it would have logged "Unexpected
> record type 'N'" before reaching the 'X' record, or some other
> error if it had jumped into the middle of a queue file record.
>
> That leaves 'unreasonable' problems such as CPUs taking the wrong
> branch, and data-dependent memory errors.
>
> Wietse
>
>

Re: Unexpected record type 'X'

[Wietse Venema]

Frank Brendel:
> I can't reproduce it anymore.
> I moved two files which failed before into incoming and they are now
> sent.
> 
> Could it be that it was because of the large deferred queue?

By design, Postfix does not know how many messages there are in the
mail queue. The queue manager knows at most 20 thousuand messages
or recipients, therefore its behavior is does not change when the
queue is larger than that.

> Filesystem or parallel processing somehow?

By design, all Postfix processes are single-threaded, and none use
shared memory, to avoid memory concurrency problems. The OS is
supposed to isolate process memory.

> The queue is now small because the remote full mailbox was fixed and
> all messages were delivered.
> 
> I'll keep the messages in the corrupt queue for now.
> Maybe it's still possible to reproduce the error.

I can't come up with a 'reasonable' way to reproduce this error.
For example, if the queue manager somehow read the wrong information
from the message size record, it would have logged "Unexpected
record type 'N'" before reaching the 'X' record, or some other
error if it had jumped into the middle of a queue file record.

That leaves 'unreasonable' problems such as CPUs taking the wrong
branch, and data-dependent memory errors.

Wietse

> 
> Thank you
> Frank
> 
> 
> 
> 
>  Frank Brendel
> Administrator Rechenzentrum
> 
> Telefon:  +49 811 9595-157
> Telefax:  +49 811 9595-199
> Internet: https://www.eurolog.com
> 
> EURO-LOG AG
> Am S?ldnermoos 17, D-85399 Hallbergmoos
> Vorstand: J?rg F?rbacher
> Aufsichtsratsvorsitzender: Markus Quicken
> Registergericht: AG M?nchen HRB 140857
> Steuer-Nr.: 115/118/10169
> Ust-ID-Nr.: DE 811547361
> 
> Diese E-Mail k?nnte vertrauliche und/oder rechtlich gesch?tzte Informationen 
> enthalten. Wenn Sie nicht der richtige Adressat sind oder diese E-Mail 
> irrt?mlich erhalten haben, informieren Sie bitte sofort den Absender und 
> vernichten Sie diese Mail. Das unerlaubte Kopieren sowie die unbefugte 
> Weitergabe dieser Mail sind nicht gestattet. This e-mail may contain 
> confidential and/or privileged information. If you are not the intended 
> recipient (or have received this e-mail in error) please notify the sender 
> immediately and destroy this e-mail. Any unauthorized copying, disclosure or 
> distribution of the material in this e-mail is strictly forbidden. Am 
> Dienstag, dem 30.08.2022 um 10:52 -0400 schrieb Wietse Venema:
> > Viktor Dukhovni:
> > > On Tue, Aug 30, 2022 at 02:25:20PM +, Frank Brendel wrote:
> > >
> > > > So I can try to reproduce it by simply putting that file into the
> > > > incoming queue?
> > >
> > > Within the same filesystem, yes.
> > >
> > > > Our test system has FreeBSD 13.1 and Postfix 3.7.2 installed.
> > > > I'd try
> > > > to resend a mail via that system.
> > >
> > > If you're copying queue files between systems, make sure to stop
> > > Postfix
> > > on the target system, and run "postsuper -s" as root after copying
> > > the
> > > queue file.  Queue file permissions need to be 0700 to make the
> > > message
> > > deliverable, the owner needs to be the "$mail_owner" user
> > > (typically
> > > "postfix").
> >
> > To reproduce the error without delivering the message, the procedure
> > is to use a non-production machine with deliveries disabled:
> >
> > # postconf defer_transports=smtp,relay default_transport=retry
> > # postfix reload
> >
> > Using the queue file 57850C4DC9 that you sent me off-list:
> >
> > # cp 57850C4DC9 /var/spool/postfix/incoming
> > # chmod 700 /var/spool/postfix/incoming/57850C4DC9
> > # chown postfix /var/spool/postfix/incoming/57850C4DC9
> >
> > # postfix flush
> >
> > Wietse
> 
> 

Re: Unexpected record type 'X'

[Frank Brendel]

I can't reproduce it anymore.
I moved two files which failed before into incoming and they are now
sent.

Could it be that it was because of the large deferred queue?
Filesystem or parallel processing somehow?
The queue is now small because the remote full mailbox was fixed and
all messages were delivered.

I'll keep the messages in the corrupt queue for now.
Maybe it's still possible to reproduce the error.


Thank you
Frank




 Frank Brendel
Administrator Rechenzentrum

Telefon:  +49 811 9595-157
Telefax:  +49 811 9595-199
Internet: https://www.eurolog.com

EURO-LOG AG
Am Söldnermoos 17, D-85399 Hallbergmoos
Vorstand: Jörg Fürbacher
Aufsichtsratsvorsitzender: Markus Quicken
Registergericht: AG München HRB 140857
Steuer-Nr.: 115/118/10169
Ust-ID-Nr.: DE 811547361

Diese E-Mail könnte vertrauliche und/oder rechtlich geschützte Informationen 
enthalten. Wenn Sie nicht der richtige Adressat sind oder diese E-Mail 
irrtümlich erhalten haben, informieren Sie bitte sofort den Absender und 
vernichten Sie diese Mail. Das unerlaubte Kopieren sowie die unbefugte 
Weitergabe dieser Mail sind nicht gestattet. This e-mail may contain 
confidential and/or privileged information. If you are not the intended 
recipient (or have received this e-mail in error) please notify the sender 
immediately and destroy this e-mail. Any unauthorized copying, disclosure or 
distribution of the material in this e-mail is strictly forbidden. Am Dienstag, 
dem 30.08.2022 um 10:52 -0400 schrieb Wietse Venema:
> Viktor Dukhovni:
> > On Tue, Aug 30, 2022 at 02:25:20PM +, Frank Brendel wrote:
> >
> > > So I can try to reproduce it by simply putting that file into the
> > > incoming queue?
> >
> > Within the same filesystem, yes.
> >
> > > Our test system has FreeBSD 13.1 and Postfix 3.7.2 installed.
> > > I'd try
> > > to resend a mail via that system.
> >
> > If you're copying queue files between systems, make sure to stop
> > Postfix
> > on the target system, and run "postsuper -s" as root after copying
> > the
> > queue file.  Queue file permissions need to be 0700 to make the
> > message
> > deliverable, the owner needs to be the "$mail_owner" user
> > (typically
> > "postfix").
>
> To reproduce the error without delivering the message, the procedure
> is to use a non-production machine with deliveries disabled:
>
> # postconf defer_transports=smtp,relay default_transport=retry
> # postfix reload
>
> Using the queue file 57850C4DC9 that you sent me off-list:
>
> # cp 57850C4DC9 /var/spool/postfix/incoming
> # chmod 700 /var/spool/postfix/incoming/57850C4DC9
> # chown postfix /var/spool/postfix/incoming/57850C4DC9
>
> # postfix flush
>
> Wietse

Re: Unexpected record type 'X'

[Wietse Venema]

Viktor Dukhovni:
> On Tue, Aug 30, 2022 at 02:25:20PM +, Frank Brendel wrote:
> 
> > So I can try to reproduce it by simply putting that file into the
> > incoming queue?
> 
> Within the same filesystem, yes.
> 
> > Our test system has FreeBSD 13.1 and Postfix 3.7.2 installed.  I'd try
> > to resend a mail via that system.
> 
> If you're copying queue files between systems, make sure to stop Postfix
> on the target system, and run "postsuper -s" as root after copying the
> queue file.  Queue file permissions need to be 0700 to make the message
> deliverable, the owner needs to be the "$mail_owner" user (typically
> "postfix").

To reproduce the error without delivering the message, the procedure
is to use a non-production machine with deliveries disabled:

# postconf defer_transports=smtp,relay default_transport=retry
# postfix reload

Using the queue file 57850C4DC9 that you sent me off-list:

# cp 57850C4DC9 /var/spool/postfix/incoming
# chmod 700 /var/spool/postfix/incoming/57850C4DC9
# chown postfix /var/spool/postfix/incoming/57850C4DC9

# postfix flush

Wietse

Re: Unexpected record type 'X'

[Viktor Dukhovni]

On Tue, Aug 30, 2022 at 02:25:20PM +, Frank Brendel wrote:

> So I can try to reproduce it by simply putting that file into the
> incoming queue?

Within the same filesystem, yes.

> Our test system has FreeBSD 13.1 and Postfix 3.7.2 installed.  I'd try
> to resend a mail via that system.

If you're copying queue files between systems, make sure to stop Postfix
on the target system, and run "postsuper -s" as root after copying the
queue file.  Queue file permissions need to be 0700 to make the message
deliverable, the owner needs to be the "$mail_owner" user (typically
"postfix").

-- 
Viktor.

Re: Unexpected record type 'X'

[Frank Brendel]

So I can try to reproduce it by simply putting that file into the incoming 
queue?

Our test system has FreeBSD 13.1 and Postfix 3.7.2 installed.
I'd try to resend a mail via that system.


Thank you
Frank


Frank Brendel
Administrator Rechenzentrum
Telefon: +49 811 9595-157
Telefax: +49 811 9595-199
Internet: https://www.eurolog.com

[cid:Element3png_a01235f5-8bb8-4c1d-83e5-4331c6a64d5b1.png]


[cid:11_3367c7b8-fcc5-4759-9452-1754d621a68411.jpg]
   [cid:12_273a3767-7a85-4d1a-bf0e-267a0b3cb13911.jpg] 
 
[cid:13_4cbb8970-b438-4e7e-94d1-b62f5aaf693b11.jpg] 
  
[cid:14_6cc658d6-cdbb-4a71-9d7a-ad905297161a11.jpg] 
   
[cid:15_5612f106-1535-48f0-af4c-8ac7c2eff1041.jpg] 

[cid:16_cd8f4895-ea07-4f8a-8039-1cebfcf9442d11.jpg] 

EURO-LOG AG
Am Söldnermoos 17, D-85399 Hallbergmoos
Vorstand: Jörg Fürbacher
Aufsichtsratsvorsitzender: Markus Quicken
Registergericht: AG München HRB 140857
Steuer-Nr.: 115/118/10169
Ust-ID-Nr.:  DE 811547361

Diese E-Mail könnte vertrauliche und/oder rechtlich geschützte Informationen 
enthalten. Wenn Sie nicht der richtige Adressat sind oder diese E-Mail 
irrtümlich erhalten haben, informieren Sie bitte sofort den Absender und 
vernichten Sie diese Mail. Das unerlaubte Kopieren sowie die unbefugte 
Weitergabe dieser Mail sind nicht gestattet. This e-mail may contain 
confidential and/or privileged information. If you are not the intended 
recipient (or have received this e-mail in error) please notify the sender 
immediately and destroy this e-mail. Any unauthorized copying, disclosure or 
distribution of the material in this e-mail is strictly forbidden.

Re: Unexpected record type 'X'

[Viktor Dukhovni]

On Tue, Aug 30, 2022 at 11:27:19AM +, Frank Brendel wrote:

> > Are you using MailScanner or other non-Postfix software that
> > reads or updates Postfix queue files?
> >
> > Wietse
> 
> No, only Postfix and Dovecot with replication.  I've attached the
> postconf output.
> 
> But regarding 'queue files' I have about 265.000 deferred mails
> (recipients mailbox full).

You really should do something about that, build a table of over-quota
recipients, and tempfail new mail for such users when briefly over
quota, and ultimately reject if long-term over-quota.

If the users don't resolve this condition, you'll be sending over a
quarter million bounces.  This is likely a bigger issue that the
occasional corrupt message.

> Filesystem is UFS2.

To make progress, you'll need detail the milters you're using, and share
complete logs and make available the raw binary queue file for at least
one corrupt spammy message with sufficiently non-sensitive content.
Please also report:

$ postconf mail_version

and whether you're running Postfix from base or ports.  Also
the OS release and patch level, and if from ports the package
version.

> header_checks = pcre:/etc/postfix/header_checks.pcre
> milter_default_action = accept
> milter_mail_macros = i {mail_addr} {client_addr} {client_name} {auth_authen}
> milter_protocol = 6
> smtpd_helo_restrictions = permit_mynetworks,
>   permit_sasl_authenticated, check_helo_access
>   pcre:/etc/postfix/helo_exceptions.pcre, reject_non_fqdn_hostname,
>   reject_invalid_helo_hostname, check_helo_access
>   pcre:/etc/postfix/helo_checks.pcre, permit
> smtpd_recipient_restrictions = reject_non_fqdn_recipient,
>   reject_unknown_recipient_domain, permit_mynetworks,
>   permit_sasl_authenticated, reject_unauth_destination,
>   reject_unlisted_recipient, check_recipient_access
>   pcre:/etc/postfix/whitelist_checks.pcre permit
> smtpd_sender_restrictions = permit_mynetworks,
>   permit_sasl_authenticated, reject_non_fqdn_sender, check_sender_access
>   pcre:/etc/postfix/sender_checks.pcre reject_unknown_sender_domain,
>   permit

Do the header_checks and/or restrictions affect which if any milters are
ultimately used?  Under what conditions?

> notify_classes = software

On a high-volume mail servers, I recommend empty notify_classes, and
monitor your logs instead.

> smtpd_milter_maps = cidr:/etc/postfix/smtpd_milter.map
> smtpd_milters = inet:aa.aaa.aaa:

Which milters are expected to have been used with the corrupt messages?

-- 
Viktor.

Re: Unexpected record type 'X'

[Wietse Venema]

Wietse Venema:
> Frank Brendel:
> > Here's the Postfix log and the queue file.
> > 
> > Aug 30 13:02:23 elvmwlx94.eurolog.com postfix/smtpd[56532] 57850C4DC9:
> > client=unknown[194.50.162.68]
> > Aug 30 13:02:23 elvmwlx94.eurolog.com postfix/cleanup[55311]
> > 57850C4DC9: message-id=<>
> > Aug 30 13:02:23 elvmwlx94.eurolog.com postfix/qmgr[63719] 57850C4DC9:
> > from=, size=103176, nrcpt=12 (queue active)
> > Aug 30 13:02:23 elvmwlx94.eurolog.com postfix/qmgr[63719] warning:
> > Unexpected record type 'X' at offset 105234
> > Aug 30 13:02:23 elvmwlx94.eurolog.com postfix/qmgr[63719] warning:
> > saving corrupt file "57850C4DC9" from queue "active" to queue "corrupt"
> > 
> > 
> > Between these log entries are some other qmgr logs with the same PID
> > too. Maybe you want the whole log section with some lines before and
> > after?
> 
> The "unexpected record" problem does not reproduce on my test system
> (Fedora Core) which uses gcc.
> 
> Now I know that FreeBSD is CLANG based which is farily aggressive
> so I'll see if I can reproduce this on a FreeBSD 13 VM that I
> already have.

Postfix 3.7.2 built with CLANG from the official Postfix source
release on FreeBSD 13.1-RC3 also does not reproduce the problem.
It attempts to deliver the message as expected.

% cc -v
FreeBSD clang version 13.0.0 (g...@github.com:llvm/llvm-project.git 
llvmorg-13.0.0-0-gd7b669b3a303)
Target: x86_64-unknown-freebsd13.1
Thread model: posix
InstalledDir: /usr/bin

and

% uname -a
FreeBSD freebsd131.porcupine.org 13.1-RC3 FreeBSD 13.1-RC3 
releng/13.1-n250110-ec2fbe4b1ec GENERIC amd64

and

% egrep '^(CC|OPT)' Makefile   
CC  = cc -I. -I../../include -I/usr/local/include -DHAS_DEV_URANDOM 
-DHAS_PCRE=2 -I/usr/local/include -UUSE_DYNAMIC_LIBS -DDEF_SHLIB_DIR=\"no\" 
-UUSE_DYNAMIC_MAPS $(WARN)
OPT = -O
OPTS= 'WARN=$(WARN)'

I'll look into FreeBSD 12.3 later. I don't have a VM with that OS.

Wietse

> Details
> ===
> 
> I copied your file into /var/spool/postfix/incoming and did "chmod
> 700 and "chown postfix".
> At that point we should have the same conditions as on your machine.
> 
> In fact, I made a mistake, and the message was delivered to my relayhost:
> 
> Aug 30 08:46:55 wzv postfix/qmgr[417146]: 57850A22B0: 
> from=, size=103176, nrcpt=12 (queue active)
> Aug 30 08:46:55 wzv postfix/tlsproxy[417370]: CONNECT to [168.100.3.2]:25
> Aug 30 08:46:55 wzv postfix/tlsproxy[417370]: Untrusted TLS connection 
> established to spike.porcupine.org[168.100.3.2]:25: TLSv1.3 with cipher 
> TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature 
> RSA-PSS (2048 bits) server-digest SHA256
> Aug 30 08:46:55 wzv postfix/smtp[417367]: Untrusted TLS connection 
> established to spike.porcupine.org[168.100.3.2]:25: TLSv1.3 with cipher 
> TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature 
> RSA-PSS (2048 bits) server-digest SHA256
> Aug 30 08:46:55 wzv postfix/tlsproxy[417370]: DISCONNECT [168.100.3.2]:25
> Aug 30 08:46:55 wzv postfix/smtp[417367]: 57850A22B0: 
> to=, 
> relay=spike.porcupine.org[168.100.3.2]:25, delay=6272, 
> delays=6272/0.06/0.07/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 
> 4MH6Wg2yvCzJrP1)
> Aug 30 08:46:55 wzv postfix/smtp[417367]: 57850A22B0: 
> to=, relay=spike.porcupine.org[168.100.3.2]:25, 
> delay=6272, delays=6272/0.06/0.07/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: 
> queued as 4MH6Wg2yvCzJrP1)
> Aug 30 08:46:55 wzv postfix/smtp[417367]: 57850A22B0: 
> to=, relay=spike.porcupine.org[168.100.3.2]:25, 
> delay=6272, delays=6272/0.06/0.07/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: 
> queued as 4MH6Wg2yvCzJrP1)
> Aug 30 08:46:55 wzv postfix/smtp[417367]: 57850A22B0: 
> to=, relay=spike.porcupine.org[168.100.3.2]:25, 
> delay=6272, delays=6272/0.06/0.07/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: 
> queued as 4MH6Wg2yvCzJrP1)
> Aug 30 08:46:55 wzv postfix/smtp[417367]: 57850A22B0: 
> to=, relay=spike.porcupine.org[168.100.3.2]:25, 
> delay=6272, delays=6272/0.06/0.07/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: 
> queued as 4MH6Wg2yvCzJrP1)
> Aug 30 08:46:55 wzv postfix/smtp[417367]: 57850A22B0: 
> to=, 
> relay=spike.porcupine.org[168.100.3.2]:25, delay=6272, 
> delays=6272/0.06/0.07/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 
> 4MH6Wg2yvCzJrP1)
> Aug 30 08:46:55 wzv postfix/smtp[417367]: 57850A22B0: 
> to=, relay=spike.porcupine.org[168.100.3.2]:25, 
> delay=6272, delays=6272/0.06/0.07/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: 
> queued as 4MH6Wg2yvCzJrP1)
> Aug 30 08:46:55 wzv postfix/smtp[417367]: 57850A22B0: 
> to=, relay=spike.porcupine.org[168.100.3.2]:25, 
> delay=6272, delays=6272/0.06/0.07/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: 
> queued as 4MH6Wg2yvCzJrP1)
> Aug 30 08:46:55 wzv postfix/smtp[417367]: 57850A22B0: 
> to=, relay=spike.porcupine.org[168.100.3.2]:25, 
> delay=6272, delays=6272/0.06/0.07/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: 
> queued as 4MH6Wg2yvCzJrP1)
> Aug 30 08:46:55 wzv 

Re: Unexpected record type 'X'

[Frank Brendel]

Hi Wietse,

no, only Postfix and Dovecot with replication.
I've attached the postconf output.

But regarding 'queue files' I have about 265.000 deferred
mails (recipients mailbox full).
Filesystem is UFS2.


Thank you
Frank




 Frank Brendel
Administrator Rechenzentrum

Telefon:  +49 811 9595-157
Telefax:  +49 811 9595-199
Internet: https://www.eurolog.com

EURO-LOG AG
Am Söldnermoos 17, D-85399 Hallbergmoos
Vorstand: Jörg Fürbacher
Aufsichtsratsvorsitzender: Markus Quicken
Registergericht: AG München HRB 140857
Steuer-Nr.: 115/118/10169
Ust-ID-Nr.: DE 811547361

Diese E-Mail könnte vertrauliche und/oder rechtlich geschützte Informationen 
enthalten. Wenn Sie nicht der richtige Adressat sind oder diese E-Mail 
irrtümlich erhalten haben, informieren Sie bitte sofort den Absender und 
vernichten Sie diese Mail. Das unerlaubte Kopieren sowie die unbefugte 
Weitergabe dieser Mail sind nicht gestattet. This e-mail may contain 
confidential and/or privileged information. If you are not the intended 
recipient (or have received this e-mail in error) please notify the sender 
immediately and destroy this e-mail. Any unauthorized copying, disclosure or 
distribution of the material in this e-mail is strictly forbidden. Am Dienstag, 
dem 30.08.2022 um 06:55 -0400 schrieb Wietse Venema:
>
> Are you using MailScanner or other non-Postfix software that
> reads or updates Postfix queue files?
>
> Wietse

postconf -n

2bounce_notice_recipient = postmas...@aaa.aaa
alias_maps = $alias_database, ldap:/etc/postfix/ldap_alias.cf
bounce_notice_recipient = postmas...@aaa.aaa
broken_sasl_auth_clients = yes
command_directory = /usr/sbin
compatibility_level = 3.6
daemon_directory = /usr/libexec/postfix
data_directory = /var/db/postfix
delay_notice_recipient = postmas...@aaa.aaa
disable_vrfy_command = yes
e-billing_recipient_check = pcre:/etc/postfix/e-billing_recipient_checks.pcre
empty_address_recipient = mailer-dae...@aaa.aaa
error_notice_recipient = postmas...@aaa.aaa
header_checks = pcre:/etc/postfix/header_checks.pcre
home_mailbox = Maildir/
inet_protocols = ipv4
local_recipient_maps = $alias_maps, proxy:unix:passwd.byname
mail_owner = postfix
mailbox_size_limit = 0
mailbox_transport = lmtp:unix:private/dovecot-lmtp
message_size_limit = 0
milter_default_action = accept
milter_mail_macros = i {mail_addr} {client_addr} {client_name} {auth_authen}
milter_protocol = 6
mydestination = $mydomain, $myhostname, localhost, invoice-signature.com
mynetworks = 127.0.0.1/32, dd.dd.dd.dd/dd
myorigin = $mydomain
notify_classes = software
queue_directory = /var/spool/postfix
sender_dependent_relayhost_maps = pcre:/etc/postfix/sender_relay.pcre
smtp_helo_name = a.aaa.aaa
smtp_sasl_auth_enable = yes
smtp_sasl_password_maps = pcre:/etc/postfix/smtp_sasl_passwd.pcre
smtp_sasl_security_options = noanonymous
smtp_sender_dependent_authentication = yes
smtp_tls_CApath = /etc/ssl
smtp_tls_security_level = may
smtpd_banner = a.aaa.aaa ESMTP ready
smtpd_data_restrictions = reject_unauth_pipelining permit
smtpd_error_sleep_time = 10s
smtpd_helo_required = yes
smtpd_helo_restrictions = permit_mynetworks, permit_sasl_authenticated, 
check_helo_access pcre:/etc/postfix/helo_exceptions.pcre, 
reject_non_fqdn_hostname, reject_invalid_helo_hostname, check_helo_access 
pcre:/etc/postfix/helo_checks.pcre, permit
smtpd_milter_maps = cidr:/etc/postfix/smtpd_milter.map
smtpd_milters = inet:aa.aaa.aaa:
smtpd_recipient_restrictions = reject_non_fqdn_recipient, 
reject_unknown_recipient_domain, permit_mynetworks, permit_sasl_authenticated, 
reject_unauth_destination, reject_unlisted_recipient, check_recipient_access 
pcre:/etc/postfix/whitelist_checks.pcre permit
smtpd_restriction_classes = e-billing_recipient_check
smtpd_sasl_auth_enable = yes
smtpd_sasl_local_domain =
smtpd_sasl_path = /var/spool/postfix/private/auth
smtpd_sasl_security_options = noanonymous
smtpd_sasl_type = dovecot
smtpd_sender_login_maps =
smtpd_sender_restrictions = permit_mynetworks, permit_sasl_authenticated, 
reject_non_fqdn_sender, check_sender_access 
pcre:/etc/postfix/sender_checks.pcre reject_unknown_sender_domain, permit
smtpd_tls_CApath = /etc/ssl
smtpd_tls_cert_file = /path/to/aaa.aaa
smtpd_tls_key_file = $smtpd_tls_cert_file
smtpd_tls_loglevel = 1
smtpd_tls_security_level = may
transport_maps = pcre:/etc/postfix/transport.pcre
virtual_alias_maps = pcre:/etc/postfix/virtual_maps.pcre
virtual_transport = lmtp:unix:private/dovecot-lmtp


postconf -fM

smtp   inet  n   -   n   -   -   smtpd
pickup unix  n   -   n   60  1   pickup
cleanupunix  n   -   n   -   0   cleanup
qmgr   unix  n   -   n   300 1   qmgr
tlsmgr unix  -   -   n   1000?   1   tlsmgr
rewriteunix  -   -   n   -   -   trivial-rewrite
bounce unix  -   -   n   -   0   bounce
defer  unix  -   -   

Re: Unexpected record type 'X'

[Wietse Venema]

Frank Brendel:
> Hi,
> 
> sporadically I get the error
>   Unexpected record type 'X' at offset ...
> and the message is moved to the corrupt queue.
> 
> E.g.
> postfix/smtpd[19574] 010EDD6443: client=unknown[1.2.3.4]
> postfix/cleanup[98995] 010EDD6443: message-id=<>
> postfix/qmgr[63719] 010EDD6443: from=,
> size=14197, nrcpt=24 (queue active)
> postfix/qmgr[63719] warning: Unexpected record type 'X' at offset 17542
> postfix/qmgr[63719] warning: saving corrupt file "010EDD6443" from
> queue "active" to queue "corrupt"
> 
> The message looks OK to me. It is multipart/mixed with multiple
> recipients. The offset is always at the end of the message.
> 
> postcat -do 010EDD6443
> ...
> 17481  78 boundary_641_fc5671dc-1c1d-438e-a827-019b96ffe19b--
> 17538  78
> 17540  78
> 17542  88 *** HEADER EXTRACTED 010EDD6443 ***
> 17544  69 *** MESSAGE FILE END 010EDD6443 ***

Are you using MailScanner or other non-Postfix software that 
reads or updates Postfix queue files?

Wietse