# fail2ban verhinder Packen der Apache-Logs für Domains



## shen (4. Apr. 2011)

Hallo zusammen,

wenn wir in unserer ISPConfig 3 / Debian 5 Umgebung fail2ban installieren bzw. aktivieren, dann werden fortan die einzelnen Logs für die Domains nicht mehr gepackt ODER wieder entpackt. Das sieht dann etwa wie folgt aus:



> -rw-r--r--  1 root root      31239  1. Feb 00:32 20110130-access.log.gz
> -rw-r--r--  1 root root       36717  2. Feb 00:32 20110131-access.log.gz
> -rw-r--r--  1 root root       28660  3. Feb 00:32 20110201-access.log.gz
> -rw-r--r--  1 root root       26269  4. Feb 00:32 20110202-access.log.gz
> ...


Übersehen wir da etwas oder ist dies ein Bug!?

Gruß
Stefan


----------



## Till (4. Apr. 2011)

Die Logs der Websites werden von fail2ban nicht überwacht, es kann also damit nichts zu tun haben. Habe auch gerade mal auf meinem ispconfig 3.0.3.2 Server nachgesehen, und dort sind die logs alle korrekt gepackt.

Die letzten 2 oder 3 Logs sind ja nie gepckt, sonst würde die Auswertung mittels awstats fehlschlagen. Ältere Logs werden gepackt und nach 30 Tagen gelöscht.

Ich vermute mal, das bei Dir das cron_daily.sh script von ispconfig nicht läuft, da dies neben der Statistik Auswertung auch die Logs packt.


----------



## shen (4. Apr. 2011)

Nein, wir haben hier tatsächlich eine direkte Abhängigkeit der beiden Dinge, sobald wir fail2ban wieder deaktivieren, wird auch wieder gepackt ... und genau das können wir uns auch nicht erklären und auch so keinen rechten Ansatzpunkt, was sich da genau in die Quere kommt 

Gruß
Stefan


----------



## Till (4. Apr. 2011)

Vielleicht behindert fail2ban auf welche Art auch immer das cron_daily script? Füg doch am ende des cron_daily.php scriptes mal sowas ein wie:

touch('/tmp/cron_daily.txt');

und schau dann morgen mal nach, ob die Datei in /tmp angelegt wurde.


----------



## shen (7. Apr. 2011)

Hi Till,

habe ich gemacht, die Datei wird erstellt, cron_daily.php wird also definitiv ausgeführt, dennoch sind die logs aktuell nicht gepackt.

Gruß
Stefan


----------



## shen (7. Apr. 2011)

Hier noch ein wenig Loggerei der cron_daily.php:


