[systemd] "Out of memory"

[Nicocys]

Hej !

Petite mise en situation: j'ai un petit serveur chez OVH (Kimsufi basique) qui tourne sous Archlinux (64bits). Jusqu'à présent, je fais mes mises à jour régulièrement. Par contre, le noyau est celui fourni par OVH (3.2.13-xxxx-grs-ipv6-64) qui lui ne se met pas à jour via les dépôts.
Aujourd'hui, je décide de m'en occuper, et récupère la dernière version en date (toujours via OVH): 3.10.23-xxxx-grs-ipv6-64. La manip' est simple (récupérer l'image du noyau, le System.map associé et faire un grub-mkconfig). Au reboot, tout semble bien se passer, le système démarre bien sur le nouveau noyau, Apache se lance correctement, la BDD aussi... Par contre, un tour dans les logs pour vérifier que rien ne se viande en cachette m'indique ceci:

Code : Tout sélectionner

Feb 17 11:50:27 ks3287976 systemd[3689]: Out of memory.
Feb 17 11:50:27 ks3287976 systemd[3689]: Failed to fully start up daemon: Cannot allocate memory

Après vérification, ce problème n'apparaissait pas avant la mise à jour du noyau.
Premier réflexe: quelle est la mémoire dispo ?

Code : Tout sélectionner

free -m
             total       used       free     shared    buffers     cached
Mem:          1976        501       1474          1         16        205
-/+ buffers/cache:        280       1695
Swap:          513          0        513

Ok, pas de souci de ce coté là...
Le disque:

Code : Tout sélectionner

df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/root       9.8G  4.5G  4.9G  49% /
devtmpfs        988M     0  988M   0% /dev
tmpfs           989M     0  989M   0% /dev/shm
tmpfs           989M  1.5M  987M   1% /run
tmpfs           989M     0  989M   0% /sys/fs/cgroup
tmpfs           989M  4.0K  989M   1% /tmp
/dev/sda2       914G  123G  745G  15% /home

Plein de place libre ici aussi. Un petit tour sur google me donne deux autres commandes à tester:

Code : Tout sélectionner

 ps --sort -rss -eo rss,pid,command | head
  RSS   PID COMMAND
142760 3267 /usr/bin/mysqld --pid-file=/run/mysqld/mysqld.pid
16732  2091 /usr/lib/systemd/systemd-journald
13632  3481 /usr/bin/httpd -k start
13388  3479 /usr/bin/httpd -k start
12768  3722 /usr/bin/httpd -k start
11404  3724 /usr/bin/httpd -k start
11216  3474 /usr/bin/httpd -k start
11096  3465 /usr/bin/php /usr/share/webapps/tt-rss/update.php --daemon
10028  3488 /usr/bin/python2 /usr/bin/fail2ban-server -b -s /var/run/fail2ban/fail2ban.sock -p /var/run/fail2ban/fail2ban.pid -x

À priori mysql pompe le plus de mémoire. Mais si je ne me trompe pas, la valeur est en ko, ce qui donne donc à peu près 139Mo de consommé. Pas spécialement inquiétant donc.

Enfin:

Code : Tout sélectionner

ulimit -a
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 20
file size               (blocks, -f) unlimited
pending signals                 (-i) 15802
max locked memory       (kbytes, -l) 64
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) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 15802
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

