Sporadische Probleme mit milter-reject

Zitat von sTeaLth

Ohje, sehe gerade das hier 2018 schonmal jemand das Problem geschildert hat.

kk Den "kritischen Bug" aus 2018 der den ClamAV zum Absturz bringt können wir wohl ausschließen, außer es gab aktuell wieder einen.
Evtl. kann mein Post aber dann weg und ich Antworte / Frage unter dem alten Thread nochmal!?!?

Schau mal im Log nach sowas wie "ERROR: Timed out while reading clamd reply"

Wenn die Datenbanken von ClamAV nicht sauber geladen wurden (z.B. ein File korrupt) dann knallt der milter an die Wand.
Ist im Regelfall (sofern man auch den Milter restartet) beim nächsten Update der Daten dann auch erledigt.

Gruß Ralf

# /etc/systemd/system/clamav-daemon.service.d/clamav_restart.conf
[Service]
Restart=always

Danach ein "systemctl daemon-reload; systemctl restart clamav-daemon" und clamav wird automatisch neu gestartet.

Bei mir tritt seit Februar exakt dasselbe Problem auf (Debian 11). Das Problem scheint immer kurz nach dem Update der Virendatenbank aufzutreten.
Ich habe lediglich clamav installiert und in LiveConfig den Haken rein gemacht.

Es kommt dann immer die "milter-reject: END-OF-MESSAGE from" Meldung in mail.log und Postfix versendet keine E-mails und empfängt auch keine. In den clamav-Logfiles kommt:

1) clamav.log:
Tue Apr 11 08:34:25 2023 -> SelfCheck: Database status OK.
Tue Apr 11 09:34:39 2023 -> SelfCheck: Database status OK.
Tue Apr 11 10:02:05 2023 -> Reading databases from /var/lib/clamav
Tue Apr 11 10:02:58 2023 -> Database correctly reloaded (8661648 signatures)
Tue Apr 11 10:02:58 2023 -> Activating the newly loaded database...
Tue Apr 11 10:34:31 2023 -> Client disconnected (FD 9)
Tue Apr 11 10:34:31 2023 -> Client disconnected (FD 10)
Tue Apr 11 10:34:31 2023 -> Client disconnected (FD 11)
Tue Apr 11 10:34:31 2023 -> Client disconnected (FD 12)

2) clamav-milter.log:
Tue Apr 11 10:05:06 2023 -> ERROR: Timed out while reading clamd reply
Tue Apr 11 10:05:06 2023 -> ERROR: No reply from clamd
Tue Apr 11 10:05:16 2023 -> ERROR: Timed out while reading clamd reply
Tue Apr 11 10:05:16 2023 -> ERROR: No reply from clamd
Tue Apr 11 10:05:36 2023 -> ERROR: Timed out while reading clamd reply
Tue Apr 11 10:05:36 2023 -> ERROR: No reply from clamd

ein wenig später folgt:
Tue Apr 11 10:15:53 2023 -> ERROR: Failed to initiate streaming/fdpassing
Tue Apr 11 10:15:53 2023 -> WARNING: No clamd server appears to be available
Tue Apr 11 10:15:58 2023 -> ERROR: Failed to initiate streaming/fdpassing
Tue Apr 11 10:15:58 2023 -> WARNING: No clamd server appears to be available
Tue Apr 11 10:15:59 2023 -> ERROR: Failed to initiate streaming/fdpassing

