vServer: seit 3 Tagen regelmäßig korrupte MySQL-Tabellen

Welche Kernel habt ihr denn momentan am Start? Bei mir ist es dieser:

# uname -a
Linux v230211191.yourvserver.net 2.6.29.6-vs2.3.0.36.14-beng #1 SMP Tue Aug 18 08:43:50 BST 2009 x86_64 GNU/Linux

Heute Nacht war es mal wieder so weit. Dieses Mal schon um 01:45 Uhr.

Nov 20 01:45:03 v230211191 mysqld_safe[353]: Number of processes running now: 0
Nov 20 01:45:03 v230211191 mysqld_safe[355]: restarted
Nov 20 01:45:03 v230211191 mysqld[358]: 091120  1:45:03  InnoDB: Database was not shut down normally!
Nov 20 01:45:03 v230211191 mysqld[358]: InnoDB: Starting crash recovery.
Nov 20 01:45:03 v230211191 mysqld[358]: InnoDB: Reading tablespace information from the .ibd files...
Nov 20 01:45:03 v230211191 mysqld[358]: InnoDB: Restoring possible half-written data pages from the doublewrite
Nov 20 01:45:03 v230211191 mysqld[358]: InnoDB: buffer...
Nov 20 01:45:03 v230211191 mysqld[358]: 091120  1:45:03  InnoDB: Starting log scan based on checkpoint at
Nov 20 01:45:03 v230211191 mysqld[358]: InnoDB: log sequence number 0 5255340.
Nov 20 01:45:03 v230211191 mysqld[358]: InnoDB: Doing recovery: scanned up to log sequence number 0 5255340
Nov 20 01:45:03 v230211191 mysqld[358]: InnoDB: Last MySQL binlog file position 0 169616, file name /var/log/mysql/mysql-bin.000222
Nov 20 01:45:03 v230211191 mysqld[358]: 091120  1:45:03  InnoDB: Started; log sequence number 0 5255340
Nov 20 01:45:03 v230211191 mysqld[358]: 091120  1:45:03 [Note] Recovering after a crash using /var/log/mysql/mysql-bin
Nov 20 01:45:03 v230211191 mysqld[358]: 091120  1:45:03 [Note] Starting crash recovery...
Nov 20 01:45:03 v230211191 mysqld[358]: 091120  1:45:03 [Note] Crash recovery finished.
Nov 20 01:45:04 v230211191 mysqld[358]: 091120  1:45:04 [Note] /usr/sbin/mysqld: ready for connections.
Nov 20 01:45:04 v230211191 mysqld[358]: Version: '5.0.32-Debian_7etch11-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Debian etch distribution

Ich benutze zurzeit nur eine einzige InnoDB-Datenbank (roundcube). Diese werde ich heute mal auf MyISAM umstellen und dann InnoDB abschalten.

Das Update auf Lenny habe ich noch nicht gemacht, weil ich heute Morgen früh aufstehen musste und dann die Nacht nicht so lange aufbleiben konnte.

Gruß
Konni

Das kann ich mir nicht vorstellen. Zumal ich Roundcube nur gaaanz selten benutze, wenn ich mal nicht am eigenen Rechner sitze.

Installiert habe ich wohl noch eine etwas ältere Version:
RoundCube Webmail IMAP Client
Version 0.2.2

Gruß
Konni

Zitat von killerbees19;9720

Habt ihr/du eigentlich bei Netcup schon einmal nachgefragt wegen diesem Problem? Ich habe den Thread jetzt nicht immer verfolgt, aber ich könnte mir vorstellen, dass irgendetwas am Node den Fehler produziert und/oder vllt. der Raid-Controller/HDD des Nodes dafür verantwortlich ist. Ist natürlich nur eine Vermutung, aber fragen kostet ja nichts :o

Ich hatte schonmal nachgefragt, ob ein Festplatten- oder Speicherproblem vorliegt.