Serait-ce un problème avec une limite donnée par le noyau ? J'en sais rien, d'où ma demande ici: qu'est ce qui ne va pas ? Surtout qu'il n'y a pas d'autre problème visible (en tout cas pour l'instant...).

Merci

[FoolEcho]

Salut,

À tout hasard, tu peux remonter dans le log pour voir ce qui apparaît avant ?

[Nicocys]

Le error.log du jour:

Code : Tout sélectionner

Feb 17 03:18:05 ks3287976 anacron[32704]: Can't find sendmail at /usr/sbin/sendmail, not mailing output
Feb 17 09:09:26 ks3287976 kernel: kvm: no hardware support
Feb 17 09:09:26 ks3287976 kernel: kvm: no hardware support
Feb 17 09:09:26 ks3287976 kernel: EXT3-fs (sda1): error: couldn't mount because of unsupported optional features (240)
Feb 17 09:09:26 ks3287976 kernel: EXT2-fs (sda1): error: couldn't mount because of unsupported optional features (240)
Feb 17 11:50:27 ks3287976 systemd[3689]: Out of memory.
Feb 17 11:50:27 ks3287976 systemd[3689]: Failed to fully start up daemon: Cannot allocate memory
Feb 17 12:05:55 ks3287976 systemd[3524]: Out of memory.
Feb 17 12:05:55 ks3287976 systemd[3524]: Failed to fully start up daemon: Cannot allocate memory
Feb 17 12:36:37 ks3287976 systemd[5561]: Out of memory.
Feb 17 12:36:37 ks3287976 systemd[5561]: Failed to fully start up daemon: Cannot allocate memory
Feb 17 13:55:02 ks3287976 systemd[9552]: Out of memory.
Feb 17 13:55:02 ks3287976 systemd[9552]: Failed to fully start up daemon: Cannot allocate memory

La mise à jour du noyau à eu lieu avant le reboot vers 11h50. Un second reboot a eu lieu après que je me sois rendu compte de l'erreur en question, c'est à dire juste avant les erreurs de 12h05. Pas de reboot ensuite.

Pour comparer, le erreur.log.1:

Code : Tout sélectionner

Feb  9 03:32:05 ks3287976 anacron[20055]: Can't find sendmail at /usr/sbin/sendmail, not mailing output
Feb  9 13:36:22 ks3287976 kernel: kvm: no hardware support
Feb  9 13:36:22 ks3287976 kernel: kvm: no hardware support
Feb  9 13:36:22 ks3287976 kernel: EXT3-fs (sda1): error: couldn't mount because of unsupported optional features (240)
Feb  9 13:36:22 ks3287976 kernel: EXT2-fs (sda1): error: couldn't mount because of unsupported optional features (240)
Feb 10 03:17:10 ks3287976 anacron[11884]: Can't find sendmail at /usr/sbin/sendmail, not mailing output
Feb 11 03:10:09 ks3287976 anacron[19280]: Can't find sendmail at /usr/sbin/sendmail, not mailing output
Feb 11 14:20:59 ks3287976 kernel: kvm: no hardware support
Feb 11 14:20:59 ks3287976 kernel: kvm: no hardware support
Feb 11 14:20:59 ks3287976 kernel: EXT3-fs (sda1): error: couldn't mount because of unsupported optional features (240)
Feb 11 14:20:59 ks3287976 kernel: EXT2-fs (sda1): error: couldn't mount because of unsupported optional features (240)
Feb 12 03:20:19 ks3287976 anacron[9146]: Can't find sendmail at /usr/sbin/sendmail, not mailing output
Feb 13 03:49:05 ks3287976 anacron[20096]: Can't find sendmail at /usr/sbin/sendmail, not mailing output
Feb 13 09:11:00 ks3287976 kernel: kvm: no hardware support
Feb 13 09:11:00 ks3287976 kernel: kvm: no hardware support
Feb 13 09:11:00 ks3287976 kernel: EXT3-fs (sda1): error: couldn't mount because of unsupported optional features (240)
Feb 13 09:11:00 ks3287976 kernel: EXT2-fs (sda1): error: couldn't mount because of unsupported optional features (240)
Feb 13 21:45:38 ks3287976 sshd[11390]: error: Received disconnect from xxx.xxx.xxx.xxx: 14: No supported authentication methods available [preauth]
Feb 14 03:48:14 ks3287976 anacron[27137]: Can't find sendmail at /usr/sbin/sendmail, not mailing output
Feb 15 03:21:07 ks3287976 anacron[16912]: Can't find sendmail at /usr/sbin/sendmail, not mailing output
Feb 16 03:15:04 ks3287976 anacron[25145]: Can't find sendmail at /usr/sbin/sendmail, not mailing output

L'erreur du 13 à 21h45, c'est moi qui me suis viandé en me connectant via sftp. Les sendmail, c'est peut être un souci de conf' avec fail2ban, j'y jetterai un oeil.
Le souci avec sda1, c'est simplement que le disque est en ext4 (spécifié dans le fstab pourtant...)

Edit: Le everything.log avec un grep sur systemd, comprenant le reboot de 12h05 (12h04 d'après le log) jusqu'à mon reboot vers 12h06.

Code : Tout sélectionner

Feb 17 12:04:58 ks3287976 systemd[1]: Starting udev Kernel Socket.
Feb 17 12:04:58 ks3287976 systemd[1]: Listening on udev Kernel Socket.
Feb 17 12:04:58 ks3287976 systemd[1]: Starting udev Control Socket.
Feb 17 12:04:58 ks3287976 systemd[1]: Listening on udev Control Socket.
Feb 17 12:04:58 ks3287976 systemd[1]: Starting udev Coldplug all Devices...
Feb 17 12:04:58 ks3287976 systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
Feb 17 12:04:58 ks3287976 systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
Feb 17 12:04:58 ks3287976 systemd[1]: Started Set Up Additional Binary Formats.
Feb 17 12:04:58 ks3287976 systemd[1]: Mounted POSIX Message Queue File System.
Feb 17 12:04:58 ks3287976 systemd[1]: Mounted Debug File System.
Feb 17 12:04:58 ks3287976 systemd[1]: Starting Create static device nodes in /dev...
Feb 17 12:05:10 ks3287976 systemd[1]: Started MariaDB database server.
Feb 17 12:05:11 ks3287976 systemd[1]: Started Netcfg networking service for profile ovh_net_eth0.
Feb 17 12:05:11 ks3287976 systemd[1]: Starting Network.
Feb 17 12:05:11 ks3287976 systemd[1]: Reached target Network.
Feb 17 12:05:11 ks3287976 systemd[1]: Starting Fail2ban Service...
Feb 17 12:05:11 ks3287976 systemd[1]: Starting Tiny Tiny RSS feeds update daemon...
Feb 17 12:05:11 ks3287976 systemd[1]: Started Tiny Tiny RSS feeds update daemon.
Feb 17 12:05:11 ks3287976 systemd[1]: Starting OpenSSH Daemon...
Feb 17 12:05:11 ks3287976 systemd[1]: Started OpenSSH Daemon.
Feb 17 12:05:11 ks3287976 systemd[1]: Starting Apache Web Server...
Feb 17 12:05:13 ks3287976 systemd[1]: PID file /run/httpd/httpd.pid not readable (yet?) after start.
Feb 17 12:05:14 ks3287976 systemd[1]: Started Apache Web Server.
Feb 17 12:05:19 ks3287976 systemd[1]: Started Fail2ban Service.
Feb 17 12:05:19 ks3287976 systemd[1]: Starting Multi-User System.
Feb 17 12:05:19 ks3287976 systemd[1]: Reached target Multi-User System.
Feb 17 12:05:19 ks3287976 systemd[1]: Starting Graphical Interface.
Feb 17 12:05:19 ks3287976 systemd[1]: Reached target Graphical Interface.
Feb 17 12:05:19 ks3287976 systemd[1]: Startup finished in 4.957s (kernel) + 21.217s (userspace) = 26.175s.
Feb 17 12:05:54 ks3287976 systemd[1]: Starting user-1000.slice.
Feb 17 12:05:54 ks3287976 systemd[1]: Created slice user-1000.slice.
Feb 17 12:05:54 ks3287976 systemd[1]: Starting User Manager for 1000...
Feb 17 12:05:54 ks3287976 systemd[1]: Starting Session c1 of user nicolas.
Feb 17 12:05:54 ks3287976 systemd[1]: Started Session c1 of user nicolas.
Feb 17 12:05:54 ks3287976 systemd[3524]: Failed to open private bus connection: Failed to connect to socket /run/user/1000/dbus/user_bus_socket: No such file or directory
Feb 17 12:05:55 ks3287976 systemd[3524]: Out of memory.
Feb 17 12:05:55 ks3287976 systemd[3524]: Failed to fully start up daemon: Cannot allocate memory
Feb 17 12:05:55 ks3287976 systemd[3524]: Starting Default.
Feb 17 12:05:55 ks3287976 systemd[3524]: Reached target Default.
Feb 17 12:05:55 ks3287976 systemd[3524]: Startup finished in 397ms.
Feb 17 12:05:55 ks3287976 systemd[1]: Started User Manager for 1000.
Feb 17 12:06:55 ks3287976 systemd[1]: Stopping User Manager for 1000...
Feb 17 12:06:55 ks3287976 systemd[3524]: Stopping Default.
Feb 17 12:06:55 ks3287976 systemd[3524]: Stopped target Default.
Feb 17 12:06:55 ks3287976 systemd[3524]: Starting Shutdown.
Feb 17 12:06:55 ks3287976 systemd[3524]: Reached target Shutdown.
Feb 17 12:06:55 ks3287976 systemd[3524]: Starting Exit the Session...
Feb 17 12:06:55 ks3287976 systemd[1]: Stopped User Manager for 1000.
Feb 17 12:06:55 ks3287976 systemd[1]: Stopping user-1000.slice.
Feb 17 12:06:55 ks3287976 systemd[1]: Removed slice user-1000.slice.

[benjarobin]

Quel est le contenu de ton fstab ?

[Nicocys]

Le fstab (réaligné à l'arrache dans le post pour être plus simple à lire):

Code : Tout sélectionner

/dev/sda1	/	       ext4	  errors=remount-ro	0	1
/dev/sda2	/home	   ext4	  defaults	         0	2
/dev/sda3	none	    swap	  defaults	         0	0
proc		  /proc	   proc	  defaults		      0	0
sysfs		 /sys	    sysfs	 defaults		      0	0
tmpfs		 /dev/shm	tmpfs	 defaults		      0	0
devpts		/dev/pts	devpts	defaults		      0	0

[benjarobin]

1) Tu devrait utiliser des UUID
2) Il ne faut surtout pas spécifier proc, sysfs, tmpfs, devpts !
3) defaults n'est pas spécifié pour la racine...

