Apache schreibt alle paar Sekunden auf die HDD, warum?

[slu]

Hallo,

ich hab hier ein Debian Jessie mit Apache am laufen, es handelt sich hier um meinen kleinen Homeserver*.
Seit einiger Zeit (evtl. auch seit Jessie) fällt mir auf das die HDD LED alle paar Sekunden kurz aufleuchtet was mir dstat auch bestätigt:

Code: Alles auswählen

----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system--
usr sys idl wai hiq siq| read  writ| recv  send|  in   out | int   csw 
  0   0  99   0   0   0|2285B   23k|   0     0 |   0     0 |  56   122 
  0   0 100   0   0   0|   0     0 | 132B  924B|   0     0 |  56   117 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  46    91 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  47    93 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  45    81 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  47    91 
  0   0  95   5   0   0|   0    92k|  66B  350B|   0     0 |  51   106 
  2   0  98   0   0   0|   0    28k|  66B  350B|   0     0 |  99   324 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  45    80 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  38    68 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  49    93 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  48    95 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  51    96 
  0   0  95   5   0   0|   0    72k|  66B  350B|   0     0 |  46    95 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  44    89 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  48    91 
  0   0 100   0   0   0|   0   196k|  66B  350B|   0     0 |  59    97 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  46    89 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  50    96 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  53   101 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  51   105 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  47    95 
  1   1  98   0   0   0|   0    28k|  66B  350B|   0     0 |  88   304 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  47    89 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  45    94 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  44    83 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  47    95 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  48    93 
  0   0  95   5   0   0|   0    72k|  66B  350B|   0     0 |  53   108 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  43    81 
  0   0 100   0   0   0|   0     0 |  66B  350B|   0     0 |  51    93

Zu diesem Zeitpunkt war auch immer kurz ein Apache Prozess in top zu sehen, daraufhin habe ich den Apache testweise gestoppt und siehe da es hört auf. Ich habe keine Ahnung was der Apache da ständig schreiben muss, die Logdateien sind es nicht (hab ich schon kontrolliert).

Jemand eine Idee wie man das weiter untersuchen könnte?


*Bei den Systemen im Büro würde ich so etwas gar nicht merken, da gibt es eine viel größere Grundlast

[DeletedUserReAsG]

Mit lsof kannst du dir u.A. anschauen, welche Files ein Prozess offen hat. Reicht das nicht, ließe sich mit strace genau schauen, was der betreffende Prozess tut – Kenntnisse von grep wären dann von Vorteil.

[slu]

Mit lsof habe ich schon gespielt, mit

Code: Alles auswählen

lsof | grep apache | grep -e "[[:digit:]]\+w"

sieht man zwar was alles offen ist, jedoch ist das weitaus mehr als er "wirklich" schreibt.

Das nächste Problem ist das sich die PID ständig ändert da es mehrere Apache Prozesse sind.

Bei iotop sehe ich zwar wieder den Apache Prozess, aber was er wirklich schreibt ist so auch nicht zu sehen.

[rendegast]

Code: Alles auswählen

strace -e trace=file -f -p $papa-pid

noch weiter eingegrenzt, in der Art:

Code: Alles auswählen

strace -e trace=file -f -p $papa-pid 2>&1 | egrep -o "/.*"

[DeletedUserReAsG]

Ein anderer Ansatzpunkt könnte sein: du verrätst, wie der Apache konfiguriert ist und was darauf läuft und wir rätzeln, was davon solche Zugriffe erzeugen mag – könnte ja auch irgendeine z.B. PHP-Anwendung sein, die regelmäßig etwa ein Sessions-Verzeichnis durchgeht, o.Ä..

Alternativ: du setzt die Config zurück und beobachtest: treten die Zugriffe dann auch auf, ist’s irgendwas Vorhandenes, treten sie nicht auf, aktivierst den ganzen Kram wieder Stück für Stück und schaust jeweils, ob es auftritt.

[slu]

Code: Alles auswählen

strace -e trace=file -f -p $papa-pid

noch weiter eingegrenzt, in der Art:

Das liefert kein einzigen Treffer, wenn man -e trace=file weg lässt kommen ein paar Ausgaben.
Die PID habe ich mir über pstree -p herausgesucht.

Ein anderer Ansatzpunkt könnte sein: du verrätst, wie der Apache konfiguriert ist und was darauf läuft und wir rätzeln, was davon solche Zugriffe erzeugen mag – könnte ja auch irgendeine z.B. PHP-Anwendung sein, die regelmäßig etwa ein Sessions-Verzeichnis durchgeht, o.Ä..

Auf dem Server läuft ausschließlich die Horde Groupware, aber deine Überlegungen mit dem regelmäßigen "Cronjob" hatte ich auch schon.

Ich hab jetzt mal die beiden Konfigurationen die ich habe deaktiviert und den Apache neu gestartet.

