Archiv für 10. Dezember 2008

Probleme mit einem Postfix-Mailserver, der seine Userdaten aus einer MySQL-DB holt

Vor ein paar Tagen bekam der Mailserver eines von mir betreuten Root-Servers mehrfach pro Tag Probleme, die sich zunächst in Mails mit Fehlerbenachrichtigungen manifestierten. In diesen Mails, die ein Subject der Art "Postfix SMTP server: errors from unknown[216.1.64.211]" und ungefähr folgendem Inhalt hatten:

Transcript of session follows.

 Out: 220 hostname.server.tld ESMTP Postfix (2.5.5)
 In:  EHLO DougTest
 Out: 250-hostname.server.tld
 Out: 250-PIPELINING
 Out: 250-SIZE 50000000
 Out: 250-ETRN
 Out: 250-STARTTLS
 Out: 250-AUTH LOGIN PLAIN
 Out: 250-AUTH=LOGIN PLAIN
 Out: 250-ENHANCEDSTATUSCODES
 Out: 250-8BITMIME
 Out: 250 DSN
 In:  MAIL FROM:<believersn3@iinet.net.au>
 Out: 250 2.1.0 Ok
 In:  RCPT TO: <username@kundendomain.tld>
 Out: 451 4.3.0 <username@kundendomain.tld>: Temporary lookup failure
 In:  DATA
 Out: 554 5.5.1 Error: no valid recipients
Session aborted, reason: lost connection

Nach ein paar Minuten hat sich dann scheinbar alles wieder normalisiert und es waren nur noch Spuren in den Logs zu finden. Auszug aus den Logdatein: postfix-mysql-problem.log Dieses Problem trat mehrfach pro Tag auf, aber in absolut unregelmäßigen Abständen und mit unterschiedlich häufigen Vorfällen pro Tag. Nach 2 oder 3 Tagen kam es dann auch zu Loginproblemen via POP3 und IMAP, u.a. auch via Webmail, denn auch Cyrus arbeitet hier mit virtuellen Usern via MySQL-DB. Es konnte dann auch keine Mail mehr verschickt werden. Googlen nach "fatal: mysql:/usr/local/etc/postfix/mysql-mydestination.cf(0,lock|fold_fix): table lookup problem" und anderen Symptomen brachte zunächst nichts. Ich habe dann erstmal die Zahl der postfix smtp und amavisd child Prozesse hochgesetzt und gegenseitig angepaßt, da ich erst dachte, daß es vielleicht bei der Zahl der Prozesse die bei Postfix und Amavisd-new sich gegenseitig zuarbeiten, vielleicht klemmt – aber das hatte keinen nennenswerten Erfolg. Erst das Suchen nach "mysql to many connections" brachte mich auf diese Seite und damit der Lösung näher. Eine Überprüfung des Werts von max_connections vom MySQL-Server mit

show variables like 'max_connections';

zeigte dann, daß der Default-Wert des mysql-server 5.0 Ports unter FreeBSD 6.4 sogar nur 100 beträgt. Ich habe ihn dann zunächst mit

set GLOBAL max_connections=500;

vorläufig hochgesetzt und dann durch Einfügen einer Zeile

set-variable=max_connections=500

in der Rubrik [mysqld] der /usr/local/etc/my.cnf den Wert dauerhaft gesetzt. Seitdem ist das Problem nicht wieder aufgetreten. Wie man im Log /var/log/messages sehen kann, findet gleichzeitig ein brute force Eindringversuch statt und da sowohl bei jeder eintreffenden Mail als auch bei jedem Mailabruf mindestens eine MySQL-Abfrage auslöst, treibt das die Zahl der gleichzeitigen Verbindungen erheblich in die Höhe und so kam es durch die wieder ansteigende Spamwelle, den brute force Angriff und die natürlich auch noch stattfindenden MySQL-Verbindungen durch PHP-Webanwendungen zu Situationen, in denen der Default-Wert von 100 Verbindungen nicht ausgereicht hat.

Bekanntmachen von Timmy mit Scotty bzw. Timmys erste Woche

Gestern Abend haben wir die erste Begegnung arrangiert. Karin saß mit Scotty unten im Wohnzimmer und hatte ihn sprichwörtlich an der kurzen Leine und hat ihn gleichzeitig mit Wurst- und Käsestückchen so vollgestopft, daß er das Interesse an der Umwelt nahezu komplett verloren hatte. Währenddessen habe ich oben die Tür zu Timmys Zimmer aufgemacht und ihn nach unten gelockt. Allerdings hat er kurz vor dem Wohnzimmer das Interesse an weiteren Erkundungen verloren und es hat eine ziemliche Zeit gedauert, bis er es überhaupt betreten hat. Und auch dann ist er nicht weiter als einen Meter reingegangen, so daß Scotty ihn eigentlich gar nicht sehen konnte (Yummy, all die guten Leckerlis für das pure gehorsame Liegen auf seiner Decke! *g*). Da wir es nicht zu sehr forcieren wollten, ist es dann erstmal dabei geblieben. Ich bin mir aber sicher, daß Timmy durchaus Scotty bemerkt hatte. Später am Abend haben wir dann nochmal oben eine entfernte Begegnung in meinem Schlafzimmer arrangiert: Ich habe Scotty am Bett mit Leckerlis "fixiert" (und ihn natürlich gleichzeitig mit der Leine gesichert) und Timmy ist aus dem anderen Zimmer gekommen und hat durch die Tür reingesehen. Scotty hat ein wenig geknurrt, es aber gleich sein gelassen, als ich ihn mit Leckerlis überfrachtet habe. Heute Abend geht es weiter. Vielleicht wird es doch was länger dauer, die beiden aneinander zu gewöhnen, als wir zunächst gedacht haben.

