Les logs

De The Linux Craftsman
Aller à la navigation Aller à la recherche

Introduction

Les fichiers journaux

Les fichiers journaux sont des fichiers qui contiennent des messages sur le système, le noyau, les services et les applications qui s'exécutent. Il y a des fichiers journaux différents en fonction des informations. Par exemple, il existe un fichier journal pour le système, un fichier journal réservé aux messages de sécurité, un fichier journal pour les tâches cron, ...

Les fichiers journaux peuvent être très utiles lorsque vous essayez de résoudre un problème car ils recèlent une mine d'informations sur ce que sont en train de faire les processus. Certains fichiers journaux sont contrôlés par un démon nommé syslogd.

Emplacement

La plupart des fichiers journaux se trouvent dans le répertoire /var/log/ et certaines applications telles que httpd et samba disposent d'un répertoire dans /var/log/ pour leurs fichiers journaux.

Vous remarquerez peut-être plusieurs fichiers dans ce répertoire qui se terminent par des chiffres. Une rotation des fichiers journaux est effectuée afin que la taille des fichiers ne devienne pas trop grande.

Le paquetage logrotate contient une tâche cron qui effectue automatiquement la rotation des fichiers journaux selon le fichier /etc/logrotate.conf ainsi que les fichiers de configuration présents dans le répertoire /etc/logrotate.d.

Dhcpd

Les logs de dhcpd se trouvent dans /var/log/messages : 

Feb 14 09:01:06 fw dhcpd: Internet Systems Consortium DHCP Server 4.1.1-P1
Feb 14 09:01:06 fw dhcpd: Copyright 2004-2010 Internet Systems Consortium.
Feb 14 09:01:06 fw dhcpd: All rights reserved.
Feb 14 09:01:06 fw dhcpd: For info, please visit https://www.isc.org/software/dhcp/
Feb 14 09:01:06 fw dhcpd: WARNING: Host declarations are global.  They are not limited to the scope you declared them in.
Feb 14 09:01:06 fw dhcpd: Not searching LDAP since ldap-server, ldap-port and ldap-base-dn were not specified in the config file
Feb 14 09:01:06 fw dhcpd: Wrote 0 deleted host decls to leases file.
Feb 14 09:01:06 fw dhcpd: Wrote 0 new dynamic host decls to leases file.
Feb 14 09:01:06 fw dhcpd: Wrote 5 leases to leases file.
Feb 14 09:01:06 fw dhcpd: Listening on LPF/eth3/00:0c:29:db:3a:1f/192.168.210.0/24
Feb 14 09:01:06 fw dhcpd: Sending on   LPF/eth3/00:0c:29:db:3a:1f/192.168.210.0/24
Feb 14 09:01:06 fw dhcpd:
Feb 14 09:01:06 fw dhcpd: No subnet declaration for eth2 (no IPv4 addresses).
Feb 14 09:01:06 fw dhcpd: ** Ignoring requests on eth2.  If this is not what
Feb 14 09:01:06 fw dhcpd:    you want, please write a subnet declaration
Feb 14 09:01:06 fw dhcpd:    in your dhcpd.conf file for the network segment
Feb 14 09:01:06 fw dhcpd:    to which interface eth2 is attached. **
Feb 14 09:01:06 fw dhcpd:
Feb 14 09:01:06 fw dhcpd: Listening on LPF/eth1/00:0c:29:db:3a:0b/192.168.200.0/24
Feb 14 09:01:06 fw dhcpd: Sending on   LPF/eth1/00:0c:29:db:3a:0b/192.168.200.0/24
Feb 14 09:01:06 fw dhcpd:
Feb 14 09:01:06 fw dhcpd: No subnet declaration for eth0 (192.168.100.200).
Feb 14 09:01:06 fw dhcpd: ** Ignoring requests on eth0.  If this is not what
Feb 14 09:01:06 fw dhcpd:    you want, please write a subnet declaration
Feb 14 09:01:06 fw dhcpd:    in your dhcpd.conf file for the network segment
Feb 14 09:01:06 fw dhcpd:    to which interface eth0 is attached. **
Feb 14 09:01:06 fw dhcpd:
Feb 14 09:01:06 fw dhcpd: Sending on   Socket/fallback/fallback-net