Die kurze Antwort:

Zitat

laut Monitoring sind keine Festplattenfehler oder Memory-Fehler auf dem von Ihnen genutzten Node bekannt. Eventuelle Fehlermeldungen werden alle 10 Minuten ausgewertet.

Gruß
Konni

Tja, wenn ich das wüsste, hätte ich das Problem bestimmt schon beheben können. Selbst mit aktivierten MySQL-Log steht nichts drin, außer, dass MySQL neu gestartet wurde.

Seit dem Update auf Lenny ist das ganze eher schlimmer geworden. Der MySQL-Server stürzt jetzt nachts komplett ab, während ja unter Etch nur postfix nicht mehr auf die Datenbank zugreifen konnte.

MySQL hat jetzt auch irgendwas beim Start zu meckern:

# /etc/init.d/mysql restart
Stopping MySQL database server: mysqld.
Starting MySQL database server: mysqld.
Linking mysqld.sock to the postfix-jail.
Checking for corrupt, not cleanly closed and upgrade needing tables..
v230211191:/etc/mysql# /usr/share/mysql/debian-start.inc.sh: line 21: MYSQL: unbound variable
/usr/share/mysql/debian-start.inc.sh: line 25: MYSQL: unbound variable

Gerade eben habe ich noch die einzige InnoDB-Datenbank zu MyISAM konvertiert und InnoDB abgeschaltet. Mal schauen, was heute Nacht passiert.

Gruß
Konni

Zitat von killerbees19;9839

Dieser Fehler wird meistens durch überschriebene (oder nicht angepasste) Startscripte in /etc/mysql verursacht, oder die debian-start.inc.sh selbst ist veraltet/falsch. Am besten alle gesetzten Variablen kontrollieren und vergleichen

Hallo Christian,

die Variable $MYSQL ist nicht gesetzt. Ich hätte das ja noch händisch erledigt, weiß aber gar nicht, auf welchen Wert die gesetzt werden soll. Dem Shell-Skript nach vermute ich, dass dort der Pfad zur mysql-binary gesetzt werden soll.

Kann das jemand bestätigen / widerlegen?

Gruß
Konni

Nachtrag:
Das kleine MySQL-Problem hat sich schon erledigt:

MYSQL="/usr/bin/mysql --defaults-file=/etc/mysql/debian.cnf"

Das hat in der /etc/mysql/debian-start gefehlt.

Mal schauen, was heute Nacht passiert.

Gruß
Konni

Erste gute Nachricht:
Der Server lief heute Nacht mit der abgeschalteten InnoDB-Engine einwandfrei durch und funktioniert immer noch bestens.

bebbo
Auch das Neustarten von postfix korrigierte ebenso wie das Neustarten von MySQL den Fehler. Ich weiß aber nicht, ob das nur an der postfix-jail Verlinkung gelegen hat. Wird diese beim postfix-Neustart auch neu angelegt?

Welcher Wert gilt denn in der my.cnf bei max connections, wenn diese Zeile auskommentiert ist?

Bleibt die Frage: Was ist jetzt ohne die InnoDB-Engine anders, dass heute Nacht zum ersten Mal Ruhe ist? Vor allem: Warum sollte postfix mitten in der Nacht so viele Verbindungen zu MySQL aufbauen? Ich bekomme nachts so gut wie keine Mails (außer die DenyHosts-Reports).

Gruß
Konni

Das hatte ich ja schon gemacht ... da passiert aber so gut wie nichts.

Freitag:

