Server Support Forum
Fehler in der Logdatei mail! Ursachenforschung

Zurück   Server Support Forum > >


Antwort
 
Themen-Optionen Thema bewerten
  #1  
Alt 23.04.2008, 13:24
gammla gammla ist offline
Registered User
 
Registriert seit: 04.2008
Beiträge: 130
Fehler in der Logdatei mail! Ursachenforschung

Hallo!
Ich bin gerade dabei jeden Fehler in meiner Logdatei zu verfolgen und wenn möglich zu beheben.
Leider bin ich an einen Punkt angekommen, der mir dies nicht mehr ermöglicht:


Hier mal ein Übersicht was zu diesem Zeitpunkt "auf" dem System passiert.
Ich habe xinetd neu gestartet! Steht aber vielleicht nur zufällig in diesem Zusammenhang!

Inhalt von System-Log (/var/log/messages)
Code:
Apr 23 09:17:17 h1385133 xinetd[8529]: Reading included configuration file: /etc/xinetd.d/daytime-udp [file=/etc/xinetd.d/daytime-udp] [line=14]
Apr 23 09:17:17 h1385133 xinetd[8529]: Reading included configuration file: /etc/xinetd.d/daytime [file=/etc/xinetd.d/daytime] [line=16]
Apr 23 09:17:17 h1385133 xinetd[8529]: Reading included configuration file: /etc/xinetd.d/cvs [file=/etc/xinetd.d/cvs] [line=11]
Apr 23 09:17:17 h1385133 xinetd[8529]: Reading included configuration file: /etc/xinetd.d/cups-lpd [file=/etc/xinetd.d/cups-lpd] [line=15]
Apr 23 09:17:17 h1385133 xinetd[8529]: Reading included configuration file: /etc/xinetd.d/chargen-udp [file=/etc/xinetd.d/chargen-udp] [line=14]
Apr 23 09:17:17 h1385133 xinetd[8529]: Reading included configuration file: /etc/xinetd.d/chargen [file=/etc/xinetd.conf] [line=26]
Apr 23 09:17:12 h1385133 vsftpd: Wed Apr 23 09:17:12 2008 [pid 8511] CONNECT: Client "127.0.0.1"
Apr 23 09:17:08 h1385133 vsftpd: Wed Apr 23 09:17:08 2008 [pid 8057] CONNECT: Client "127.0.0.1"
Apr 23 09:17:03 h1385133 vsftpd: Wed Apr 23 09:17:03 2008 [pid 8045] CONNECT: Client "127.0.0.1"
Apr 23 09:16:53 h1385133 vsftpd: Wed Apr 23 09:16:53 2008 [pid 5620] CONNECT: Client "127.0.0.1"
Apr 23 09:16:40 h1385133 syslog-ng[2971]: STATS: dropped 0
Apr 23 09:16:39 h1385133 xinetd[3311]: Exiting...
Kurz vor den gleich angesprochenen Fehlern startet EXIM (Mein MTA) einen queue run, bei dem er nach der logfile nur frozen messages
feststellt. Nach meiner Information wird an dieser Stelle ja nichts "aufgetaut". Muss also auch nicht mit dem Problem zusammenhängen.

Inhalt von Exim Logfile (/var/log/exim/main.log)
Code:
2008-04-23 09:16:45 End queue run: pid=5607
2008-04-23 09:16:45 1JoM2M-00075N-1f Message is frozen
2008-04-23 09:16:45 1JnzYS-0003ez-Dl Message is frozen
2008-04-23 09:16:45 1JoTLX-0007eV-8z Message is frozen
2008-04-23 09:16:45 Start queue run: pid=5607
Hier werden die Fehler protokolliert, die ich beheben möchte:
Inhalt von Mail Logfile (/var/log/mail)
Code:
Apr 23 09:17:12 h1385133 spamd[3404]: prefork: child states: II
Apr 23 09:17:12 h1385133 spamd[3413]: spamd: bad protocol: header error: (closed before headers) at /usr/sbin/spamd line 1985.
Apr 23 09:17:12 h1385133 spamd[3413]: spamd: connection from localhost [127.0.0.1] at port 33014
Apr 23 09:17:12 h1385133 imapd-ssl: Unexpected SSL connection shutdown.
Apr 23 09:17:12 h1385133 imapd: Disconnected, ip=[::ffff:127.0.0.1], time=0
Apr 23 09:17:12 h1385133 imapd: Connection, ip=[::ffff:127.0.0.1]
Apr 23 09:17:12 h1385133 pop3d: Unexpected SSL connection shutdown.
Apr 23 09:17:12 h1385133 pop3d: Disconnected, ip=[::ffff:127.0.0.1]
Apr 23 09:17:12 h1385133 pop3d: Connection, ip=[::ffff:127.0.0.1]

