Hallo Bernhard, * On Mon, Oct 31, 2005 at 04:04 PM (+0100), Bernhard Schalk wrote:

...

Am Samstag um 10:30 Uhr hat "cron.daily" das Kommando "logrotate" ge- startet. So weit - so gut.

Na ja, vielleicht war das die Wurzel allen Übels. Ist dein /tmp vielleicht "noexec" gemountet?

Nein, das ist hier nicht der Fall. Habe gerade zur Sicherheit nochmals nachgesehen: | fsa01-neu:~ # mount | | /dev/md1 on / type ext3 (rw,acl,user_xattr) | proc on /proc type proc (rw) | sysfs on /sys type sysfs (rw) | tmpfs on /dev/shm type tmpfs (rw) | devpts on /dev/pts type devpts (rw,mode=0620,gid=5) | /dev/md0 on /boot type ext3 (rw,acl,user_xattr) | /dev/md3 on /tmp type ext3 (rw,acl,user_xattr) | /dev/md2 on /usr type ext3 (rw,acl,user_xattr) | /dev/md4 on /var type ext3 (rw,acl,user_xattr) | /dev/mapper/system-home on /home type xfs (rw,usrquota) | /dev/mapper/system-export on /srv/export type xfs (rw) | usbfs on /proc/bus/usb type usbfs (rw) Da die Maschine auch "nur" als Fileserver läuft und wir unseren Usern keine lokale Shell geben, habe ich bislang auch noch keinen Grund ge- sehen, "/tmp" mit "noexec" zu mounten. Aber trotzdem - vielen Dank für den Tipp. Wenn es daran gelegen hätte, wäre ich -wenn überhaupt- erst nach sehr, sehr langem Suchen drauf ge- stoßen. Gruß, Steffen

Hallo Andreas, * On Mon, Oct 31, 2005 at 05:30 PM (+0100), Andreas Winkelmann wrote:

Am Monday 31 October 2005 17:09 schrieb Steffen Moser:

...

...

...

startet. So weit - so gut.

Na ja, vielleicht war das die Wurzel allen Übels. Ist dein /tmp vielleicht "noexec" gemountet?

Nein, das ist hier nicht der Fall. Habe gerade zur Sicherheit nochmals

Hast Du eigentlich mal die Hardware geprüft? Filesysteme, Speicher,... ?

Ja, den Speicher habe ich geprüft, diverse CPU-Test-Geschichten ließ ich auch relativ lange drüberlaufen. Der Grund dafür: Nach dem Zusammenbau dieser Dual-Opteron-Maschine (zwei Opteron Single-Core-CPUs 246 und 2 GB RAM auf einem Tyan Thunder S2892) hatte ich das Problem, dass "grep" ständig crashte: | Oct 20 14:30:44 fsa01-neu kernel: grep[15069]: segfault at 0000000000000000 rip 00002aaaaaaae05c rsp 00007fffffffcf30 error 4 | Oct 20 14:30:44 fsa01-neu kernel: grep[15079]: segfault at 0000000000000000 rip 00002aaaaaaae05c rsp 00007fffffffcf30 error 4 | Oct 20 14:30:59 fsa01-neu kernel: grep[15489]: segfault at 0000000000000000 rip 00002aaaaaaae05c rsp 00007fffffffcf50 error 4 | Oct 20 14:31:00 fsa01-neu kernel: grep[15543]: segfault at 0000000000000000 rip 00002aaaaaaae05c rsp 00007fffffffcf50 error 4 | Oct 20 14:31:00 fsa01-neu kernel: grep[15573]: segfault at 0000000000000000 rip 00002aaaaaaae05c rsp 00007fffffffcf50 error 4 | Oct 20 14:31:08 fsa01-neu kernel: grep[16055]: segfault at 0000000000000000 rip 00002aaaaaaae05c rsp 00007fffffffcf60 error 4 Ich gehe davon aus, dass ich auf diesen Hardware-Bug gestoßen bin, der leider erst von aktuellen Kernels "aufgedeckt" wurde: http://bugzilla.kernel.org/show_bug.cgi?id=4851 Das ist auch der Grund, weshalb ich nicht den mit der SuSE 10.0 mitge- lieferten SuSE-Kernel einsetze, sondern einen Vanilla-2.6.14. Dieser erkennt, dass die Hardware diesen Bug hat und berücksichtigt dies, indem er das entsprechende Feature deaktiviert. So erklärte es mir jedenfalls Andi Kleen von SuSE. Jedenfalls hatte ich seit dem Einsatz von 2.6.14 auch keinerlei "grep"- Crashes mehr - und der Rest läuft stabil. Naja, von "traceroute" einmal abgesehen, das hängt sich manchmal auf. Aber das dürfte 'ne andere Bau- stelle sein. Gruß, Steffen