3) freshclam.log:
Tue Apr 11 10:01:36 2023 -> daily database available for update (local version: 26871, remote version: 26872)
Tue Apr 11 10:01:50 2023 -> Testing database: '/var/lib/clamav/tmp.e5d96d1992/clamav-b8b9027196e7c225d606da08a47c5692.tmp-daily.cld' ...
Tue Apr 11 10:02:04 2023 -> Database test passed.
Tue Apr 11 10:02:04 2023 -> daily.cld updated (version: 26872, sigs: 2029730, f-level: 90, builder: raynman)
Tue Apr 11 10:02:04 2023 -> main.cvd database is up-to-date (version: 62, sigs: 6647427, f-level: 90, builder: sigmgr)
Tue Apr 11 10:02:04 2023 -> bytecode.cld database is up-to-date (version: 334, sigs: 91, f-level: 90, builder: anvilleg)
Tue Apr 11 10:02:05 2023 -> Clamd successfully notified about the update.
Tue Apr 11 10:02:05 2023 -> --------------------------------------
Tue Apr 11 11:02:05 2023 -> Received signal: wake up
Tue Apr 11 11:02:05 2023 -> ClamAV update process started at Tue Apr 11 11:02:05 2023
Tue Apr 11 11:02:05 2023 -> daily.cld database is up-to-date (version: 26872, sigs: 2029730, f-level: 90, builder: raynman)
Tue Apr 11 11:02:05 2023 -> main.cvd database is up-to-date (version: 62, sigs: 6647427, f-level: 90, builder: sigmgr)
Tue Apr 11 11:02:05 2023 -> bytecode.cld database is up-to-date (version: 334, sigs: 91, f-level: 90, builder: anvilleg)
Tue Apr 11 11:02:05 2023 -> --------------------------------------
Tue Apr 11 12:02:05 2023 -> Received signal: wake up
Tue Apr 11 12:02:05 2023 -> ClamAV update process started at Tue Apr 11 12:02:05 2023

Das sind meine Konfigurationen:

1) clamd.conf:
LocalSocket /var/run/clamav/clamd.ctl
FixStaleSocket true
LocalSocketGroup clamav
LocalSocketMode 666
# TemporaryDirectory is not set to its default /tmp here to make overriding
# the default with environment variables TMPDIR/TMP/TEMP possible
User clamav
ScanMail true
ScanArchive true
ArchiveBlockEncrypted false
MaxDirectoryRecursion 15
FollowDirectorySymlinks false
FollowFileSymlinks false
ReadTimeout 180
MaxThreads 12
MaxConnectionQueueLength 15
LogSyslog false
LogRotate true
LogFacility LOG_LOCAL6
LogClean false
LogVerbose true
PreludeEnable no
PreludeAnalyzerName ClamAV
DatabaseDirectory /var/lib/clamav
OfficialDatabaseOnly false
SelfCheck 3600
Foreground false
Debug false
ScanPE true
MaxEmbeddedPE 10M
ScanOLE2 true
ScanPDF true
ScanHTML true
MaxHTMLNormalize 10M
MaxHTMLNoTags 2M
MaxScriptNormalize 5M
MaxZipTypeRcg 1M
ScanSWF true
ExitOnOOM false
LeaveTemporaryFiles false
AlgorithmicDetection true
ScanELF true
IdleTimeout 30
CrossFilesystems true
PhishingSignatures true
PhishingScanURLs true
PhishingAlwaysBlockSSLMismatch false
PhishingAlwaysBlockCloak false
PartitionIntersection false
DetectPUA false
ScanPartialMessages false
HeuristicScanPrecedence false
StructuredDataDetection false
CommandReadTimeout 30
SendBufTimeout 200
MaxQueue 100
ExtendedDetectionInfo true
OLE2BlockMacros false
AllowAllMatchScan true
ForceToDisk false
DisableCertCheck false
DisableCache false
MaxScanTime 120000
MaxScanSize 100M
MaxFileSize 25M
MaxRecursion 16
MaxFiles 10000
MaxPartitions 50
MaxIconsPE 100
PCREMatchLimit 10000
PCRERecMatchLimit 5000
PCREMaxFileSize 25M
ScanXMLDOCS true
ScanHWP3 true
MaxRecHWP3 16
StreamMaxLength 25M
LogFile /var/log/clamav/clamav.log
LogTime true
LogFileUnlock false
LogFileMaxSize 0
Bytecode true
BytecodeSecurity TrustSigned
BytecodeTimeout 60000
OnAccessMaxFileSize 5M
ConcurrentDatabaseReload yes

2) clamav-milter.conf:
MilterSocket /var/run/clamav/clamav-milter.ctl
FixStaleSocket true
User clamav
ReadTimeout 120
Foreground false
PidFile /var/run/clamav/clamav-milter.pid
ClamdSocket unix:/var/run/clamav/clamd.ctl
OnClean Accept
OnInfected Reject
OnFail Defer
AddHeader Replace
LogSyslog false
LogFacility LOG_LOCAL6
LogVerbose false
LogInfected Off
LogClean Off
LogRotate true
MaxFileSize 25M
SupportMultipleRecipients false
TemporaryDirectory /tmp
LogFile /var/log/clamav/clamav-milter.log
LogTime true
LogFileUnlock false
LogFileMaxSize 1M
MilterSocketGroup clamav
MilterSocketMode 666
RejectMsg Rejecting harmful email: %v found.

