Problem - Konfiguration oder Anwendung?

Hallo zusammen,

Ich muss zugeben wirklich Plan wie ich mein Problem in den Griff bekommen kann habe ich nicht.Vielleicht ist meine Konfiguration schlicht “totaler Blödsinn” oder die Anwendung die ich nutze macht Mist.

In Kurzfassung - meine Anwendung die ich nutzen will heißt “Photo Supreme”. Es ist eine Bildverwaltung. Wenn die Anwendung viele Dateien aktualisieren will - sagen wir mehr als 20000 ist es sicher, dass der Server es nicht überlebt und irgendwann wegen “out of memory” alles hinschmeißt.

Mein Server hat 48GB RAM, 8 CPU Kerne und läuft virtuell auf einem Linux Debian KVM Server.

Stelle ich in der Konfiguration Anzahl der max Verbindungen auf 50, so macht die Anwenung Ärger und kommt immer wieder mit:

07-01-_2023_11-25-16

Setze ich die Verbindungen auf 70 kommt irgendwann:


und kurz danach ist Ende.

Momentan sehen die wichtigste Konfigeinträge so aus

max_connections = 100
shared_buffers = 64MB
temp_buffers = 1GB
work_mem = 64MB
maintenance_work_mem = 1GB
max_wal_size = 3GB
effective_cache_size = 24GB
dynamic_shared_memory_type = posix

Mir kommt es so vor, dass aus welchem Grund auch immer der Server mit der Zeit mehr Speicher benutzen will als überhaupt vorhanden und dann kommt es zu dem Crash.

ist das dediziert für PostgreSQL, oder läuft da noch mehr auf der Maschine? Also auch noch die Bildverarbeitung? Ist in der Anwendung einstellbar, wie viele Verbindungen zur DB aufgemacht werden?
Der Wert für shared_buffers ist SEHR, SEHR klein, wenn das dediziert für PG ist sollte das auf ca. 25% RAM sein. work_mem ist dafür vermutlich zu groß. Aber alles in allem: wir wissen zu wenig über das alles… was z.B. heißt ‘kurz danach ist Ende’? Fehlermeldung?

PS.: hab grad Deinen Beitrag in der FB-Gruppe freigegeben (ja, bin da einer der Admins). Da hast Du aber eine andere Konfiguration angegeben…

Vielen Dank für die Antwoten.

Ja da habe ich andere Konfig angegeben, wollte (mache ich die Änderungen auch gleich hier)
Ich habe etwas probiert. Die aktuelle Konfiguration ist zum großen Teil aus der Dokumentation der Anwendung. Und nein da kann man nichts einstellen bzgl. der Verbindungen.
Die sparsame Dokumentation zu der Anwendung und Postgres ist hier zu finden https://manualsu.idimager.com/version7/QuickInstall-PostgreSQL14-PhotoSupreme.pdf

Die angegebene Parameter zu der VM sind für die Exklusiv. Die Hostmaschine hat 128GB RAM und 24 Kerne. Das wird auf andere VM’s verteilt.

Die aktuelle Parameter sehen also so aus:

max_connections = 300
shared_buffers = 12GB
work_mem = 32MB
maintenance_work_mem = 512MB
dynamic_shared_memory_type = posix
checkpoint_timeout = 30min
max_wal_size = 10GB
min_wal_size = 3GB
cpu_tuple_cost = 0.03

Brachte aber nicht wirklich etwas. Der Server ist nach etwas mehr als 10000 Datensätze abgestürzt.

Mit welcher Fehlermeldung im Log?

Irgendwann kommt so etwas:

