Unerklärlich hoher Speicherverbrauch (RAM)

[zylox]

Auf einem meiner Server, der lediglich als Backupablage dient und auf dem nichts läuft ist mir heute ein unerklärlicher Speicherverbrauch aufgefallen. Es war 1gb Speicher in Verwendung, obwohl (fast) nichts läuft. Nach einem Neustart war der Verbrauch auch wieder bei 40mb und jetzt nach ein paar Stunden ist wieder 1gb verbraucht.

# free -m
             total       used       free     shared    buffers     cached
Mem:          3008       2773        235          0        891        875
-/+ buffers/cache:       1005       2003
Swap:          980          0        980

Hier mal die Prozesse ...

# ps waux

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         1  0.0  0.0   1984   696 ?        Ss   Nov17   0:00 init [2]  
root         2  0.0  0.0      0     0 ?        S<   Nov17   0:00 [kthreadd]
root         3  0.0  0.0      0     0 ?        S<   Nov17   0:00 [migration/0]
root         4  0.0  0.0      0     0 ?        S<   Nov17   0:00 [ksoftirqd/0]
root         5  0.0  0.0      0     0 ?        S<   Nov17   0:00 [watchdog/0]
root         6  0.0  0.0      0     0 ?        S<   Nov17   0:00 [migration/1]
root         7  0.0  0.0      0     0 ?        S<   Nov17   0:00 [ksoftirqd/1]
root         8  0.0  0.0      0     0 ?        S<   Nov17   0:00 [watchdog/1]
root         9  0.0  0.0      0     0 ?        S<   Nov17   0:00 [events/0]
root        10  0.0  0.0      0     0 ?        S<   Nov17   0:01 [events/1]
root        11  0.0  0.0      0     0 ?        S<   Nov17   0:00 [khelper]
root        46  0.0  0.0      0     0 ?        S<   Nov17   0:00 [kblockd/0]
root        47  0.0  0.0      0     0 ?        S<   Nov17   0:00 [kblockd/1]
root        49  0.0  0.0      0     0 ?        S<   Nov17   0:00 [kacpid]
root        50  0.0  0.0      0     0 ?        S<   Nov17   0:00 [kacpi_notify]
root       131  0.0  0.0      0     0 ?        S<   Nov17   0:00 [ksuspend_usbd]
root       137  0.0  0.0      0     0 ?        S<   Nov17   0:00 [khubd]
root       140  0.0  0.0      0     0 ?        S<   Nov17   0:00 [kseriod]
root       186  0.0  0.0      0     0 ?        S    Nov17   0:00 [pdflush]
root       187  0.0  0.0      0     0 ?        S    Nov17   0:00 [pdflush]
root       188  0.0  0.0      0     0 ?        S<   Nov17   0:00 [kswapd0]
root       189  0.0  0.0      0     0 ?        S<   Nov17   0:00 [aio/0]
root       190  0.0  0.0      0     0 ?        S<   Nov17   0:00 [aio/1]
root       719  0.0  0.0      0     0 ?        S<   Nov17   0:00 [ata/0]
root       720  0.0  0.0      0     0 ?        S<   Nov17   0:00 [ata/1]
root       721  0.0  0.0      0     0 ?        S<   Nov17   0:00 [ata_aux]
root       768  0.0  0.0      0     0 ?        S<   Nov17   0:00 [scsi_eh_0]
root       769  0.0  0.0      0     0 ?        S<   Nov17   0:00 [scsi_eh_1]
root       897  0.0  0.0      0     0 ?        S<   Nov17   0:03 [md0_raid1]
root       932  0.0  0.0      0     0 ?        S<   Nov17   0:01 [kjournald]
root      1013  0.0  0.0   2160   788 ?        S<s  Nov17   0:00 udevd --daemon
root      1975  0.0  0.0  28280  1512 ?        Sl   Nov17   0:00 /usr/sbin/rsyslogd -c3
root      1989  0.0  0.0   5276  1016 ?        Ss   Nov17   0:00 /usr/sbin/sshd
101       2511  0.0  0.0   6108   900 ?        Ss   Nov17   0:00 /usr/sbin/exim4 -bd -q30m
ntp       2534  0.0  0.0   4136  1260 ?        Ss   Nov17   0:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -u 103:105 -g
root      2544  0.0  0.0   2016   444 ?        Ss   Nov17   0:00 /sbin/mdadm --monitor --pid-file /var/run/mdadm/monitor.pid --daemonise --scan
root      2564  0.0  0.0   2040   888 ?        Ss   Nov17   0:00 /usr/sbin/cron
root      2605  0.0  0.0   1648   524 tty1     Ss+  Nov17   0:00 /sbin/getty 38400 tty1
root      2607  0.0  0.0   1648   516 tty2     Ss+  Nov17   0:00 /sbin/getty 38400 tty2
root      2608  0.0  0.0   1648   520 tty3     Ss+  Nov17   0:00 /sbin/getty 38400 tty3
root      2610  0.0  0.0   1648   520 tty4     Ss+  Nov17   0:00 /sbin/getty 38400 tty4
root      2611  0.0  0.0   1648   524 tty5     Ss+  Nov17   0:00 /sbin/getty 38400 tty5
root      2612  0.0  0.0   1648   524 tty6     Ss+  Nov17   0:00 /sbin/getty 38400 tty6
root     10581  0.0  0.0   8020  2624 ?        Ss   01:08   0:00 sshd: jan [priv] 
user      10584  0.0  0.0   8020  1512 ?        R    01:08   0:00 sshd: user@pts/0  
user      10585  0.0  0.0   3352  1852 pts/0    Ss   01:08   0:00 -bash
root     10591  0.0  0.0   2384  1064 pts/0    S    01:08   0:00 su
root     10608  0.0  0.0   2860  1632 pts/0    S    01:09   0:00 bash
root     10721  0.0  0.0   2300   908 pts/0    R+   01:25   0:00 ps waux

