[SOLVED] 451 4.3.0 Error: queue file write error

M

mach

Member
Proxmox Subscriber
Sep 1, 2020
21
3
8
46
Hello,

I keep getting a large number of "451 4.3.0 Error: queue file write error" in logs and also mail notification about it.

I've received over 700 of them for just past day, this is for about 30,000 total emails received for the day.

It always happens with a reject/timeout to proxy:

Sep 20 00:12:06 franklin-pmg1 postfix/smtpd[31176]: connect from mta107b.pmx1.epsl1.com[142.54.244.107]
Sep 20 00:12:06 franklin-pmg1 postfix/smtpd[31176]: Anonymous TLS connection established from mta107b.pmx1.epsl1.com[142.54.244.107]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Sep 20 00:12:08 franklin-pmg1 postfix/smtpd[31176]: NOQUEUE: client=mta107b.pmx1.epsl1.com[142.54.244.107]
Sep 20 00:13:48 franklin-pmg1 postfix/smtpd[31176]: warning: timeout talking to proxy 127.0.0.1:10024
Sep 20 00:13:48 franklin-pmg1 postfix/smtpd[31176]: proxy-reject: END-OF-MESSAGE: 451 4.3.0 Error: queue file write error; from=<bounce@mail.paypal.de> to=<giselle@domain.com> proto=ESMTP helo=<mta107b.pmx1.epsl1.com>
Sep 20 00:13:53 franklin-pmg1 postfix/smtpd[31176]: disconnect from mta107b.pmx1.epsl1.com[142.54.244.107] ehlo=2 starttls=1 mail=1 rcpt=1 data=0/1 quit=1 commands=6/7

And then it is delivered successfully few minutes later:

Sep 20 00:17:09 franklin-pmg1 postfix/smtpd[31387]: connect from localhost[127.0.0.1]
Sep 20 00:17:09 franklin-pmg1 postfix/smtpd[31387]: 86795143AA: client=localhost[127.0.0.1], orig_client=mta107b.pmx1.epsl1.com[142.54.244.107]
Sep 20 00:17:09 franklin-pmg1 postfix/cleanup[31388]: 86795143AA: message-id=<HP2v400000174a9b6230fa7eb496e96638858169@mail.paypal.de>
Sep 20 00:17:09 franklin-pmg1 postfix/qmgr[694]: 86795143AA: from=<bounce@mail.paypal.de>, size=65874, nrcpt=1 (queue active)
Sep 20 00:17:09 franklin-pmg1 postfix/smtpd[31387]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 commands=5
Sep 20 00:17:10 franklin-pmg1 postfix/smtp[31389]: 86795143AA: to=<giselle@domain.com>, relay=host.domain.com[2602:ffb8::#:#:#:#]:25, delay=0.5, delays=0.03/0.04/0.08/0.35, dsn=2.0.0, status=sent (250 ok 1600575430 qp 3724)
Sep 20 00:17:10 franklin-pmg1 postfix/qmgr[694]: 86795143AA: removed

pmg-smtp-filter is running just fine

I've tried to increase number of pmg-smtp-filter processes to the following:

> $max_servers = $pmg_cfg->get('mail', 'max_filters') + 100;
> $min_servers = 50;
> $min_spare_servers = 25;
> $max_spare_servers = 100;
> $max_requests = 1000;

but that didn't seem to have any effect.

Any idea what is happening or why? I've searched the past forum posts and seems it happens to others, but no one really resolved it as to why it happens.
 
Pls double check your pmg-smtp-filter service is running fine.
Double check your mail.log/syslog is there any error starting pmg-smtp-filter.
 
There are no errors starting pmg-smtp-filter and it is running:

ps -ef |grep pmg-smtp-filter
root 16109 1 0 05:59 ? 00:00:05 /usr/bin/perl /usr/bin/pmg-smtp-filter
root 16145 16109 0 05:59 ? 00:00:01 pmg-smtp-filter child
root 16146 16109 0 05:59 ? 00:00:01 pmg-smtp-filter child

I've restarted it:

Sep 24 05:59:42 franklin-pmg1 systemd[1]: Stopping Proxmox SMTP Filter Daemon...
Sep 24 05:59:43 franklin-pmg1 pmg-smtp-filter[651]: 2020/09/24-05:59:43 Server closing!
Sep 24 05:59:43 franklin-pmg1 systemd[1]: pmg-smtp-filter.service: Succeeded.
Sep 24 05:59:43 franklin-pmg1 systemd[1]: Stopped Proxmox SMTP Filter Daemon.
Sep 24 05:59:43 franklin-pmg1 systemd[1]: Starting Proxmox SMTP Filter Daemon...
Sep 24 05:59:45 franklin-pmg1 pmg-smtp-filter[16109]: Process Backgrounded
Sep 24 05:59:45 franklin-pmg1 pmg-smtp-filter[16109]: 2020/09/24-05:59:45 main (type Net::Server::preFork) starting! pid(16109)
Sep 24 05:59:45 franklin-pmg1 pmg-smtp-filter[16109]: Binding to TCP port 10023 on host 127.0.0.1 with IPv4
Sep 24 05:59:45 franklin-pmg1 pmg-smtp-filter[16109]: Binding to TCP port 10024 on host 127.0.0.1 with IPv4
Sep 24 05:59:45 franklin-pmg1 pmg-smtp-filter[16109]: Group Not Defined. Defaulting to EGID '0'
Sep 24 05:59:45 franklin-pmg1 pmg-smtp-filter[16109]: User Not Defined. Defaulting to EUID '0'
Sep 24 05:59:45 franklin-pmg1 pmg-smtp-filter[16109]: Setting up serialization via flock
Sep 24 05:59:45 franklin-pmg1 pmg-smtp-filter[16109]: Filter daemon (re)started (max. 40 processes)
Sep 24 05:59:45 franklin-pmg1 systemd[1]: Started Proxmox SMTP Filter Daemon.
Sep 24 05:59:50 franklin-pmg1 pmg-smtp-filter[16109]: WARNING: Use of uninitialized value in numeric lt (<) at /usr/share/perl5/Mail/SpamAssassin/AutoWhitelist.pm line 149.
Sep 24 05:59:50 franklin-pmg1 pmg-smtp-filter[16109]: WARNING: Use of uninitialized value in numeric ne (!=) at /usr/share/perl5/Mail/SpamAssassin/AutoWhitelist.pm line 149.
Sep 24 05:59:50 franklin-pmg1 pmg-smtp-filter[16109]: WARNING: Use of uninitialized value in numeric ne (!=) at /usr/share/perl5/Mail/SpamAssassin/AutoWhitelist.pm line 149.
Sep 24 05:59:50 franklin-pmg1 pmg-smtp-filter[16109]: Beginning prefork (2 processes)
Sep 24 05:59:50 franklin-pmg1 pmg-smtp-filter[16109]: Starting "1" children

ps -ef |grep pmg-smtp-filter
root 16109 1 0 05:59 ? 00:00:05 /usr/bin/perl /usr/bin/pmg-smtp-filter
root 16145 16109 0 05:59 ? 00:00:04 pmg-smtp-filter child
root 16146 16109 0 05:59 ? 00:00:05 pmg-smtp-filter child
 
mach said:
WARNING: Use of uninitialized value in numeric lt (<) at /usr/share/perl5/Mail/SpamAssassin/AutoWhitelist.pm line 149.
Click to expand...
this should not be printed upon pmg-smtp-filter restart:
* please post your `pmgversion -v`
* did you modify the configuration ? (if yes how)
 
pmgversion -v
proxmox-mailgateway-container: 6.2-1 (API: 6.2-5/05a7829e, running kernel: 5.4.55-1-pve)
pmg-api: 6.2-5
pmg-gui: 2.2-2
clamav-daemon: 0.102.4+dfsg-0+deb10u1
libarchive-perl: 3.3.3-1
libjs-extjs: 6.0.1-10
libjs-framework7: 4.4.7-1
libpve-apiclient-perl: 3.0-3
libpve-common-perl: 6.2-2
libpve-http-server-perl: 3.0-6
libxdgmime-perl: 0.01-5
lvm2: not correctly installed
pmg-docs: 6.2-2
pmg-log-tracker: 2.1.7-1
postgresql-11: 11.7-0+deb10u1
proxmox-mini-journalreader: 1.1-1
proxmox-spamassassin: 3.4.4-2
proxmox-widget-toolkit: 2.2-12
pve-xtermjs: 4.3.0-1

I've made Bayes and AWL use Redis for backend. Which is Spamassassin recommended backend for Bayes.

I can disable Bayes and AWL and test to see if still happens.

And I've also followed some suggestions from "Advancing Proxmox Mail Gateway" tutorial such as adding DCC and Pyzor and updated KAM rules.
 
mach said:
I've made Bayes and AWL use Redis for backend. Which is Spamassassin recommended backend for Bayes.
Click to expand...
* does the journal say anything about problems with redis maybe?
* could you post your config modifications?
 
No errors from Redis.

For Bayes:

bayes_store_module Mail::SpamAssassin::BayesStore::Redis
bayes_sql_dsn server=127.0.0.1:6379;database=0
use_bayes_rules 1
bayes_auto_learn 1
bayes_learn_to_journal 0
bayes_auto_expire 1
bayes_token_ttl 30d
bayes_seen_ttl 14d

For AWL:

auto_whitelist_factory Mail::SpamAssassin::RedisAddrList
auto_whitelist_redis_server 127.0.0.1:6379
auto_whitelist_redis_prefix awl_
auto_whitelist_redis_expire 5184000

Need to install Mail::SpamAssassin::RedisAddrList through cpan (prefer_external_tar should be turned off in /root/.cpan/CPAN/MyConfig.pm)
 
Last edited:
hmm - my first guess would be that this might be related to the modification and external plugins ...
mach said:
Need to install Mail::SpamAssassin::BayesStore::Redis through cpan.
Click to expand...
why do you need to install it via cpan? - Haven't tried this configuration myself so I might be missing something.
the file/module is shipped by proxmox-spamassassin:
Code: 
dpkg -L proxmox-spamassassin |grep -i bayes.*redis
/usr/share/man/man3/Mail::SpamAssassin::BayesStore::Redis.3pm.gz
/usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm

What are the messages (in the journal) from pmg-smtp-filter around the time you get:
mach said:
Sep 20 00:13:48 franklin-pmg1 postfix/smtpd[31176]: warning: timeout talking to proxy 127.0.0.1:10024
Click to expand...

the proxy timeout indicates that pmg-smtp-filter is not responding to connection attempts
 
Switching from Redis Bayes and AWL to the default file based store did stop the "451 4.3.0 Error: queue file write error" errors so far.

You're right, it's not needed to be installed through cpan, though if you try it, it will say it's already installed.

With the default settings, is the file based bayes/awl store maintained somehow to prevent it from growing indefinitely?

Is bayes/awl recommended for busy server?
 
any messages from pmg-smtp-filter around the time when the queue-file write error was reported?

mach said:
With the default settings, is the file based bayes/awl store maintained somehow to prevent it from growing indefinitely?
Click to expand...
Haven't looked it up explicitly, but have never heard of a case where the size of the db's grew so large that it became a problem - I would suggest you try to stick with the file/berkeley-db and keep an eye on the size for a while

mach said:
Is bayes/awl recommended for busy server?
Click to expand...
In my experience both tend to lead to more false positives than help detection - however my experience is partially based on giving support on our various channels, where people report that the detection rate is not good - so it is probably a bit biased :) - performancewise I would assume it should not be too expensive.

