[Postfixbuch-users] Verzögerung von 33 Sekunden

[Andreas Meyer]

Hallo Peer!

Peer Heinlein <p.heinlein at heinlein-support.de> wrote:

> Am 13.10.2013 15:06, schrieb Andreas Meyer:
> 
> 
> > Mir fällt eine regelmäßige Verzögerung von immer 33 Sekunden vom connect
> > bis zur Übergabe an 
> 
> > Kann man irgendwie analysieren, wieso diese Verzögerung auftritt?
> 
> a) In das Logfile schauen von dem, wo die Verzögerung auftritt. Also
> Amavis. Loglevel auf 3 setzen, dann stehen da alle Timings sauber drin.

Oct 13 19:17:53 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) p.path root at localhost: "P=p001,L=1,M=text/plain,T=asc"
Oct 13 19:17:53 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) presenting full original message to scanners as /var/spool/amavis/tmp/amavis-20131013T183650-20778-FYFX_iBu/parts/p002
Oct 13 19:17:53 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) run_av Using (ClamAV-clamd): (code) CONTSCAN /var/spool/amavis/tmp/amavis-20131013T183650-20778-FYFX_iBu/parts\n
Oct 13 19:17:53 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) ClamAV-clamd: Connecting to socket  /var/run/clamav/clamd-socket
Oct 13 19:17:53 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) new socket by IO::Socket::UNIX to /var/run/clamav/clamd-socket, timeout 10
Oct 13 19:17:53 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) ClamAV-clamd: Sending CONTSCAN /var/spool/amavis/tmp/amavis-20131013T183650-20778-FYFX_iBu/parts\n to socket /var/run/clamav/clamd-socket
Oct 13 19:17:53 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) rw_loop read: got eof
Oct 13 19:17:53 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) run_av (ClamAV-clamd): CLEAN
Oct 13 19:17:53 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) run_av (ClamAV-clamd) result: clean
Oct 13 19:17:53 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) calling SA parse (0), SA vers 3.3.2, 3.003002, data as STRING, recips_ind [0], user: "vscan"
Oct 13 19:18:25 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) spam_scan: score=0.779 autolearn=no tests=[ALL_TRUSTED=-1,BAYES_00=-1.9,FH_FROMEML_NOTLD=1.082,MISSING_MID=0.497,TO_MALFORMED=2.099,TVD_SPACE_RATIO=0.001] recips=0
Oct 13 19:18:25 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) do_notify_and_quar: ccat=CleanTag (1,1) ("1,1":CleanTag, "1":Clean, "0":CatchAll) ccat_block=(), qar_mth=
Oct 13 19:18:25 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) delivery method is 1, recips: root at localhost
Oct 13 19:18:25 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) dkim: candidate originators: From:<iwatch at localhost>
Oct 13 19:18:25 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) dkim: not signing, empty signing domain, From: <iwatch at localhost>
Oct 13 19:18:25 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) smtp session: setting up a new session
Oct 13 19:18:25 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) new socket using IO::Socket::INET to [127.0.0.1]:10025, timeout 35
Oct 13 19:18:25 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) smtp greeting: 220 mail.bitcorner.eu ESMTP, dt: 0.8 ms
Oct 13 19:18:25 mail.bitcorner.eu /usr/sbin/amavisd[20778]: (20778-12) smtp cmd> EHLO localhost


Vom calling SA parse bis zur Übergabe an localhost:10025 vergehen diese 33 Sekunden.
Das ist aber nicht üblich, dass der SA-check solange braucht?


> b) DNS-Timeouts? Prüfe alle DNS-Resolver aus /etc/resolv.conf und prüfe
> auch, ob die resolv.conf in einer etwaigen chroot-Umgebung noch aktuell ist.

  Andreas