Hallo Andreas, * On Mon, Oct 31, 2005 at 08:25 PM (+0100), Andreas Winkelmann wrote:

Am Monday 31 October 2005 17:56 schrieb Steffen Moser:

...

Ja, den Speicher habe ich geprüft, diverse CPU-Test-Geschichten ließ ich auch relativ lange drüberlaufen.

Filesystem? Oder Festplatte?

Die Filesysteme habe ich inzwischen gecheckt (es sind "ext3"- und "xfs"-Systeme im Einsatz, wobei die systemrelevanten Dinge alle auf "ext3" liegen und die "xfs"-Dateisysteme für die eigentlichen Nutz- daten der Fileserver-Dienstes da sind, wie z.B. "/home" oder "/export"). Keine Fehler gefunden. Natürlich habe ich bei den "ext3"- Filesystemen einen Check erzwungen. Die Platten an sich hatte ich vor zwei Wochen unmittelbar nach dem Zusammenbau des Rechners mit "badblocks" getestet. Keine Fehler. Auch die SMART-Werte sehen gut aus, Meldungen über Lese-/Schreib- probleme seitens des Kernels gab es bislang auch keine. Auch RAM und CPU zeigten, wie gesagt, bei keinem Test Probleme.

...

Der Grund dafür: Nach dem Zusammenbau dieser Dual-Opteron-Maschine (zwei Opteron Single-Core-CPUs 246 und 2 GB RAM auf einem Tyan Thunder S2892) hatte ich das Problem, dass "grep" ständig crashte:

Und dann suchst Du bei syslog?

Nun, die Frage ist sicher berechtigt. Allerdings scheint das ein klar umgrenzter Bug der Hardware (Mainboard oder CPUs) zu sein, der einfach dadurch "umschifft" wird, indem das entsprechende Feature vom Kernel nicht genutzt wird, so wie es schon frühere Kernel-Versionen nicht genutzt haben (und damit wohl unentdeckt blieb). Anscheinend soll aber der Hersteller des Mainboards (Tyan) an einem BIOS-Update arbeiten (und es für verwandte Boards schon draußen haben), das dieses Problem lösen soll. Wobei ich fairerweise dazusagen muss, dass ich noch nicht weiß, ob damit wirklich das Problem an sich gelöst wird oder ob da ebenfalls nur ein "buggy Feature" der Opteron-CPUs "unterdrückt" wird. Ich werde mir die Details zu diesem Bug ansehen. Ich weiß z.B. momentan nicht, ob es sich um einen Bug in den Opteron-CPUs oder um einen Bug im Mainboard handelt. Auf jeden Fall plant wohl auch SuSE, zukünftige SuSE-Kernels abchecken zu lassen, ob auf der Hardware dieser Bug vorliegt oder nicht. Je nach dem wird dann von dem Feature Gebrauch gemacht oder eben nicht. Momentan kann der SuSE-Kernel der 10.0 das wohl noch nicht, aber der 2.6.14 ist dazu in der Lage. Danke und Grüße, Steffen

Hallo Hans-Werner, * On Mon, Oct 31, 2005 at 04:15 PM (+0100), Hans-Werner Hilse wrote:

On Mon, 31 Oct 2005 15:37:34 +0100 Steffen Moser wrote:

...

"logrotate" schickt (wenn es was zu rotieren gibt) - laut der Da- tei "/etc/logrotate.d/syslog" ein "/etc/init.d/syslog reload". Das wiederum dürfte ein "SIGHUP" senden.

Jepp.

...

- Warum "spinnt" der "syslog-ng" herum, wenn er ein HUP-Signal ge- sendet bekommt? Warum hört er dann mit dem Logging auf?

Du kannst definitiv ausschließen, dass du auch noch andere Logfiles rotierst, deren Dienste nicht neugestartet werden? Insbesondere hier wohl LDAP (scheint aber ja ins Syslog zu gehen), named, nscd.

Ich kann sonst nichts erkennen. Außerdem war ja wirklich in "messages" nichts mehr los nach dem "rotate". Und dass keiner der Dienste (auch der zunächst mehrfach neu gestartete LDAP-Daemon) gar nichts vom Syslog protokollieren ließ, wäre ja eher seltsam. Den "nscd" hatte ich am Sonn- tag übrigens auch mehrfach neu gestartet. Also gehe ich schon davon aus, dass "syslog-ng" Probleme hatte. Aller- dings wurde nur am Samstag "messages" rotiert. Am Sonntag war dafür die "localmessages" dran - aber auch die wird ja vom Syslog beschrieben, al- so hat er den SIGHUP gekriegt (und der steht ja noch im Logfile drin). Ich habe eben noch weiter gestetet, d.h. die Logfiles künstlich gefüllt und mehrfach dafür gesorgt, dass die Skripte in "/etc/cron.daily" abge- arbeitet wurden. Ich konnte den Fehler nicht provozieren. Das "logrotate" rotierte einwandfrei - auch Dateien des Syslogs und reloadete ihn neu.