I hope this helps!
 
Stoiko Ivanov said:
any messages from pmg-smtp-filter around the time when the queue-file write error was reported?
Click to expand...

There were number of warnings, but the times didn't exactly match the times of the queue error:

grep "queue fi" /var/log/mail.log |grep "Sep 24 07:34"
Sep 24 07:34:01 franklin-pmg1 postfix/smtpd[26758]: proxy-reject: END-OF-MESSAGE: 451 4.3.0 Error: queue file write error; from=<donotreply@honeywell.com> to=<vijay@####.com> proto=ESMTP helo=<NAM12-DM6-obe.outbound.protection.outlook.com>
Sep 24 07:34:03 franklin-pmg1 postfix/smtpd[26765]: proxy-reject: END-OF-MESSAGE: 451 4.3.0 Error: queue file write error; from=<donotreply@honeywell.com> to=<vijay@####.com> proto=ESMTP helo=<NAM12-BN8-obe.outbound.protection.outlook.com>
Sep 24 07:34:05 franklin-pmg1 postfix/smtpd[26003]: proxy-reject: END-OF-MESSAGE: 451 4.3.0 Error: queue file write error; from=<donotreply@honeywell.com> to=<mohandas@####.com> proto=ESMTP helo=<NAM02-CY1-obe.outbound.protection.outlook.com>
Sep 24 07:34:05 franklin-pmg1 postfix/smtpd[26846]: proxy-reject: END-OF-MESSAGE: 451 4.3.0 Error: queue file write error; from=<####@indeedemail.com> to=<hr@####.com> proto=ESMTP helo=<mail96.indeedmail.com>
Sep 24 07:34:06 franklin-pmg1 postfix/smtpd[26822]: proxy-reject: END-OF-MESSAGE: 451 4.3.0 Error: queue file write error; from=<donotreply@honeywell.com> to=<vijay@####.com> proto=ESMTP helo=<NAM11-DM6-obe.outbound.protection.outlook.com>
Sep 24 07:34:09 franklin-pmg1 postfix/smtpd[26158]: proxy-reject: END-OF-MESSAGE: 451 4.3.0 Error: queue file write error; from=<msprvs1=18536CBaVgoqz=bounces-283417@send.montefor.com> to=<spatel@####.com> proto=ESMTP helo=<mta-70-5-10.sparkpostmail.com>
Sep 24 07:34:14 franklin-pmg1 postfix/smtpd[26804]: proxy-reject: END-OF-MESSAGE: 451 4.3.0 Error: queue file write error; from=<bounceback@connect.hpe.com> to=<tsu@####.com> proto=ESMTP helo=<mail01.connect.hpe.com>
Sep 24 07:34:16 franklin-pmg1 postfix/smtpd[26800]: proxy-reject: END-OF-MESSAGE: 451 4.3.0 Error: queue file write error; from=<donotreply@honeywell.com> to=<vijay@####.com> proto=ESMTP helo=<NAM04-SN1-obe.outbound.protection.outlook.com>
Sep 24 07:34:57 franklin-pmg1 postfix/smtpd[26699]: proxy-reject: END-OF-MESSAGE: 451 4.3.0 Error: queue file write error; from=<####@ford.com> to=<cristina.####@####.com> proto=ESMTP helo=<mail1.bemta23.messagelabs.com>