```
starte cron_daily.php
UPDATE mail_traffic SET traffic = 11620003 WHERE traffic_id = 267UPDATE mail_traffic SET traffic = 1265481 WHERE traffic_id = 268UPDATE mail_traffic SET traffic = 43305207 WHERE traffic_id = 269UPDATE mail_traffic SET traffic = 3954918 WHERE traffic_id = 270UPDATE mail_traffic SET traffic = 477167 WHERE traffic_id = 271UPDATE mail_traffic SET traffic = 751487 WHERE traffic_id = 326UPDATE mail_traffic SET traffic = 10559873 WHERE traffic_id = 272UPDATE mail_traffic SET traffic = 536662 WHERE traffic_id = 274UPDATE mail_traffic SET traffic = 889275 WHERE traffic_id = 275UPDATE mail_traffic SET traffic = 273789 WHERE traffic_id = 276UPDATE mail_traffic SET traffic = 715937 WHERE traffic_id = 277UPDATE mail_traffic SET traffic = 672602 WHERE traffic_id = 315UPDATE mail_traffic SET traffic = 191993 WHERE traffic_id = 316UPDATE mail_traffic SET traffic = 2990136 WHERE traffic_id = 318UPDATE mail_traffic SET traffic = 24689991 WHERE traffic_id = 279UPDATE mail_traffic SET traffic = 2004873 WHERE traffic_id = 280UPDATE mail_traffic SET traffic = 18049 WHERE traffic_id = 339UPDATE mail_traffic SET traffic = 789401 WHERE traffic_id = 282UPDATE mail_traffic SET traffic = 50535 WHERE traffic_id = 283UPDATE mail_traffic SET traffic = 243733 WHERE traffic_id = 284UPDATE mail_traffic SET traffic = 1191609 WHERE traffic_id = 286UPDATE mail_traffic SET traffic = 143040 WHERE traffic_id = 319UPDATE mail_traffic SET traffic = 39390 WHERE traffic_id = 320UPDATE mail_traffic SET traffic = 1117688 WHERE traffic_id = 287UPDATE mail_traffic SET traffic = 122514 WHERE traffic_id = 322UPDATE mail_traffic SET traffic = 137940 WHERE traffic_id = 327UPDATE mail_traffic SET traffic = 26055 WHERE traffic_id = 328UPDATE mail_traffic SET traffic = 26061 WHERE traffic_id = 329UPDATE mail_traffic SET traffic = 26055 WHERE traffic_id = 330UPDATE mail_traffic SET traffic = 26055 WHERE traffic_id = 331UPDATE mail_traffic SET traffic = 87697 WHERE traffic_id = 332UPDATE mail_traffic SET traffic = 490477 WHERE traffic_id = 288UPDATE mail_traffic SET traffic = 1213437 WHERE traffic_id = 289UPDATE mail_traffic SET traffic = 11296 WHERE traffic_id = 323UPDATE mail_traffic SET traffic = 45472 WHERE traffic_id = 290UPDATE mail_traffic SET traffic = 1546936 WHERE traffic_id = 291UPDATE mail_traffic SET traffic = 2101416 WHERE traffic_id = 293UPDATE mail_traffic SET traffic = 482935 WHERE traffic_id = 294UPDATE mail_traffic SET traffic = 2038682 WHERE traffic_id = 295UPDATE mail_traffic SET traffic = 805500 WHERE traffic_id = 296UPDATE mail_traffic SET traffic = 2328171 WHERE traffic_id = 297UPDATE mail_traffic SET traffic = 1612081 WHERE traffic_id = 298UPDATE mail_traffic SET traffic = 2918037 WHERE traffic_id = 299UPDATE mail_traffic SET traffic = 816025 WHERE traffic_id = 300UPDATE mail_traffic SET traffic = 5883 WHERE traffic_id = 335UPDATE mail_traffic SET traffic = 36866 WHERE traffic_id = 301UPDATE mail_traffic SET traffic = 902041 WHERE traffic_id = 302UPDATE mail_traffic SET traffic = 2645568 WHERE traffic_id = 303UPDATE mail_traffic SET traffic = 4553509 WHERE traffic_id = 304UPDATE mail_traffic SET traffic = 4145943 WHERE traffic_id = 305UPDATE mail_traffic SET traffic = 5153695 WHERE traffic_id = 324UPDATE mail_traffic SET traffic = 4344608 WHERE traffic_id = 306UPDATE mail_traffic SET traffic = 6286079 WHERE traffic_id = 307UPDATE mail_traffic SET traffic = 237280 WHERE traffic_id = 308UPDATE mail_traffic SET traffic = 583187 WHERE traffic_id = 309UPDATE mail_traffic SET traffic = 6694925 WHERE traffic_id = 325UPDATE mail_traffic SET traffic = 17713652 WHERE traffic_id = 310UPDATE mail_traffic SET traffic = 2840303 WHERE traffic_id = 313UPDATE mail_traffic SET traffic = 369767 WHERE traffic_id = 314Warning: Truncating oversized referrer field
Warning: Truncating oversized referrer field
Warning: Truncating oversized request field
Skipping bad record (42)
Warning: Truncating oversized request field
Skipping bad record (93)
Warning: Truncating oversized request field
Skipping bad record (142)
Warning: Truncating oversized request field
Skipping bad record (156)
Warning: Truncating oversized request field
Skipping bad record (175)
Warning: Truncating oversized request field
Skipping bad record (211)
Warning: Truncating oversized request field
Skipping bad record (238)
Warning: Truncating oversized request field
Skipping bad record (240)
Warning: Truncating oversized request field
Skipping bad record (252)
Warning: Truncating oversized request field
Skipping bad record (253)
Warning: Truncating oversized request field
Skipping bad record (258)
Warning: Truncating oversized request field
Skipping bad record (278)
Warning: Truncating oversized request field
Skipping bad record (302)
Warning: Truncating oversized request field
Skipping bad record (319)
Warning: Truncating oversized request field
Skipping bad record (357)
Warning: Truncating oversized request field
Skipping bad record (362)
Warning: Truncating oversized request field
Skipping bad record (374)
Warning: Truncating oversized request field
Skipping bad record (416)
Warning: Truncating oversized request field
Skipping bad record (443)
Warning: Truncating oversized request field
Skipping bad record (482)
Warning: Truncating oversized request field
Skipping bad record (517)
Warning: Truncating oversized request field
Skipping bad record (566)
Warning: Truncating oversized request field
Skipping bad record (574)
Warning: Truncating oversized request field
Skipping bad record (585)
Warning: Truncating oversized request field
Skipping bad record (628)
Warning: Truncating oversized request field
Skipping bad record (647)
Warning: Truncating oversized request field
Skipping bad record (648)
Warning: Truncating oversized request field
Skipping bad record (660)
Warning: Truncating oversized request field
Skipping bad record (661)
Warning: Truncating oversized request field
Skipping bad record (669)
Warning: Truncating oversized request field
Skipping bad record (685)
Warning: Truncating oversized request field
Skipping bad record (775)
Warning: Truncating oversized request field
Skipping bad record (782)
Warning: Truncating oversized request field
Skipping bad record (800)
Warning: Truncating oversized request field
Skipping bad record (829)
Warning: Truncating oversized request field
Skipping bad record (845)
Warning: Truncating oversized request field
Skipping bad record (859)
Warning: Truncating oversized request field
Skipping bad record (863)
Warning: Truncating oversized request field
Skipping bad record (885)
Warning: Truncating oversized request field
Skipping bad record (912)
Warning: Truncating oversized request field
Skipping bad record (926)
Warning: Truncating oversized request field
Skipping bad record (961)
Warning: Truncating oversized request field
Skipping bad record (995)
Warning: Truncating oversized request field
Skipping bad record (1037)
Warning: Truncating oversized request field
Skipping bad record (1060)
Warning: Truncating oversized request field
Skipping bad record (1080)
Warning: Truncating oversized request field
Skipping bad record (1094)
Warning: Truncating oversized request field
Skipping bad record (1103)
Warning: Truncating oversized request field
Skipping bad record (1113)
Warning: Perl versions before 5.6 cannot handle nested includes

Warning: Invalid argument supplied for foreach() in /usr/local/ispconfig/server/cron_daily.php on line 216

Warning: Invalid argument supplied for foreach() in /usr/local/ispconfig/server/cron_daily.php on line 330
finished.
Thu Apr  7 00:32:21 CEST 2011
beende cron_daily.php
```