Interfaces d'écoutes

On voit clairement les interfaces où dhcpd va répondre : 

Feb 14 09:01:06 fw dhcpd: Listening on LPF/eth1/00:0c:29:db:3a:0b/192.168.200.0/24
Feb 14 09:01:06 fw dhcpd: Sending on   LPF/eth1/00:0c:29:db:3a:0b/192.168.200.0/24

et celles où rien ne se passera : 

Feb 14 09:01:06 fw dhcpd: No subnet declaration for eth2 (no IPv4 addresses).
Feb 14 09:01:06 fw dhcpd: ** Ignoring requests on eth2.  If this is not what
Feb 14 09:01:06 fw dhcpd:    you want, please write a subnet declaration
Feb 14 09:01:06 fw dhcpd:    in your dhcpd.conf file for the network segment
Feb 14 09:01:06 fw dhcpd:    to which interface eth2 is attached. **
Feb 14 09:01:06 fw dhcpd:
Feb 14 09:01:06 fw dhcpd: No subnet declaration for eth0 (192.168.100.200).
Feb 14 09:01:06 fw dhcpd: ** Ignoring requests on eth0.  If this is not what
Feb 14 09:01:06 fw dhcpd:    you want, please write a subnet declaration
Feb 14 09:01:06 fw dhcpd:    in your dhcpd.conf file for the network segment
Feb 14 09:01:06 fw dhcpd:    to which interface eth0 is attached. **

Délivrance des baux

Quand une machine demande un bail au serveur DHCP, on peut le suivre dans les logs... ce qui est très pratique quand on n'a pas envie de recopier son adresse MAC ! 

Feb 14 09:08:33 fw dhcpd: DHCPDISCOVER from 00:0c:29:e6:c5:aa via eth1
Feb 14 09:08:33 fw dhcpd: DHCPOFFER on 192.168.200.253 to 00:0c:29:e6:c5:aa via eth1
Feb 14 09:08:33 fw dhcpd: DHCPREQUEST for 192.168.200.253 (192.168.200.254) from 00:0c:29:e6:c5:aa via eth1
Feb 14 09:08:33 fw dhcpd: DHCPACK on 192.168.200.253 to 00:0c:29:e6:c5:aa via eth1


Named (Bind)

Les logs de named se trouve en majeure partie dans /var/log/message 