Code: Alles auswählen

root@wds:/etc/apache2/sites-enabled# ls -la
insgesamt 8
drwxr-xr-x 2 root root 4096 Nov 25 22:08 .
drwxr-xr-x 9 root root 4096 Okt 18 14:31 ..
root@wds:/etc/apache2/sites-enabled#

Gleiches Fehlerbild, sobald der Apache läuft gibt es die Schreibzugriffe.

Vielleicht bin ich mit dem Apache auch auf dem Holzweg, irgendwie ist das alles sehr spannend.

[slu]

Hab gerade herausgefunden das dstat noch viel mehr kann "dstat -ta --top-bio":

Code: Alles auswählen

----system---- ----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system-- ----most-expensive----
     time     |usr sys idl wai hiq siq| read  writ| recv  send|  in   out | int   csw |  block i/o process   
25-11 22:23:07|  1   0  99   0   0   0|   0     0 | 132B  508B|   0     0 |  94   148 |                      
25-11 22:23:08|  2   1  97   0   0   0|   0    28k|  66B 1054B|   0     0 | 124   361 |mysqld        0   112k
25-11 22:23:09|  1   0  99   0   0   0|   0     0 |  66B  446B|   0     0 |  93   156 |                      
25-11 22:23:10|  1   0  98   1   0   0|   0    96k|  66B  414B|   0     0 |  93   156 |jbd2/dm-0-8   0    52k
25-11 22:23:11|  1   0  99   0   0   0|   0     0 |  66B  446B|   0     0 |  83   128 |                      
25-11 22:23:12|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  73    98 |                      
25-11 22:23:13|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  80   130 |                      
25-11 22:23:14|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  74   102 |                      
25-11 22:23:15|  1   0  99   0   0   0|   0     0 | 126B  456B|   0     0 |  89   144 |                      
25-11 22:23:16|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  72   100 |                      
25-11 22:23:17|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  79   130 |                      
25-11 22:23:18|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  81   113 |                      
25-11 22:23:19|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  87   129 |                      
25-11 22:23:20|  2   1  97   0   0   0|   0    28k|  66B  414B|   0     0 | 116   318 |mysqld        0   112k
25-11 22:23:21|  1   0  99   0   0   0|   0     0 |  66B  446B|   0     0 |  86   134 |                      
25-11 22:23:22|  1   1  99   0   0   0|   0     0 |  66B  414B|   0     0 |  74   104 |                      
25-11 22:23:23|  2   0  98   0   0   0|   0    28k|  66B  414B|   0     0 | 121   352 |mysqld        0   112k
25-11 22:23:24|  1   0  99   0   0   0|   0     0 |  66B  446B|   0     0 |  71    97 |                      
25-11 22:23:25|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  72   103 |                      
25-11 22:23:26|  1   0  95   5   0   0|   0   100k|5340B 2055B|   0     0 | 124   197 |jbd2/dm-0-8   0    44k
25-11 22:23:27|  1   0  98   0   0   0|   0     0 |  17k 6728B|   0     0 | 191   229 |                      
25-11 22:23:28|  1   0  99   0   0   0|   0     0 | 668B  845B|   0     0 |  94   138 |                      
25-11 22:23:29|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  68    96 |                      
25-11 22:23:30|  1   1  99   0   0   0|   0   188k|  66B  414B|   0     0 | 117   147 |                      
25-11 22:23:31|  1   0  99   0   0   0|   0     0 | 126B  456B|   0     0 |  76    99 |                      
25-11 22:23:32|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  78   131 |                      
25-11 22:23:33|  1   1  99   0   0   0|   0     0 |  66B  414B|   0     0 |  79   123 |                      
25-11 22:23:34|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  82   133 |                      
25-11 22:23:35|  2   1  97   0   0   0|   0    28k|  66B  414B|   0     0 | 126   358 |mysqld        0   112k
25-11 22:23:36|  1   0  99   0   0   0|   0     0 |  66B  446B|   0     0 |  90   142 |                      
25-11 22:23:37|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  71    97 |                      
25-11 22:23:38|  2   0  97   0   0   0|   0    28k|  66B  414B|   0     0 | 128   351 |mysqld        0   112k
25-11 22:23:39|  1   0  99   0   0   0|   0     0 |  66B  446B|   0     0 |  80   108 |                      
25-11 22:23:40|  1   0  99   0   0   0|   0     0 |  66B  414B|   0     0 |  82   133 |                      
25-11 22:23:41|  1   0  95   4   0   0|   0   100k|  66B  414B|   0     0 |  77   114 |jbd2/dm-0-8   0    92k

So richtig klar ist mir das jetzt aber nicht.

[hikaru]