Die Aufrufe an die jeweiligen Logging-Routinen blocken dann für gewöhnlich. /dev/log ist ja ein FIFO, der hat glaube ich immer einen gewissen Puffer (8k?).

Okay... Ich schalte jetzt mal den "syslog-ng" ab und warte ein paar Stunden, ob sich das System dann genauso verhält wie am Samstag und am Sonntag. Um einen Vor-Ort-Einsatz zu umgehen, lasse ich eine SSH- Connection offen.

Ich glaube eher nicht an den syslog-Dienst als Schuldigen. Ich vermute, du ziehst einem anderen Dienst sein Logfile mit logrotate weg und startest ihn nicht neu (oder bringst ihn anders dazu, das Logfilehandle zu schließen und neu zu öffnen). Irgendwas kritisches... Dafür spricht ja auch, dass erstmal alles weiterläuft, wenn du syslog-ng beendest.

Oder aber der Puffer des FIFO hat bei meinen kurzen Abschaltungen soweit erstmal alles aufgenommen. Daher lasse ich ihn jetzt mal längere Zeit aus und sorge dafür, dass z.B. der LDAP etwas loggt. Da die Maschine noch nicht wirklich im Einsatz ist (sondern erst in etwa einer Woche richtig genutzt werden soll), spielt es keine Rolle, wenn heute Abend für einige Stunden nicht mitgeloggt wird. Aber auf jeden Fall einmal Danke für Deine Hinweise - ich werde auch insbesondere noch auf andere Dienste und deren Logfiles achten. Viele Grüße, Steffen

Hallo Hans-Werner, * On Mon, Oct 31, 2005 at 09:09 PM (+0100), Hans-Werner Hilse wrote:

On Mon, 31 Oct 2005 18:07:31 +0100 Steffen Moser wrote:

...

Ich kann sonst nichts erkennen. Außerdem war ja wirklich in "messages" nichts mehr los nach dem "rotate". Und dass keiner der Dienste (auch der zunächst mehrfach neu gestartete LDAP-Daemon) gar nichts vom Syslog protokollieren ließ, wäre ja eher seltsam. Den "nscd" hatte ich am Sonn- tag übrigens auch mehrfach neu gestartet.

Einen hab' ich jetzt doch noch, und das wird abenteuerlich: hast du die Unix-Authentifizierung über das LDAP laufen, das der Rechner selbst über den besagten LDAP-Dienst anbietet?

Ja, das habe ich...

Dann könnten wir u.U. eine Art Race Condition haben.

Das könnte in der Tat sein. Du wirst lachen, ich hatte schon an eine Art "Race Condition" gedacht, was das Neustarten des Syslog betrifft, ich dachte aber gar nicht an den OpenLDAP, sondern eher daran, dass es vielleicht mit anderen Cron-Daily-Jobs Probleme gibt und hatte da- her gestern bei meinen Erzwungenen Cron-Daily-Läufen auch versucht, eben nicht nur "logrotate" auszuführen, sondern alle Cron-Daily-Ge- schichten. Aber das, was Du hier schreibst, ist ein hochinteressanter Aspekt, dem ich nachgehen werde.

Wenn dann nämlich der Neustart von syslog-ng eine Anfrage an das LDAP-Verzeichnis provoziert (z.B. Rechte des ausführenden Nutzers etc.pp.)

Wieso "syslog-ng" das tun sollte, ist mir zwar noch nicht ganz klar, aber ausschließen kann ich's nicht. "syslog-ng" läuft natürlich als "root" und "root" wird lokal verwaltet. Aber vielleicht ist es ja auch nur eine Anfrage im Rahmen von "nss_ldap", also z.B. die Auf- lösung irgend eines Namens (nein, die Hostnamen verwalte ich schon per DNS, aber vielleicht irgendwie "Benutzername <---> UID").

_und_ dabei der FIFO voll läuft _und_ dadurch dann OpenLDAP blockt, ja dann beißt sich die Katze in den Schwanz und nichts geht mehr (sprich, es hängt der Neustart des syslog-ng fest).

