The Revenge of Mariadb IV

Es ist mal wieder Zeit für eine MariaDB Geschichte. Keine Panik, die wird nicht wieder biblisch werden 🙂

Es war mal wieder Zeit für ein OS-Upgrade

Mittlerweile waren drei OS-Releases ins Land gegangen und eine sich anbahnende Sicherheitslücke im Exim .. PSSST! Ich habe sie Euch nicht verraten. Tut so, also wenn Ihr nächste Woche das erste mal davon gelesen habt, ja? 😉 .. zwang zu einem schnellen Update auf eine nicht betroffene Version. Fedora 29 sollte es sein 😉

Nun, glücklicherweise war auch ein anderer Testserver noch auf der gleichen alten OS Release, so daß er als Testlauf herhalten durfte. Dieser Test lief ausgesprochen positiv ab, um genau zu sein, makellos. Daher wurde kürzestfristig entschieden, auch den eigentlichen Kandidaten auf die gleiche Art zu updaten. Ein Snapshot der VM und 30 Minuten später  war das Update komplett und der Server startete wieder.

Mailserver, Webserver, IMAP-Server, diverse Dienste liefen. Was natürlich nicht lief war die MariaDB .. Ätzzz. N I C H T  S C  H O N  W I E D E R!   Auch gutes Zureden, energisches Nachtreten mit systemctl änderte nichts an diesem Status, der Datenbankserver startete nicht.

Same procedure als last year, Miss Sophie?

Leider nein. Letztes mal hatte sich bekanntlich ein Konfigfile des Systemd geändert, so daß die zum Start nötigen Limits nicht gesetzt wurden. Natürlich wurde der DIFF Test vom letzten mal auch wieder angewendet, zeigte aber keinen Unterschied an. Also mußte die gute alte Methode „Start den Dienst von Hand, dann bekommst Du Infos“ herhalten.

Wie macht man das?

Wir schauen uns mal an, was der Systemd so starten wollen würde:

cat /usr/lib/systemd/system/mariadb.service

Da findet dann das hier:

ExecStartPre=/usr/libexec/mysql-prepare-db-dir %n
# MYSQLD_OPTS here is for users to set in /etc/systemd/system/mariadb@.service.d/MY_SPECIAL.conf
# Note: we set –basedir to prevent probes that might trigger SELinux alarms,
# per bug #547485
ExecStart=/usr/libexec/mysqld –basedir=/usr $MYSQLD_OPTS $_WSREP_NEW_CLUSTER
ExecStartPost=/usr/libexec/mysql-check-upgrade

Das POST können wir ignorieren, soweit kommen wir nicht, bleiben nur Pre und der eigentliche Dienststart.

Das in den einschlägigen Envfiles  unter /etc/sysconfig/ nichts steht, reicht also ein :

/usr/libexec/mysqld –basedir=/usr

für den Test aus. Ja super.. eine Fehlermeldung:   Can’t set requested open_files (1024) to 2000 …

Das lag an dem ulimit hier:

# ulimit -a
core file size (blocks, -c) unlimited
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 32088
max locked memory (kbytes, -l) 16384
max memory size (kbytes, -m) unlimited
open files (-n) 1024
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) unlimited
cpu time (seconds, -t) unlimited
max user processes (-u) 32088
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited

Damit kann nicht mal die minimale Version der Datenbank starten 😉 Ergo geben wir ein: „ulimit -n 99999“ und starten es nochmal und siehe da, es hat sich doch wieder was geändert:

2019-06-04 23:13:41 0 [ERROR] /usr/libexec/mysqld: unknown variable ‚innodb_additional_mem_pool_size=50M‘
2019-06-04 23:13:41 0 [ERROR] Aborting

Wenn man denn endlich mal in Logfile schaut, sieht man dort auch die Warnung, daß sich das ja mal ändern könnte. Wer rechnet schon mit damit, daß da jemand mal Ernst macht 😉

2019-05-26 09:18:16 b753fd80 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB’s internal memory allocator.
2019-05-26 9:18:16 3075734912 [Note] InnoDB: innodb_empty_free_list_algorithm has been changed to legacy because of small buffer pool size. In order to use backoff, increase buffer pool at least up to 20MB.

Merke, erst ins Datenbank Log schauen, dann Server updaten!