Fehler 1:
Code:
Apr 23 09:17:12 h1385133 pop3d: Unexpected SSL connection shutdown.
Fehler 2:
Code:
Apr 23 09:17:12 h1385133 spamd[3413]: spamd: bad protocol: header error: (closed before headers) at /usr/sbin/spamd line 1985.
Zu Fehler 1:
Ist das überhaupt ein Fehler?
Sobald etwas "unerwartet" ist, ist es ja zumindest etwas, was nicht ganz normal ist!
Wenn ich mir die zwei Logeinträge zuvor anschaue,
Code:
Apr 23 09:17:12 h1385133 pop3d: Disconnected, ip=[::ffff:127.0.0.1]
Apr 23 09:17:12 h1385133 pop3d: Connection, ip=[::ffff:127.0.0.1]
machte es den Eindruck, dass der Server (127.0.0.1) versucht eine Verbindung aufzubauen. Schafft es aber nicht, da es eine "Unexpected SSL connection" ist.

Falls dies "Unexpected SSL connection" nicht mit dem vorherigen Verbindungsversuch zusammenhängt, bin ich ahnungslos!
Auffällig ist aber, dass es sich hierbei um eine IPv6 ([::ffff:127.0.0.1]) handelt. Vielleicht ist dem pop3d und dem imapd diese "Art" nicht bekannt.

In welche Richtung, kann ich hier weiterforschen?


Zu Fehler 2:
Spamassassin funktionert soweit fehlerfrei. Die Emails werden ohne Probleme durchgereicht und als Spam oder nicht Spam markiert!
Zumindest schränkt dieser "Fehler" nicht die Funktion ein. Mich würde trotzdem interessieren, was da abläuft.

Zu diesem Problem kann ich über Google folgendes finden:

Zitat:
Überwachung ist gut, wenn man sie denn kontrolliert
Munin ist eine gute Möglichkeit Trends von verschiedenen Werten abzugeben. Was aber, wenn es mal schnell gehen muss? Für die einfache Überwachung von Prozessen, Dateien, Verzeichnissen oder Devices bietet sich monit an. So überwache ich auf meinem Server z.B. u.a. meinen Apache, Exim, ClamAV und auch SpamAssassin.

Allerdings hat sich herausgestellt, dass das Monitoring von meinem SpamAssassin ein wenig für Ärger sorgen kann. Sollte man monit einsetzen und folgende Zeilen in seinem /var/log/spamd.log sehen, dann ist u.U. monit bzw. dessen Fehlkonfiguration schuld.

Tue Jan 1 20:24:12 2008 [6906] info: spamd: connection from localhost [127.0.0.1] at port 4366
Tue Jan 1 20:24:12 2008 [6906] warn: spamd: bad protocol: header error: (closed before headers) at /usr/sbin/spamd line 1985.
Tue Jan 1 20:24:12 2008 [6897] info: prefork: child states: II

Passiert ist mir dies beim Versuch SpamAssassin über den Port 783 zu monitoren. Das sorgt dann brav dafür, dass sich das Logfile rasch mit nervigen und unnötigen Meldungen aufbläht.
Quelle:
http://blog.sinnwidrig.org/2008/01/03/uberwachung-ist-gut-wenn-man-sie-denn-kontrolliert/

Hier wird gesagt, dass "monit" und dessen Fehlkonfiguration daran schuld sei!
monit ist laut Yast bei mir nicht installiert.
Auch eine Suche nach monit bringt keinen Erfolg. (-> ist ja auch nicht installiert)

Es könnte doch auch gut möglich sein, dass ein anderes Monitoring-Programm den "gleichen" Fehler wie monit erzeugt.
Vielleicht muss man auch in einer ganz anderen Richtung suchen!
Vielleicht steht es auch in direktem Zusammenhang mit dem eventuellen IPv6 Problem?

Es wird ja angegeben, dass der Fehler in Zeil 1985 auftrat.
Hier ein Auszug:

Code:
sub protocol_error {
  my ($err) = @_;
  my $resp = "EX_PROTOCOL";
  syswrite($client, "SPAMD/1.0 $resphash{$resp} Bad header line: $err\r\n");
  warn("spamd: bad protocol: header error: $err");
}
Das scheint die Funktion zur Fehlerausgabe zu sin. Wenn man jetzt nur noch wüsste, wer sie aufruft....?


