Oeris

Shopping Cart: 0.00 0 items

Le blog

Comprendre les logs Freeradius

Introduction sur les logs freeradius

Ce deuxième tutoriel permettra de mieux appréhender / trouver pourquoi le serveur Freeradius ne fonctionne pas principalement en regardant les logs. La règle de base lorsque quelque chose ne fonctionne pas est classique et vraie pour tous les programmes : Regarder les logs freeradius Freeradius peut être lancé en mode debug (radiusd -X), les logs sont souvent très verbeux, mais dès lors qu’on les comprend, très explicite. Les chapitres ci dessous détaillent de manière détaillé les différents types de problèmes que l’on peut rencontrer sans lister les solutions, mais celle ci sont explicites une fois que le problème a été identifié.

Le serveur ne démarre pas

Lorsque Freeradius démarre, il essaie de charger ses fichiers de configuration, les échecs de démarrage sont souvent liés aux erreurs suivantes :

  • Il y a une erreur de syntaxe dans un fichier de configuration
  • Le serveur est déjà démarré ou un autre démon écoute sur le même port sur la même machine

  Exemple de port déjà utilisé

radiusd: FreeRADIUS Version 2.2.5, for host amd64-portbld-freebsd10.0, built on Jul 10 2014 at 09:04:56 Copyright (C) 1999-2013 The FreeRADIUS server project and contributors. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. You may redistribute copies of FreeRADIUS under the terms of the GNU General Public License. For more information about these matters, see the file named COPYRIGHT. Starting – reading configuration files … including configuration file /usr/local/etc/raddb/radiusd.conf including configuration file /usr/local/etc/raddb/proxy.conf including configuration file /usr/local/etc/raddb/clients.conf including files in directory /usr/local/etc/raddb/modules/ including configuration file /usr/local/etc/raddb/modules/wimax ….Failed binding to authentication address 192.168.3.1 port 1812: Address already in use /usr/local/etc/raddb/radiusd.conf[21]: Error binding to port for 192.168.3.1 port 1812

Exemple d’erreur de syntaxe  

radiusd: FreeRADIUS Version 2.2.5, for host amd64-portbld-freebsd10.0, built on Jul 10 2014 at 09:04:56 Copyright (C) 1999-2013 The FreeRADIUS server project and contributors. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. You may redistribute copies of FreeRADIUS under the terms of the GNU General Public License. For more information about these matters, see the file named COPYRIGHT. Starting – reading configuration files … including configuration file /usr/local/etc/raddb/radiusd.conf including configuration file /usr/local/etc/raddb/proxy.conf including configuration file /usr/local/etc/raddb/clients.conf including files in directory /usr/local/etc/raddb/modules/ including configuration file /usr/local/etc/raddb/modules/wimax …./usr/local/etc/raddb/sites-enabled/default[14]: Failed to find « erreur-syntaxe » in the « modules » section. /usr/local/etc/raddb/sites-enabled/default[1]: Errors parsing authorize section.

Freeradius vous précise alors dans ces cas là, dans quel fichier est l’erreur et à quelle ligne.  

Le serveur démarre mais ne reçoit aucune requête venant d’un client

Il s’agit dans ces cas là probablement d’un problème de firewall (ie les requêtes émises par le client n’arrivent pas jusqu’au serveur), mais aussi de clef partagé entre le client et le serveur, ou encore un problème de route sur la machine qui héberge le serveur qui lui fait répondre avec une autre @IP que celle sur laquelle il a reçu la requête émise. Une bonne pratique consiste alors à écouter le trafic réseau afin de vérifier ce qu’il advient de la requête. Exemple de ce qu’il se passe lorsque le serveur est éteint :

root@www1:~ # tcpdump -n -i vlan3 host 192.168.3.252 and not port ssh tcpdump: verbose output suppressed, use -v or -vv for full protocol decode listening on vlan3, link-type EN10MB (Ethernet), capture size 65535 bytes capability mode sandbox enabled23:43:47.606876 IP 192.168.3.252.58598 > 192.168.3.1.1812: RADIUS, Access Request (1), id: 0x1c length: 74 23:43:47.606900 IP 192.168.3.1 > 192.168.3.252: ICMP 192.168.3.1 udp port 1812 unreachable, length 36 23:43:52.647921 IP 192.168.3.252.58598 > 192.168.3.1.1812: RADIUS, Access Request (1), id: 0x1c length: 74 23:43:52.647936 IP 192.168.3.1 > 192.168.3.252: ICMP 192.168.3.1 udp port 1812 unreachable, length 36

  Exemple de ce qu’il se passe lorsque le client n’est pas défini comme pouvant discuter avec le serveur ou que le mot de passe est incorrect : (clients.conf)