----------



## shen (16. Juli 2011)

Hallo,

das Problem besteht leider immer noch. Wir hatten fail2ban mal deinstalliert, da wurden die Logs wieder ordentlich gepackt. Nach dem Update auf eine neue ISPConfig Version war fail2ban wieder da und die Logs wieder nicht gepackt 

Gruß
Stefan


----------



## Till (16. Juli 2011)

Das ist wirklich merkwürdig, denn diese Logs werden nicht von fail2ban überwacht und ich betreibe ja auch einige Debian Server mit ISPConfig 3 und Debian 5 sowie 6 und dort treten keinerlei Probleme damit auf.

Hast Du vielleicht in Deiner fail2ban config irgend etwas geändert oder ergänzt, so dass er die Logs der einzelnen websites überwacht?

Welche ISPConfig Verson vrwendest Du denn und ist in den webseiten webalizer oder awstats als Statistiksoftware aktiviert?


----------



## shen (16. Juli 2011)

Hi Till,

Wir haben ISPConfig 3.0.3.3 - in der Vorversion trat es auch schon auf.

Es mach keinen Unterschied, ob eines der beiden Statistiktools aktiviert ist, es betrifft durch die Bank weg alle Domains. Ich hegte Anfangs den Verdacht, einer der beiden würde die Dateien auspacken zur Erstellung der Statistiken und dann das Archiv löschen, so ist es aber nicht.
Ebensowenig werden alte noch vorhandene gepackte Logs entpackt und deren gepackte Datei gelöscht, es sieht tatsächlich so aus, als würde das tagesaktuelle Logfile nicht gepackt werden.

An der f2b config habe ich nichts geändert, habe aber dennoch mal reingeschaut, da ist nicht zu erkennen, dass f2b die betreffenden Logs anpacken würde.

Es ist uns auch völlig unerklärlich und irgendwie verrückt, aber ich weiss nicht, wo ich ansetzen soll. Fakt ist, dass wenn f2b deinstalliert oder gestoppt wird wieder alles wie gewünscht funktioniert.


Gruß
Stefan


----------



## Till (16. Juli 2011)

Ich denke die einzige Möglichkeit dem weiter auf die Spur zu komen warum es auf Deinem Server nicht funktioniert ist dass Du die cron_daily.php datei um eine Zeilen erweiterst die das Packen jeder Logdatei und des Ergebnis der Aktion (also Rückgabe des Exec Befehls) in eine Lodatei schreibt, die Du dann 24 Stunden später mal ansiehst. Ich kann das Problem wie oben geschrieben nicht auf meinen Servern nachvollziehen und keinne auch sonst kein System mit einem ähnlichen Problem.


----------



## shen (18. Juli 2011)

Ich versuche mal, ein logging aufzusetzen.

Ich würde nun aber gerne die nicht gepackten Logfiles gerne rekursiv nachträglich packen (d.h. für alle Domains), wie mache ich das wohl am geschicktesten?

Gruß
Stefan


----------



## Till (18. Juli 2011)