Drei OS-Versionen sind dann vielleicht doch etwas happig bei einem Update. Diese Option findet man, so man sie gesetzt hat, in der Datei /etc/my.cnf . Anweisung auskommentieren, diesmal Datenbank über systemctl starten und läuft wieder 🙂

Und hier dachte ich eigentlich, ist die Story zu ende… war sie aber nicht!

Der an diesem Master angeschlossene Replications Elf ( Sklave sagt man im PCSG nicht mehr 😉 ) mochte die Replikationsblöcke vom Master nicht mehr lesen, weil Checksumme unbekannt! Das lag daran, daß der Replikations Elfe eine ältere Datenbankversion laufen hatte, da LTS. Einer langen Suche kurzes Ende:

Elfen anhalten: mysql -p -e „stop slave
auf den Master connecten: mysql -p -e „set global binlog_checksum=’NONE‘; SHOW MASTER STATUS;“ ausführen.

+------------------+----------+--------------+------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| mysql-bin.000138 | 521505   |              |                  |
+------------------+----------+--------------+------------------+

Datenbank auf dem Master dumpen, auf den Elfen kopieren. Auf dem Elfen die Datenbank wipen, den SQL Dump einspielen.

Auf dem Elfen : mysql -p -e „change master to MASTER_LOG_FILE=’mysql-bin.000138′, MASTER_LOG_POS=521505;start slave

Sollte wieder gehen. Ging nicht.. Neuer Fehler! Statt:

Last_IO_Errno: 1236
Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: 'Slave can not handle replication events with the checksum that master is configured to log; the first event 'mysql-bin.000136' a'

gabs jetzt :

Last_IO_Errno: 1045
Last_IO_Error: error connecting to master 'test@masterserver:3306' - retry-time: 60  retries: 86400

Er zum Geier ist „TEST“ !?

Tja, keine Ahnung wie das passieren konnte, aber der „change master to …“ Befehl hatte den Replikationsusernamen durch „test“ ersetzt! Einfach so! Passwort war ok, Servername war ok, Username weg! Wie geil ist das denn ?!?!?

Also nochmal mit dem change master an den Elfen ran:

/usr/bin/mysql -p -e „stop slave;;CHANGE MASTER TO MASTER_USER=’myreplicationusername‘,MASTER_PASSWORD=’MeinPasswort‘;start slave

Da machste was mit als Admin … Ich wollte doch nur den Exim abdichten, nicht das Rad neu erfinden! Naja, jetzt gehts ja erstmal wieder 🙂 Und bevor noch einer fragt, nein, der Server hatte extern nur Port 25 zu bieten, deswegen ja auch das Update 😉

Fedora 28 und das Upgradeaftermatch

„Hey, Fedora 27 ist Geschichte, freu Dich auf Fedora 28, User!“ Ich habe ihn nicht gehört, aber der MCP hat das bestimmt vorhin beim Upgrade gesagt oder gedacht. Leider hat es nicht funktioniert.

Keine Friends in Sicht…

Ja, heute war es soweit: das obligatorische Sechsmonatsupgrade auf Fedora 28 war dran. Auf dem Laptop läuft es seit letzter Woche, also sollte das ja jetzt kein Problem werden. Flugs den Desktop stoppen, in eine Root-Shell und DNF mit Arbeitsanweisung versorgen. Gesagt, getan. 15 Minuten später waren alle 3800 Pakete geladen und bereit. Zwei unwichtige Downgrades und 3 unwesentliche Altpaketentfernungen waren abgesegnet. Schritt 1/7550 kam in Sicht und …. hey… (nanü? Was ist mit der Absatzüberschrift los?)… ging 🙂

7550 Schritte später, wartet mein Cursor, meine Root-Shell und mein neues Fedora auf mich, also „reboot“ getippt, beide Daumen zerquetscht und gewartet. Bios .. Grub \o/ … die seit Jahren vertraute Meldung, daß die Kernel-Module vom Systemd nicht geladen werden konnten…( Anm.d.R „auch diesmal“ wieder nicht 🙁 ) .. Fedora Bootlogo… wird weiß… Login! … DESKTOP! … P.R.O.G.R.A.M.M.E !.! … was ist das denn?

„Wollen Sie die Default Ordner rename to die lokal gewählte Sprache…“

