[Megoldva] Podman (docker) konténer timeout

Virtualizáció

Üdv,

Adott egy podman konténer, amiben egy mariadb,apache,PHP fut.

Inditom a konténert, szépen működik is, de egy kis idő után timeout lesz. Pedig azt látom, hogy fut.

Igaz furcsa, hogy ránézve azt látom a konténeren, hogy "Up 3s ago...". Mintha újraindulna...?

Mi lehet a gond?

  • 503 megtekintés

( Oops | 2022. 12. 12., h – 08:29 )

konténerlogokat néztél?

konténerazonosító változik?

ha "get pods -w" -t írva figyeled, látsz valamit?

Generáltattam egy service-t a systemd-vel, hogy automatikus legyen az indulás ez okozta:

# autogenerated by Podman 4.3.1

[Unit]
Description=Podman container-drupal8.service
Documentation=man:podman-generate-systemd(1)
Wants=network-online.target
After=network-online.target
RequiresMountsFor=%t/containers

[Service]
Environment=PODMAN_SYSTEMD_UNIT=%n
Restart=on-failure
TimeoutStopSec=70
ExecStartPre=/bin/rm \
	-f %t/%n.ctr-id
ExecStart=/usr/bin/podman container start drupal8
ExecStop=/usr/bin/podman container stop drupal8
#ExecStopPost=/usr/bin/podman rm \
#	-f \
#	--ignore -t 10 \
#	--cidfile=%t/%n.ctr-id
Type=notify
NotifyAccess=all

[Install]
WantedBy=default.target