Vielleicht könnt ihr ein wenig Licht in Dunkle bringen!

Gruß,

Gammla

Geändert von gammla (23.04.2008 um 19:21 Uhr)
Mit Zitat antworten

  #2  
Alt 23.04.2008, 13:47
Roger Wilco Roger Wilco ist offline
Registered User
 
Registriert seit: 11.2006
Beiträge: 3.462
Zitat:
Zitat von gammla Beitrag anzeigen
Inhalt von Exim Logfile (/var/log/exim/main.log)
Code:
2008-04-23 09:16:45 End queue run: pid=5607
2008-04-23 09:16:45 1JoM2M-00075N-1f Message is frozen
2008-04-23 09:16:45 1JnzYS-0003ez-Dl Message is frozen
2008-04-23 09:16:45 1JoTLX-0007eV-8z Message is frozen
2008-04-23 09:16:45 Start queue run: pid=5607
Suche in dem Log nach den Message-IDs. Dann findest du auch den Grund, warum die Mails noch in der Queue hängen.

Zitat:
Zitat von gammla Beitrag anzeigen
Zu Fehler 1:
Ist das überhaupt ein Fehler?
Nein.

Zitat:
Zitat von gammla Beitrag anzeigen
Wenn ich mir die zwei Logeinträge zuvor anschaue,
Code:
Apr 23 09:17:12 h1385133 pop3d: Disconnected, ip=[::ffff:127.0.0.1]
Apr 23 09:17:12 h1385133 pop3d: Connection, ip=[::ffff:127.0.0.1]
machte es den Eindruck, dass der Server (127.0.0.1) versucht eine Verbindung aufzubauen. Schafft es aber nicht, da es eine "Unexpected SSL connection" ist.
Bitte lies die Fehlermeldung komplett. Da steht nicht "Unexpected SSL connection", sondern "Unexpected SSL connection shutdown". Der Client hat einfach die Verbindung beendet, ohne auf Wiedersehen zu sagen.

Zitat:
Zitat von gammla Beitrag anzeigen
Zu Fehler 2:
Spamassassin funktionert soweit fehlerfrei. Die Emails werden ohne Probleme durchgereicht und als Spam oder nicht Spam markiert!
Zumindest schränkt dieser "Fehler" nicht die Funktion ein. Mich würde trotzdem interessieren, was da abläuft.
Steht doch klipp und klar in der Logmeldung: Es gab einen Verbindungsaufbau (in deinem Fall wohl durch monit). Die Verbindung wurde danach gleich wieder beendet, ohne entsprechende Header zu senden.

Zitat:
Zitat von gammla Beitrag anzeigen
monit ist laut Yast bei mir nicht installiert.
Irgendein Prozess greift jedenfalls von localhost aus auf deinen SpamAssassin zu.

Zitat:
Zitat von gammla Beitrag anzeigen
Es könnte doch auch gut möglich sein, dass ein anderes Monitoring-Programm den "gleichen" Fehler wie monit erzeugt.
Ja.

Zitat:
Zitat von gammla Beitrag anzeigen
Vielleicht steht es auch in direktem Zusammenhang mit dem eventuellen IPv6 Problem?
Nein.
Mit Zitat antworten
  #3  
Alt 23.04.2008, 13:53
Benutzerbild von LinuxAdmin
LinuxAdmin LinuxAdmin ist offline
Moderator
 
Registriert seit: 07.2007
Ort: Basel
Beiträge: 3.604
Wenn einige Prozesse "unerwartet" sterben wenn gerade Last erzeugt wird (--> exim queue-run) würde ich mal als erstes mal nachschauen, ob ein Ressourcen-Problem vorhanden ist.
Mit Zitat antworten
  #4  
Alt 23.04.2008, 14:57
gammla gammla ist offline
Registered User
 
Registriert seit: 04.2008
Beiträge: 130
Hallo!
Habe mal einen q-run manuell gestartet:
Code:
exim -q -v
LOG: queue_run MAIN
  Start queue run: pid=14403
delivering 1JoTLX-0007eV-8z (queue run pid 14403)
LOG: skip_delivery MAIN
  Message is frozen
delivering 1JoM2M-00075N-1f (queue run pid 14403)
LOG: skip_delivery MAIN
  Message is frozen
delivering 1JnzYS-0003ez-Dl (queue run pid 14403)
LOG: skip_delivery MAIN
  Message is frozen