Update: Leider bin ich diese Woche Abends immer sehr spät nach Hause gekommen. Deshalb hat Karin alleine weitere Annäherungs-"Maßnahmen" durchgeführt und mehrfach die beiden in größerer Entfernung sowohl unten im Wohnzimmer als auch oben bei ihr sich begegnen lassen. Das einzige, was ich diese Woche von Timmy selber berichten kann: Mittwoch habe bin ich um halb zehn zu ihm, habe mich ein paar Minuten mit ihm beschaeftigt, bevor er sich entschieden hat, erstmal in Gesellschaft sein Abendbrot zu sich zu nehmen. Da das ein wenig länger dauerte, bin ich dabei leider eingeschlafen und erst wieder mit Timmy auf mir aufgewacht, als Karin um nach 24h nach Hause kam. Gottseidank hat sie dann für mich den Nachtspaziergang mit Scotty übernommen, denn ich bin dann nur noch rüber in mein eigenes Bett getorkelt. Außerdem haben wir in den letzten beiden Tagen für den Kater Vormittags immer die Tür oben geöffnet und Scotty auf Küche und Wohnzimmer beschränkt, damit sich der Kater die ganze obere Etage, Treppenhaus und Flur aneignen kann. Am Wochenende werden wir das dann auch nochmal umdrehen, also Timmy Küche und Wohnzimmer entdecken lassen und Scotty nach oben bringen. Gespannt bin ich auch auf die weiteren direkten Begegnungen, die wir am Wochenende versuchen werden.
Update 2:
Gestern und heute haben wir weitere Schritte unternommen, um Scotty und Timmy aneinander zu gewöhnen. Aber wir brauchen uns wohl wirklich keinen Illusionen hingeben, daß sich das schnell bewerkstelligen läßt. Heute habe ich mit Timmy erstmal das Wohnzimmer in Beschlag genommen, während Karin mit Scotty den Nachmittagsspaziergang gemacht hat. Timmy war aber nicht so ganz glücklich mit der Situation und wäre am liebsten wieder schnell zurück in sein Refugium im Obergeschoß gezischt. Deshalb habe ich die Wohnzimmertür zugemacht und er hat sich dann in aller Ruhe Wohnzimmer, Küche und Hausarbeitsraum angesehen und erschnuppert. Ich hatte keine Ahnung, daß alleine ein Karton mit Kaminholz es wert ist, knapp 10 min beschnuppert zu werden! 😉 Als Karin dann wieder zurück war, hat Scotty einen Textilmaulkorb angelegt bekommen und Timmy hat sofort hinter der Tür Aufstellung genommen – scheinbar war die Aussicht, wieder hoch in Sicherheit zu kommen, für ihn wertvoller als dem Hund aus dem Weg zu gehen. Ich habe dann Timmy von der Tür weggebracht und Karin hat sich mit Scotty in die Mitte des Wohnzimmers gesetzt und hat Scotty mit einer Leine gesichert, die sie um sich herumgelegt hat. Dann haben sich Timmy und Scotty länger beäugt, Timmy saß dazu auf einer erhöhten Position auf der Fensterbank. Karin hat Scotty mit Leckerlis versorgt, solange er ganz ruhig war. Einmal hat Scotty ganz kurz gebellt, was aber Timmy scheinbar nicht wirklich beeindruckt hat. Kurz darauf kam eine Nachbarin zu Besuch und als sie geklingelt hat, fing Scotty sofort zu bellen an, wie es nun mal seine Art ist. Auch das hat Timmy sehr "cool" genommen. Nachdem die Nachbarin wieder weg war, ist er sogar an Scotty vorbei in die Küche gegangen und nach kurzer Zeit auch wieder zurück ins Wohnzimmer gekommen, ohne das man ihm irgendeine Angst vor Scotty ansehen konnte. Ich habe mich dann noch aufs Sofa gesetzt und Timmy ist zu mir gekommen. Ich habe dann eine Weile ferngesehen und habe dabei Timmy gestreichelt. Er hat das offensichtlich genossen, denn er fing an zu schnurren. Währenddessen hat Karin weiter mit Scotty in der Mitte des Wohnzimmers gesessen. Nach ca. 10 min haben wir dann diese Begegnung beendet und für Timmy die Wohnzimmertür geöffnet. Diese Gelegenheit hat er dann auch sofort genutzt. Hier Bilder von unserem heutigen Versuch: [mygal=timmy_5]

Update 3: Da ich während der Woche kaum Gelegenheit finden werde, bei den täglichen Annäherungs-"Maßnahmen" mitzumachen und hier auch noch davon zu berichten, habe ich Karin ein eigenes Blog eingerichtet. Sobald ich Gelegenheit gefunden habe, es endgültig einzurichten und Karin die Nutzung zu zeigen, wird Karin dort berichten.