[had to remove one of two attachments due to 'Message too long' issue]
Wietse Venema <
wie...@porcupine.org> wrote:
Michael Grimm:
Wietse Venema <wie...@porcupine.org> wrote
What is the output from:
postconf smtputf8_enable
Today it is:
smtputf8_enable = no
This is in main.cf. When was this changed?
The command that I emailed you would have changed the postscreen
setting in master.cf only, without affecting the smtputf8 setting
for email from "good" clients.
Mea maxima culpa, my fault. Added that line without thinking to main.cf instead of master.cf, sorry.
Added it now in order to check 'smtputf8_enable = no' for postscreen only.
Here are two examples with a comparable 'BARE NEWLINE' pattern
reported in my first post that didn't crash postscreen:
Apr 23 12:07:45 <mail.info> mail.lan postfix/postscreen[61983]: CONNECT from [1.2.3.4]:58878 to [10.2.2.1]:25
Apr 23 12:07:45 <mail.info> mail.lan postfix/postscreen[61983]: PREGREET 159 after 0.03 from [1.2.3.4]:58878: \026\003\001\000\232\001\000\...
...
Apr 23 12:09:49 <mail.info> mail.lan postfix/postscreen[4271]: CONNECT from [10.20.30.40]:48872 to [10.1.1.1]:25
Apr 23 12:09:49 <mail.info> mail.lan postfix/postscreen[4271]: PREGREET 159 after 0 from [10.20.30.40]:48872: \026\003\001\000\232\001\000\...
I have good reasons to believe that 1.2.3.4 is fake information,
and that the eight crashing sessions that you mailed in a later
message are from different clients, and that none of those clients
appears in a non-crashing session above.
Yes, that's correct.
So at this point I don't think we have established that changing
smtputf8_enable stops the crashes.
Here is why I think that the eight non-crashing sessions are not
from the same client.
In all cases the PREGREET and BARE NEWLINE logging is because a
mis-configured SMTP client sends a TLS hello packet.
The PREGREET logging for those eight craashing sessions shows that
this client 1.2.3.4 was changing its TLS record version from 0x0303
(\003\003) to 0x0302 (\003\002) to 0x0301 (\003\001).
Mar 28 01:33:22 <mail.info> mail.lan postfix/postscreen[7179]: PREGREET 426 after 0 from [1.2.3.4]:33288: \026\003\003\001\245\001\000...
Mar 28 01:33:23 <mail.info> mail.lan postfix/postscreen[7186]: PREGREET 426 after 0 from [1.2.3.4]:33850: \026\003\003\001\245\001\000...
Mar 28 01:33:23 <mail.info> mail.lan postfix/postscreen[7187]: PREGREET 347 after 0 from [1.2.3.4]:34124: \026\003\003\001V\001\000...
Mar 28 01:33:23 <mail.info> mail.lan postfix/postscreen[7188]: PREGREET 333 after 0 from [1.2.3.4]:34386: \026\003\003\001H\001\000...
Mar 28 01:33:23 <mail.info> mail.lan postfix/postscreen[7189]: PREGREET 414 after 0.05 from [1.2.3.4]:34506: \026\003\003\001\231\001\000...
Mar 28 01:33:24 <mail.info> mail.lan postfix/postscreen[7190]: PREGREET 415 after 0 from [1.2.3.4]:34644: \026\003\002\001\232\001\000...
Mar 28 01:33:24 <mail.info> mail.lan postfix/postscreen[7191]: PREGREET 428 after 0.02 from [1.2.3.4]:34772: \026\003\001\001\247\001\000...
Mar 28 01:33:24 <mail.info> mail.lan postfix/postscreen[7192]: PREGREET 428 after 0 from [1.2.3.4]:34874: \026\003\001\001\247\001\000...
Mar 28 01:33:24 <mail.info> mail.lan postfix/postscreen[7193]: PREGREET 418 after 0 from [1.2.3.4]:34980: \026\003\001\001\235\001\000...
Mar 28 01:33:24 <mail.info> mail.lan postfix/postscreen[7194]: PREGREET 441 after 0 from [1.2.3.4]:35048: \026\003\001\001\264\001\000...
I find it hard to believe that one client changes its TLS implementation
within a two-second time interval (assuming the time stamps are real).
I do have some more examples for that behaviour (see attachment).
For comparison, this is from your non-crashing session. It has TLS
record version 0x0301 (\003\001) and a much shorter TLS hello packet
than any of the crashing sessions.
Apr 23 12:07:45 <mail.info> mail.lan postfix/postscreen[61983]: PREGREET 159 after 0.03 from [1.2.3.4]:58878: \026\003\001\000\232\001\000\...
So that non-crashing session is from a different client than the
clients in the eight crashing sessions.
And this from the first message in this thread, with TLS record
version 0x0303 (\003\003), and a TLS hello packet simialr to other
crashing sessions:
Apr 20 06:36:27 <mail.info> mail.lan postfix/postscreen[74803]: PREGREET 429 after 0 from [1.2.3.4]:49074: \026\003\003\001\250\001\000...
Again, a different client than the non-crashing session.
I did some grepping/awking/editing [1] on all maillogs on both servers of mine in order to cut the information down to the bare essential. This should serve as an insight on what is happening before a 'signal 11' crash.
I kept all connections of clients from the same IP before 'signal 11' even when these connections didn't crash postscreen, just in order to show that client's history.
This time the maillog files are unedited (besides my local hostnames), thus showing the real IPs. Some do resolve, some not.
I reported in my first post that all those 'signal 11' events were headed by 'BARE NEWLINE' entries.
Today, while editing these files, I ran over a different pattern triggering 'signal 11' without a heading 'BARE NEWLINE' entries.
Two entries with 'mstshash=Domain' PREGREET patterns:
Apr 19 03:49:08 <mail.info> mx2.lan postfix/postscreen[17604]: CONNECT from [94.232.41.27]:48273 to [10.1.1.1]:25 Apr 19 03:49:08 <mail.info> mx2.lan postfix/postscreen[17604]: PREGREET 44 after 0 from [94.232.41.27]:48273: \003\000\000,'\340\000\000\000\000\000Cookie: mstshash=Domain\r\n\001\000\b\000\003\000\000\000 Apr 19 03:49:08 <mail.info> mx2.lan postfix/postscreen[17604]: CONNECT from [94.232.41.27]:48397 to [10.1.1.1]:25 Apr 19 03:49:08 <mail.info> mx2.lan postfix/postscreen[17604]: PREGREET 44 after 0 from [94.232.41.27]:48397: \003\000\000,'\340\000\000\000\000\000Cookie: mstshash=Domain\r\n\001\000\b\000\003\000\000\000 Apr 19 03:49:08 <mail.warn> mx2.lan postfix/master[7359]: warning: process /usr/local/libexec/postfix/postscreen pid 17604 killed by signal 11
One entry with 'mstshash=Administr' PREGREET pattern:
Mar 25 03:43:17 <
mail.info> mx2.lan postfix/postscreen[5463]: CONNECT from [89.248.165.24]:61384 to [10.1.1.1]:25
Mar 25 03:43:17 <mail.info> mx2.lan postfix/postscreen[5463]: PREGREET 47 after 0 from [89.248.165.24]:61384: \003\000\000/*\340\000\000\000\000\000Cookie: mstshash=Administr\r\n\001\000\b\000\003\000\000\000 Mar 25 03:43:17 <mail.warn> mx2.lan postfix/master[2645]: warning: process /usr/local/libexec/postfix/postscreen pid 5463 killed by signal 11
No idea what is going on here.
HTH and thanks for your help,
Michael
[1] bzgrep 'signal 11' maillog.?.bz2 maillog.[1-3]?.bz2 | grep postfix/master | sed 's/:.*pid//' | awk '{print "bzgrep "$2" "$1" | grep postfix/ ; echo \"\""}' | csh | egrep -v '(DNSBL|anvil|dnsblog|qmgr|smtpd)' > /tmp/zMX1.txt
zMX2.txt.bz2