[postfix-users] Delay bei internen zustellen der Mails
Hallo zusammen
Ich habe das Problem, dass wenn ich auf dem Server eine Email an eine interne Email-Adresse schicke, diese mehr als 10 Sekunden braucht bis sie zugestellt wird. In diesem Fall sogar 13 Sekunden. Ich kann nicht nachvollziehen was in der Zeit zwischen 14:55:04 bis 14:55:17 genau passiert. Kann ich das irrgendwie loggen?
Feb 14 14:55:04 server postfix/pickup[25160]: B677326C073: uid=0 from=absender@meinserver.com Feb 14 14:55:04 server postfix/cleanup[26859]: B677326C073: message-id=1360850104.26850@meinserver.com Feb 14 14:55:04 server postfix/qmgr[25161]: B677326C073: from=absender@meinserver.com, size=584, nrcpt=1 (queue active) Feb 14 14:55:17 server spamd[21339]: spamd: connection from localhost [127.0.0.1] at port 56744 Feb 14 14:55:17 server spamd[21339]: spamd: setuid to mathias succeeded Feb 14 14:55:17 server spamd[21339]: spamd: processing message 1360850104.26850@meinserver.com for benutzer:500 Feb 14 14:55:17 server spamd[21339]: spamd: clean message (-101.5/2.0) for benutzer:500 in 0.1 seconds, 942 bytes. Feb 14 14:55:17 server spamd[21339]: spamd: result: . -101 - AWL,BAYES_00,RDNS_NONE,USER_IN_WHITELIST scantime=0.1,size=942,user=benutzer,uid=500,required_score=2.0,rhost=localhost,raddr=127.0.0.1,rport=56744,mid=1360850104.26850@meinserver.com,bayes=0.000012,autolearn=no Feb 14 14:55:17 server spamd[21334]: prefork: child states: II Feb 14 14:55:17 server postfix/local[26863]: B677326C073: to=benutzer@mail.meinserver.com, orig_to=benutzer@meinserver.com, relay=local, delay=13, delays=0.32/0.01/0/13, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail -a "$EXTENSION") Feb 14 14:55:17 server postfix/qmgr[25161]: B677326C073: removed
Gruss Mathias
Am 14.02.2013 15:02, schrieb Mathias Betschart:
Hallo zusammen
Ich habe das Problem, dass wenn ich auf dem Server eine Email an eine interne Email-Adresse schicke, diese mehr als 10 Sekunden braucht bis sie zugestellt wird. In diesem Fall sogar 13 Sekunden. Ich kann nicht nachvollziehen was in der Zeit zwischen 14:55:04 bis 14:55:17 genau passiert. Kann ich das irrgendwie loggen?
Feb 14 14:55:04 server postfix/pickup[25160]: B677326C073: uid=0 from=absender@meinserver.com Feb 14 14:55:04 server postfix/cleanup[26859]: B677326C073: message-id=1360850104.26850@meinserver.com Feb 14 14:55:04 server postfix/qmgr[25161]: B677326C073: from=absender@meinserver.com, size=584, nrcpt=1 (queue active) Feb 14 14:55:17 server spamd[21339]: spamd: connection from localhost [127.0.0.1] at port 56744 Feb 14 14:55:17 server spamd[21339]: spamd: setuid to mathias succeeded Feb 14 14:55:17 server spamd[21339]: spamd: processing message 1360850104.26850@meinserver.com for benutzer:500 Feb 14 14:55:17 server spamd[21339]: spamd: clean message (-101.5/2.0) for benutzer:500 in 0.1 seconds, 942 bytes. Feb 14 14:55:17 server spamd[21339]: spamd: result: . -101 - AWL,BAYES_00,RDNS_NONE,USER_IN_WHITELIST scantime=0.1,size=942,user=benutzer,uid=500,required_score=2.0,rhost=localhost,raddr=127.0.0.1,rport=56744,mid=1360850104.26850@meinserver.com,bayes=0.000012,autolearn=no Feb 14 14:55:17 server spamd[21334]: prefork: child states: II Feb 14 14:55:17 server postfix/local[26863]: B677326C073: to=benutzer@mail.meinserver.com, orig_to=benutzer@meinserver.com, relay=local, delay=13, delays=0.32/0.01/0/13, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail -a "$EXTENSION") Feb 14 14:55:17 server postfix/qmgr[25161]: B677326C073: removed
Gruss Mathias
postfix-users mailing list postfix-users@de.postfix.org http://de.postfix.org/cgi-bin/mailman/listinfo/postfix-users
wie uebergibst du die mail an spamd ?
Best Regards MfG Robert Schetterer
Zitat von Robert Schetterer rs@sys4.de:
Am 14.02.2013 15:02, schrieb Mathias Betschart:
Hallo zusammen
Ich habe das Problem, dass wenn ich auf dem Server eine Email an eine interne Email-Adresse schicke, diese mehr als 10 Sekunden braucht bis sie zugestellt wird. In diesem Fall sogar 13 Sekunden. Ich kann nicht nachvollziehen was in der Zeit zwischen 14:55:04 bis 14:55:17 genau passiert. Kann ich das irrgendwie loggen?
Feb 14 14:55:04 server postfix/pickup[25160]: B677326C073: uid=0 from=absender@meinserver.com Feb 14 14:55:04 server postfix/cleanup[26859]: B677326C073: message-id=1360850104.26850@meinserver.com Feb 14 14:55:04 server postfix/qmgr[25161]: B677326C073: from=absender@meinserver.com, size=584, nrcpt=1 (queue active) Feb 14 14:55:17 server spamd[21339]: spamd: connection from localhost [127.0.0.1] at port 56744 Feb 14 14:55:17 server spamd[21339]: spamd: setuid to mathias succeeded Feb 14 14:55:17 server spamd[21339]: spamd: processing message 1360850104.26850@meinserver.com for benutzer:500 Feb 14 14:55:17 server spamd[21339]: spamd: clean message (-101.5/2.0) for benutzer:500 in 0.1 seconds, 942 bytes. Feb 14 14:55:17 server spamd[21339]: spamd: result: . -101 - AWL,BAYES_00,RDNS_NONE,USER_IN_WHITELIST scantime=0.1,size=942,user=benutzer,uid=500,required_score=2.0,rhost=localhost,raddr=127.0.0.1,rport=56744,mid=1360850104.26850@meinserver.com,bayes=0.000012,autolearn=no Feb 14 14:55:17 server spamd[21334]: prefork: child states: II Feb 14 14:55:17 server postfix/local[26863]: B677326C073: to=benutzer@mail.meinserver.com, orig_to=benutzer@meinserver.com, relay=local, delay=13, delays=0.32/0.01/0/13, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail -a "$EXTENSION") Feb 14 14:55:17 server postfix/qmgr[25161]: B677326C073: removed
Gruss Mathias
postfix-users mailing list postfix-users@de.postfix.org http://de.postfix.org/cgi-bin/mailman/listinfo/postfix-users
wie uebergibst du die mail an spamd ?
Best Regards MfG Robert Schetterer
-- [*] sys4 AG
http://sys4.de, +49 (89) 30 90 46 64 Franziskanerstraße 15, 81669 München
Eventuell IP-Versions Mismatch? Postfix bevorzugt IPv6 auch zu "localhost" und falls Postfix nicht IPv4 only konfiguriert oder spamd nicht auch IPv6 kann, dann kann es schon mal dauern bis man sich begegnet. Prüfen ob der Content Filter mit "localhost" oder mit [127.0.0.1] definiert ist.
Gruß
Andreas
Hallo zusammen
Ich habe das Problem, dass wenn ich auf dem Server eine Email an eine interne Email-Adresse schicke, diese mehr als 10 Sekunden braucht bis sie zugestellt wird. In diesem Fall sogar 13 Sekunden. Ich kann nicht nachvollziehen was in der Zeit zwischen 14:55:04 bis 14:55:17 genau passiert. Kann ich das irrgendwie loggen?
Feb 14 14:55:04 server postfix/pickup[25160]: B677326C073: uid=0 from=absender@meinserver.com Feb 14 14:55:04 server postfix/cleanup[26859]: B677326C073: message-id=1360850104.26850@meinserver.com Feb 14 14:55:04 server postfix/qmgr[25161]: B677326C073: from=absender@meinserver.com, size=584, nrcpt=1 (queue active) Feb 14 14:55:17 server spamd[21339]: spamd: connection from localhost [127.0.0.1] at port 56744 Feb 14 14:55:17 server spamd[21339]: spamd: setuid to mathias succeeded Feb 14 14:55:17 server spamd[21339]: spamd: processing message 1360850104.26850@meinserver.com for benutzer:500 Feb 14 14:55:17 server spamd[21339]: spamd: clean message (-101.5/2.0) for benutzer:500 in 0.1 seconds, 942 bytes. Feb 14 14:55:17 server spamd[21339]: spamd: result: . -101 - AWL,BAYES_00,RDNS_NONE,USER_IN_WHITELIST scantime=0.1,size=942,user=benutzer,uid=500,required_score=2.0,rhost=localhost,raddr=127.0.0.1,rport=56744,mid=1360850104.26850@meinserver.com,bayes=0.000012,autolearn=no Feb 14 14:55:17 server spamd[21334]: prefork: child states: II Feb 14 14:55:17 server postfix/local[26863]: B677326C073: to=benutzer@mail.meinserver.com, orig_to=benutzer@meinserver.com, relay=local, delay=13, delays=0.32/0.01/0/13, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail -a "$EXTENSION") Feb 14 14:55:17 server postfix/qmgr[25161]: B677326C073: removed
Gruss Mathias
postfix-users mailing list postfix-users@de.postfix.org http://de.postfix.org/cgi-bin/mailman/listinfo/postfix-users
wie uebergibst du die mail an spamd ?
Best Regards MfG Robert Schetterer
-- [*] sys4 AG
http://sys4.de, +49 (89) 30 90 46 64 Franziskanerstraße 15, 81669 München
Eventuell IP-Versions Mismatch? Postfix bevorzugt IPv6 auch zu "localhost" und falls Postfix nicht IPv4 only konfiguriert oder spamd nicht auch IPv6 kann, dann kann es schon mal dauern bis man sich begegnet. Prüfen ob der Content Filter mit "localhost" oder mit [127.0.0.1] definiert ist.
Gruß
Andreas
Meine master.cf hat diesen Eintrag: localhost:10025 inet n - n - - smtpd -o content_filter=
Habe heute localhost mit [127.0.0.1] gewechselt. Hat aber nicht gebracht. Kann man nicht sehen (debuggen) was nach "(queue active)" bis "spamd: connection from localhost [127.0.0.1] at port 56744" geschieht? Mit "smtpd -v" sehe ich nichts.
* Mathias Betschart mbetschart_ch@yahoo.de:
Hallo zusammen
Ich habe das Problem, dass wenn ich auf dem Server eine Email an eine interne Email-Adresse schicke, diese mehr als 10 Sekunden braucht bis sie zugestellt wird. In diesem Fall sogar 13 Sekunden. Ich kann nicht nachvollziehen was in der Zeit zwischen 14:55:04 bis 14:55:17 genau passiert. Kann ich das irrgendwie loggen?
Feb 14 14:55:04 server postfix/pickup[25160]: B677326C073: uid=0 from=absender@meinserver.com Feb 14 14:55:04 server postfix/cleanup[26859]: B677326C073: message-id=1360850104.26850@meinserver.com Feb 14 14:55:04 server postfix/qmgr[25161]: B677326C073: from=absender@meinserver.com, size=584, nrcpt=1 (queue active) Feb 14 14:55:17 server spamd[21339]: spamd: connection from localhost [127.0.0.1] at port 56744 Feb 14 14:55:17 server spamd[21339]: spamd: setuid to mathias succeeded Feb 14 14:55:17 server spamd[21339]: spamd: processing message 1360850104.26850@meinserver.com for benutzer:500 Feb 14 14:55:17 server spamd[21339]: spamd: clean message (-101.5/2.0) for benutzer:500 in 0.1 seconds, 942 bytes. Feb 14 14:55:17 server spamd[21339]: spamd: result: . -101 - AWL,BAYES_00,RDNS_NONE,USER_IN_WHITELIST scantime=0.1,size=942,user=benutzer,uid=500,required_score=2.0,rhost=localhost,raddr=127.0.0.1,rport=56744,mid=1360850104.26850@meinserver.com,bayes=0.000012,autolearn=no Feb 14 14:55:17 server spamd[21334]: prefork: child states: II Feb 14 14:55:17 server postfix/local[26863]: B677326C073: to=benutzer@mail.meinserver.com, orig_to=benutzer@meinserver.com, relay=local, delay=13, delays=0.32/0.01/0/13, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail -a "$EXTENSION") Feb 14 14:55:17 server postfix/qmgr[25161]: B677326C073: removed
Du rufst spamd aus /usr/bin/procmail auf, das dauert 13s Steht da sogar im timing:
delay=13, delays=0.32/0.01/0/13
Hallo zusammen
Ich habe das Problem, dass wenn ich auf dem Server eine Email an eine interne Email-Adresse schicke, diese mehr als 10 Sekunden braucht bis sie zugestellt wird. In diesem Fall sogar 13 Sekunden. Ich kann nicht nachvollziehen was in der Zeit zwischen 14:55:04 bis 14:55:17 genau passiert. Kann ich das irrgendwie loggen?
Feb 14 14:55:04 server postfix/pickup[25160]: B677326C073: uid=0 from=absender@meinserver.com Feb 14 14:55:04 server postfix/cleanup[26859]: B677326C073: message-id=1360850104.26850@meinserver.com Feb 14 14:55:04 server postfix/qmgr[25161]: B677326C073: from=absender@meinserver.com, size=584, nrcpt=1 (queue active) Feb 14 14:55:17 server spamd[21339]: spamd: connection from localhost [127.0.0.1] at port 56744 Feb 14 14:55:17 server spamd[21339]: spamd: setuid to mathias succeeded Feb 14 14:55:17 server spamd[21339]: spamd: processing message 1360850104.26850@meinserver.com for benutzer:500 Feb 14 14:55:17 server spamd[21339]: spamd: clean message (-101.5/2.0) for benutzer:500 in 0.1 seconds, 942 bytes. Feb 14 14:55:17 server spamd[21339]: spamd: result: . -101 - AWL,BAYES_00,RDNS_NONE,USER_IN_WHITELIST scantime=0.1,size=942,user=benutzer,uid=500,required_score=2.0,rhost=localhost,raddr=127.0.0.1,rport=56744,mid=1360850104.26850@meinserver.com,bayes=0.000012,autolearn=no Feb 14 14:55:17 server spamd[21334]: prefork: child states: II Feb 14 14:55:17 server postfix/local[26863]: B677326C073: to=benutzer@mail.meinserver.com, orig_to=benutzer@meinserver.com, relay=local, delay=13, delays=0.32/0.01/0/13, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail -a "$EXTENSION") Feb 14 14:55:17 server postfix/qmgr[25161]: B677326C073: removed
Du rufst spamd aus /usr/bin/procmail auf, das dauert 13s Steht da sogar im timing:
delay=13, delays=0.32/0.01/0/13
Tatsächlich ist das so. Habe mal in der "main.cf" Datei die Zeile mailbox_command = /usr/bin/procmail -a "$EXTENSION" auskommentiert und die Mails gehen in Windeseile in die Postfächer.
Jetzt stehe ich aber immer noch vor dem gleichen Problem. Wo trödelt das Mail herum nachdem procmail aufgerufen wurde. Vielleicht finde ich eine debug oder Logfile Einstellung.
* Mathias Betschart mbetschart_ch@yahoo.de:
Tatsächlich ist das so. Habe mal in der "main.cf" Datei die Zeile mailbox_command = /usr/bin/procmail -a "$EXTENSION" auskommentiert und die Mails gehen in Windeseile in die Postfächer.
Vorher hat procmail die zustellung korrekt gemacht. Nach Deaktivierung wird die Mail irgendwo hingeschrieben
Jetzt stehe ich aber immer noch vor dem gleichen Problem. Wo trödelt das Mail herum nachdem procmail aufgerufen wurde. Vielleicht finde ich eine debug oder Logfile Einstellung.
Aktuelle Logs?
* Ralf Hildebrandt r@sys4.de:
- Mathias Betschart mbetschart_ch@yahoo.de:
Tatsächlich ist das so. Habe mal in der "main.cf" Datei die Zeile mailbox_command = /usr/bin/procmail -a "$EXTENSION" auskommentiert und die Mails gehen in Windeseile in die Postfächer.
Vorher hat procmail die zustellung korrekt gemacht. Nach Deaktivierung wird die Mail irgendwo hingeschrieben
Jetzt stehe ich aber immer noch vor dem gleichen Problem. Wo trödelt das Mail herum nachdem procmail aufgerufen wurde.
na im spamd
Tatsächlich ist das so. Habe mal in der "main.cf" Datei die Zeile mailbox_command = /usr/bin/procmail -a "$EXTENSION" auskommentiert und die Mails gehen in Windeseile in die Postfächer.
Vorher hat procmail die zustellung korrekt gemacht. Nach Deaktivierung wird die Mail irgendwo hingeschrieben
Jetzt stehe ich aber immer noch vor dem gleichen Problem. Wo trödelt das Mail herum nachdem procmail aufgerufen wurde.
na im spamd
Habe nun mal im spamd (SPAMD_ARGS="-d -x -c -L -D") die debug Funktion eingeschaltet. Aber wo sehe ich die Zeit zweischen 20:37:18 bis 20:37:29 ? Kann man irrgendwie sehen wie lange Postfix braucht die die Realtime Blacklist abzufragen? da ich einige abfrage, kann es sein, dass dort die meiste Zeit verloren geht.
Feb 15 20:37:18 server postfix/pickup[27237]: 6FA4726C070: uid=0 from=absender@meinserver.com Feb 15 20:37:18 server postfix/cleanup[30061]: 6FA4726C070: message-id=1360957038.30055@meinserver.com Feb 15 20:37:18 server postfix/qmgr[15753]: 6FA4726C070: from=absender@meinserver.com, size=584, nrcpt=1 (queue active) Feb 15 20:37:29 server spamd[30013]: prefork: ordered 30015 to accept Feb 15 20:37:29 server spamd[30013]: prefork: sysread(7) not ready, wait max 300 secs Feb 15 20:37:29 server spamd[30013]: prefork: child 30015: entering state 2 Feb 15 20:37:29 server spamd[30015]: spamd: connection from localhost [127.0.0.1] at port 38399 Feb 15 20:37:29 server spamd[30013]: prefork: new lowest idle kid: 30016 Feb 15 20:37:29 server spamd[30015]: spamd: setuid to mathias succeeded Feb 15 20:37:29 server spamd[30015]: info: user has changed Feb 15 20:37:29 server spamd[30015]: bayes: tie-ing to DB file R/O /var/spool/spamassassin/bayes_toks Feb 15 20:37:29 server spamd[30015]: bayes: tie-ing to DB file R/O /var/spool/spamassassin/bayes_seen Feb 15 20:37:29 server spamd[30015]: bayes: found bayes db version 3 Feb 15 20:37:29 server spamd[30015]: bayes: DB journal sync: last sync: 1360933333 Feb 15 20:37:29 server spamd[30015]: config: score set 2 chosen. Feb 15 20:37:29 server spamd[30015]: spamd: running as uid 500 Feb 15 20:37:29 server spamd[30015]: dns: name server: 8.8.8.8, LocalAddr: 0.0.0.0 Feb 15 20:37:29 server spamd[30015]: dns: resolver socket rx buffer size is 114688 bytes Feb 15 20:37:29 server spamd[30015]: message: main message type: multipart/mixed Feb 15 20:37:29 server spamd[30015]: spamd: processing message 1360957038.30055@meinserver.com for benutzer:500 Feb 15 20:37:29 server spamd[30015]: conf: trusted_networks are not configured; it is recommended that you configure trusted_networks manually Feb 15 20:37:29 server spamd[30015]: received-header: parsed as [ ip=83.77.173.231 rdns= helo= by= ident= envfrom= intl=0 id= auth= msa=0 ] Feb 15 20:37:29 server spamd[30015]: received-header: do not trust any hosts from here on Feb 15 20:37:29 server spamd[30015]: received-header: relay 83.77.173.231 trusted? no internal? no msa? no Feb 15 20:37:29 server spamd[30015]: metadata: X-Spam-Relays-Trusted: Feb 15 20:37:29 server spamd[30015]: metadata: X-Spam-Relays-Untrusted: [ ip=83.77.173.231 rdns= helo= by= ident= envfrom= intl=0 id= auth= msa=0 ] Feb 15 20:37:29 server spamd[30015]: metadata: X-Spam-Relays-Internal: Feb 15 20:37:29 server spamd[30015]: metadata: X-Spam-Relays-External: [ ip=83.77.173.231 rdns= helo= by= ident= envfrom= intl=0 id= auth= msa=0 ] Feb 15 20:37:29 server spamd[30015]: message: ---- MIME PARSER START ---- Feb 15 20:37:29 server spamd[30015]: message: parsing multipart, got boundary: bound1360957038 Feb 15 20:37:29 server spamd[30015]: message: found part of type text/plain, boundary: bound1360957038 Feb 15 20:37:29 server spamd[30015]: message: added part, type: text/plain Feb 15 20:37:29 server spamd[30015]: message: parsing normal part Feb 15 20:37:29 server spamd[30015]: message: ---- MIME PARSER END ---- Feb 15 20:37:29 server spamd[30015]: message: decoding other encoding type (7bit), ignoring Feb 15 20:37:29 server spamd[30015]: rules: local tests only, ignoring RBL eval Feb 15 20:37:29 server spamd[30015]: check: running tests for priority: -1000 Feb 15 20:37:29 server spamd[30015]: rules: running head tests; score so far=0 Feb 15 20:37:29 server spamd[30015]: rules: ran eval rule USER_IN_WHITELIST ======> got hit (1) Feb 15 20:37:29 server spamd[30015]: rules: running body tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running uri tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running rawbody tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running full tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running meta tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: check: running tests for priority: -950 Feb 15 20:37:29 server spamd[30015]: rules: running head tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running body tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running uri tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running rawbody tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running full tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running meta tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: check: running tests for priority: -900 Feb 15 20:37:29 server spamd[30015]: rules: running head tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running body tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running uri tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running rawbody tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running full tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running meta tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: check: running tests for priority: -400 Feb 15 20:37:29 server spamd[30015]: rules: running head tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running body tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running uri tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: plugin: Mail::SpamAssassin::Plugin::WLBLEval=HASH(0x9115cbc) implements 'check_wb_list', priority 0 Feb 15 20:37:29 server spamd[30015]: bayes: DB journal sync: last sync: 1360933333 Feb 15 20:37:29 server spamd[30015]: bayes: corpus size: nspam = 73264, nham = 13465 Feb 15 20:37:29 server spamd[30015]: bayes: score = 1.17131387712965e-05 Feb 15 20:37:29 server spamd[30015]: bayes: DB journal sync: last sync: 1360933333 Feb 15 20:37:29 server spamd[30015]: bayes: DB expiry: tokens in DB: 134013, Expiry max size: 150000, Oldest atime: 1346717594, Newest atime: 1360949986, Last expire: 1357772363, Current time: 1360957049 Feb 15 20:37:29 server spamd[30015]: bayes: untie-ing Feb 15 20:37:29 server spamd[30015]: rules: running rawbody tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running full tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: running meta tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: check: running tests for priority: 0 Feb 15 20:37:29 server spamd[30015]: rules: running head tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __TVD_MIME_CT_MM ======> got hit: "multipart/mixed" Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __CTYPE_HAS_BOUNDARY ======> got hit: "boundary" Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __CT ======> got hit: "m" Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __RDNS_NONE ======> got hit: "[ ip=83.77.173.231 rdns= " Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __LAST_UNTRUSTED_RELAY_NO_AUTH ======> got hit: "[ ip=83.77.173.231 rdns= helo= by= ident= envfrom= intl=0 id= auth= " Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __HELO_NO_DOMAIN ======> got hit: "[ ip=83.77.173.231 rdns= helo= by= ident= envfrom= intl=0 id= auth= msa=0 " Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __MISSING_REF ======> got hit: "UNSET" Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __MIME_VERSION ======> got hit: "1" Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __TOCC_EXISTS ======> got hit: "m" Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __MSOE_MID_WRONG_CASE ======> got hit: " Feb 15 20:37:29 server spamd[30015]: rules: Message-Id: " Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __HAS_X_MAILER ======> got hit: "W" Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __DOS_SINGLE_EXT_RELAY ======> got hit: "[ ip=83.77.173.231 rdns= helo= by= ident= envfrom= intl=0 id= auth= msa=0 ]" Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __HAS_RCVD ======> got hit: "b" Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __DOS_RCVD_FRI ======> got hit: " Fri, " Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __MSGID_OK_DIGITS ======> got hit: "1360957038" Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __HAS_MSGID ======> got hit: "<" Feb 15 20:37:29 server spamd[30015]: rules: " Feb 15 20:37:29 server spamd[30015]: rules: ran header rule __HAS_SUBJECT ======> got hit: "T" Feb 15 20:37:29 server spamd[30015]: spf: checking to see if the message has a Received-SPF header that we can use Feb 15 20:37:29 server spamd[30015]: spf: already checked for Received-SPF headers, proceeding with DNS based checks Feb 15 20:37:29 server spamd[30015]: spf: already checked for Received-SPF headers, proceeding with DNS based checks Feb 15 20:37:29 server spamd[30015]: spf: already checked for Received-SPF headers, proceeding with DNS based checks Feb 15 20:37:29 server spamd[30015]: spf: already checked for Received-SPF headers, proceeding with DNS based checks Feb 15 20:37:29 server spamd[30015]: rules: ran eval rule __ENV_AND_HDR_FROM_MATCH ======> got hit (1) Feb 15 20:37:29 server spamd[30015]: spf: def_whitelist_from_spf: pager@betschart.com is not in DEF_WHITELIST_FROM_SPF Feb 15 20:37:29 server spamd[30015]: spf: already checked for Received-SPF headers, proceeding with DNS based checks Feb 15 20:37:29 server spamd[30015]: spf: already checked for Received-SPF headers, proceeding with DNS based checks Feb 15 20:37:29 server spamd[30015]: spf: already checked for Received-SPF headers, proceeding with DNS based checks Feb 15 20:37:29 server spamd[30015]: rules: running body tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: rules: ran body rule __NONEMPTY_BODY ======> got hit: "T" Feb 15 20:37:29 server spamd[30015]: rules: running uri tests; score so far=-100 Feb 15 20:37:29 server spamd[30015]: eval: stock info total: 0 Feb 15 20:37:29 server spamd[30015]: rules: ran eval rule __TVD_MIME_ATT_TP ======> got hit (1) Feb 15 20:37:29 server spamd[30015]: rules: ran eval rule BAYES_00 ======> got hit (1) Feb 15 20:37:29 server spamd[30015]: rules: running rawbody tests; score so far=-102.312 Feb 15 20:37:29 server spamd[30015]: rules: ran rawbody rule __TVD_BODY ======> got hit: "Test" Feb 15 20:37:29 server spamd[30015]: rules: running full tests; score so far=-102.312 Feb 15 20:37:29 server spamd[30015]: rules: running meta tests; score so far=-102.312 Feb 15 20:37:29 server spamd[30015]: check: running tests for priority: 500 Feb 15 20:37:29 server spamd[30015]: dns: harvest_dnsbl_queries Feb 15 20:37:29 server spamd[30015]: rules: running head tests; score so far=-102.312 Feb 15 20:37:29 server spamd[30015]: rules: running body tests; score so far=-102.312 Feb 15 20:37:29 server spamd[30015]: rules: running uri tests; score so far=-102.312 Feb 15 20:37:29 server spamd[30015]: rules: running rawbody tests; score so far=-102.312 Feb 15 20:37:29 server spamd[30015]: rules: running full tests; score so far=-102.312 Feb 15 20:37:29 server spamd[30015]: rules: running meta tests; score so far=-102.312 Feb 15 20:37:29 server spamd[30015]: check: running tests for priority: 1000 Feb 15 20:37:29 server spamd[30015]: rules: running head tests; score so far=-102.212 Feb 15 20:37:29 server spamd[30015]: config: using "/home/benutzer/.spamassassin" for user state dir Feb 15 20:37:29 server spamd[30015]: locker: safe_lock: created /home/benutzer/.spamassassin/auto-whitelist.mutex Feb 15 20:37:29 server spamd[30015]: locker: safe_lock: trying to get lock on /home/benutzer/.spamassassin/auto-whitelist with 30 timeout Feb 15 20:37:29 server spamd[30015]: locker: safe_lock: link to /home/benutzer/.spamassassin/auto-whitelist.mutex: link ok Feb 15 20:37:29 server spamd[30015]: auto-whitelist: tie-ing to DB file of type DB_File R/W in /home/benutzer/.spamassassin/auto-whitelist Feb 15 20:37:29 server spamd[30015]: auto-whitelist: db-based absender@meinserver.com|ip=83.77 scores 29/73.652 Feb 15 20:37:29 server spamd[30015]: auto-whitelist: AWL active, pre-score: -102.212, autolearn score: -2.212, mean: 2.53972413793103, IP: 83.77.173.231 Feb 15 20:37:29 server spamd[30015]: auto-whitelist: add_score: new count: 30, new totscore: 71.44 Feb 15 20:37:29 server spamd[30015]: auto-whitelist: DB addr list: untie-ing and unlocking Feb 15 20:37:29 server spamd[30015]: auto-whitelist: DB addr list: file locked, breaking lock Feb 15 20:37:29 server spamd[30015]: locker: safe_unlock: unlocked /home/benutzer/.spamassassin/auto-whitelist.mutex Feb 15 20:37:29 server spamd[30015]: auto-whitelist: post auto-whitelist score: -99.8361379310345 Feb 15 20:37:29 server spamd[30015]: rules: running body tests; score so far=-99.8361379310345 Feb 15 20:37:29 server spamd[30015]: rules: running uri tests; score so far=-99.8361379310345 Feb 15 20:37:29 server spamd[30015]: rules: running rawbody tests; score so far=-99.8361379310345 Feb 15 20:37:29 server spamd[30015]: rules: running full tests; score so far=-99.8361379310345 Feb 15 20:37:29 server spamd[30015]: rules: running meta tests; score so far=-99.8361379310345 Feb 15 20:37:29 server spamd[30015]: plugin: Mail::SpamAssassin::Plugin::AutoLearnThreshold=HASH(0x8dd3084) implements 'autolearn_discriminator', priority 0 Feb 15 20:37:29 server spamd[30015]: learn: auto-learn: currently using scoreset 2, recomputing score based on scoreset 0 Feb 15 20:37:29 server spamd[30015]: learn: auto-learn: message score: -99.8361379310345, computed score for autolearn: 0.1 Feb 15 20:37:29 server spamd[30015]: learn: auto-learn? ham=0.1, spam=12, body-points=0.1, head-points=0.1, learned-points=-2.312 Feb 15 20:37:29 server spamd[30015]: learn: auto-learn? no: inside auto-learn thresholds, not considered ham or spam Feb 15 20:37:29 server spamd[30015]: check: is spam? score=-99.836 required=4.5 Feb 15 20:37:29 server spamd[30015]: check: tests=AWL,BAYES_00,RDNS_NONE,USER_IN_WHITELIST Feb 15 20:37:29 server spamd[30015]: check: subtests=__CT,__CTYPE_HAS_BOUNDARY,__DOS_DIRECT_TO_MX,__DOS_RCVD_FRI,__DOS_SINGLE_EXT_RELAY,__ENV_AND_HDR_FROM_MATCH,__HAS_MSGID,__HAS_RCVD,__HAS_SUBJECT,__HAS_X_MAILER,__HELO_NO_DOMAIN,__LAST_UNTRUSTED_RELAY_NO_AUTH,__MIME_VERSION,__MISSING_REF,__MSGID_OK_DIGITS,__MSGID_OK_HOST,__MSOE_MID_WRONG_CASE,__NAKED_TO,__NONEMPTY_BODY,__RDNS_NONE,__SANE_MSGID,__TOCC_EXISTS,__TVD_BODY,__TVD_MIME_ATT_TP,__TVD_MIME_CT_MM Feb 15 20:37:29 server spamd[30015]: spamd: clean message (-99.8/4.5) for benutzer:500 in 0.2 seconds, 1007 bytes. Feb 15 20:37:29 server spamd[30015]: spamd: result: . -99 - AWL,BAYES_00,RDNS_NONE,USER_IN_WHITELIST scantime=0.2,size=1007,user=mathias,uid=500,required_score=4.5,rhost=localhost,raddr=127.0.0.1,rport=38399,mid=1360957038.30055@betschart.com,bayes=0.000012,autolearn=no Feb 15 20:37:29 server spamd[30015]: config: copying current conf from backup Feb 15 20:37:29 server spamd[30015]: prefork: sysread(8) not ready, wait max 300 secs Feb 15 20:37:29 server spamd[30013]: prefork: child 30015: entering state 1 Feb 15 20:37:29 server spamd[30013]: prefork: new lowest idle kid: 30015 Feb 15 20:37:29 server spamd[30013]: prefork: child reports idle Feb 15 20:37:29 server spamd[30013]: prefork: child states: II Feb 15 20:37:29 server postfix/local[30065]: 6FA4726C070: to=benutzer@mail.meinserver.com, orig_to=benutzer@meinserver.com, relay=local, delay=11, delays=0.27/0.02/0/11, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail -a "$EXTENSION") Feb 15 20:37:29 server postfix/qmgr[15753]: 6FA4726C070: removed
_______________________________________________ postfix-users mailing list postfix-users@de.postfix.org http://de.postfix.org/cgi-bin/mailman/listinfo/postfix-users
* Mathias Betschart mbetschart_ch@yahoo.de:
Habe nun mal im spamd (SPAMD_ARGS="-d -x -c -L -D") die debug Funktion eingeschaltet. Aber wo sehe ich die Zeit zweischen 20:37:18 bis 20:37:29 ? Kann man irrgendwie sehen wie lange Postfix braucht die die Realtime Blacklist abzufragen? da ich einige abfrage, kann es sein, dass dort die meiste Zeit verloren geht.
Postfix macht keine Abfragen, spamd macht die.
Sieht für mich so aus als würde spamd nur am ende alles "en bloc" loggen. Ich kann dafür aber nicht meine Hand ins Feuer legen.
Man könnte das mal testen, indem man eine File mit einer Mail durchpiped.
Feb 15 20:37:29 server spamd[30015]: dns: name server: 8.8.8.8, LocalAddr: 0.0.0.0
8.8.8.8 kannst Du nicht für RBL Abfragen nutzen (der ist überall gesperrt). Nutze einen lokalen DNS Resolver!
Feb 15 20:37:29 server spamd[30015]: conf: trusted_networks are not configured; it is recommended that you configure trusted_networks manually
Sollte man auch mal ansehen
Feb 15 20:37:29 server spamd[30015]: rules: local tests only, ignoring RBL eval
Dein Setup nutzt keine RBLs
Feb 15 20:37:29 server spamd[30015]: bayes: DB expiry: tokens in DB: 134013, Expiry max size: 150000, Oldest atime: 1346717594, Newest atime: 1360949986, Last expire: 1357772363, Current time: 1360957049
Eine Bayes expire dauert ne Weile!!! Ist dein Spamd immer so langsam oder hast du hier einen konkret langsamen rausgepickt?
Postfix macht keine Abfragen, spamd macht die.
Sieht für mich so aus als würde spamd nur am ende alles "en bloc" loggen. Ich kann dafür aber nicht meine Hand ins Feuer legen.
Man könnte das mal testen, indem man eine File mit einer Mail durchpiped.
Feb 15 20:37:29 server spamd[30015]: dns: name server: 8.8.8.8, LocalAddr: 0.0.0.0
8.8.8.8 kannst Du nicht für RBL Abfragen nutzen (der ist überall gesperrt). Nutze einen lokalen DNS Resolver!
Feb 15 20:37:29 server spamd[30015]: conf: trusted_networks are not configured; it is recommended that you configure trusted_networks manually
Sollte man auch mal ansehen
Feb 15 20:37:29 server spamd[30015]: rules: local tests only, ignoring RBL eval
Dein Setup nutzt keine RBLs
Feb 15 20:37:29 server spamd[30015]: bayes: DB expiry: tokens in DB: 134013, Expiry max size: 150000, Oldest atime: 1346717594, Newest atime: 1360949986, Last expire: 1357772363, Current time: 1360957049
Eine Bayes expire dauert ne Weile!!! Ist dein Spamd immer so langsam oder hast du hier einen konkret langsamen rausgepickt?
Also den DNS habe ich auf den lokalen DNS-Server gelegt. Ausserdem auch noch die Zeile "internal_networks !0/0" in local.cf angelegt.
Das Email welches verschickt wurde ist in Plaintext und beinhaltet nur 20 Wörter. Also recht klein. Spamd braucht zwischen 8 -15 Sekunden. Egal ob die Mail vom lokalen Server oder von extern kommen. Kann an die Bayes beschleunigen? Werde mal versuchen die DB neu anzulegen. Gibt es eine Möglichkeit bei Postfix oder Spamd anzulegen, welche den Spamd nicht durchläuft sondern direkt ins Postfach legt?
* Mathias Betschart mbetschart_ch@yahoo.de:
Also den DNS habe ich auf den lokalen DNS-Server gelegt.
OK
Ausserdem auch noch die Zeile "internal_networks !0/0" in local.cf angelegt.
Nichts ist intern. OK, könnte klappen :)
Das Email welches verschickt wurde ist in Plaintext und beinhaltet nur 20 Wörter. Also recht klein.
Spamd braucht zwischen 8 -15 Sekunden. Egal ob die Mail vom lokalen Server oder von extern kommen.
OK, also JEDE Mail.
Kann an die Bayes beschleunigen? Werde mal versuchen die DB neu anzulegen.
Wenn die sehr groß ist, braucht expiry ne Weile.
bayes_auto_expire true bzw. 1 in der config bewirkt, daß der spamd ein Expiry macht, wenn er es für notwendig hält.
sa-learn --force-expire --sync als GENAU DER USER als der auch spamd normalerweise läuft
Gibt es eine Möglichkeit bei Postfix oder Spamd anzulegen, welche den Spamd nicht durchläuft sondern direkt ins Postfach legt?
Wie wird spamd denn aktuell aufgerufen? Durch procmailrc?
Also den DNS habe ich auf den lokalen DNS-Server gelegt.
OK
Ausserdem auch noch die Zeile "internal_networks !0/0" in local.cf angelegt.
Nichts ist intern. OK, könnte klappen :)
Das Email welches verschickt wurde ist in Plaintext und beinhaltet nur 20 Wörter. Also recht klein.
Spamd braucht zwischen 8 -15 Sekunden. Egal ob die Mail vom lokalen Server oder von extern kommen.
OK, also JEDE Mail.
Kann an die Bayes beschleunigen? Werde mal versuchen die DB neu anzulegen.
Wenn die sehr groß ist, braucht expiry ne Weile.
bayes_auto_expire true bzw. 1 in der config bewirkt, daß der spamd ein Expiry macht, wenn er es für notwendig hält.
sa-learn --force-expire --sync als GENAU DER USER als der auch spamd normalerweise läuft
Gibt es eine Möglichkeit bei Postfix oder Spamd anzulegen, welche den Spamd nicht durchläuft sondern direkt ins Postfach legt?
Wie wird spamd denn aktuell aufgerufen? Durch procmailrc?
Ja. Jeder Benutzer hat eine .procmailrc Datei in welcher spamd (usr/bin/spamc) aufgerufen wird. Habe nun auch noch bayes-auto_expre = 1 gesetzt und sa-learn --force-expire --sync ausgeführt. Ist nun ca. 2 Sekunden schneller... Aber ich finde immer noch, dass es etwas lange dauert (8 Sekunden).
* Mathias Betschart mbetschart_ch@yahoo.de:
Wie wird spamd denn aktuell aufgerufen? Durch procmailrc?
Ja. Jeder Benutzer hat eine .procmailrc Datei in welcher spamd (usr/bin/spamc) aufgerufen wird.
Dort kann man dann ja sagen, welche Mails NICHT durch spamd durchsollen.
Habe nun auch noch bayes-auto_expre = 1 gesetzt
Nein, es muss 0 sein.
und sa-learn --force-expire --sync ausgeführt.
OK. ggf. als Cronjob 1x pro Woche
Wie wird spamd denn aktuell aufgerufen? Durch procmailrc?
Ja. Jeder Benutzer hat eine .procmailrc Datei in welcher spamd (usr/bin/spamc) aufgerufen wird.
Dort kann man dann ja sagen, welche Mails NICHT durch spamd durchsollen.
Habe nun auch noch bayes-auto_expre = 1 gesetzt
Nein, es muss 0 sein.
und sa-learn --force-expire --sync ausgeführt.
OK. ggf. als Cronjob 1x pro Woche
Alles jetzt so eingestellt. Was ich aber immer noch nicht schnell ist folgendes. Wenn ich von benutzer1 ein Email an benutzer1 (gleicher Benutzer) ein Mail schicke und seine .procmailrc leer ist (sprich kein spamc konfiguriert) dann bracuht die Mail in dem Fall 20 Sekunden....(spamd debug ist eingestellt, zeig auch nichts an)
Feb 18 14:45:32 server postfix/qmgr[30484]: A5B2A26C070: from=benutzer1@meinserver.com, size=582, nrcpt=1 (queue active) Feb 18 14:45:55 server postfix/local[31248]: A5B2A26C070: to=benutzer@meinserver.com, relay=local, delay=23, delays=0.21/0.01/0/23, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail -a "$EXTENSION")
Das zeigt für mich, dass es ein postfix->procmail problem ist. nicht wahr?
Hallo Mathias,
kannst Du bitte mal auf plaintext mails umstellen und deinem mailclient korrektes Quoten beibringen?
Ich kann in den Mails nicht nachvollziehen welche Teile Du zitierst und welche Du selbst geschrieben hast, was vermutlich auch bei anderen zu meiner Reaktion führt: ich lese sie nicht, weil es mit zu anstrengend ist.
Grüße, Florian
PS: CC an die Liste damit die Bitte nich x-fach kommt ;)
participants (5)
-
Florian Streibelt
-
lst_hoe02@kwsoft.de
-
Mathias Betschart
-
Ralf Hildebrandt
-
Robert Schetterer