Timeout / Error: queue file write error
Hallo,
hin und wieder gibt es bei mir einen Timeout scheinbar bei der Übergabe an Amavis (localhost:10024) und ich weiß nicht, wo ich suchen muss, da ich keine ausführlicheren Informationen erhalte. Kann mir jemand vielleicht sagen, wie ich dem Problem auf die Spur kommen kann? Ich erhalte bei diesem "queue file write error" jedesmal eine e-Mail, die an Postmaster als Benachrichtigung geschick wird.
Aug 31 14:14:19 mx2 postfix/smtpd[15861]: connect from unknown[177.37.96.254] Aug 31 14:14:20 mx2 postfix/smtpd[15861]: NOQUEUE: client=unknown[177.37.96.254] Aug 31 14:16:02 mx2 postfix/smtpd[15861]: warning: timeout talking to proxy localhost:10024 Aug 31 14:16:02 mx2 postfix/smtpd[15861]: proxy-reject: END-OF-MESSAGE: 451 4.3.0 Error: queue file write error; from=BillyThompson@lookandwellness.it to=yr@domain.de proto=ESMTP helo=<lookandwellness.it> Aug 31 14:16:02 mx2 postfix/smtpd[15861]: disconnect from unknown[177.37.96.254] ehlo=1 mail=1 rcpt=1 data=0/1 commands=3/4
Normalerweise dauert die Rückantwort von Amavis maximal 3 Sekunden.
Fast zeitlich wurde im Hintergrund die Clamav-Database geladen.
/var/log/clamav/clamav.log Sat Aug 31 14:14:15 2019 -> Database correctly reloaded (10971844 signatures) Sat Aug 31 14:14:15 2019 -> Reading databases from /var/lib/clamav Sat Aug 31 14:14:15 2019 -> /var/lib/amavis/tmp/amavis-20190831T125532-12347-lWbaS7Ci/parts/p001: Sanesecurity.Scam.12584.UNOFFICIAL(00000000000000000000000000000000:6617) FOUND Sat Aug 31 14:16:13 2019 -> Database correctly reloaded (10971844 signatures) Sat Aug 31 14:16:13 2019 -> /var/lib/amavis/tmp/amavis-20190831T120830-10930-zSEWR54L/parts/p001: Sanesecurity.Scam.12559.UNOFFICIAL(00000000000000000000000000000000:6449) FOUND
Kann das vielleicht damit zusammenhängen?
Gruß Thomas
Hi Thomas,
On 31.08.19 14:42, tbarth@txbweb.de wrote:
Fast zeitlich wurde im Hintergrund die Clamav-Database geladen. Kann das vielleicht damit zusammenhängen?
genau das ist das Problem. Ich habe hier (noch) so eine uralte Gurke als SMTP-Gateway, die ebenfalls ewig fürs Laden der aktualisierten DB benötigt. Und dabei tritt genau dieser Fehler auf.
Gruß Markus
Am 2019-08-31 17:10, schrieb Markus Winkler:
Hi Thomas,
On 31.08.19 14:42, tbarth@txbweb.de wrote:
Fast zeitlich wurde im Hintergrund die Clamav-Database geladen. Kann das vielleicht damit zusammenhängen?
genau das ist das Problem. Ich habe hier (noch) so eine uralte Gurke als SMTP-Gateway, die ebenfalls ewig fürs Laden der aktualisierten DB benötigt. Und dabei tritt genau dieser Fehler auf.
Hm, so alt ist der Server bei mir jetzt nicht. Es ist ein virtueller Server mit Debian Buster und 100% SSD, mit 6 Kernen (Intel(R) Xeon(R) CPU E5-2630 v4 @ 2.20GHz) und 16 GB Arbeitsspeicher und hat kaum was zu tun.
Besteht vielleicht die Möglichkeit, irgendwo bei Postfix den Timeout auf 3 Minuten zu erhöhen? Ich habe die gleiche Frage auch in der Clamav-Mailingliste gestellt. Es stellte sich heraus, dass für dieses Problem, das offensichtlich von Clamav verursacht wird, seit 5 Jahren! ein Patch existiert, der aber noch nicht in die Version implementiert wurde. Ein Kommentar dazu von einem der Entwickler:
Micah Snyder 2019-08-22 14:38:59 EDT We are not actively working on this, though it is on our list. (https://bugzilla.clamav.net/show_bug.cgi?id=10979)
Am 31.08.2019 um 18:21 schrieb tbarth@txbweb.de:
Am 2019-08-31 17:10, schrieb Markus Winkler:
Hi Thomas,
On 31.08.19 14:42, tbarth@txbweb.de wrote:
Fast zeitlich wurde im Hintergrund die Clamav-Database geladen. Kann das vielleicht damit zusammenhängen?
genau das ist das Problem. Ich habe hier (noch) so eine uralte Gurke als SMTP-Gateway, die ebenfalls ewig fürs Laden der aktualisierten DB benötigt. Und dabei tritt genau dieser Fehler auf.
Hm, so alt ist der Server bei mir jetzt nicht. Es ist ein virtueller Server mit Debian Buster und 100% SSD, mit 6 Kernen (Intel(R) Xeon(R) CPU E5-2630 v4 @ 2.20GHz) und 16 GB Arbeitsspeicher und hat kaum was zu tun.
Besteht vielleicht die Möglichkeit, irgendwo bei Postfix den Timeout auf 3 Minuten zu erhöhen?
Wir gaben damit auch schon gekämpft und konnten mit Änderungen an den Timeouts leider keine Verbesserungen erzielen. Aber da bei uns 99,9% von Spam und Malware nicht von den Standarddatenbanken von ClamAV sondern mit den Signaturen von SaneSecurity erkannt werden haben wir uns dazu entschieden die Standarddatenbanken raus zu nehmen. Das hat die Ladezeit deutlich reduziert, und wir haben's bisher nicht bereit.
Am 2019-09-01 15:40, schrieb Alex JOST:
Am 31.08.2019 um 18:21 schrieb tbarth@txbweb.de:
Besteht vielleicht die Möglichkeit, irgendwo bei Postfix den Timeout auf 3 Minuten zu erhöhen?
Wir gaben damit auch schon gekämpft und konnten mit Änderungen an den Timeouts leider keine Verbesserungen erzielen. Aber da bei uns 99,9% von Spam und Malware nicht von den Standarddatenbanken von ClamAV sondern mit den Signaturen von SaneSecurity erkannt werden haben wir uns dazu entschieden die Standarddatenbanken raus zu nehmen. Das hat die Ladezeit deutlich reduziert, und wir haben's bisher nicht bereit.
Und Standarddatenbanken herausnehmen heißt, dass ich sie sozusagen aus einer Config-Datei austragen muss oder löschen? In den beiden Configs /etc/clamav/clamd.conf /etc/clamav/freshclam.conf sehe ich allerdings keine Verweise auf diese Datenbanken.
Es besteht aber seit heute wieder Hoffnung, dass dieser Patch, der das Laden der Datenbanken im Hintergrund ermöglichen soll, doch noch in eine Clamav-Version seinen Weg finden wird. Ich hatte mich in der Clamav-Mailingliste noch erkundigt, wie denn dieser Patch anzuwenden sei. Daraufhin folgte eine sehr ausführliche Erklärung, die zeigte, wie kompliziert die Anwendung doch ist. Dann meldete sich Joel von cisco.com:
"Alright. I think we’ve beat the proverbial dead horse here. The devs know this is a request and they will get it into their dev queue for examination. "
:-)
Am 01.09.2019 um 21:51 schrieb tbarth@txbweb.de:
Am 2019-09-01 15:40, schrieb Alex JOST:
Am 31.08.2019 um 18:21 schrieb tbarth@txbweb.de:
Besteht vielleicht die Möglichkeit, irgendwo bei Postfix den Timeout auf 3 Minuten zu erhöhen?
Wir gaben damit auch schon gekämpft und konnten mit Änderungen an den Timeouts leider keine Verbesserungen erzielen. Aber da bei uns 99,9% von Spam und Malware nicht von den Standarddatenbanken von ClamAV sondern mit den Signaturen von SaneSecurity erkannt werden haben wir uns dazu entschieden die Standarddatenbanken raus zu nehmen. Das hat die Ladezeit deutlich reduziert, und wir haben's bisher nicht bereit.
Und Standarddatenbanken herausnehmen heißt, dass ich sie sozusagen aus einer Config-Datei austragen muss oder löschen? In den beiden Configs /etc/clamav/clamd.conf /etc/clamav/freshclam.conf sehe ich allerdings keine Verweise auf diese Datenbanken.
ClamAV kommt mit 3 Signaturdatenbanken, die üblicherweise unter /var/lib/clamav zu finden sind: * bytecode.cvd * daily.cvd * main.cvd
Wir haben main.cvd und daily.cvd raus gelöscht. Die beiden brachten glaube ich über 150MB auf die Waage und fanden nur sehr selten etwas.
Freshclam musst du natürlich deaktivieren, damit die Datenbanken nicht gleich wieder heruntergeladen werden.
Es besteht aber seit heute wieder Hoffnung, dass dieser Patch, der das Laden der Datenbanken im Hintergrund ermöglichen soll, doch noch in eine Clamav-Version seinen Weg finden wird. Ich hatte mich in der Clamav-Mailingliste noch erkundigt, wie denn dieser Patch anzuwenden sei. Daraufhin folgte eine sehr ausführliche Erklärung, die zeigte, wie kompliziert die Anwendung doch ist. Dann meldete sich Joel von cisco.com:
"Alright. I think we’ve beat the proverbial dead horse here. The devs know this is a request and they will get it into their dev queue for examination. "
:-)
Das kann sich trotzdem noch sehr lange hinziehen, bis ein richtiger Patch entwickelt wird und dann auch tatsächlich in den Distributionen landet.
Am 2019-09-02 09:50, schrieb Alex JOST:
Am 01.09.2019 um 21:51 schrieb tbarth@txbweb.de:
Es besteht aber seit heute wieder Hoffnung, dass dieser Patch, der das Laden der Datenbanken im Hintergrund ermöglichen soll, doch noch in eine Clamav-Version seinen Weg finden wird. Ich hatte mich in der Clamav-Mailingliste noch erkundigt, wie denn dieser Patch anzuwenden sei. Daraufhin folgte eine sehr ausführliche Erklärung, die zeigte, wie kompliziert die Anwendung doch ist. Dann meldete sich Joel von cisco.com:
"Alright. I think we’ve beat the proverbial dead horse here. The devs know this is a request and they will get it into their dev queue for examination. "
:-)
Das kann sich trotzdem noch sehr lange hinziehen, bis ein richtiger Patch entwickelt wird und dann auch tatsächlich in den Distributionen landet.
Hallo Alex,
es könnte sein, dass dieser Patch bereits in die Version 0.102 eingebracht wird. Ein ehemaliger Kernentwickler fühlte sich sogar dazu berufen, den Code dafür zu entwickeln.
"Alberto Wu, a former ClamAV core developer, has very kindly provided a patch to us today that he created to perform clamd database reloads in a separate thread. I have attached his work, with some minor tweaks on my part, to the relevant Bugzilla ticket..."
Ich denke, clamav kommt aus Sicherheitsgründen schneller in die Distributionen. Ich habe vorgestern beim Systemupdate unter Debian 10.1 die Version 0.101.4 erhalten.
Gruß Thomas B
Am 13.09.2019 um 12:51 schrieb Thomas Barth:
Am 2019-09-02 09:50, schrieb Alex JOST:
Am 01.09.2019 um 21:51 schrieb tbarth@txbweb.de:
Es besteht aber seit heute wieder Hoffnung, dass dieser Patch, der das Laden der Datenbanken im Hintergrund ermöglichen soll, doch noch in eine Clamav-Version seinen Weg finden wird. Ich hatte mich in der Clamav-Mailingliste noch erkundigt, wie denn dieser Patch anzuwenden sei. Daraufhin folgte eine sehr ausführliche Erklärung, die zeigte, wie kompliziert die Anwendung doch ist. Dann meldete sich Joel von cisco.com:
"Alright. I think we’ve beat the proverbial dead horse here. The devs know this is a request and they will get it into their dev queue for examination. "
:-)
Das kann sich trotzdem noch sehr lange hinziehen, bis ein richtiger Patch entwickelt wird und dann auch tatsächlich in den Distributionen landet.
Hallo Alex,
es könnte sein, dass dieser Patch bereits in die Version 0.102 eingebracht wird. Ein ehemaliger Kernentwickler fühlte sich sogar dazu berufen, den Code dafür zu entwickeln.
"Alberto Wu, a former ClamAV core developer, has very kindly provided a patch to us today that he created to perform clamd database reloads in a separate thread. I have attached his work, with some minor tweaks on my part, to the relevant Bugzilla ticket..."
Ich denke, clamav kommt aus Sicherheitsgründen schneller in die Distributionen. Ich habe vorgestern beim Systemupdate unter Debian 10.1 die Version 0.101.4 erhalten.
Das klingt doch mal viel versprechend. :)
Hallo,
ich muss dieses Thema noch einmal aufgreifen, weil ich das Gefühl habe, dass bei meiner Konfiguration etwas nicht mehr stimmt. Ich sehe, dass clamd immer nur einen CPU-Kern zum Laden der Datenbanken benutzt. Das Laden der Datenbanken dauert hier also immer etwa 2 Minuten.
----------------- top - 16:09:43 up 23:33, 2 users, load average: 0.47, 0.13, 0.04 Tasks: 176 total, 2 running, 174 sleeping, 0 stopped, 0 zombie %Cpu0 : 0.0 us, 0.0 sy, 0.0 ni, 99.0 id, 0.0 wa, 0.0 hi, 0.0 si, 1.0 st %Cpu1 : 1.0 us, 1.0 sy, 0.0 ni, 98.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu2 : 85.4 us, 6.8 sy, 0.0 ni, 0.0 id, 0.0 wa, 0.0 hi, 0.0 si, 7.8 st %Cpu3 : 0.0 us, 0.0 sy, 0.0 ni,100.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu4 : 0.0 us, 1.0 sy, 0.0 ni, 99.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu5 : 0.0 us, 0.0 sy, 0.0 ni,100.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st MiB Mem : 16042.2 total, 14207.5 free, 813.4 used, 1021.3 buff/cache MiB Swap: 0.0 total, 0.0 free, 0.0 used. 14921.4 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 455 clamav 20 0 469352 207432 10840 R 100.0 1.3 30:33.51 /usr/sbin/clamd --foreground=true 22861 root 20 0 11316 3648 3108 R 2.0 0.0 0:24.91 top
Always 2 minute loading time Wed Sep 4 16:09:17 2019 -> Reading databases from /var/lib/clamav Wed Sep 4 16:11:24 2019 -> Database correctly reloaded (10966440 signatures) -----------------
Das Problem ist dann auch, das ich während des Ladevorgangs als authentifizierter User keine e-Mails versenden kann. Der Mailclient wartet mit einer Fortschrittsanzeige. Das war auf dem vorherigen Mailserver nicht so. Ich habe den Mailserver erst vor zwei Wochen neu aufgesetzt und weitestgehend die Konfigurationseinstellungen vom alten Server übernommen. Und ich dachte, ich hätte es so konfiguriert ist, dass die Mails von authentifizierten Usern nicht noch durch Amavis gehen. Oder es war einfach kein Problem auf dem alten Server.
Bei der geringen Auslastung müsste das Versenden einer Mail doch auch während des Ladevorgangs möglich sein, oder? Es kann doch nicht sein, dass ein Prozess den gesamten Mailverkehr blockiert.
Nun ist alles schon so lange her. Deshalb ist meine Frage, ob jemand über die Konfiguration einen Blick werfen könnte. Die meisten Einstellungen habe ich in der main.cf vorgenommen, deshalb erst die master.cf mit den vorgenommenen Einstellungen, dann die main.cf (Postfix, Dovecot, Amavis, MySQL):
/etc/postfix/master.cf smtp inet n - y - - smtpd -o smtpd_proxy_filter=localhost:10024 -o content_filter=
localhost:10025 inet n - - - - smtpd -o content_filter= -o smtpd_proxy_filter= -o smtpd_authorized_xforward_hosts=127.0.0.0/8 -o smtpd_client_restrictions= -o smtpd_helo_restrictions= -o smtpd_sender_restrictions= -o smtpd_recipient_restrictions=permit_mynetworks,reject -o smtpd_data_restrictions= -o mynetworks=127.0.0.0/8 -o receive_override_options=no_unknown_recipient_checks
/etc/postfix/main.cf smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU) biff = no
# appending .domain is the MUA's job. append_dot_mydomain = no
# Uncomment the next line to generate "delayed mail" warnings #delay_warning_time = 4h
readme_directory = no
# See http://www.postfix.org/COMPATIBILITY_README.html -- default to 2 on # fresh installs. compatibility_level = 2
# TLS parameters / Eingehende SMTP-Verbindungen smtpd_tls_loglevel = 1 smtpd_tls_security_level = may smtpd_use_tls=yes
smtpd_tls_ask_ccert = yes smtpd_tls_auth_only = no smtpd_tls_session_cache_timeout = 3600s smtpd_tls_received_header = yes
smtpd_tls_key_file = /etc/letsencrypt/live/mx2.domain.de/privkey.pem smtpd_tls_cert_file = /etc/letsencrypt/live/mx2.domain.de/fullchain.pem smtpd_tls_CAfile = /etc/ssl/certs/ca-certificates.crt smtpd_tls_protocols = !SSLv2, !SSLv3 smtpd_tls_ciphers = high smtpd_tls_dh1024_param_file = /etc/myssl/dh2048.pem smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
# TLS parameter / Ausgehende SMTP-Verbindungen smtp_tls_security_level = dane smtp_tls_note_starttls_offer = yes smtp_tls_protocols = !SSLv2, !SSLv3 smtp_tls_ciphers = high smtp_tls_CAfile = /etc/ssl/certs/ca-certificates.crt smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache
# Client #smtpd_client_connection_rate_limit = 25 #smtpd_client_connection_count_limit = 100
#tls_random_source = dev:/dev/urandom tls_random_source = /etc/mail.entropy
# DNS smtp_dns_support_level = dnssec
# SASL / Dovecot smtpd_sasl_auth_enable = yes smtpd_sasl_authenticated_header = no smtpd_sasl_path=private/auth smtpd_sasl_tls_security_options = noanonymous smtpd_sasl_type=dovecot broken_sasl_auth_clients = yes
#strict_rfc821_envelopes = yes disable_vrfy_command = yes smtpd_helo_required = yes
#Gueltige Begruessung der sendenden Server? smtpd_helo_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_invalid_helo_hostname, reject_non_fqdn_helo_hostname, reject_unknown_helo_hostname
#Bedingungen fuer sendende Server/Clients smtpd_client_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination, reject_invalid_hostname, reject_unauth_pipelining, reject_non_fqdn_sender, reject_unknown_sender_domain, reject_non_fqdn_recipient, reject_unknown_recipient_domain
smtpd_sender_restrictions =
smtpd_relay_restrictions = permit_mynetworks permit_sasl_authenticated defer_unauth_destination
#Empfaenger/Sender Adressen ueberpruefen smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, check_sender_access hash:/etc/postfix/access-sender, check_recipient_access hash:/etc/postfix/access-recipient
smtpd_restriction_classes = insiders_only insiders_only = check_sender_access hash:/etc/postfix/access-sender, reject #sender_canonical_maps = hash:/etc/postfix/canonical
milter_default_action = accept milter_protocol = 6 # opendkim, opendmarc smtpd_milters = unix:var/run/opendkim/opendkim.sock, unix:var/run/opendmarc/opendmarc.sock non_smtpd_milters = $smtpd_milters
myhostname = mx2.domain.de alias_maps = hash:/etc/aliases alias_database = hash:/etc/aliases myorigin = /etc/mailname mydestination = localhost relayhost = mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128 mailbox_size_limit = 0 message_size_limit = 104857600 recipient_delimiter = + inet_interfaces = all inet_protocols = ipv4
soft_bounce=no virtual_alias_domains = virtual_alias_maps = proxy:mysql:/etc/postfix/mysql-virtual_forwardings.cf, mysql:/etc/postfix/mysql-virtual_email2email.cf virtual_mailbox_domains = proxy:mysql:/etc/postfix/mysql-virtual_domains.cf virtual_mailbox_maps = proxy:mysql:/etc/postfix/mysql-virtual_mailboxes.cf virtual_mailbox_base = /data/virtual_mailboxes virtual_uid_maps = static:5001 virtual_gid_maps = static:5001 virtual_transport = lmtp:unix:private/dovecot-lmtp
Ist das soweit noch alles gültig?
Teilnehmer (4)
-
Alex JOST -
Markus Winkler -
tbarth＠txbweb.de -
Thomas Barth