Eigentlich braucht auch kein Prozess wirklich Speicher, oder übersehe ich was? Woran kann das liegen?

 

[Pijay]

Hallo,

folgender Link erläutert das genau.
http://wiki.debianforum.de/LinuxSpeichermanagement

Kurzfassung: das ist normal.

Gruß
Michael

 

[zylox]

Ich weiß, dass Linux cached und dann eben der Speicher in der ersten Zeile unter "used" auftaucht. In der zweiten Zeile, mit "buffers/cache" tauchen 1005mb unter used und 2003mb als free (buffers/cache) auf.

In dem von dir verlinkten Wiki Artikel steht ja auch:

Die Zeile mit -/+ buffers/cache zeigt an, wie viel Speicher aus Anwendungssicht frei beziehungsweise belegt ist. In diesem Beispiel belegen auf meinem System laufende Anwendungen 278 MB, während 606 MB frei zur Verfügung stehen.

und die Beispiel Ausgabe von "free -m" sieht dort so aus:

user@debian:~$ free -m
             total       used       free     shared    buffers     cached
Mem:           885        874         10          0         16        579
-/+ buffers/cache:        278        606
Swap:         1024          0       1024

Das ist normal. Aber bei mir ist es nicht normal wenn unter "used" 1005mb auftauchen und nichts läuft. Ich habe noch zwei andere Server und bei denen ist das nicht so, dort ist eben wirklich nur unter "used" (in der zweiten Zeile) das was auch verwendet wird.

Das ist das komische.

 

[marce]

irgendwelche ramfs / tmpfs am laufen?

 

[henk77]

Hallo zylox,

meldet dmesg was auffälliges?

Ansonsten würde ich mal ein Skript schreiben, dass die Ausgabe von free und ps aux samt Uhrzeit wenigstens jede Minute loggt.

 

[Pijay]

Hups zylox,

bin davon ausgegangen das mal wieder nicht bekannt ist wie Linux arbeitet, sorry.

Ich werfe jetzt einfach mal das Stichwort versteckte Prozesse ein als weitere Möglichkeit.

Liebe Grüße
Michael

 

[zylox]

Danke erstmal für die Antworten.

irgendwelche ramfs / tmpfs am laufen?

Ja, zwei. Aber praktisch "leer".

tmpfs                 1.5G     0  1.5G   0% /lib/init/rw
tmpfs                 1.5G  4.0K  1.5G   1% /dev/shm

Ich werfe jetzt einfach mal das Stichwort versteckte Prozesse ein als weitere Möglichkeit.

listps zeigt mir keine versteckten Prozesse und auch ein chkrootkit findet nichts was sich irgendwo versteckt haben könnte.

meldet dmesg was auffälliges?

Auch nicht, sieht ganz "normal" aus.

Ich werde jetzt tatsächlich mal ein Skript basteln und den Server nochmals neustarten. Vielleicht kann man dann auf etwas schließen.

Das Problem ist mir auch erst "von heute auf morgen" aufgefallen, war also nicht von Anfang an vorhanden. An der Konfiguration habe ich in letzter Zeit auch nicht wirklich was geändert.

Grüße,
Z

 

[zylox]

So, das log Skript hat jetzt zugeschlagen. Um 21 Uhr lief ein rsync welches die Festplatte eines anderes Server in ein Unterverzeichnis spiegelt. Der Speicherverbrauch ist bei dem rsync Vorgang auf 800mb gestiegen. Nach dem rsync Lauf wird der Speicher aber nicht mehr freigegeben, auch wenn der Prozess nicht mehr läuft.

Woran kann das liegen?

System ist ein Debian Lenny (32 bit) mit dem regulären rsync Paket aus den Debian Repositories.

 

[henk77]