> Ich würde nun aber gerne die nicht gepackten Logfiles gerne rekursiv nachträglich packen (d.h. für alle Domains), wie mache ich das wohl am geschicktesten?


Dafür müsstest Du wahrscheinlich ein Script schreiben, welches durch alle Logs Verzeichnisse geht und die Dateien komprimiert.


----------



## shen (18. Juli 2011)

Es wird immer verrückter: Während wir "damals" eine Abhängigkeit mit f2b ausmachen konnten, half dieses mal eine Deinstallation von f2b nicht, die Logs werden nachwievor nicht gepackt.

Nun habe ich zum Test die cron_daily.php mal auf den Teil reduziert, der die Logs packt und einzeln laufen lassen, das funktioniert einwandfrei.

Wir hatten damals ja schonmal den Output der cron_daily.php mitgeloggt (Beitrag auf Seite 1), und dort fiel folgendes auf:

_Warning: Invalid argument supplied for foreach() in /usr/local/ispconfig/server/cron_daily.php on line 216  _

_ Warning: Invalid argument supplied for foreach() in /usr/local/ispconfig/server/cron_daily.php on line 330_

Die korrespondierenden Stellen wären dann wohl

```
$sql = "SELECT domain_id, domain, document_root FROM web_domain WHERE server_id = ".$conf['server_id'];
$records = $app->db->queryAllRecords($sql);
foreach($records as $rec) {
```
und

```
/* First we need all servers and the last sys_datalog-id they processed */
    $sql = "SELECT server_id, updated FROM server ORDER BY server_id";
    $records = $app->dbmaster->queryAllRecords($sql);

    /* Then we need the highest value ever */
    $sql = "SELECT max(datalog_id) FROM sys_datalog";
    $res = $app->dbmaster->queryOneRecord($sql);
    $maxId = $res['max(datalog_id)'];

    /* Then delete server by server */
    foreach($records as $server) {
```
wobei die erste für unser Problem verantwortlich sein dürfte, denn im Anschluss werden hier die Logs komprimiert.

Da nun aber die Statistiken (AWStats, Webalizer) erstellt werden, wir das Skript grundsätzlich ausgeführt.

Die Frage ist nun: *Was passiert, dass die Daten der MySQL-Query nicht passen und foreach() an dieser Stelle aussteigt?* 

Die einzige Variable in der Query ist ja _$conf['server_id']_, die wird an anderer Stelle aber auch eingesetzt und erzeugt offensichtlich keine Fehler.

Dass der MySQL-Server genau in diesem Moment nicht läuft, ist auch auszuschliessen, der läuft nun seit 30 Tagen ununterbrochen.

Ich bin völlig ratlos 

Gruß
Stefan


----------



## Till (18. Juli 2011)

Du kannst ja mal folgende Zeilen jeweils vor dem Foreach einbauen:

if(!is_array($records)) echo $sql . "Mit Fehlermeldung: " . $app->db->errorMessage ."\n";


----------



## shen (19. Juli 2011)

Die Ursache ist gefunden: $app->db->errorMessage ist "*MySQL Server has gone away*" ... warum auch immer.

Ich habe allerdings in der MySQL Config u.a. folgende Werte verändert:


```
wait_timeout            = 60
interactive_timeout     = 60
```
Ursächlich dafür war ein gelegentliches _Mysql:Too many connections

_Die könnten ja nun in der Tat ursächlich sein, je nach dem, wie Dein Skript / die Class mit der DB umgeht (wird die DB nur einmal geöffnet und danach davon ausgegangen, dass der Link noch existiert oder wird ggf. geprüft, ob der Link noch da ist und wenn nicht dann neu verbunden).

Gruß
Stefan

ps: Lässt sich ggf. der Titel des Threads noch auf die jetzt erkannte Problematik ändern!?


----------



## Till (19. Juli 2011)

Das script öffnet nur eine einzige Verbindung zu der mysql datenbank. was Du aber vielleicht nicht bedacht hast, ist dass ISPConfig ja bei weitem nicht das einzige Script ist, das sich verbindet. da sind ja unter anderem noch postfix, amavisd, pure-ftpd etc. die sich alle mit dem gleiuchen mysql user verbinden.

Du solltest daher max_connections und max_user_connections in der my.cnf Datei auf 500 setzen.


----------



## shen (19. Juli 2011)

Das Problem ist nicht die Anzahl der gleichzeitigen Verbindungen, die sind ausreichend dimensioniert.

Die Frage ist, ob das Skript während der ganzen Laufzeit auf die bereits geöffnete Verbindung vertraut, die bei mir ja aktuell nach 60 Sekunden wieder geschlossen werden würde (was für Website-Skripte ja i.d.R. auch ausreicht).

Gruß
Stefan


----------