De valamiért leáll és ezért indítja ujra. Gondolom... :(

2022-12-12 08:01:57,946 INFO exited: php-fpm (exit status 70; not expected)
2022-12-12 08:01:57,947 INFO reaped unknown pid 867 (exit status 78)
2022-12-12 08:01:58,950 INFO spawned: 'php-fpm' with pid 868
2022-12-12 08:02:00,047 INFO success: php-fpm entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2022-12-12 08:02:00,047 INFO exited: php-fpm (exit status 70; not expected)
2022-12-12 08:02:00,047 INFO reaped unknown pid 869 (exit status 78)
2022-12-12 08:02:01,051 INFO spawned: 'php-fpm' with pid 870
2022-12-12 08:02:02,150 INFO success: php-fpm entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2022-12-12 08:02:02,151 INFO exited: php-fpm (exit status 70; not expected)
2022-12-12 08:02:02,151 INFO reaped unknown pid 871 (exit status 78)
2022-12-12 08:02:03,076 INFO spawned: 'php-fpm' with pid 873
2022-12-12 08:02:03,078 INFO reaped unknown pid 196 (exit status 0)
2022-12-12 08:02:03,078 WARN received SIGTERM indicating exit request
2022-12-12 08:02:03,080 INFO waiting for httpd, mariadbd, php-fpm to die
2022-12-12 08:02:03,088 INFO exited: httpd (exit status 0; expected)
2022-12-12 08:02:04,187 INFO exited: mariadbd (exit status 0; expected)
2022-12-12 08:02:04,188 INFO stopped: php-fpm (exit status 0)

A logban ezeket látni. Kevés a memória talán...(?) Másra nem tudok gondolni.

A neten láttam mintákat, de lehet hogy rosszul alkalmaztam:

[supervisord]
logfile=/tmp/supervisord.log ; (main log file;default $CWD/supervisord.log)
logfile_maxbytes=50MB        ; (max main logfile bytes b4 rotation;default 50MB)
logfile_backups=10           ; (num of main logfile rotation backups;default 10)
loglevel=info                ; (log level;default info; others: debug,warn,trace)
pidfile=/tmp/supervisord.pid ; (supervisord pidfile;default supervisord.pid)
nodaemon=true                ; (start in foreground if true;default false)
minfds=1024                  ; (min. avail startup file descriptors;default 1024)
minprocs=200                 ; (min. avail process descriptors;default 200)
user=root


[inet_http_server]
port=127.0.0.1:9001

[supervisorctl]
serverurl=http://127.0.0.1:9001

[program:mariadb]
#command=/usr/bin/pidproxy /var/run/mysql/mysqld.pid /usr/bin/mysqld_safe --pid-file=/var/run/mysql/mysqld.pid
command=/usr/sbin/mariadbd -u root
process_name=mariadbd
# process_name=mysqld
user_name=mysql
redirect_stderr=true

[program:httpd]
command=/usr/sbin/httpd -c "ErrorLog /dev/stdout" -DFOREGROUND
redirect_stderr=true
process_name=httpd

[program:php-fpm]
command=/usr/sbin/php-fpm
redirect_stderr=true
process_name=php-fpm

Egy idő után így is kilép, bár mintha hiba nem lenne:

2022-12-12 13:37:37,937 INFO supervisord started with pid 1
2022-12-12 13:37:38,940 INFO spawned: 'httpd' with pid 2
2022-12-12 13:37:38,943 INFO spawned: 'mariadbd' with pid 3
2022-12-12 13:37:38,947 INFO spawned: 'php-fpm' with pid 4
2022-12-12 13:37:40,248 INFO success: httpd entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2022-12-12 13:37:40,248 INFO success: mariadbd entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2022-12-12 13:37:40,248 INFO success: php-fpm entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2022-12-12 13:48:58,309 INFO exited: php-fpm (exit status 0; expected)
2022-12-12 13:48:58,311 WARN received SIGTERM indicating exit request
2022-12-12 13:48:58,312 INFO waiting for httpd, mariadbd to die
2022-12-12 13:48:59,325 INFO exited: httpd (exit status 0; expected)
2022-12-12 13:48:59,325 INFO stopped: mariadbd (exit status 0)

Hát, tizenegy perc nem tűnik nagyon kerek számnak (bár közel van a 720hoz), ezen a ponton esetleg érdemes volna a a php-fpm logját is megtekinteni, a doksi alapján a /var/log/php-fpm.log alatt lakik. (a konténeren belül nyilván)

szerk: mondjuk rémlik, hogy a supervisor csinált az stdoutnak (meg az stderrnek is a redirected miatt) egy logfilet, nem ebbe tolja, hanem ott lakik valahol.

/var/log/php-fpm/error.log

[12-Dec-2022 14:04:20] NOTICE: fpm is running, pid 15
[12-Dec-2022 14:04:20] NOTICE: ready to handle connections
[12-Dec-2022 14:04:20] NOTICE: systemd monitor interval set to 10000ms
[12-Dec-2022 14:13:45] NOTICE: fpm is running, pid 198
[12-Dec-2022 14:13:45] NOTICE: ready to handle connections
[12-Dec-2022 14:13:45] NOTICE: systemd monitor interval set to 10000ms
[12-Dec-2022 15:28:18] NOTICE: Terminating ...
[12-Dec-2022 15:28:18] NOTICE: exiting, bye-bye!
[12-Dec-2022 15:34:06] NOTICE: fpm is running, pid 188
[12-Dec-2022 15:34:06] NOTICE: ready to handle connections
[12-Dec-2022 15:34:06] NOTICE: systemd monitor interval set to 10000ms
[12-Dec-2022 15:35:22] NOTICE: Terminating ...
[12-Dec-2022 15:35:22] NOTICE: exiting, bye-bye!
[12-Dec-2022 15:36:17] NOTICE: fpm is running, pid 199
[12-Dec-2022 15:36:17] NOTICE: ready to handle connections
[12-Dec-2022 15:36:17] NOTICE: systemd monitor interval set to 10000ms

supervisord.log

2022-12-12 15:36:15,884 INFO supervisord started with pid 1
2022-12-12 15:36:16,888 INFO spawned: 'httpd' with pid 2
2022-12-12 15:36:16,891 INFO spawned: 'mariadbd' with pid 3
2022-12-12 15:36:16,895 INFO spawned: 'php-fpm' with pid 4
2022-12-12 15:36:18,137 INFO success: httpd entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2022-12-12 15:36:18,137 INFO success: mariadbd entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2022-12-12 15:36:18,137 INFO success: php-fpm entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2022-12-12 15:36:18,137 INFO exited: php-fpm (exit status 0; expected)
2022-12-12 15:38:29,299 INFO reaped unknown pid 220 (terminated by SIGHUP)

( kroozo v | 2022. 12. 12., h – 08:35 )

log? Szinte biztosan újraindul valamiért.

( makgab v | 2022. 12. 12., h – 17:08 )

Nem kellene nekem a php-fpm, de anélkül nem fut. Ki lehet azt szedni? Vagy ez már alapból fpm-el működik?

Nem a php-fpm a baja, anélkül is megáll a konténer:

2022-12-12 16:17:09,119 INFO supervisord started with pid 1
2022-12-12 16:17:10,124 INFO spawned: 'httpd' with pid 2
2022-12-12 16:17:10,128 INFO spawned: 'mariadbd' with pid 3
2022-12-12 16:17:11,561 INFO success: httpd entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2022-12-12 16:17:11,562 INFO success: mariadbd entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2022-12-12 16:19:44,913 WARN received SIGTERM indicating exit request
2022-12-12 16:19:44,913 INFO waiting for httpd, mariadbd to die
2022-12-12 16:19:45,939 INFO exited: httpd (exit status 0; expected)
2022-12-12 16:19:45,939 INFO stopped: mariadbd (exit status 0)

mariadb.log:

2022-12-12 16:17:10 0 [Note] mariadbd: O_TMPFILE is not supported on /var/tmp (disabling future attempts)
2022-12-12 16:17:10 0 [Note] InnoDB: Using Linux native AIO
2022-12-12 16:17:10 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
2022-12-12 16:17:10 0 [Note] InnoDB: Completed initialization of buffer pool
2022-12-12 16:17:10 0 [Note] InnoDB: 128 rollback segments are active.
2022-12-12 16:17:10 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2022-12-12 16:17:10 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2022-12-12 16:17:10 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2022-12-12 16:17:10 0 [Note] InnoDB: 10.5.18 started; log sequence number 19777517; transaction id 2096
2022-12-12 16:17:10 0 [Note] Plugin 'FEEDBACK' is disabled.
2022-12-12 16:17:10 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2022-12-12 16:17:10 0 [Note] Server socket created on IP: '::'.
2022-12-12 16:17:10 0 [Note] Reading of all Master_info entries succeeded
2022-12-12 16:17:10 0 [Note] Added new Master_info '' to hash table
2022-12-12 16:17:10 0 [Note] /usr/sbin/mariadbd: ready for connections.
Version: '10.5.18-MariaDB'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MariaDB Server
2022-12-12 16:17:10 0 [Note] InnoDB: Buffer pool(s) load completed at 221212 16:17:10
2022-12-12 16:19:44 0 [Note] /usr/sbin/mariadbd (initiated by: unknown): Normal shutdown
2022-12-12 16:19:44 0 [Note] Event Scheduler: Purging the queue. 0 events
2022-12-12 16:19:44 0 [Note] InnoDB: FTS optimize thread exiting.
2022-12-12 16:19:44 0 [Note] InnoDB: Starting shutdown...
2022-12-12 16:19:44 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2022-12-12 16:19:44 0 [Note] InnoDB: Restricted to 2016 pages due to innodb_buf_pool_dump_pct=25
2022-12-12 16:19:44 0 [Note] InnoDB: Buffer pool(s) dump completed at 221212 16:19:44
2022-12-12 16:19:45 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2022-12-12 16:19:45 0 [Note] InnoDB: Shutdown completed; log sequence number 19778252; transaction id 2109
2022-12-12 16:19:45 0 [Note] /usr/sbin/mariadbd: Shutdown complete

 

Én nem igazán értem, hogy mi a baja...

Az apache-nak nem tetszik valami? A prefork modult nem szereti?

AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 10.0.2.100. Set the 'ServerName' directive globally to suppress this message
[Mon Dec 12 17:14:27.191014 2022] [lbmethod_heartbeat:notice] [pid 2:tid 2] AH02282: No slotmem from mod_heartmonitor
[Mon Dec 12 17:14:27.191257 2022] [http2:warn] [pid 2:tid 2] AH10034: The mpm module (prefork.c) is not supported by mod_http2. The mpm determines how things are processed in your server. HTTP/2 has more demands in this regard and the currently selected mpm will just not do. This is an advisory warning. Your server will continue to work, but the HTTP/2 protocol will be inactive.
[Mon Dec 12 17:14:27.363961 2022] [mpm_prefork:notice] [pid 2:tid 2] AH00163: Apache/2.4.54 (Fedora Linux) PHP/7.4.33 configured -- resuming normal operations
[Mon Dec 12 17:14:27.364326 2022] [core:notice] [pid 2:tid 2] AH00094: Command line: '/usr/sbin/httpd -c ErrorLog /dev/stdout -D FOREGROUND'
sh: line 1: /usr/sbin/sendmail: No such file or directory

Lesz is, ugyanis - meglepetés - ez a MariaDB normál shutdown üzenete.

Először is, azt az ominózus systemd service-t állítsd le és tiltsd le a rákba (systemctl disable), és kézzel, a unit-ban levő parancsokkal indítsd el a konténert, és nézd meg, hogy úgy meddig marad fenn. 

A podman hogy van konfigurálva? A konténer hogy van definiálva? Hogy fut? Milyen Docker imaget használsz ehhez? 

Ami számomra eddig kiderül, az az, hogy maga az egész kontíner - pontosabban a supervisord - kap egy SIGINT-et valahonnan, és emiatt minden belül futó service leáll. Mert ez a dolgok normál menete. Semmi hibaüzenetet nem látok, csak azt, hogy SIGINT miatt állunk meg, ez pedig normál működés, nem a kontíneren belül van a hiba.

Arra kell rájönni, hogy mi és miért állítja le. Ha a SystemD unitot letiltod, és kézzel inditva nem áll le, akkor a SystemD unit a hibás, másképp vagy máshogy kell konfigurálni.

Az a tippem amúgy, hogy nincs a SystemD unit-nak Type paraméter megadva, emiatt azt várja, hogy maga a processz amit elindít (podman start) futva marad addig, amíg valami nem állítja le (ugye a SystemD alapból nem démonokkal dolgozik). Potenciálisan a Type=oneshot megoldhatja, de előbb nézzük meg SystemD nélkül...

Blog | @hron84

valahol egy üzemeltetőmaci most mérgesen toppant a lábával 

via @snq-

Az a tippem amúgy, hogy nincs a SystemD unit-nak Type paraméter megadva, emiatt azt várja, hogy maga a processz amit elindít (podman start) futva marad addig, amíg valami nem állítja le (ugye a SystemD alapból nem démonokkal dolgozik). Potenciálisan a Type=oneshot megoldhatja, de előbb nézzük meg SystemD nélkül

Van type, notify, ami ugyan vet fel kérdéseket, de tizenperc timeout miatt hátrébb tettem a debug sorban 

"Review the system logs to discover whether the mysqld process is being shutdown due to OOM (out of memory) killer conditions. If the memory consumption of the server is high it might end up sending the shutdown signal to the process. "

1GB RAM vps-en ez előfordulhat...(?)

Már csak a httpd fut (egyelőre supervisrod-vel)!

1Gb rammal elofordulhat, hacsak nem allitottad be hogy kevesebb memoriat egyen. Alapbol a renddlkezesre allo 90%-at foglalja le, ugy tudom.

Masik hogy a mysql ugy indul hogy ures tarhelyre inicializal egy db-t, majd normal shutdown es rendes indulas masodikra. Ha a tarhely nem ures, akkor elso indulas is jo. Ugye a konténerbol kivezetted a /mysql/data-t, azaz nem belul tarolod az adatokat? 

... és eleve mi a MySQL Datadirje? Mert az, hogy valami random példa oda teszi be... sok MySQL instance a /var/lib/mysql alá várja a MySQL datadir-t. Amíg él az instance, ezt illik lekérdezni.

Blog | @hron84

valahol egy üzemeltetőmaci most mérgesen toppant a lábával 

via @snq-

1 GB RAM egy ilyen szörny futtatásához kevés. 2-4GB alatt nem érdemes próbálkozni LAMP szerverrel, mert kb bármi megeheti a kontínerben a RAM-ot.

Én VPS előtt - főleg ha idegen számodra a Podman, meg eleve, a konténerek világa - lokális gépen próbálkoznék, ha Windowsod van, akkor Docker Desktoppal, ha Linuxod akkor pedig natív Dockerrel. Azt érzem, hogy számodra sok dolog itt mágikusan működik, érdemes lépésenként haladni a tanulásban.

Blog | @hron84

valahol egy üzemeltetőmaci most mérgesen toppant a lábával 

via @snq-

( makgab v | 2022. 12. 13., k – 07:52 )

Szerkesztve: 2022. 12. 13., k – 07:52

Na most supervisord nélkül és csak httpd-vel, php modullal, php-fpm nélkül:

ENTRYPOINT /usr/sbin/httpd -DFOREGROUND

 

Most indítottam, kíváncsi vagyok meddig fut. :)