root@www1:~ # tcpdump -n -i vlan3 port 1812 tcpdump: verbose output suppressed, use -v or -vv for full protocol decode listening on vlan3, link-type EN10MB (Ethernet), capture size 65535 bytes capability mode sandbox enabled23:41:29.676315 IP 192.168.3.252.21960 > 192.168.3.1.1812: RADIUS, Access Request (1), id: 0xbf length: 74 23:41:34.687257 IP 192.168.3.252.21960 > 192.168.3.1.1812: RADIUS, Access Request (1), id: 0xbf length: 74 23:41:39.702801 IP 192.168.3.252.21960 > 192.168.3.1.1812: RADIUS, Access Request (1), id: 0xbf length: 74

Il est alors intéressant de commencer à regarder les logs du serveur Radius (cas du mot de passe erroné)

root@www1:~ # radiusd -X….Ready to process requests. rad_recv: Access-Request packet from host 192.168.3.252 port 32288, id=166, length=74 Received packet from 192.168.3.252 with invalid Message-Authenticator!  (Shared secret is incorrect.) Dropping packet without response. Going to the next request Waking up in 0.9 seconds. Cleaning up request 0 ID 166 with timestamp +8 Ready to process requests. rad_recv: Access-Request packet from host 192.168.3.252 port 32288, id=166, length=74 Received packet from 192.168.3.252 with invalid Message-Authenticator!  (Shared secret is incorrect.) Dropping packet without response. Going to the next request Waking up in 0.9 seconds. Cleaning up request 1 ID 166 with timestamp +14

  Cas du client non défini

root@www1:~ # radiusd -X….Ready to process requests. Ignoring request to authentication address 192.168.3.1 port 1812 from unknown client 192.168.3.252 port 33664 Ready to process requests. Ignoring request to authentication address 192.168.3.1 port 1812 from unknown client 192.168.3.252 port 33664 Ready to process requests.

 

Le serveur voit bien passer les requêtes mais cela ne se passe pas comme vous le souhaitiez

  Nous sommes sorti de tous les cas d’erreurs classiques et sur cette partie là, il y a désormais trop de possibilités de se tromper pour les lister une par une. L’objectif est donc ici de montrer comment comprendre le fichier de log Freeradius  

# Le serveur écouteReady to process requests.# Freeradius a recu un paquet Radius de type Access-Request correctement formaté, les attributs Radius contenus dans ce paquet sont listé à la suite rad_recv: Access-Request packet from host 192.168.3.252 port 34748, id=198, length=74 User-Name = « test » User-Password = « test » NAS-IP-Address = 192.168.15.15 NAS-Port = 123 Message-Authenticator = 0xff30a001ec6cf36e682338e9faf883a5# Freeradius appelle le serveur virtuel default et execute la premiere section (authorize) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default +group authorize {# Le module preprocess renvoie un ok, car il a traité la requete (en l’occurence il n’a pas agi dessus) ++[preprocess] = ok# Les module chap,mschap, suffix renvoie un noop, ce qui signifie que freeradius a detecté que la requete ne pouvait pas être traité par ces modules là (en l’occurence la requete est en PAP et le User Name n’a pas de Realm, il n’est donc pas non plus éligible pour le module suffix) ++[chap] = noop ++[mschap] = noop [suffix] No ‘@’ in User-Name = « test », looking up realm NULL [suffix] No such realm « NULL » ++[suffix] = noop ++[files] = noop # Le module SQL liste les requêtes executés, mais ne trouve pas d’utilisateur test [sql]   expand: %{User-Name} -> test [sql] sql_set_user escaped user –> ‘test’ rlm_sql (sql): Reserving sql socket id: 4 [sql]   expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = ‘%{SQL-User-Name}’           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = ‘test’           ORDER BY id [sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = ‘%{SQL-User-Name}’           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = ‘test’           ORDER BY priority rlm_sql (sql): Released sql socket id: 4 [sql] User test not found ++[sql] = notfound ++[expiration] = noop ++[logintime] = noop # Le module pap qui est pourtant le module adéquat pour traiter la requête ne trouve aucune méthode pour accepter cette requête, celle ci échoue donc puisqu’aucun module n’a décrété que l’access-request pouvait être traité. Freeradius renvoie alors un access-reject [pap] WARNING! No « known good » password found for the user.  Authentication may fail because of this. ++[pap] = noop +} # group authorize = ok ERROR: No authenticate method (Auth-Type) found for the request: Rejecting the user Failed to authenticate the user. Login incorrect: [test/test] (from client linksys port 123) Using Post-Auth-Type REJECT # Executing group from file /usr/local/etc/raddb/sites-enabled/default +group REJECT { [attr_filter.access_reject]     expand: %{User-Name} -> test attr_filter: Matched entry DEFAULT at line 11 # Le module att_filter.access_reject enrichit la réponse (updated) ++[attr_filter.access_reject] = updated +} # group REJECT = updated Delaying reject of request 0 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 0 # Finalement l’access reject est renvoyé au client Sending Access-Reject of id 198 to 192.168.3.252 port 34748 Waking up in 4.9 seconds. Cleaning up request 0 ID 198 with timestamp +3 Ready to process requests.

 

Laisser un commentaire

Votre adresse de messagerie ne sera pas publiée. Les champs obligatoires sont indiqués avec *