Nov 20 22:48:32 v230211191 postfix/anvil[28481]: statistics: max connection rate 1/60s for (smtp:188.40.236.***) at Nov 20 22:45:11
Nov 20 22:48:32 v230211191 postfix/anvil[28481]: statistics: max connection count 1 for (smtp:188.40.236.***) at Nov 20 22:45:11
Nov 20 22:48:32 v230211191 postfix/anvil[28481]: statistics: max cache size 1 at Nov 20 22:45:11
Nov 20 23:08:55 v230211191 dovecot: IMAP(***@konrath.***): Disconnected in IDLE
Nov 20 23:08:55 v230211191 dovecot: IMAP(***@konrath.***): Disconnected in IDLE
Nov 20 23:12:59 v230211191 dovecot: auth-worker(default): mysql: Connected to localhost (syscp)
Nov 20 23:12:59 v230211191 dovecot: imap-login: Login: user=<***@konrath.***>, method=PLAIN, rip=***.87.***.51, lip=188.40.236.111, TLS
Nov 20 23:13:06 v230211191 dovecot: IMAP(***@konrath.***): Disconnected in IDLE
Nov 21 00:40:17 v230211191 postfix/smtpd[22387]: connect from mx0.gmx.net[213.165.64.100]
Nov 21 00:40:17 v230211191 postfix/smtpd[22387]: 246BEB3C180: client=mx0.gmx.net[213.165.64.100]
Nov 21 00:40:17 v230211191 postfix/cleanup[22391]: 246BEB3C180: message-id=<***.787gmx1@mx052.gmx.net>
Nov 21 00:40:17 v230211191 postfix/qmgr[14307]: 246BEB3C180: from=<***@web.de>, size=65511, nrcpt=1 (queue active)
Nov 21 00:40:17 v230211191 postfix/smtpd[22387]: disconnect from mx0.gmx.net[213.165.64.100]
Nov 21 00:40:17 v230211191 postfix/virtual[22392]: 246BEB3C180: to=<***@konrath.***>, relay=virtual, delay=0.12, delays=0.11/0/0/0.01, dsn=2.0.0, status=sent (delivered to maildir)
Nov 21 00:40:17 v230211191 postfix/qmgr[14307]: 246BEB3C180: removed
Nov 21 00:43:37 v230211191 postfix/anvil[22389]: statistics: max connection rate 1/60s for (smtp:213.165.64.100) at Nov 21 00:40:17
Nov 21 00:43:37 v230211191 postfix/anvil[22389]: statistics: max connection count 1 for (smtp:213.165.64.100) at Nov 21 00:40:17
Nov 21 00:43:37 v230211191 postfix/anvil[22389]: statistics: max cache size 1 at Nov 21 00:40:17
Nov 21 01:50:01 v230211191 postfix/pickup[27085]: 6AC21B3C182: uid=0 from=<root>
Nov 21 01:50:01 v230211191 postfix/cleanup[6402]: warning: connect to mysql server localhost: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111)

Wie man sieht, war nicht viel los vor dem Crash ...

Gruß
Konni

Hm ...

Ich habe glaube ich einzig in der main.cf die Einstellungen zu TLS geändert - das müsste dieser Teil sein:

# tls config
smtpd_use_tls = yes
smtp_tls_note_starttls_offer = yes
smtpd_tls_key_file = /etc/ssl/private/***.key
smtpd_tls_cert_file = /etc/ssl/certs/***.crt
smtpd_tls_loglevel = 1
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
tls_random_source = dev:/dev/urandom
tls_random_prng_update_period = 3600s

Das lief ja aber auch über Monate hinweg einwandfrei. Die master.cd habe ich - soweit ich mich erinnere - nicht angefasst.

tlsmgr lässt laut master.cf nur einen Prozess zu. Kann es sein, dass dann ein Prozess blockiert und somit die darauffolgenden Mails nicht mehr ausgeliefert werden?

Denn in meiner ersten netstat.txt sieht man, dass python zu diesem Zeitpunkt aktuell mit postfix verbunden ist (wird wohl eine Report-Mail von denyhosts sein).

Auf TLS würde ich aber ungern verzichten. Das ist auch immerhin einer der Gründe, warum ich einen eigenen vServer als Mail-Server einsetze.

Gruß
Konni