apache error.log:

[Tue Dec 13 09:17:09.298040 2022] [suexec:notice] [pid 1:tid 1] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 10.0.2.100. Set the 'ServerName' directive globally to suppress this message
[Tue Dec 13 09:17:09.344016 2022] [lbmethod_heartbeat:notice] [pid 1:tid 1] AH02282: No slotmem from mod_heartmonitor
[Tue Dec 13 09:17:09.344702 2022] [http2:warn] [pid 1:tid 1] AH10034: The mpm module (prefork.c) is not supported by mod_http2. The mpm determines how things are processed in your server. HTTP/2 has more demands in this regard and the currently selected mpm will just not do. This is an advisory warning. Your server will continue to work, but the HTTP/2 protocol will be inactive.
[Tue Dec 13 09:17:09.524142 2022] [mpm_prefork:notice] [pid 1:tid 1] AH00163: Apache/2.4.54 (Fedora Linux) PHP/7.4.33 configured -- resuming normal operations
[Tue Dec 13 09:17:09.524209 2022] [core:notice] [pid 1:tid 1] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND'

A "mpm module is not supported by mod_http2" sor érdekes lehet, de mást nem látni.

( makgab v | 2022. 12. 13., k – 10:32 )

Ez ugye nem lehet... :o

A vps-en amíg bent vagyok ssh-val addig megy, ha kilépek akkor hal le. Ilyen nincs, ugye?