Da schreibt wohl Mysql alle 15 Sekunden was auf die Platte. Ich würde mal die Apache- und Mysql-Konfiguration nach Sachen durchstöbern die alle 15 Sekunden passieren.

[rendegast]

strace -e trace=file -f -p $papa-pid
...
Das liefert kein einzigen Treffer,

Hab gerade herausgefunden das Debiandstat noch viel mehr kann

'iotop -a' wäre noch so ein Tool.
(Steht bei mir immer auf "IO", mit 'links'-'links' auf "DISK WRITE" schalten)

[pferdefreund]

wo ich so mysql höre - schreibt das eventuell so ne art Redo-logs oder ähnliches, bez synct der regelmäßig ?

[slu]

Hab gerade herausgefunden das Debiandstat noch viel mehr kann

'iotop -a' wäre noch so ein Tool.
(Steht bei mir immer auf "IO", mit 'links'-'links' auf "DISK WRITE" schalten)

Guter Hinweis und zeigt wieder den Apache als Ursache.
Das Journal vom ext4 ist meiner Meinung nur ein Nebeneffekt.

Code: Alles auswählen

Total DISK READ :       0.00 B/s | Total DISK WRITE :       0.00 B/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:       0.00 B/s
  TID  PRIO  USER     DISK READ DISK WRITE>  SWAPIN      IO    COMMAND                                                                                                   
  150 be/3 root          0.00 B    728.00 K  0.00 %  0.09 % [jbd2/dm-0-8]
 4477 be/4 www-data      0.00 B    224.00 K  0.00 %  0.00 % apache2 -k start
 4503 be/4 www-data      0.00 B    224.00 K  0.00 %  0.00 % apache2 -k start
    1 be/4 root          0.00 B      0.00 B  0.00 %  0.00 % init

[slu]

wo ich so mysql höre - schreibt das eventuell so ne art Redo-logs oder ähnliches, bez synct der regelmäßig ?

Mit dem iotop kann man den mysql sicher ausschliessen.

[rendegast]

strace -e trace=file -f -p $papa-pid
...
Das liefert kein einzigen Treffer,

Was hast Du da explizit angegeben?
<->

Code: Alles auswählen

pstree -p

Beide Befehle am besten als root.
(falls zBsp.

$ mount | grep proc
proc on /proc type proc (rw,nosuid,nodev,noexec,relatime,hidepid=1)

kann ein anderer Benutzer außer root andere Benutzer nicht beobachten)
Auch gibt es wohl su-forks(?) von Programmen, die 'strace -f' nicht weiter verfolgt.

[slu]

strace -e trace=file -f -p $papa-pid
...
Das liefert kein einzigen Treffer,

Was hast Du da explizit angegeben?
<->

Hab das alles als root gemacht.

Code: Alles auswählen

root@wds:/tmp# pstree -p | grep apache
           |-apache2(689)-+-apache2(4474)
           |              |-apache2(4476)
           |              |-apache2(4477)
           |              |-apache2(4503)
           |              |-apache2(4535)
           |              |-apache2(4578)
           |              |-apache2(4831)
           |              |-apache2(4975)
           |              |-apache2(4986)
           |              |-apache2(4987)
           |              `-apache2(7173)
root@wds:/tmp# date
Fr 27. Nov 20:56:58 CET 2015
root@wds:/tmp# strace -e trace=file -f -p 689
Process 689 attached
^CProcess 689 detached
root@wds:/tmp# date
Fr 27. Nov 20:57:45 CET 2015
root@wds:/tmp#

Es fuchst mich etwas das ich nicht hinter das Problem komme.

[slu]

Jehuu gelöst, vielen Dank an alle die mir in dem Thread geantwortet haben!

Ich hab mich mit dem strace an einen child Apache process gehängt und gewartet nachdem mir im iotop -a aufgefallen war das sich
die PID beim Apache immer wieder ändert.

Und siehe da:

Code: Alles auswählen

open("/tmp/HordeCacheTQKuze", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 18
rename("/tmp/HordeCacheTQKuze", "/var/cache/horde/cache_182c260a8128cfc03866e1251fada4ea") = -1 EACCES (Permission denied)
open("/var/cache/horde/horde_cache_gc", O_WRONLY|O_CREAT|O_APPEND, 0666) = -1 EACCES (Permission denied)

Der Cache vom Horde hat root gehört und damit durfte www-data nicht schreiben.
Es ist wirklich schön das Problem gefunden zu haben und ich hab dank euch wieder viel dazu gelernt.

[rendegast]

Nachtrag,
'strace -f -p PID'
verfolgt nur ab dem strace geforkte Child-Prozesse, aua.
Es hätte eher

Code: Alles auswählen

strace .... -f $(pidof apache2 | sed 's@\([0-9]*\)@-p \1@g')

->
strace .... -f -p 111 -p 222 -p 333 -p 444 ...

gepaßt.