Feb 14 13:17:30 dns named[1559]: ----------------------------------------------------
Feb 14 13:17:30 dns named[1559]: BIND 9 is maintained by Internet Systems Consortium,
Feb 14 13:17:30 dns named[1559]: Inc. (ISC), a non-profit 501(c)(3) public-benefit
Feb 14 13:17:30 dns named[1559]: corporation.  Support and training for BIND 9 are
Feb 14 13:17:30 dns named[1559]: available at https://www.isc.org/support
Feb 14 13:17:30 dns named[1559]: ----------------------------------------------------
Feb 14 13:17:30 dns named[1559]: adjusted limit on open files from 4096 to 1048576
Feb 14 13:17:30 dns named[1559]: found 2 CPUs, using 2 worker threads
Feb 14 13:17:30 dns named[1559]: using up to 4096 sockets
Feb 14 13:17:30 dns named[1559]: loading configuration from '/etc/named.conf'
Feb 14 13:17:30 dns named[1559]: reading built-in trusted keys from file '/etc/named.iscdlv.key'
Feb 14 13:17:30 dns named[1559]: using default UDP/IPv4 port range: [1024, 65535]
Feb 14 13:17:30 dns named[1559]: using default UDP/IPv6 port range: [1024, 65535]
Feb 14 13:17:30 dns named[1559]: listening on IPv4 interface lo, 127.0.0.1#53
Feb 14 13:17:30 dns named[1559]: listening on IPv4 interface eth0, 192.168.200.253#53
Feb 14 13:17:30 dns named[1559]: generating session key for dynamic DNS
Feb 14 13:17:30 dns named[1559]: sizing zone task pool based on 8 zones
Feb 14 13:17:30 dns named[1559]: using built-in DLV key for view _default
Feb 14 13:17:30 dns named[1559]: set up managed keys zone for view _default, file '/var/named/dynamic/managed-keys.bind'
Feb 14 13:17:30 dns named[1559]: Warning: 'empty-zones-enable/disable-empty-zone' not set: disabling RFC 1918 empty zones
Feb 14 13:17:30 dns named[1559]: automatic empty zone: 127.IN-ADDR.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: 254.169.IN-ADDR.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: 2.0.192.IN-ADDR.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: 100.51.198.IN-ADDR.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: 113.0.203.IN-ADDR.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: 255.255.255.255.IN-ADDR.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: 0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.IP6.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: D.F.IP6.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: 8.E.F.IP6.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: 9.E.F.IP6.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: A.E.F.IP6.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: B.E.F.IP6.ARPA
Feb 14 13:17:30 dns named[1559]: automatic empty zone: 8.B.D.0.1.0.0.2.IP6.ARPA
Feb 14 13:17:30 dns named[1559]: command channel listening on 0.0.0.0#953
Feb 14 13:17:30 dns named[1559]: zone 0.in-addr.arpa/IN: loaded serial 0
Feb 14 13:17:30 dns named[1559]: zone 1.0.0.127.in-addr.arpa/IN: loaded serial 0
Feb 14 13:17:30 dns named[1559]: zone 200.168.192.in-addr.arpa/IN: loaded serial 10
Feb 14 13:17:30 dns named[1559]: zone 1.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.ip6.arpa/IN: loaded serial 0
Feb 14 13:17:30 dns named[1559]: zone tala-informatique.fr/IN: loaded serial 20
Feb 14 13:17:30 dns named[1559]: zone localhost.localdomain/IN: loaded serial 0
Feb 14 13:17:30 dns named[1559]: zone localhost/IN: loaded serial 0
Feb 14 13:17:30 dns named[1559]: managed-keys-zone ./IN: loaded serial 81
Feb 14 13:17:30 dns named[1559]: running

Chargement des fichiers de zones

Il faut repérer dans cet amas de lignes celles qui sont font référence au chargement des zones spécifiques : 

Feb 14 13:17:30 dns named[1559]: zone 200.168.192.in-addr.arpa/IN: loaded serial 10
Feb 14 13:17:30 dns named[1559]: zone tala-informatique.fr/IN: loaded serial 20

Interfaces d'écoute

On peut s'assurer, autrement qu'avec netsatat que named écoute bien sur les bonnes interfaces : 

Feb 14 13:17:30 dns named[1559]: listening on IPv4 interface lo, 127.0.0.1#53
Feb 14 13:17:30 dns named[1559]: listening on IPv4 interface eth0, 192.168.200.253#53

Httpd

httpd log dans le répertoire /var/log/httpd/ et utilise deux fichiers:

  • access_log → pour journaliser tous les accès
  • error_log → pour journaliser toutes les erreurs

Démarrage et erreurs

Le fichier /var/log/httpd/error_log est fait pour ça. Quand vous avez une erreur PHP ou autre, c'est ici qu'il faut venir faire un tour: 

[Sat Feb 15 02:32:53 2014] [notice] suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Sat Feb 15 02:32:53 2014] [notice] Digest: generating secret for digest authentication ...
[Sat Feb 15 02:32:53 2014] [notice] Digest: done
[Sat Feb 15 02:32:54 2014] [notice] Apache/2.2.15 (Unix) DAV/2 mod_ssl/2.2.15 OpenSSL/1.0.0-fips configured -- resuming normal operations

