Interne DB Sicherung hat sich Urlaub genommen .... -.- [GELÖST]

[OlliTheDarkness]

Ich bin sicher, dass die Ursache des Problems bei KeyHelp liegt
(Probleme ohne KeyHelp-Bezug gehören ins Offtopic-Forum)
Check

Server-Betriebssystem + Version
(z.B. Ubuntu 20.04)
Deb 12

Eingesetzte Server-Virtualisierung-Technologie
(z.B. keine, OpenVZ, KVM, XEN, etc.)
KVM

KeyHelp-Version + Build-Nummer
(z.B. 22.0 - Build 2366)
23.2 (Build 3097)

Problembeschreibung / Fehlermeldungen
Sicherung der internen DB schlägt fehl

Erstmals 23.10, ab da alle 24 Std.

Code: Select all

[PID-537084] [29-Oct-2023 00:00:02] DEBUG | Event log rotation performed.
[PID-537084] [29-Oct-2023 00:00:02] DEBUG | Event log IPs anonymized.
[PID-537084] [29-Oct-2023 00:00:02] INFO | cleanup roundcube contacts
[PID-537084] [29-Oct-2023 00:00:02] INFO | check rspamd configuration for outdated secure_ip configuration in worker-controller
[PID-537084] [29-Oct-2023 00:00:02] INFO | perform internal database backups
[PID-537084] [29-Oct-2023 00:00:02] ERROR | error while dumping internal database "keyhelp"
[PID-537084] [29-Oct-2023 00:00:02] ERROR | error while dumping internal database "phpmyadmin"
[PID-537084] [29-Oct-2023 00:00:02] ERROR | error while dumping internal database "roundcube"
[PID-537084] [29-Oct-2023 00:00:02] ERROR | error while dumping internal database "rainloop"
[PID-537084] [29-Oct-2023 00:00:02] ERROR | error while dumping internal database "snappymail"
[PID-537084] [29-Oct-2023 00:00:02] ERROR | error while dumping internal database "mysql"
[PID-537084] [29-Oct-2023 00:00:02] INFO | clean up file manager exchange directory
[PID-537084] [29-Oct-2023 00:00:02] INFO | jobs to run: update.php, statistic.php
[PID-537084] [29-Oct-2023 00:00:02] INFO | >>> trying to run "update"
[PID-537084] [29-Oct-2023 00:00:02] INFO | lock "update" acquired
[PID-537084] [29-Oct-2023 00:00:02] INFO | processing the job ...
[PID-537084] [29-Oct-2023 00:00:02] INFO | <<< job done, releasing lock "update"
[PID-537084] [29-Oct-2023 00:00:02] INFO | >>> trying to run "statistic"
[PID-537084] [29-Oct-2023 00:00:02] INFO | lock "statistic" acquired
[PID-537084] [29-Oct-2023 00:00:02] INFO | processing the job ...
[PID-537916] [29-Oct-2023 00:01:01] INFO | jobs to run: update.php, ssl_maintenance.php
[PID-537916] [29-Oct-2023 00:01:01] INFO | >>> trying to run "update"
[PID-537916] [29-Oct-2023 00:01:01] INFO | lock "update" acquired
[PID-537916] [29-Oct-2023 00:01:01] INFO | processing the job ...
[PID-537916] [29-Oct-2023 00:01:01] INFO | <<< job done, releasing lock "update"
[PID-537916] [29-Oct-2023 00:01:01] INFO | >>> trying to run "ssl-maintenance"
[PID-537916] [29-Oct-2023 00:01:01] INFO | lock "ssl-maintenance" acquired
[PID-537916] [29-Oct-2023 00:01:01] INFO | processing the job ...
[PID-537916] [29-Oct-2023 00:01:19] INFO | <<< job done, releasing lock "ssl-maintenance"
====
[PID-537084] [29-Oct-2023 00:01:50] INFO | <<< job done, releasing lock "statistic"

Erwartetes Ergebnis
Eine erfolgreiche Sicherung wäre ganz nett ^^

Tatsächliches Ergebnis
Nen anderes als das erwartete ?! ^^

Schritte zur Reproduktion
Wenn ich das wüsste, gäb es kein Problem

Zusätzliche Informationen
Ausser der obrigen Ausgabe von /var/log/keyhelp/cronjob/master.log, keine weiteren.
Beim zurückschauen war festzustellen, dass dies wohl schon ein paar Tage so ist.

Erstmals aufgetretten scheint das Problem nach einem Recovery.
Da es aber während der Wiederherstellung zu keinen Warn / Error Meldungen kam, steh ich grad bissel auf dem Schlauch.

[Tobi]

Und was passiert wenn du mysqldump manuell aufrufst?

[Henning]

Guten Morgen Olli,

bist du praktisch durch das Log durch Zufall darauf gestoßen und hast keine weiteren Meldung - bspw. per Mail - erhalten?

[Ralph]

hm, vieleicht ist da irgendwo noch ein altes lock file (vom oder vorm restore) im Spiel ...