Was zum Geier… wie kommt Cinnamon darauf, daß ich bei einem Deutschen Desktop englische Verzeichnisnamen haben können wollte? Könnten die Spracheinstellungen defekt sein? Nachguck.. Nö. Deutsch/Deutsch. Sieht ok aus. „Da hat bestimmt Gnome beim Update was zerlegt.“ war der Gedanke, also ins Gnome gewechselt… was ein schwerer Fehler war, den GNOME ist nicht mehr .. DAS hat es tatsächlich beim Upgrade zerlegt, denn die Gnome-Shell kommt nicht an den Start. Die Programme schon, aber ohne Windowmanager nützt das nicht viel 😀 … Hmm.. Programme melden sich aber in Deutsch, das ja komisch.

Mit STRG+ALT+F3 ab in die Root-Shell, anmelden …. was ist das denn? „setlocale: Konnte LC_TIME nicht setzen“ (War natürlich auf english, aber zum besseren Verständnis wird es hier eingedeutscht). Wie kann das denn sein?

Kurz mal die Umgebungsvariablen checken:

# strings /proc/self/environ 
...
LANG=de_DE.UTF-8
...
_=/usr/bin/strings


# locale
LANG=de_DE.UTF-8
LC_CTYPE="de_DE.UTF-8"
LC_NUMERIC="de_DE.UTF-8"
LC_TIME="de_DE.UTF-8"
LC_COLLATE="de_DE.UTF-8"
LC_MONETARY="de_DE.UTF-8"
LC_MESSAGES="de_DE.UTF-8"
LC_PAPER="de_DE.UTF-8"
LC_NAME="de_DE.UTF-8"
LC_ADDRESS="de_DE.UTF-8"
LC_TELEPHONE="de_DE.UTF-8"
LC_MEASUREMENT="de_DE.UTF-8"
LC_IDENTIFICATION="de_DE.UTF-8"
LC_ALL=

Alles ok, Deutsch ist eingestellt. Übersetzungen gingen ja in den Programmen, aber tatsächlich war die Zeit in English mit 12H+AM/PM .. schauen wir doch mal mit strace auf welche Locale will das Programm eigentlich zugreifen: also „strace -f locale de_DE.UTF-8“ eingegeben und es würde gern diese Datei benutzen „/usr/lib/locale/de_DE.utf8/LC_TIME“ … ist ja merkwürdig, die ist gar nicht vorhanden…. hey! den ganzen Ordnerbaum gibt es gar nicht! HIER FEHLT DEUTSCH!

Und so behebt man das

Die Sachelage ist klar: Keine Deutsche Locale vorhanden, also nachinstallieren. Da wir den Pfad kennen, fragen wir dnf wer das bereitstellen könnte:

# dnf provides „/usr/lib/locale/de_DE.utf8/LC_TIME“

glibc-langpack-de-2.27-32.fc28.x86_64 : Locale data for de
….

also installieren wir das und rebooten kurz ( damit auch die Bootprozesse in Deutsch melden können, wenn Sie das wünschen):

# dnf install glibc-langpack-de

und da merkt man dann, daß das kein Witz war, weil der jetzt „j“ nicht mehr als „ja“ => „yes“ erkennt .. muß man also wirklich „y“ drücken 🙂

Nach dem Reboot war es dann in Ordnung. Warum der den Language-pack nicht installiert hat, werden wir nicht erfahren. Um GNOME werde ich mich wohl mit „rm -rf .config/gnome-session“ kümmern müssen.

Update Tag 2:

Die WetterApp geht nicht. Libmozjs crasht beim Start extrem hart, incl. Coredump. Autsch. Mal sehen was von den HinterbänklerApps noch so nicht geht.

Jitsi kann keine SIP Anrufe mehr annehmen

Wer kennt das nicht, in der Firma läuft es ruhig. Kunden melden sich nur per Email, aber das Telefon schweigt seit Tagen. Das alljährliche Sommerloch, wegen dessen wir alle in den Urlaub fahren …, oder ?

Paranoide Menschen würden jetzt per Telefon sich selbst anrufen und entsetzt feststellen, daß die Telefone nicht klingeln, weil .. ja .. scheisse, wieso klingeln die nicht ????!!!!!!

Ab jetzt herrscht Panik in der IT-Abteilung:  Was ist passiert ?

Ist der SIP Provider pleite gegangen ?
Haben Mäuse die Glasfaserkabel geknackt ?
Oder liegt es etwa an uns ?
Gab es ein Update der Telefonsoftware ?
Gab es überhaupt irgend ein Update ?