grep pmg-smtp-filter /var/log/syslog |grep "Sep 24 07:34" |grep WARNING
Sep 24 07:34:00 franklin-pmg1 pmg-smtp-filter[25984]: WARNING: bayes: db_seen corrupt: value='1' for 293c3cf6f091d1521aa97f403cfd60ff47c54699@sa_generated, ignored at /usr/share/perl5/Mail/SpamAssassin/Plugin/Bayes.pm line 424, <GEN14> line 2978.
Sep 24 07:34:02 franklin-pmg1 pmg-smtp-filter[25911]: WARNING: bayes: db_seen corrupt: value='1' for cd2a57f183572e4a09755c4397134fd860a1da8c@sa_generated, ignored at /usr/share/perl5/Mail/SpamAssassin/Plugin/Bayes.pm line 424, <GEN14> line 1305.
Sep 24 07:34:09 franklin-pmg1 pmg-smtp-filter[25904]: WARNING: rules: failed to run BAYES_20 test, skipping:#012#011(Can't use string ("1") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 3010.#012)
Sep 24 07:34:09 franklin-pmg1 pmg-smtp-filter[25904]: WARNING: rules: failed to run BAYES_60 test, skipping:#012#011(Can't use string ("611") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 3011.#012)
Sep 24 07:34:09 franklin-pmg1 pmg-smtp-filter[25904]: WARNING: rules: failed to run BAYES_95 test, skipping:#012#011(Can't use string ("1") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 3012.#012)
Sep 24 07:34:09 franklin-pmg1 pmg-smtp-filter[25904]: WARNING: rules: failed to run BAYES_50 test, skipping:#012#011(Can't use string ("9") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 3013.#012)
Sep 24 07:34:09 franklin-pmg1 pmg-smtp-filter[25904]: WARNING: rules: failed to run BAYES_999 test, skipping:#012#011(Can't use string ("1") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 3014.#012)
Sep 24 07:34:09 franklin-pmg1 pmg-smtp-filter[25904]: WARNING: rules: failed to run BAYES_99 test, skipping:#012#011(Can't use string ("18") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 3015.#012)
Sep 24 07:34:09 franklin-pmg1 pmg-smtp-filter[25904]: WARNING: rules: failed to run BAYES_80 test, skipping:#012#011(Can't use string ("1") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 3016.#012)
Sep 24 07:34:09 franklin-pmg1 pmg-smtp-filter[25904]: WARNING: rules: failed to run BAYES_05 test, skipping:#012#011(Can't use string ("1347") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 3017.#012)
Sep 24 07:34:09 franklin-pmg1 pmg-smtp-filter[25904]: WARNING: rules: failed to run BAYES_00 test, skipping:#012#011(Can't use string ("1") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 3018.#012)
Sep 24 07:34:09 franklin-pmg1 pmg-smtp-filter[25904]: WARNING: rules: failed to run BAYES_40 test, skipping:#012#011(Can't use string ("50") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 3019.#012)
Sep 24 07:34:16 franklin-pmg1 pmg-smtp-filter[25913]: WARNING: rules: failed to run BAYES_20 test, skipping:#012#011(Can't use string ("1") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 1141.#012)
Sep 24 07:34:16 franklin-pmg1 pmg-smtp-filter[25913]: WARNING: rules: failed to run BAYES_60 test, skipping:#012#011(Can't use string ("188") as an ARRAY ref while "strict refs" in use at /usr/share/perl5/Mail/SpamAssassin/BayesStore/Redis.pm line 592, <GEN14> line 1142.#012)

Stoiko Ivanov said:
In my experience both tend to lead to more false positives than help detection - however my experience is partially based on giving support on our various channels, where people report that the detection rate is not good - so it is probably a bit biased :) - performancewise I would assume it should not be too expensive.

I hope this helps!
Click to expand...

I'll keep an eye on the file and performance, worst comes to worst, I'll just disable Bayes/AWL. But so far it's working great. Thank you Stoiko for your help.
 
That explains it - each of the warnings causes the pmg-smtp-filter to stop processing the mail (and postfix in turn to return a tempfail 4XX code)

Would be great if you let us know how AWL/BAYES performs (detectionwise) in your environment
 
You must log in or register to reply here.

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Quick Navigation

Home Get Subscription Wiki Downloads Proxmox Customer Portal About

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!
Community platform by XenForo® © 2010-2024 XenForo Ltd.
Top Bottom
Back