Donc en gros remplace le tout par (Tu peux trouver la liste de UUID via blkid) :

Code : Tout sélectionner

UUID=XXXXXXXXXXXXXXXXXXXX   /          ext4     defaults           0   1
UUID=XXXXXXXXXXXXXXXXXXXX   /home      ext4     defaults            0   2
UUID=XXXXXXXXXXXXXXXXXXXX   none       swap     defaults            0   0

[Nicocys]

Je viens de faire la modif': ça règle le souci du montage des partitions, mais pas celui de systemd (pas vraiment de surprise ici je suppose).

Du nouveau sinon: l'erreur dans le log semble ne se produire qu'à l'ouverture de la session, comme indiqué par le everything.log:

Code : Tout sélectionner

Feb 17 16:12:16 ks3287976 systemd[1]: Starting user-1000.slice.
Feb 17 16:12:16 ks3287976 systemd[1]: Created slice user-1000.slice.
Feb 17 16:12:16 ks3287976 systemd[1]: Starting User Manager for 1000...
Feb 17 16:12:16 ks3287976 systemd[1]: Starting Session c1 of user nicolas.
Feb 17 16:12:16 ks3287976 systemd[1]: Started Session c1 of user nicolas.
Feb 17 16:12:16 ks3287976 systemd[4200]: Failed to open private bus connection: Failed to connect to socket /run/user/1000/dbus/user_bus_socket: No such file or directory
Feb 17 16:12:17 ks3287976 systemd[4200]: Out of memory.
Feb 17 16:12:17 ks3287976 systemd[4200]: Failed to fully start up daemon: Cannot allocate memory
Feb 17 16:12:17 ks3287976 systemd[4200]: Starting Default.
Feb 17 16:12:17 ks3287976 systemd[4200]: Reached target Default.
Feb 17 16:12:17 ks3287976 systemd[4200]: Startup finished in 416ms.
Feb 17 16:12:17 ks3287976 systemd[1]: Started User Manager for 1000.