3) freshclam.conf:
DatabaseOwner clamav
UpdateLogFile /var/log/clamav/freshclam.log
LogVerbose false
LogSyslog false
LogFacility LOG_LOCAL6
LogFileMaxSize 0
LogRotate true
LogTime true
Foreground false
Debug false
MaxAttempts 5
DatabaseDirectory /var/lib/clamav
DNSDatabaseInfo current.cvd.clamav.net
ConnectTimeout 30
ReceiveTimeout 0
TestDatabases yes
ScriptedUpdates yes
CompressLocalDatabase no
Bytecode true
NotifyClamd /etc/clamav/clamd.conf
# Check for new database 24 times a day
Checks 24
DatabaseMirror db.local.clamav.net
DatabaseMirror database.clamav.net

Hat irgendwer eine Idee wie man das Problem in den Griff bekommt? So ist das nicht benutzbar. Mal ist der Mailserver für 0,5h weg, mal für 5-6h. Mit dem Monitoring bemerkt man das nicht, weil der Dienst ja verfügbar ist.

Vielen Dank schon mal!

Das Problem hatte ich auch schon, lag bei mir am Greylisting.

Greylisting deaktiviert, lief wieder alles normal.

Hallo Sven,
Ja, die milter_reject Meldung im mail.log erscheint natürlich bei Aussetzern sämtlicher Milter. Bei mir ist es klar der Clamav, und das nur kurz nach dem Downloaden neuer Virendaten. Mal eine halbe Stunde, mal Stunden. Greylisting funktioniert bei mir. Wenn ich hingegen Clamav deaktiviere in LiveConfig, läuft ebenso alles. Also bei mir ist es exakt so wie im Eingangsposting beschrieben.
Wenn irgendwer eine Lösung hätte, wäre ich sehr verbunden. Aktuelle Updates sind natürlich eingespielt...

IT-Worker, läuft bei dir der Spamassassin?

Zitat von Sven_67

IT-Worker, läuft bei dir der Spamassassin?

Ja, der läuft gut. Es kommen auch die Fehler nur in den clamav-logs (und natürlich im mail.log - Ausschnitte aus den Logs siehe oben). Aber leider nicht mit dem Hinweis woran es liegt dass Clamav nicht verfügbar ist Wenn ich Clamav ausschalte in LiveConfig läuft auch alles einwandfrei. Auch wenn Spamassassin, Blacklists, Greylisting und DKIM eingeschaltet sind in LiveConfig.
In der /var/run ist clamav übrigens vorhanden. Es scheitert nur bei den Updates bzw. kurz danach. Aber ich finde nicht heraus was genau schief läuft.

Ich habe es schon mit "ConcurrentDatabaseReload yes" und "no" versucht, ob das einen Unterschied macht, aber das ändert leider gar nichts. Damit bin ich leider völlig ratlos und habe jetzt kurzerhand Clamav mal deaktiviert, um weitere Ausfälle zu vermeiden. Aber Dauerzustand kann das natürlich auch nicht sein.

Wie viel RAM hat denn der betroffene Server?

Zitat von kk

Wie viel RAM hat denn der betroffene Server?

8GB Ram, 4GB Swap.
In der kern.log finde ich um den Updatezeitpunkt (also wenn das Problem auftaucht) keinerlei Hinweise darauf dass der Maschine das Ram ausgehen würde.

Und sonst läuft Clamav ja auch. Nur nach den Updates treten zeitweise diese Probleme auf.

Meine Erfahrungen mit zu wenig Ram bei Clamav ist, dass dann auch die ctl-Datei in der /var/run/clamav/ nicht geschrieben wird. Die gibt es aber. Aber ich könnte jetzt nicht sagen, ob bei zu wenig Ram auch entsprechende log-Einträge in den clamav-Logs und in der kern.log erscheinen. Aber davon wäre eigentlich auszugehen, oder?