Wurde der Speicher von rsync oder vom kernel alloziert? Solltest du eigentlich anhand der Ausgaben von ps aux feststellen bzw. wenigstens vermuten können.

 

[zylox]

Also auf jeden Fall scheint rsync sich den Speicher nicht selbst zu nehmen:

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
[...]
user      3707  2.2  0.7  67440 23908 ?        S    21:00   0:05 rsync --delete -a -r -v -z -e ssh --rsync-pa ....

 

[henk77]

Schön, das passt schon mal.

Was für Techniken bzw. Module sind beim Lesen und Schreiben der Daten von rsync involviert?

Bspw.:
- ssh tunnel?
- device mapper?
- lvm?
- Dateisysteme?
..

Muss allerdings zugeben, dass ich keine Konstellation kenne, die sowas eher als andere zur Folge haben könnte. Aber vielleicht kannst du es nach und nach ausschließen.


Außerdem würde ich in so einem Fall vermutlich erst mal einen Check des Dateisystems durchführen und einen anderen Kernel versuchen. Insbesondere solltest du dir vielleicht mal die Möglichkeiten neuerer Kernel anschauen, Memory Leaks aufzuspüren (http://lwn.net/Articles/187979/).

 

[zylox]

Ich habe den Server jetzt mal in die Rescue Console gebootet und eine fsck gemacht, da gab es keine Beanstandungen.

Was für Techniken bzw. Module sind beim Lesen und Schreiben der Daten von rsync involviert?

Rsync wird durch SSH getunnelt, das ganze geht aber niemals über 100mb Speichernutzung. Der Server selbst hat ein Software Raid-1 und das Dateisystem ist Ext3.

Interessanterweise "fressen" unterschiedliche rsyncs unterschiedlich viel Speicher. Bei einem rsync sind danach 400mb Speicher belegt, bei einem anderen 800mb.

Den Kernel werde ich nochmal testen, wobei es sich da eigentlich um den aktuell offiziellen Debian 2.6 AMD64 Kernel handelt.

 

[henk77]

Ich habe ein ähnliches Setup, also rsync über ssh tunnel und Softwareraid auf dem Zielserver. Deshalb habe ich mal versucht, das Phänomen bei mir zu reproduzieren. Dazu habe ich den Zielserver neugestartet und dann rsync laufen lassen.

xxxx:~# free -m
             total       used       free     shared    buffers     cached
Mem:          1003        549        453          0         12        177
-/+ buffers/cache:        359        643
Swap:         1929          0       1929
xxxx:~# ps aux | gawk 'BEGIN{D=0;C=0}{D+=$5;C+=$6}END{print D;print C}'
6174860
559344
xxxx:~# free -m
             total       used       free     shared    buffers     cached
Mem:          1003        902        101          0        141        241
-/+ buffers/cache:        519        483
Swap:         1929          5       1924
xxxx:~# ps aux | gawk 'BEGIN{D=0;C=0}{D+=$5;C+=$6}END{print D;print C}'
6182224
563964

Die ersten zwei Ausgaben sind vor dem rsync und die letzten zwei danach. Auch bei mir ist der Anstieg also deutlich zu sehen. Mich hat es vor allem interessiert, ob der Speicher wieder freigegeben wird:

xxxx:~# cd /dev/shm/
xxxx:/dev/shm# dd if=/dev/zero of=ttttttt bs=1024k count=600
dd: writing `ttttttt': No space left on device
501+0 records in
500+0 records out
525029376 bytes (525 MB) copied, 2.55131 s, 206 MB/s
xxxx:/dev/shm# rm ttttttt 
xxxx:/dev/shm# free -m
             total       used       free     shared    buffers     cached
Mem:          1003        490        512          0         55         26
-/+ buffers/cache:        408        594
Swap:         1929         29       1900

Der wesentliche Teil wird also offenbar wieder freigegeben. Falls es sich also um einen Fehler handelt, dürfte er nicht dramatisch sein und betrifft offenbar nicht nur dein System.

Nachtrag: Ich habe Ihn gerade mal noch eine mehrere GB große Datei schreiben lassen, danach hat er nochmals 50MB freigegeben. Der Speicher ist demnach definitiv nicht fest in Benutzung. Falls du genau wissen willst, wie die seltsame Anzeige zustande kommt, solltest du das Problem mal der kernel mailing list schildern.

Nachtrag2: Hab es ein weiteres Mal reproduziert und mir den Verlauf der Werte aus /proc/meminfo angeschaut. Es fällt auf, dass sich der fehlende Teil ziemlich genau in SReclaimable versteckt. Der Teil wird wohl erst mal nicht freigegeben, damit der Speicher nicht so sehr fragmentiert. Ist also wohl ein Feature und kein Fehler des Kernels. Wobei ich mich frage, falls das wirklich stimmt, ob man dann free nicht anpassen sollte, damit der Wert abgezogen wird.