2023-01-08 01:58:02.443 CET [765] LOG:  Checkpoints passieren zu oft (alle 28 Sekunden)
2023-01-08 01:58:02.443 CET [765] TIPP:  Erhöhen Sie eventuell den Konfigurationsparameter »max_wal_size«.
2023-01-08 01:58:29.354 CET [765] LOG:  Checkpoints passieren zu oft (alle 27 Sekunden)
2023-01-08 01:58:29.354 CET [765] TIPP:  Erhöhen Sie eventuell den Konfigurationsparameter »max_wal_size«.
2023-01-08 01:58:57.827 CET [765] LOG:  Checkpoints passieren zu oft (alle 28 Sekunden)
2023-01-08 01:58:57.827 CET [765] TIPP:  Erhöhen Sie eventuell den Konfigurationsparameter »max_wal_size«.
2023-01-08 01:59:19.819 CET [763] LOG:  schnelles Herunterfahren verlangt
2023-01-08 01:59:19.845 CET [763] LOG:  etwaige aktive Transaktionen werden abgebrochen
2023-01-08 01:59:19.845 CET [2548] idimager_main@moments of time FATAL:  Verbindung wird abgebrochen aufgrund von Anweisung des Administrators
2023-01-08 01:59:19.845 CET [2533] idimager_main@moments of time FATAL:  Verbindung wird abgebrochen aufgrund von Anweisung des Administrators
2023-01-08 01:59:19.845 CET [2547] idimager_main@moments of time FATAL:  Verbindung wird abgebrochen aufgrund von Anweisung des Administrators
2023-01-08 01:59:19.846 CET [763] LOG:  Checkpointer-Prozess (PID 765) wurde von Signal 9 beendet: Getötet
2023-01-08 01:59:19.846 CET [763] LOG:  aktive Serverprozesse werden abgebrochen
2023-01-08 01:59:19.846 CET [2533] idimager_main@moments of time LOG:  SSL error: protocol is shutdown
2023-01-08 01:59:19.846 CET [2548] idimager_main@moments of time LOG:  SSL error: protocol is shutdown
2023-01-08 01:59:19.846 CET [2547] idimager_main@moments of time LOG:  SSL error: protocol is shutdown
2023-01-08 01:59:19.846 CET [2548] idimager_main@moments of time LOG:  could not send data to client: Die Verbindung wurde vom Kommunikationspartner zurückgesetzt
2023-01-08 01:59:19.846 CET [2533] idimager_main@moments of time LOG:  could not send data to client: Die Verbindung wurde vom Kommunikationspartner zurückgesetzt
2023-01-08 01:59:19.846 CET [2547] idimager_main@moments of time LOG:  could not send data to client: Die Verbindung wurde vom Kommunikationspartner zurückgesetzt
2023-01-08 01:59:20.025 CET [2562] idimager_main@moments of time FATAL:  das Datenbanksystem fährt herunter
...
...
2023-01-08 01:59:24.014 CET [763] LOG:  SIGKILL wird an ungehorsame Kinder gesendet

Und nein die Bildverarbeitung selbst läuft auf der Windowsmaschine.
Die Anwendung nutzt 2 Datenbanken. Eine wo so zu sagen alle Daten stehen und eine wo die Vorschaubilder gespeichert werden.

Klingt als ob Du / der Admin den Server beendet. Steht im OS-Log was von out-of-memory (OOM)?
Und du solltest max_wal_size erhöhen, aber das ist nur ein Hint.

Im Log ist zu OCM nichts zu finden

Ach jetzt bei neusten Versucht mit den o.g Parametern steht da