delivering 1JodwE-0003iW-Df (queue run pid 14403)
LOG: skip_delivery MAIN
  Message is frozen
LOG: queue_run MAIN
  End queue run: pid=14403
bzw.:
Code:
2008-04-23 14:25:32 End queue run: pid=14403
2008-04-23 14:25:32 1JodwE-0003iW-Df Message is frozen
2008-04-23 14:25:32 1JnzYS-0003ez-Dl Message is frozen
2008-04-23 14:25:32 1JoM2M-00075N-1f Message is frozen
2008-04-23 14:25:32 1JoTLX-0007eV-8z Message is frozen
2008-04-23 14:25:32 Start queue run: pid=14403
Hierbei handelt es sich um Mails, die an root nicht zugestellt werden können. Das ist aber eine andere Baustelle.
Betrachten wir nochmals, ob Prozesse "unerwartet" sterben.
Zu der Zeit 14.25.32 taucht in keiner Logdatei eine ungewöhnlichkeit auf.

Ich hoffe, dass ich keine Ressoucen-Problem habe. Das wäre ärgerlich.
Hier die Ausgabe von free:

Code:
             total       used       free     shared    buffers     cached
Mem:        515072     424576      90496          0      52444     146284
-/+ buffers/cache:     225848     289224
Swap:      2104496      14180    2090316
Das sieht so aus, als wäre noch reichlich frei (289224)!

So, fassen wir nochmal alles kurz zusammen:

Ein Ressourcen-Problem scheint es nicht zu sein.


Zu dem Clienten, der die Verbindung nicht richtig beendet:
Das Microsoft Outlook solche Sachen oft bzw. teilweise nicht richtig macht, ist wohl bekannt. Diese Information habe ich bei Google gefunden.

Da es sich hier aber um einen "internen" Client (127.0.0.1) handelt macht mir das schon ein wenig Sorgen. Wer greift denn da auf Spamassassin zu?

Wie kann ich das herausfinden?

Nun sehe ich noch ein Problem. xinetd scheint wohl irgendwie ein Problem zu haben:
Code:
Apr 23 14:23:35 h1385133 xinetd[14383]: warning: can't get client address: Transport endpoint is not connected
Apr 23 14:20:01 h1385133 /usr/sbin/cron[14297]: (root) CMD (/usr/local/sa24/sa24d3/sa24d3 --server-stats >>/dev/null 2>&1)
Apr 23 14:16:42 h1385133 xinetd[14283]: warning: can't get client address: Transport endpoint is not connected
Apr 23 14:16:42 h1385133 syslog-ng[2971]: STATS: dropped 0
Apr 23 14:15:01 h1385133 /usr/sbin/cron[14227]: (root) CMD (/usr/local/sa24/sa24d3/sa24d3 --server-stats >>/dev/null 2>&1)
Was könnte dafür die Ursache sein?

Gruß,

Gammla
Mit Zitat antworten
Antwort

Lesezeichen


Themen-Optionen
Thema bewerten
Thema bewerten:

Forumregeln
Es ist dir nicht erlaubt, neue Themen zu verfassen.
Es ist dir nicht erlaubt, auf Beiträge zu antworten.
Es ist dir nicht erlaubt, Anhänge hochzuladen.
Es ist dir nicht erlaubt, deine Beiträge zu bearbeiten.

BB-Code ist an.
Smileys sind an.
[IMG] Code ist aus.
HTML-Code ist aus.

Gehe zu

Ähnliche Themen
Thema Autor Forum Antworten Letzter Beitrag
Plesk Greylisting Control Panel haggybear Plesk 346 05.07.2012 15:28
Plesk 8.3 mail versand nicht mehr möglich auf einer domain sniper2282 Plesk 3 29.01.2008 17:39
Qmail - Thunderbird: Verbindung abgelehn od. unterbrochen misterx01 Mail 7 30.11.2007 12:03
Spammails über qmail weissnix Mail 19 10.03.2007 15:27
ddos Attacke auf Postfix Server inst0000 Mail 14 12.12.2006 16:23


Fehler in der Logdatei mail! Ursachenforschung
Fehler in der Logdatei mail! Ursachenforschung
Fehler in der Logdatei mail! Ursachenforschung Fehler in der Logdatei mail! Ursachenforschung
Powered by vBulletin® Version 3.8.11 (Deutsch)
Copyright ©2000 - 2017, vBulletin Solutions, Inc.
Search Engine Optimisation provided by DragonByte SEO (Pro) - vBulletin Mods & Addons Copyright © 2017 DragonByte Technologies Ltd.