Auf jeden Fall schonmal vielen Dank für den Tipp, das muss ich un- bedingt näher untersuchen... Bei meinen Tests mit abgeschaltetem Syslog gestern Abend blieb das System übrigens über Stunden stabil. Ein "strace" von "/bin/logger" zeigte auch, dass es beim Versuch, "/dev/log" zu öffnen, während der Syslog abgeschaltet ist, einfach ein "Connection refused" gibt und "/bin/logger" dann halt nichts schreibt - und fertig. Es kam auf jeden Fall (selbst nach dem ich bei abgeschaltetem Sys- log in einer Endlosschleife den "/bin/logger" massiv loggen ließ) nicht zu einer Situation, wo "/bin/logger" in irgend einer Art und Weise auf das "/dev/log"-Socket gewartet hatte und sich dabei ver- klemmte. Das würde auf jeden Fall dagegen sprechen, dass der Syslog beim Auf- treten des Problems am Samstag und Sonntag "abgestellt" war. Er müsste zumindest noch soweit aktiv gewesen sein, dass Anwendungen versucht haben, nach "/dev/log" zu schreiben, also nicht schon gleich mit einem "Connection refused" abgewiesen wurden. Ich weiß leider zu wenig, wie "named sockets" funktionieren. Es gibt auch Unterschiede zwischen "named sockets" und FIFOs. Die "named sockets" haben ja ein "s" im "Spezialflag" des Dateisystems, während die FIFOs (oder auch "named pipes") ein "p" haben: | steffen@pc01:~> ll /dev/log | srw-rw-rw- 1 root root 0 2005-10-15 20:08 /dev/log Ich versuche jetzt einmal abzuklären, ob es tatsächlich zu einer "Race Condition" kommen kann. So nach dem Motto: Der Syslog will reloaden. Er läuft dabei. Er muss aber zum Reload -aus welchem Grund auch immer- den OpenLDAP fragen. Dieser will daraufhin auch antworten, aber loggt natürlich erstmal. Da der Syslog noch läuft, kriegt der OpenLDAP auch kein "Connection refused" beim Öffnen des Log-Sockets. Also schreibt der OpenLDAP ins Log-Socket, aber auf der anderen Seite liest niemand raus, und OpenLDAP hängt fest. Der Syslog kommt dann nie zu seiner angeforder- ten Antwort. Dem gehe ich nachher einmal nach... Es muss ja auch gar nicht unbe- dingt "OpenLDAP" sein, sondern evtl. ein ganz anderer Prozess, der dann den Syslog blockiert. Viele Grüße, Steffen

Moin, On Wed, 2 Nov 2005 16:47:14 +0100 Steffen Moser wrote:

Hallo Hans-Werner,

* On Tue, Nov 01, 2005 at 09:01 AM (+0100), Steffen Moser wrote:

...

Ich versuche jetzt einmal abzuklären, ob es tatsächlich zu einer "Race Condition" kommen kann.

So nach dem Motto: Der Syslog will reloaden. Er läuft dabei. Er muss aber zum Reload -aus welchem Grund auch immer- den OpenLDAP fragen. Dieser will daraufhin auch antworten, aber loggt natürlich erstmal.

Und genau in die Richtung scheint es zu gehen!

[...] Jetzt muss ich noch schauen, wie ich das sicher reproduzieren kann, dann geht's an SuSE als Bugreport raus. Gestern hatte ich einige Zeit herumgespielt, es aber nicht "auf Befehl" hingekriegt.

Die Frage dürfte vor allem sein: Wieso braucht "syslog-ng" die "nss_ldap" und wieso hilft hier der Timeout nicht aus der Ver- klemmung?

syslog-ng parst die Konfiguration neu. Dabei dürften die Anfragen rausgehen. Vielleicht der Nutzer/die Gruppe, auf die syslog-ng seine Rechte abwirft, vielleicht Einstellungen zu den Rechten der Logfiles oder des Unix-Sockets (/dev/log). Das Problem scheint nss_ldap zu sein. Es blockt nämlich scheinbar, wenn der Unix-Socket zwar bereits offen ist - es gibt schließlich auch schon ein Handle - aber die hineingeschriebenen Daten nicht liest. Das MSG_DONTWAIT-Flag bei sendto ist ja auch nicht gesetzt. Der kürzeste Weg aus der Misere scheint mir zu sein, mal /etc/nsswitch.conf zu checken. Sollte so aussehen: passwd: files ldap (und nicht "passwd: ldap files") gilt auch für die anderen. Die Bedeutung ist dann anders: Es wird erst versucht, auf Dateibasis alles zu machen, und wenn's da Probleme gibt, wird auf LDAP zurückgegriffen. Dann müssen natürlich die User rund um syslog-ng auch über das "files"-Modul verfügbar sein. Grundsätzlich wäre es bei so etwas grundlegendem wie dem nss_ldap/pam_ldap-Modul vielleicht auch besser, mit einem Timeout zu arbeiten... (achso ja, in /etc/pam.d natürlich auch nach der Präferenz der Authentifizierungsverfahren gucken, sollte hier aber mangels Authentifikation nicht relevant sein, wenn ich nicht irre). Vielleicht magst du ja auch deine augenblickliche Fassung von /etc/nsswitch.conf mal posten. Gruß, -hwh