Vérifier l'accès aux pages

Pour vérifier qui demande quoi sur à votre serveur, c'est dans le fichier /var/log/httpd/access_log qu'il faut venir regarder: 

192.168.200.254 - - [30/Dec/2013:13:43:38 +0100] "GET / HTTP/1.1" 200 130 "-" "Mozilla/5.0 (X11; Linux i686; rv:24.0) Gecko/20100101 Firefox/24.0"
192.168.200.254 - - [30/Dec/2013:13:43:39 +0100] "GET / HTTP/1.1" 304 - "-" "Mozilla/5.0 (X11; Linux i686; rv:24.0) Gecko/20100101 Firefox/24.0"
192.168.200.254 - - [30/Dec/2013:13:43:42 +0100] "GET / HTTP/1.1" 200 14 "-" "Mozilla/5.0 (X11; Linux i686; rv:24.0) Gecko/20100101 Firefox/24.0"
192.168.200.254 - - [30/Dec/2013:13:43:45 +0100] "GET / HTTP/1.1" 200 130 "-" "Mozilla/5.0 (X11; Linux i686; rv:24.0) Gecko/20100101 Firefox/24.0"


Squid

Les messages de Squid

Quand quelque chose ne tourne pas rond, Squid le dit dans le fichier /var/log/squid.out: 

2014/01/22 06:47:57| WARNING: Could not determine this machines public hostname. Please configure one or set 'visible_hostname'.
FATAL: Bungled squid.conf line 61: http_port 3128 transaprent
Squid Cache (Version 3.1.10): Terminated abnormally.
CPU Usage: 0.023 seconds = 0.010 user + 0.013 sys
Maximum Resident Size: 22848 KB
Page faults with physical i/o: 0
2014/01/22 08:03:41| WARNING cache_mem is larger than total disk cache space!
squid: ERROR: No running copy
2014/01/22 08:03:52| Creating Swap Directories
2014/01/22 08:03:52| /var/spool/squid exists
2014/01/22 08:03:52| Making directories in /var/spool/squid/00
2014/01/22 08:03:52| Making directories in /var/spool/squid/01
2014/01/22 08:03:52| Making directories in /var/spool/squid/02
2014/01/22 08:03:52| Making directories in /var/spool/squid/03
2014/01/22 08:03:52| Making directories in /var/spool/squid/04
2014/01/22 08:03:52| Making directories in /var/spool/squid/05
2014/01/22 08:03:52| Making directories in /var/spool/squid/06
2014/01/22 08:03:52| Making directories in /var/spool/squid/07
2014/01/22 08:03:52| Making directories in /var/spool/squid/08
2014/01/22 08:03:52| Making directories in /var/spool/squid/09
2014/01/22 08:03:52| Making directories in /var/spool/squid/0A
2014/01/22 08:03:52| Making directories in /var/spool/squid/0B
2014/01/22 08:03:52| Making directories in /var/spool/squid/0C
2014/01/22 08:03:52| Making directories in /var/spool/squid/0D
2014/01/22 08:03:52| Making directories in /var/spool/squid/0E
2014/01/22 08:03:52| Making directories in /var/spool/squid/0F

Souvent, les erreurs sont facilement corrigées, comme par exemple: 

2014/01/22 06:47:57| WARNING: Could not determine this machines public hostname. Please configure one or set 'visible_hostname'.

Il suffit de rajouter la directive visible_hostname dans le fichier squid.conf

Ou encore l’absence de l'option cache_mem provoque l'erreur suivante: 

2014/01/22 08:03:41| WARNING cache_mem is larger than total disk cache space!

Les accès HTTP

Tous les accès sont consignés dans le fichier /var/log/squid/access.log 