Vu le numéro du process concerné (4200), il y a des chances que ce soit lié à l'erreur dbus. Google me renvoie sur un post (résolu ?) sur le forum d'archlinux.org qui mentionne cette erreur, mais le forum a l'air down pour le moment...

Edit: le forum est de retour. Visiblement ce n'est pas lié à mon souci (pour les curieux: https://bbs.archlinux.org/viewtopic.php?pid=1351687 )

[benjarobin]

Pour information j'ai ceci

Code : Tout sélectionner

systemd[782]: Failed to open private bus connection: Failed to connect to socket /run/user/1000/dbus/user_bus_socket: No such file or directory
systemd[782]: Mounted /sys/kernel/config.
systemd[782]: Mounted /sys/fs/fuse/connections.
systemd[782]: Stopped target Sound Card.
systemd[782]: Starting Default.
systemd[782]: Reached target Default.
systemd[782]: Startup finished in 338ms.

Quelle est la sortie de mount :

Code : Tout sélectionner

mount

Personnellement :

Code : Tout sélectionner

proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
sys on /sys type sysfs (rw,nosuid,nodev,noexec,relatime)
dev on /dev type devtmpfs (rw,nosuid,relatime,size=1546932k,nr_inodes=181737,mode=755)
run on /run type tmpfs (rw,nosuid,nodev,relatime,mode=755)
/dev/sda5 on / type ext4 (rw,relatime,data=ordered)
securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
tmpfs on /sys/fs/cgroup type tmpfs (rw,nosuid,nodev,noexec,mode=755)
cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/usr/lib/systemd/systemd-cgroups-agent,name=systemd)
pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime)
cgroup on /sys/fs/cgroup/cpuset type cgroup (rw,nosuid,nodev,noexec,relatime,cpuset)
cgroup on /sys/fs/cgroup/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpuacct,cpu)
cgroup on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory)
cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices)
cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer)
cgroup on /sys/fs/cgroup/net_cls type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls)
cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio)
systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=30,pgrp=1,timeout=300,minproto=5,maxproto=5,direct)
binfmt_misc on /proc/sys/fs/binfmt_misc type binfmt_misc (rw,relatime)
mqueue on /dev/mqueue type mqueue (rw,relatime)
debugfs on /sys/kernel/debug type debugfs (rw,relatime)
configfs on /sys/kernel/config type configfs (rw,relatime)
hugetlbfs on /dev/hugepages type hugetlbfs (rw,relatime)
tmpfs on /tmp type tmpfs (rw)
fusectl on /sys/fs/fuse/connections type fusectl (rw,relatime)
/dev/sda7 on /home type ext4 (rw,relatime,data=ordered)
/dev/sda10 on /media/ArchApp type ext4 (rw,relatime,data=ordered)
/dev/sda9 on /media/WinDocs type fuseblk (rw,nosuid,nodev,relatime,user_id=0,group_id=0,default_permissions,allow_other,blksize=4096)
gvfsd-fuse on /run/user/1000/gvfs type fuse.gvfsd-fuse (rw,nosuid,nodev,relatime,user_id=1000,group_id=1000)