[OlliTheDarkness]

Sorry, bissel eingespannt aktuell, daher so spät erst die Rückmeldungen.

Und was passiert wenn du mysqldump manuell aufrufst?

Keine Auffälligkeiten, die Dumps laufen fehlerfrei und vollständig.

Guten Morgen Olli,

bist du praktisch durch das Log durch Zufall darauf gestoßen und hast keine weiteren Meldung - bspw. per Mail - erhalten?

Gab keine Mailbenachrichtung, bin drüber gestolpert als ich im Panel in die Ereignis-Protokolle geschaut habe.

hm, vieleicht ist da irgendwo noch ein altes lock file (vom oder vorm restore) im Spiel ...

Hmm, nur wo sollte das rumliegen, bin auf keines gestoßen bisher.

[Alexander]

Das Passwort des KeyHelp-DB-root-Users ist noch korrekt (/etc/keyhelp/config/config.json)?

/tmp/ ist beschreibbar?

[OlliTheDarkness]

Das Passwort des KeyHelp-DB-root-Users ist noch korrekt (/etc/keyhelp/config/config.json)?

/tmp/ ist beschreibbar?

Eig. ja, aber ich spiel gleich nochmal die Sicherung des DB Benutzers ein.

Jup is es.

[OlliTheDarkness]

Guten Morgen

So, dass erneute Einspielen des KH-Root Users brachte keine Veränderung.
Um exakt 00:00:02 Uhr schlug der Fehler wieder zu.
Allerdings (ich weiß nicht warum es mir vorher nicht aufgefallen ist) wurde im zuge des Fehlers nachfolgender geloggt.

Code: Select all

Okt 31 00:00:02 mariadbd[809]: 2023-10-31  0:00:02 11478 [ERROR] Incorrect definition of table mysql.proc: expected column 'definer' at position 11 to have type varchar(, found type char(141).

Im Grundsatz erscheint es mir jetzt auch logisch, die KH Routine legt Backups an aber im Fehlerfall stoppt sie vollständig.
Soweit , so gut, auch verstehe ich die Meldung und was er wo zu beanstanden hat.

ABER wie man sieht betrifft es die DB mysql und ich bin jetzt nicht so der Freund von "OP am offenen Herzen" ...

Da ich noch nie mit der Problematik "Zerschossenes MySQL Herz" zutun hatte, hat wer vieleicht nen sicheren Lösungsweg

Hab leichte Befürchtungen mir den MySQL Server zu zerschießen wenn ich in der DB "rumpfusche".

Vermutlich kam der Fehler durch einen Versionsunterschied der DB Server zwischen altem und neuem zustande, anders kann ich es mir nicht erklären.

[Jolinar]

ABER wie man sieht betrifft es die DB mysql und ich bin jetzt nicht so der Freund von "OP am offenen Herzen" ...

Da ich noch nie mit der Problematik "Zerschossenes MySQL Herz" zutun hatte, hat wer vieleicht nen sicheren Lösungsweg

Um nicht nur auf der dunklen, sondern auch auf der sicheren Seite zu sein, machst du einfach vorher ein Backup...
Dann ein:

Code: Select all

ALTER TABLE mysql.proc MODIFY definer varchar(255);

DB Server noch neu starten
Glücklich sein

[Ralph]

könnte durch ein Upgrade Bug verursacht werden ...
https://suay.site/?p=2463

also ich kenne es nur über diesen Weg z.b. nach mysql import auf höhere Version:

Code: Select all

cd /usr/bin
mysql_upgrade --force
systemctl restart mysql

[OlliTheDarkness]

ABER wie man sieht betrifft es die DB mysql und ich bin jetzt nicht so der Freund von "OP am offenen Herzen" ...

Da ich noch nie mit der Problematik "Zerschossenes MySQL Herz" zutun hatte, hat wer vieleicht nen sicheren Lösungsweg

Um nicht nur auf der dunklen, sondern auch auf der sicheren Seite zu sein, machst du einfach vorher ein Backup...
Dann ein:

Code: Select all

ALTER TABLE mysql.proc MODIFY definer varchar(255);

DB Server noch neu starten
Glücklich sein

Wäre auch mein vorgehen gewesen, nur wie gesagt, noch nie gehabt das ausgerechnet die mysql DB was abbekommen hat.
Somit auch kein Plan was eventuell noch an Rattenschwanz dran hängt.

Is auf jedenfall jetzt durchgeführt, wir warten nun bis 00:00:02 Uhr ab

OTD International News hält sie auf dem laufenden und berichtet heut Nacht Live vor Ort.

[OlliTheDarkness]

OTD International News berichtet Live vom Ort des geschehens.

Es gibt keine weiteren Verletzte zu vermelden.

Der Täter, eine junge mysql Table wurde erfolgreich therapiert.

Wir geben hiermit nun zurück ins Forum.

Für Sie vor Ort war OlliTheDarkness.