1392570666.167    746 192.168.1.2 TCP_MISS/200 413 GET http://www.lesclesdumidi.com/updatestats.php? - DIRECT/94.23
1392570668.165    784 192.168.1.2 TCP_MISS/200 413 GET http://www.lesclesdumidi.com/updatestats.php? - DIRECT/94.23
1392570675.655    206 192.168.1.1 TCP_MISS/200 261 POST http://vl.ff.avast.com/F/AAHwy7oPFEJHZIaA4ipWFKJy - DIRECT/
1392570682.608    109 192.168.1.2 TCP_MISS/200 413 GET http://www.lesclesdumidi.com/updatestats.php? - DIRECT/94.2

On peut voir:

  • le temps
  • la durée de la requête
  • l'adresse du client
  • le code / status
  • le volume de données (octet)
  • la méthode
  • l'URL demandée
  • le status du peer

Ce qui nous fait:

Time elapsed client address code / status bytes method URL peer status
1392570682.608 109 192.168.1.2 TCP_MISS/200 413 GET http://www.lesclesdumidi.com/updatestats.php? DIRECT/94.2

Vérification du cache

Il peut être judicieux de vérifier régulièrement si le cache de votre proxy est toujours adapté à l'utilisation que vous en faites.

Cela se passe dans le fichier /var/log/squid/cache.log 

2014/02/16 18:17:01| Starting Squid Cache version 3.1.10 for x86_64-redhat-linux-gnu...
2014/02/16 18:17:01| Process ID 21458
2014/02/16 18:17:01| With 1024 file descriptors available
2014/02/16 18:17:01| Initializing IP Cache...
2014/02/16 18:17:01| DNS Socket created at [::], FD 7
2014/02/16 18:17:01| DNS Socket created at 0.0.0.0, FD 8
2014/02/16 18:17:01| Adding nameserver 192.168.1.254 from /etc/resolv.conf
2014/02/16 18:17:01| Adding nameserver 212.27.40.244 from /etc/resolv.conf
2014/02/16 18:17:01| Adding domain tala-informatique.fr from /etc/resolv.conf
2014/02/16 18:17:01| helperOpenServers: Starting 30/30 'wrapzap' processes
2014/02/16 18:17:01| User-Agent logging is disabled.
2014/02/16 18:17:01| Referer logging is disabled.
2014/02/16 18:17:01| Unlinkd pipe opened on FD 73
2014/02/16 18:17:01| Local cache digest enabled; rebuild/rewrite every 3600/3600 sec
2014/02/16 18:17:01| Store logging disabled
2014/02/16 18:17:01| Swap maxSize 102400 + 102400 KB, estimated 15753 objects
2014/02/16 18:17:01| Target number of buckets: 787
2014/02/16 18:17:01| Using 8192 Store buckets
2014/02/16 18:17:01| Max Mem  size: 102400 KB
2014/02/16 18:17:01| Max Swap size: 102400 KB
2014/02/16 18:17:01| Version 1 of swap file with LFS support detected...
2014/02/16 18:17:01| Rebuilding storage in /var/spool/squid (CLEAN)
2014/02/16 18:17:01| Using Least Load store dir selection
2014/02/16 18:17:01| Set Current Directory to /var/spool/squid
2014/02/16 18:17:02| Loaded Icons.
2014/02/16 18:17:02| Accepting  intercepted HTTP connections at 0.0.0.0:3128, FD 76.
2014/02/16 18:17:02| HTCP Disabled.
2014/02/16 18:17:02| Squid plugin modules loaded: 0
2014/02/16 18:17:02| Adaptation support is off.
2014/02/16 18:17:02| Ready to serve requests.
2014/02/16 18:17:03| Store rebuilding is 62.28% complete
2014/02/16 18:17:04| Done reading /var/spool/squid swaplog (6576 entries)
2014/02/16 18:17:04| Finished rebuilding storage from disk.
2014/02/16 18:17:04|      6576 Entries scanned
2014/02/16 18:17:04|         0 Invalid entries.
2014/02/16 18:17:04|         0 With invalid flags.
2014/02/16 18:17:04|      6576 Objects loaded.
2014/02/16 18:17:04|         0 Objects expired.
2014/02/16 18:17:04|         0 Objects cancelled.
2014/02/16 18:17:04|         0 Duplicate URLs purged.
2014/02/16 18:17:04|         0 Swapfile clashes avoided.
2014/02/16 18:17:04|   Took 2.49 seconds (2639.67 objects/sec).
2014/02/16 18:17:04| Beginning Validation Procedure
2014/02/16 18:17:04|   Completed Validation Procedure
2014/02/16 18:17:04|   Validated 13177 Entries
2014/02/16 18:17:04|   store_swap_size = 92156
2014/02/16 18:17:04| storeLateRelease: released 0 objects