Grand total: 652718376 bytes in 116271 blocks; 189213416 free (16544 chunks); 463504960 used
2023-01-08 13:21:48.322 CET [5955] idimager_main@moments of time FEHLER:  Speicher aufgebraucht
2023-01-08 13:21:48.322 CET [5955] idimager_main@moments of time DETAIL:  Fehler bei Anfrage mit Größe 5632 im Speicherkontext »ExecutorState«.
2023-01-08 13:21:48.322 CET [5955] idimager_main@moments of time ANWEISUNG:  prepare prepst8301  as select   * from     v_CatalogItem where    GUID = '00BDA053572E4B4691CAFED76A13FBFE'
2023-01-08 13:21:48.329 CET [1461] LOG:  konnte neuen Prozess für Verbindung nicht starten (fork-Fehler): Nicht genügend Hauptspeicher verfügbar```

okay, du könntest work_mem reduzieren und/oder shared_buffers reduzieren sowie auch max_connections, um mehr RAM dynamisch zur Verfügung zu haben. Wie viele postgresql-Prozesse laufen denn?

Ich habe jetzt es noch mal gestartet und sehe 33 Prozesse der Anwendung und 6 so allgemeine

ps aux | grep postgres
root         832  0.0  0.0   5400   472 pts/3    S+   09:32   0:00 tail -f /var/log/postgresql/postgresql-14-main.log
root         833  0.0  0.0  10112  3912 pts/4    S    09:32   0:00 su - postgres
postgres     834  0.0  0.0   7164  2992 pts/4    S+   09:32   0:00 -bash
root         837  0.0  0.0  10112  3976 pts/5    S    09:32   0:00 su - postgres
postgres     838  0.0  0.0   7164  2496 pts/5    S    09:32   0:00 -bash
postgres    2806  0.0  0.0  21032  7964 pts/5    S+   10:59   0:00 /usr/lib/postgresql/14/bin/psql
postgres    6769  0.0  0.5 12955592 283496 ?     Ss   13:27   0:00 /usr/lib/postgresql/14/bin/postgres -D /var/lib/postgresql/14/main -c config_file=/etc/postgresql/14/main/postgresql.conf
postgres    6771  0.0  1.1 12955872 564572 ?     Ss   13:27   0:01 postgres: 14/main: checkpointer
postgres    6772  0.0  0.2 12955784 108676 ?     Ss   13:27   0:00 postgres: 14/main: background writer
postgres    6773  0.0  0.0 12955592 22500 ?      Ss   13:27   0:00 postgres: 14/main: walwriter
postgres    6774  0.0  0.0 12956496 8904 ?       Ss   13:27   0:00 postgres: 14/main: autovacuum launcher
postgres    6775  0.0  0.0  69448  5792 ?        Ss   13:27   0:01 postgres: 14/main: stats collector
postgres    6776  0.0  0.0 12956192 6856 ?       Ss   13:27   0:00 postgres: 14/main: logical replication launcher
postgres    7060  0.0  0.2 13053576 140956 ?     Ss   13:42   0:00 postgres: 14/main: idimager_main moments of time 192.168.4.15(51556) idle
postgres    7081  0.1  7.3 15459968 3606776 ?    Ss   13:43   0:17 postgres: 14/main: idimager_main moments of time 192.168.4.15(51564) idle
postgres    9217  2.6  2.4 13033364 1193744 ?    Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53932) idle
postgres    9219  2.6  2.1 13030216 1080960 ?    Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53934) idle
postgres    9220  1.8  1.8 13015516 900848 ?     Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53935) idle
postgres    9221  2.4  2.0 13029260 1031936 ?    Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53936) idle
postgres    9222  2.2  2.1 13024648 1039676 ?    Ds   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53937) COMMIT
postgres    9223  2.0  2.0 13018060 1030792 ?    Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53938) idle
postgres    9224  2.2  2.0 13024376 999632 ?     Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53939) idle
postgres    9225  2.1  1.9 13018204 975968 ?     Ds   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53940) INSERT
postgres    9226  2.2  2.0 13019048 1017508 ?    Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53941) idle
postgres    9228  2.8  2.2 13035848 1120236 ?    Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53943) idle
postgres    9229  1.9  1.7 13019100 857660 ?     Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53944) idle
postgres    9230  2.4  2.1 13029276 1071208 ?    Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53945) idle
postgres    9231  2.1  1.8 13023028 895604 ?     Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53946) idle
postgres    9234  2.0  1.9 13017260 963024 ?     Ds   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53949) INSERT
postgres    9235  0.8  0.5 13046312 269892 ?     Ss   16:47   0:00 postgres: 14/main: idimager_main moments of time 192.168.4.15(53950) idle
postgres    9236  2.3  2.1 13029956 1045592 ?    Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53951) idle
postgres    9237  1.9  1.6 13021256 806620 ?     Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53952) idle
postgres    9239  0.9  0.5 13052200 284352 ?     Ss   16:47   0:00 postgres: 14/main: idimager_main moments of time 192.168.4.15(53954) idle
postgres    9244  2.3  0.5 13005724 276828 ?     Ss   16:47   0:01 postgres: 14/main: idimager_main moments of time 192.168.4.15(53959) COMMIT
postgres    9251  0.9  0.5 13046128 270080 ?     Ss   16:47   0:00 postgres: 14/main: idimager_main moments of time 192.168.4.15(53969) idle
postgres    9252  0.8  0.5 13044648 264564 ?     Ss   16:47   0:00 postgres: 14/main: idimager_main moments of time 192.168.4.15(53970) idle
postgres    9255  1.0  0.5 13052580 283276 ?     Ss   16:47   0:00 postgres: 14/main: idimager_main moments of time 192.168.4.15(53973) idle
postgres    9260  1.2  0.4 12962400 219688 ?     Ss   16:47   0:00 postgres: 14/main: idimager_main moments of time_thumbs 192.168.4.15(53978) idle
postgres    9261  1.2  0.4 12962436 217680 ?     Ss   16:47   0:00 postgres: 14/main: idimager_main moments of time_thumbs 192.168.4.15(53979) idle
postgres    9262  1.2  0.4 12961672 212492 ?     Ss   16:47   0:00 postgres: 14/main: idimager_main moments of time_thumbs 192.168.4.15(53980) idle
postgres    9270  1.2  0.4 12962268 211716 ?     Ss   16:47   0:00 postgres: 14/main: idimager_main moments of time_thumbs 192.168.4.15(53988) idle
postgres    9271  1.3  0.4 12962428 217368 ?     Ss   16:47   0:00 postgres: 14/main: idimager_main moments of time_thumbs 192.168.4.15(53989) idle
postgres    9291  1.1  0.2 12958600 132240 ?     Ss   16:48   0:00 postgres: 14/main: idimager_main moments of time 192.168.4.15(54025) idle
postgres    9292  0.3  0.3 12958420 171840 ?     Ss   16:48   0:00 postgres: 14/main: idimager_main moments of time 192.168.4.15(54026) idle
postgres    9294  1.5  0.1 12958124 89196 ?      Ss   16:48   0:00 postgres: 14/main: idimager_main moments of time 192.168.4.15(54028) COMMIT
postgres    9295  0.5  0.3 12958040 151492 ?     Ss   16:48   0:00 postgres: 14/main: idimager_main moments of time 192.168.4.15(54029) idle
last pid:  9416;  load avg:  3.03,  1.75,  0.73;       up 0+07:41:06                                                                                                                                                                                     16:51    39 processes: 5 other background task(s), 28 idle, 6 active
CPU states:  4.3% user,  0.0% nice,  0.9% system, 76.6% idle, 18.3% iowait
Memory: 42G used, 5033M free, 0K shared, 93M buffers, 33G cached
Swap: 376K used, 4619M free, 28K cached, 0K in, 0K out

    PID USERNAME    SIZE   RES STATE   XTIME  QTIME  %CPU LOCKS COMMAND
   9417 postgres     12G   30M active   0:00   0:00   0.0     8 postgres: 14/main: postgres postgres [local] idle
   9260 idimager     12G  538M active   0:00   0:00   1.2     7 postgres: 14/main: idimager_main moments of time_thumbs 192.168.4.15(53978) COMMIT
   9382 idimager     12G  204M active   0:00   0:00   2.0     6 postgres: 14/main: idimager_main moments of time 192.168.4.15(54113) COMMIT
   9415 idimager     12G  103M active   0:00   0:00   0.6     1 postgres: 14/main: idimager_main moments of time 192.168.4.15(54135) COMMIT
   9270 idimager     12G  538M active   0:00   0:00   1.2     7 postgres: 14/main: idimager_main moments of time_thumbs 192.168.4.15(53988) COMMIT
   9219 idimager     13G 2408M idle     0:00   0:00   1.4     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53934) idle
   9230 idimager     13G 2398M idle     0:00   0:00   0.2     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53945) idle
   9226 idimager     13G 2349M idle     0:00   0:00   1.2     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53941) idle
   9261 idimager     12G  539M idle     0:00   0:00   1.2     0 postgres: 14/main: idimager_main moments of time_thumbs 192.168.4.15(53979) idle
   9416 idimager     12G  206M idle     0:00   0:00   0.2     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(54136) idle
   9223 idimager     13G 2503M idle     0:00   0:00   2.0     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53938) idle
   9221 idimager     13G 2370M idle     0:00   0:00   2.0     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53936) idle
   6772              12G  106M          0:00   0:00   0.0     0 postgres: 14/main: background writer
   9224 idimager     13G 2454M idle     0:00   0:00   1.4     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53939) idle
   9271 idimager     12G  547M idle     0:00   0:00   1.2     0 postgres: 14/main: idimager_main moments of time_thumbs 192.168.4.15(53989) idle
   9237 idimager     13G 2319M idle     0:00   0:00   4.2     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53952) idle
   9229 idimager     13G 2466M idle     0:00   0:00   2.2     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53944) idle
   9217 idimager     13G 2496M idle     0:00   0:00   0.8     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53932) idle
   9262 idimager     12G  541M idle     0:00   0:00   1.4     0 postgres: 14/main: idimager_main moments of time_thumbs 192.168.4.15(53980) idle
   6771              12G  551M          0:00   0:00   0.0     0 postgres: 14/main: checkpointer
   9231 idimager     13G 2609M idle     0:00   0:00   0.8     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53946) idle
   6774              12G 8904K          0:00   0:00   0.0     0 postgres: 14/main: autovacuum launcher
   9404 idimager     12G  262M idle     0:00   0:00   0.8     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(54130) idle
   9225 idimager     13G 2407M idle     0:00   0:00   1.4     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53940) idle
   9252 idimager     13G  524M idle     0:00   0:00   0.6     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53970) idle
   9228 idimager     13G 2444M idle     0:00   0:00   1.2     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53943) idle
   9235 idimager     13G  536M idle     0:00   0:00   0.6     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53950) idle
   9255 idimager     13G  554M idle     0:00   0:00   0.6     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53973) idle
   9397 idimager     12G  592M idle     0:00   0:00   0.0     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(54127) idle
   6773              12G   22M          0:00   0:00   0.2     0 postgres: 14/main: walwriter
   7081 idimager     15G 4894M idle     0:00   0:00   0.0     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(51564) idle
   9222 idimager     13G 2555M idle     0:00   0:00   2.0     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53937) idle
   9220 idimager     13G 2460M idle     0:00   0:00   1.4     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53935) idle
   9251 idimager     13G  536M idle     0:00   0:00   0.4     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53969) idle
   9236 idimager     13G 2358M idle     0:00   0:00   1.8     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53951) idle
   7060 idimager     13G  336M idle     0:00   0:00   0.4     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(51556) idle
   9234 idimager     13G 2381M active   0:00   0:00   2.4     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53949) BIND
   6776 postgres     12G 6856K          0:00   0:00   0.0     0 postgres: 14/main: logical replication launcher
   9239 idimager     13G  557M idle     0:00   0:00   0.8     0 postgres: 14/main: idimager_main moments of time 192.168.4.15(53954) idle

OK, mit weiterer Suche auf dem System ist mir aufgefallen, dass ich wohl vor Jahren als das System aufgebaut war und deutlich weniger RAM/ CPU Power hatte Parameter an den Linux Kernel übergeben hatte, die die Ressourcen an anderer Stelle beschnitten hatten.

echo 10737418240 > /proc/sys/kernel/shmmax
echo 2097152 > /proc/sys/kernel/shmall
echo 2 > /proc/sys/vm/overcommit_memory

Bei dem System selbst ohne diese Parameter liefert mir der Kernel:

cat /proc/sys/kernel/shmmax
18446744073692774399
cat /proc/sys/kernel/shmmall
18446744073692774399
cat /proc/sys/vm/overcommit_memory
0

Mit etwa kritischer Datenmenge ist ein Testlauf durchgelaufen. Ob das jetzt so bleiben wird, muss ich weiter testen.
Auf jedem Fall verringern der Werte für work_mem und shared_buffers haben zu Absturz der Datenbank geführt nach etwa 10000 datensätze.

Was mich aber jetzt wundert - die Applikation ist so weit “fertig”. Also die macht nichts mehr.
Musste in so einem Fall nicht der belegte Speicher wieder frei werden?

Es bleiben diese 10 Applikationsprozesse und Speicher wird nicht frei.
Gibt es dafür irgendeinen Parameter? Womöglich ist meine Annahme falsch, aber ich denke, wenn ich jetzt verarbeiten weiterer Datensätze anstoße ohne vorher die Applikation auf der Windows Maschine zu beenden, wird es nicht sehr lange dauern und der Datenbankserver wird wieder Probleme machen.

die Prozesse bleiben solange die Applikation, die diese gestartet hat, nicht beendet. shared_buffers werden bei Start der DB allokiert und bleiben dies auch, bis zum Ende. work_mem ist Speicher, der dynamisch allokiert wird - und freigegeben, wenn nicht mehr benötigt. Dies passiert je Client-Prozess. Jede neue Verbindung zur DB startet einen Client-Prozess, diese kann bis zu work_mem je Abfragenode allokieren, dynamisch.

Ich glaube ich gebe auf. Ich habe bei dem System SWAP Partition auf 25 GB erweitert. Dachte - oj super, jetzt läuft das ganze. Ja 16.000 Datensätze konnten verarbeitet werden und dann war Schluss

Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411335] postgres invoked oom-killer: gfp_mask=0x100cca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411337] CPU: 3 PID: 920 Comm: postgres Not tainted 5.10.0-19-amd64 #1 Debian 5.10.149-2
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411337] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.14.0-2 04/01/2014
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411338] Call Trace:
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411348]  dump_stack+0x6b/0x83
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411350]  dump_header+0x4a/0x1f4
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411351]  oom_kill_process.cold+0xb/0x10
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411353]  out_of_memory+0x1bd/0x4e0
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411355]  __alloc_pages_slowpath.constprop.0+0xbcc/0xc90
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411356]  __alloc_pages_nodemask+0x2de/0x310
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411357]  pagecache_get_page+0x175/0x390
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411358]  filemap_fault+0x6a2/0x900
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411360]  ? xas_load+0x5/0x80
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411370]  ext4_filemap_fault+0x2d/0x50 [ext4]
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411372]  __do_fault+0x37/0x170
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411374]  handle_mm_fault+0x1208/0x1c10
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411376]  do_user_addr_fault+0x1b8/0x400
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411378]  exc_page_fault+0x78/0x160
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411379]  ? asm_exc_page_fault+0x8/0x30
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411380]  asm_exc_page_fault+0x1e/0x30
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411381] RIP: 0033:0x55a6a44de420
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411384] Code: Unable to access opcode bytes at RIP 0x55a6a44de3f6.
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411385] RSP: 002b:00007ffcbd643ef8 EFLAGS: 00010246
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411386] RAX: 000055a6a5ee4980 RBX: 000055a6a5ee51a8 RCX: 0000000000000006
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411386] RDX: 000055a6a5ee4980 RSI: 000055a6a5ee51a8 RDI: 000055a6a5ee4948
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411386] RBP: 00007ffcbd643fb0 R08: 000055a6a4685727 R09: 000055a6a5ee49f0
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411387] R10: 000055a759822d18 R11: 00007f261408bc80 R12: 000055a6a5ee4998
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411387] R13: 000055a6a5ee4868 R14: 0000000000000000 R15: 000055a6a5ee4948
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411388] Mem-Info:
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411390] active_anon:3252410 inactive_anon:8714454 isolated_anon:0
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411390]  active_file:172 inactive_file:28 isolated_file:0
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411390]  unevictable:0 dirty:2 writeback:0
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411390]  slab_reclaimable:50439 slab_unreclaimable:10546
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411390]  mapped:3204479 shmem:3204570 pagetables:226265 bounce:0
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411390]  free:67530 free_pcp:907 free_cma:0
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411391] Node 0 active_anon:13009640kB inactive_anon:34857816kB active_file:688kB inactive_file:112kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:12817916kB dirty:8kB writeback:0kB shmem:12818280kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 585728kB writeback_tmp:0kB kernel_stack:3568kB all_unreclaimable? no
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411392] Node 0 DMA free:15908kB min:20kB low:32kB high:44kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15908kB mlocked:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411393] lowmem_reserve[]: 0 1940 48143 48143 48143
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411395] Node 0 DMA32 free:187496kB min:2720kB low:4704kB high:6688kB reserved_highatomic:0KB active_anon:447520kB inactive_anon:1347524kB active_file:8kB inactive_file:28kB unevictable:0kB writepending:0kB present:2080624kB managed:2015088kB mlocked:0kB pagetables:29652kB bounce:0kB free_pcp:260kB local_pcp:248kB free_cma:0kB
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411396] lowmem_reserve[]: 0 0 46203 46203 46203
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411398] Node 0 Normal free:66716kB min:64836kB low:112148kB high:159460kB reserved_highatomic:2048KB active_anon:12562120kB inactive_anon:33510292kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:8kB present:48234496kB managed:47317716kB mlocked:0kB pagetables:875408kB bounce:0kB free_pcp:3368kB local_pcp:408kB free_cma:0kB
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411399] lowmem_reserve[]: 0 0 0 0 0
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411400] Node 0 DMA: 1*4kB (U) 0*8kB 0*16kB 1*32kB (U) 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15908kB
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411405] Node 0 DMA32: 347*4kB (UE) 217*8kB (UME) 467*16kB (UME) 849*32kB (UME) 476*64kB (UME) 168*128kB (UME) 160*256kB (UME) 77*512kB (UME) 17*1024kB (UME) 0*2048kB 0*4096kB = 187524kB
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411409] Node 0 Normal: 770*4kB (UME) 599*8kB (UME) 2073*16kB (UME) 608*32kB (UME) 107*64kB (UME) 1*128kB (M) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 67472kB
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411414] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411414] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411415] 3225456 total pagecache pages
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411416] 20473 pages in swap cache
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411417] Swap cache stats: add 7670676, delete 7650202, find 146536/150576
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411417] Free swap  = 0kB
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411418] Total swap = 25701372kB
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411418] 12582778 pages RAM
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411418] 0 pages HighMem/MovableOnly
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411418] 245600 pages reserved
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411419] 0 pages hwpoisoned
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411419] Tasks state (memory values in pages):
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411420] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411423] [    293]     0   293    13583      222   135168        0          -250 systemd-journal
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411424] [    312]     0   312     5398      278    65536        0         -1000 systemd-udevd
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411425] [    411]     0   411    24972      332    73728        1             0 dhclient
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411425] [    427]   109   427     1976      113    53248        0             0 rpcbind
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411426] [    429]     0   429     1687       68    53248        0             0 cron
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411427] [    430]   105   430     2065      114    53248        0          -900 dbus-daemon
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411428] [    436]     0   436    55234      638    69632       57             0 rsyslogd
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411429] [    438]     0   438     3430      197    65536        0             0 systemd-logind
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411429] [    573]   103   573     4652      255    81920        0             0 exim4
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411430] [    694]     0   694      958       52    49152        0             0 ntpd
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411431] [    696]   110   696      994       35    49152        0             0 ntpd
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411432] [    698]   110   698     1011       56    49152        0             0 ntpd
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411432] [    740]     0   740     2412       92    57344        1             0 xinetd
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411433] [    741]     0   741     3737      307    61440        7             0 sshd
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411434] [    744]     0   744     3800      293    73728        0             0 systemd
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411434] [    745]     0   745    41754      650    94208       11             0 (sd-pam)
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411435] [    762]     0   762     1791        2    57344      139             0 bash
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411436] [    765]     0   765     1715       16    53248       45             0 screen
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411436] [    766]     0   766     2475      596    57344      244             0 screen
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411437] [    767]     0   767     1791        1    61440      124             0 bash
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411438] [    768]     0   768     1791        1    53248      124             0 bash
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411438] [    769]     0   769     1791       27    49152       83             0 bash
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411439] [    770]     0   770     1791        1    53248      133             0 bash
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411440] [    771]     0   771     1791        1    53248      142             0 bash
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411440] [    772]     0   772     1791        1    61440      141             0 bash
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411441] [    773]     0   773     1791        1    57344      141             0 bash
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411441] [    774]     0   774     1791        1    57344      141             0 bash
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411442] [    781]   107   781  3237047    55414   675840      310          -900 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411443] [    783]   107   783  3237297  3183505 25681920      329             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411444] [    784]   107   784  3237086  3075367 25624576      323             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411444] [    785]   107   785  3237047     4367   176128      331             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411445] [    786]   107   786    17358      206   131072      359             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411446] [    787]   107   787  3237187      253   155648      377             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411446] [    795]     0   795     2591      189    61440       19             0 top
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411447] [    800]     0   800     1462       28    45056        0             0 agetty
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411448] [    802]     0   802     2528       33    57344      113             0 su
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411449] [    803]   107   803     1791        5    53248      121             0 bash
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411449] [    805]   107   805     4457      742    73728      109             0 pg_top
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411450] [    809]     0   809     1350       13    45056        2             0 tail
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411450] [    814]     0   814     1350        0    49152       19             0 tail
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411451] [    816]     0   816     2528       76    57344       70             0 su
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411452] [    817]   107   817     1791       77    53248       48             0 bash
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411452] [    820]   107   820     5258      164    77824      186             0 psql
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411453] [    821]   107   821  3237318     1507   266240      528             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411454] [    895]   107   895  4176597   470580  8835072   440570             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411454] [    916]   107   916  3998518  3307919 31916032   363732             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411455] [    920]   107   920  3974889  3427544 31723520   213220             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411456] [   1440]   107  1440  3991991  3315035 31862784   352355             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411456] [   1441]   107  1441  3980138  3288174 31772672   355637             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411457] [   1442]   107  1442  3949216  3256933 31522816   337108             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411458] [   1443]   107  1443  3985666  3293792 31809536   356836             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411458] [   1444]   107  1444  3968051  3292503 31674368   340971             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411459] [   1445]   107  1445  3964887  3302708 31649792   330042             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411460] [   1446]   107  1446  3956283  3283604 31580160   331813             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411460] [   1447]   107  1447  3977547  3288972 31752192   354726             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411461] [   1448]   107  1448  3992117  3304474 31862784   361598             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411462] [   1449]   107  1449  3970448  3300835 31694848   336678             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411462] [   1450]   107  1450  3978281  3292648 31756288   351614             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411463] [   1452]   107  1452  3948804  3272602 31518720   332384             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411464] [   1453]   107  1453  3952763  3277925 31551488   332973             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411464] [   1454]   107  1454  3970674  3292624 31694848   343132             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411465] [   1456]   107  1456  3986605  3292711 31817728   359756             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411466] [   1496]   107  1496  3267949   910914 25538560    18162             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411466] [   1498]   107  1498  3268046   909466 25456640    18233             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411467] [   1499]   107  1499  3267457   901230 25513984    18050             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411468] [   1500]   107  1500  3266930   899750 25526272    17580             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411468] [   1501]   107  1501  3267822   898528 25505792    18096             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411469] [   1962]   107  1962  3548712   388651 27648000   132307             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411470] [   2132]   107  2132  3237928   458277 25616384      896             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411471] [   3115]   107  3115  3539254   445361 13619200      261             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411471] [   3118]   107  3118  3536983   448909 13660160      262             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411472] [   3119]   107  3119  3542391   451070 13713408      262             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411473] [   3121]   107  3121  3542814   446970 13594624      262             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411473] [   3122]   107  3122  3541475   443816 13451264      262             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411474] [   3297]   107  3297  3237732   418883 24821760      262             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411475] [   3307]   107  3307  3237704   415495 24813568      262             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411475] [   3311]   107  3311  3237654    15367  1142784      262             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411476] [   3312]   107  3312  3237688   413668 24805376      262             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411477] [   3314]   107  3314  3237226      680   184320      284             0 postgres
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411477] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/system.slice/system-postgresql.slice/postgresql@14-main.service,task=postgres,pid=916,uid=107
Jan  9 08:30:36 xenpsql001 kernel: [ 7328.411490] Out of memory: Killed process 916 (postgres) total-vm:15994072kB, anon-rss:1548688kB, file-rss:4kB, shmem-rss:11682984kB, UID:107 pgtables:31168kB oom_score_adj:0
Jan  9 08:30:37 xenpsql001 systemd[1]: postgresql@14-main.service: A process of this unit has been killed by the OOM killer.
Jan  9 08:30:43 xenpsql001 systemd[1]: postgresql@14-main.service: Failed with result 'oom-kill'.
Jan  9 08:30:43 xenpsql001 systemd[1]: postgresql@14-main.service: Consumed 25min 49.114s CPU time.
Jan  9 08:35:01 xenpsql001 CRON[3702]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jan  9 08:45:01 xenpsql001 CRON[3707]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jan  9 08:46:32 xenpsql001 systemd[1]: postgresql.service: Succeeded.
Jan  9 08:46:32 xenpsql001 systemd[1]: Stopped PostgreSQL RDBMS.


strange. Welche PG-Versio ist im Einsatz?

Hmm, irgendwo wird immer noch zu viel Speicher verbraucht (zumindest aus Sicht des Betriebssystems).

Kannst Du den OOM Killer nicht komplett abschalten?

PostgreSQL 14.6 (Debian 14.6-1.pgdg110+1)

Hmm, wie kann man es machen?

Hmm, OK mal schauen was es bringt. Ein “cat” bringt mir Standardmäßig 666 als Ergebnis. Ich habe jetzt ein -1000 in das _adj gesetzt.

cat /proc/1004/oom_score
666

Ob damit gleich die ganze VM um die Ohren fliegt…