Also prüfen wir zunächst mal, ob alle betroffen sind und stellen fest : Alle Jitsi SIP Softphones sind quasi tod, aber normale Telefone für SIP nicht. Jitsi kann zwar noch raustelefonieren, sonst wäre das ja auch eher aufgefallen, aber ankommende Anrufe gehen nicht mehr. Komischerweise geht Jitsi auf den Handies noch.

Das schliesst per se ein DSL Router und Netzwerkproblem aus, außer die lokale Firewall wäre im Spiel:

TEST:
systemctl stop firewalld
Anruf => kein Klingeln
systemctl start firewalld

Das wars nicht. Hatte Jitsi ein Update ? Seit Monaten nicht mehr.  Fällt somit als Ursache auch weg.  Hmm…

2 Tage und eine systematische Suche später ..

Das Problem, das  Jitsi keine SIP Calls mehr annehmen konnte, ist behoben worden.

Es lag NICHT an Jitsi, Sipgate, den Mäusen, dem DSL Router, den Kabeln, der Firewall sondern an :  JAVA.

Die Ursache

Fedora hat vor zwei Tagen ein neues openjdk 1.8.0.141_b16 eingespielt, das hat Jitsi und vermutlich andere Apps beeinträchtigt. Das Update war als Security Update markiert, es ist also potentiell gefährlich, die App weiter zu betreiben. Ist es in dem Fall nicht, da das Update pauschal als Security Update eingestuft wurde, weil 4 Security Tests beim Build nicht liefen. Dazu noch eine Menge normaler Updates, von denen vermutlich eins die Ursache ist.

Der Workaround

Der schnellste Workaround ist natürlich, Java zu downgraden auf die letzte funktionierende Version:

java-1.8.0-openjdk-1.8.0.131-5.b12.fc25.x86_64.rpm
java-1.8.0-openjdk-devel-1.8.0.131-5.b12.fc25.x86_64.rpm
java-1.8.0-openjdk-headless-1.8.0.131-5.b12.fc25.x86_64.rpm
java-1.8.0-openjdk-javadoc-1.8.0.131-5.b12.fc25.noarch.rpm

Wenn man das jetzt mit „dnf downgrade java-*“ macht, landet man bei einer uralten Version, was Securitymäßig keine gute Idee ist. Also lädt man die Pakete hier runter:

https://kojipkgs.fedoraproject.org//packages/java-1.8.0-openjdk/1.8.0.131/5.b12.fc25/noarch/java-1.8.0-openjdk-javadoc-1.8.0.131-5.b12.fc25.noarch.rpm
https://kojipkgs.fedoraproject.org//packages/java-1.8.0-openjdk/1.8.0.131/5.b12.fc25/x86_64/java-1.8.0-openjdk-headless-1.8.0.131-5.b12.fc25.x86_64.rpm
https://kojipkgs.fedoraproject.org//packages/java-1.8.0-openjdk/1.8.0.131/5.b12.fc25/x86_64/java-1.8.0-openjdk-devel-1.8.0.131-5.b12.fc25.x86_64.rpm
https://kojipkgs.fedoraproject.org//packages/java-1.8.0-openjdk/1.8.0.131/5.b12.fc25/x86_64/java-1.8.0-openjdk-1.8.0.131-5.b12.fc25.x86_64.rpm

Aber natürlich nur passenderweise für Fedora 25, andere Versionen bitte selbst bei koji suchen.

Nicht vergessen: /etc/dnf/dnf.conf editieren und java auf die Sperrliste setzen, sonst kommt das Update gleich wieder rein.

Warum ist jetzt der Downgrade auf b12 akzeptable und der auf die Fedora Downgrade Version nicht ?

Weil Jitsi nur Verbindungen zu bestimmten, vertrauenswürdigen Servern aufnimmt. Es ist daher kaum möglich etwaige SecBugs in Java über diesen Channel auszunutzen, zumal in der ML von OpenJAVA keine Hinweise zu Securitybugs enthalten waren. 4 Tests beim Build failten, das kann alles sein. in nächster Zeit wird es sicher Updates von Jitsi geben, damit es auch mit der aktuellen Java Version läuft, denn es steht zu befürchten, daß Openjdk, den „Bug“ nicht fixt.