Így indítom: podman container start konténer_neve

 

Ahogy kilépek távolról, utána 1-2 mp és leáll. :o

Szinte biztosan a systemd-logind csinálja, a user neve alatt futó dolgokat default beállítások mellett elég agresszíven tartja karban.  A podman daemonless, szóval a sima kézzel kiadott podman run az u.n. session scope része szerintem, tehát ha befejeződik a session, lelövi (minden más háttérben futó izével együtt. Igen, akkor is, ha nohupoltál). Ezt a viselkedést a logind.conf KillUserProcesses beállításával lehet megváltoztatni (illetve van hozzá valami include/exclude user paraméter is, azt fejből nem tudom hogy hívják). 

Ha a fenti unitodat a user unitként futtattad, akkor is rá lehet szaladni ilyenre, mert a user unitok is alapesetben addig élnek, ameddig van legalább egy aktív sessionje a usernek. Ha ezt el akarod kerülni, akkor loginctl enable-linger usernév, ekkor a user unitjai futhatnak akkor is, ha nincs aktív sessionje. Illetve ilyenkor a one-shot dolgokat systemd-run segítségével el lehet indítani egy tranziens serviceként, akkor megmarad logout után is.

ez se működött (https://www.freedesktop.org/software/systemd/man/logind.conf.html):

KillUserProcesses=yes
KillExcludeUsers=root username

 

logind.conf teljes:

[Login]
#NAutoVTs=6
#ReserveVT=6
#KillUserProcesses=no
#KillOnlyUsers=
KillExcludeUsers=root admin
#InhibitDelayMaxSec=5
#UserStopDelaySec=10
#HandlePowerKey=poweroff
#HandleSuspendKey=suspend
#HandleHibernateKey=hibernate
#HandleLidSwitch=suspend
#HandleLidSwitchExternalPower=suspend
#HandleLidSwitchDocked=ignore
#HandleRebootKey=reboot
#HandleRebootKeyLongPress=poweroff
#PowerKeyIgnoreInhibited=no
#SuspendKeyIgnoreInhibited=no
#HibernateKeyIgnoreInhibited=no
#LidSwitchIgnoreInhibited=yes
#RebootKeyIgnoreInhibited=no
#HoldoffTimeoutSec=30s
#IdleAction=ignore
#IdleActionSec=30min
#RuntimeDirectorySize=10%
#RuntimeDirectoryInodesMax=
#RemoveIPC=yes
#InhibitorsMax=8192
#SessionsMax=8192

( benz | 2022. 12. 14., sze – 09:24 )

ENTRYPOINT /usr/sbin/httpd -DFOREGROUND

Amugy miert foregroundban inditod?