J'ai /sys/kernel/config ainsi que /sys/fs/fuse/connections de montés

[Nicocys]

mount me renvoie:

Code : Tout sélectionner

/dev/sda1 on / type ext4 (rw,relatime,data=ordered)
devtmpfs on /dev type devtmpfs (rw,relatime,size=1011376k,nr_inodes=252844,mode=755)
proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime)
securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620)
tmpfs on /run type tmpfs (rw,nosuid,nodev,mode=755)
tmpfs on /sys/fs/cgroup type tmpfs (rw,nosuid,nodev,noexec,mode=755)
cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/usr/lib/systemd/systemd-cgroups-agent,name=systemd)
pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime)
cgroup on /sys/fs/cgroup/cpuset type cgroup (rw,nosuid,nodev,noexec,relatime,cpuset)
cgroup on /sys/fs/cgroup/cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpuacct)
cgroup on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory)
cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices)
cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer)
cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio)
systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=35,pgrp=1,timeout=300,minproto=5,maxproto=5,direct)
configfs on /sys/kernel/config type configfs (rw,relatime)
fusectl on /sys/fs/fuse/connections type fusectl (rw,relatime)
tmpfs on /tmp type tmpfs (rw)
/dev/sda2 on /home type ext4 (rw,relatime,data=ordered)

J'ai bien le /sys/kernel/config et le /sys/fs/fuse/connections de montés.

Edit: L'erreur semble bien liée à l'ouverture de session (voir au dessus pour le everything.log correspondant). Je ne me suis pas connecté pendant quelques temps, et ce matin, je regarde ce qui se passe: dans le everything.log, on voit que tout va bien, jusqu'à l'ouverture de session qui me sort ce

Code : Tout sélectionner

systemd[26704]: Out of memory.

Re-Edit: Par curiosité, j'ai sorti un graphe avec systemd-analyze, histoire de comparer avec un plus ancien. Il y a quelques différences, notamment l'apparition des *.slice, qui vient sans dout d'une update de systemd. Le plus impressionant est l'apparition d'une liste impressionante de dev-ttyXX.device (avec XX qui va de a0,...,af,b0,...,zf)... C'est normal ça ?

Sinon, ça donne quoi ulimit -a de votre coté ? Peut-être que le nombre de tty lancés fait que systemd se retrouve ensuite bloqué. Mais les autre services lancés ensuite fonctionnent normalement, donc c'est bizarre cette histoire. Et le système se lance (relativement) rapidement: 26s, en incluant apache & co (y compris aussi fail2ban qui se lance en 8s, les tty étant ouverts instantanément...)