Ci-dessus, un démarrage de cache, mais tout ne se passe pas toujours bien. Dans l'exemple ci-dessous, on s'aperçoit que le nombre de processus redirecteurs est trop faible. 

2014/02/16 17:43:20| WARNING: All redirector processes are busy.
2014/02/16 17:43:20| WARNING: 5 pending requests queued
2014/02/16 17:43:20| Consider increasing the number of redirector processes in your config file.


Pour corriger cela, il suffit de positionner la directive redirect_children avec une valeur correcte (~ 20 / 30).

Samba

smbd

nmbd

Iptables

Fail2ban

Une fois le service démarré, il va commencer à écrire dans le fichier /var/log/secure 

Sep 22 03:52:36 s17650782 sshd[2094]: Failed password for root from 122.225.109.214 port 36975 ssh2
Sep 22 03:52:36 s17650782 sshd[2096]: Failed password for root from 122.225.109.214 port 39090 ssh2
Sep 22 03:52:37 s17650782 sshd[2102]: Failed password for root from 122.225.109.214 port 41395 ssh2
Sep 22 03:52:38 s17650782 sshd[2099]: Failed password for invalid user admin from 122.225.109.214 port 41013 ssh2
Sep 22 03:52:39 s17650782 sshd[2098]: Failed password for root from 222.186.34.119 port 4255 ssh2
Sep 22 03:52:42 s17650782 sshd[2098]: Failed password for root from 222.186.34.119 port 4255 ssh2
Sep 22 03:52:43 s17650782 sshd[2094]: Failed password for root from 122.225.109.214 port 36975 ssh2
Sep 22 03:52:43 s17650782 sshd[2095]: Disconnecting: Too many authentication failures for root
Sep 22 03:52:43 s17650782 sshd[2094]: PAM 5 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=122.225.109.214  user=root
Sep 22 03:52:43 s17650782 sshd[2094]: PAM service(sshd) ignoring max retries; 6 > 3
Sep 22 03:52:43 s17650782 sshd[2102]: Failed password for root from 122.225.109.214 port 41395 ssh2^C
Sep 22 03:52:43 s17650782 sshd[2096]: Failed password for root from 122.225.109.214 port 39090 ssh2
Sep 22 03:52:45 s17650782 sshd[2098]: Failed password for root from 222.186.34.119 port 4255 ssh2
Sep 22 03:52:46 s17650782 sshd[2101]: fatal: Read from socket failed: Connection reset by peer
Sep 22 03:52:46 s17650782 sshd[2098]: PAM 4 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=222.186.34.119  user=root

Cela vous donne une idée des IP qui essayent de casser votre mot de passe...

La commande suivante vous donne une idée du nombre de tentatives: 

cat /var/log/secure | grep disconnect | awk -F ' ' '{ print $9 }'

La commande suivante liste les adresses IP: 

cat /var/log/secure | grep disconnect | awk -F ' ' '{ print $9 }' | sort -u
Récupérée de « https://www.tala-informatique.fr/wiki/index.php?title=Les_logs&oldid=1292 »