freeradius: handler logging via radiusd module

freeradius/auth.py

@@ -20,23 +20,39 @@ from gestion.gen_confs.trigger import trigger_generate_cochon as trigger_generat
 import annuaires_pg
 from gestion import secrets_new as secrets
 
+#: Serveur radius de test (pas la prod)
 TEST_SERVER = bool(os.getenv('DBG_FREERADIUS', False))
+
+#: Le taggage dynamique de vlan (dans la réponse) est désactivé sur WiFi
 WIFI_DYN_VLAN = TEST_SERVER
 
+#: Suffixe à retirer du username si présent (en wifi)
 USERNAME_SUFFIX_WIFI = '.wifi.crans.org'
+
+#: Suffixe à retirer du username si présent (filaire)
 USERNAME_SUFFIX_FIL = '.crans.org'
 
 ## -*- Logging -*-
-# Initialisation d'un logger pour faire des stats etc
-# pour l'instant, on centralise tout sur thot en mode debug
+
+class RadiusdHandler(logging.Handler):
+    """Handler de logs pour freeradius"""
+
+    def emit(self, record):
+        """Process un message de log, en convertissant les niveaux"""
+        if record.levelno >= logging.WARN:
+            rad_sig = radiusd.L_ERR
+        elif record.levelno >= logging.INFO:
+            rad_sig = radiusd.L_INFO
+        else:
+            rad_sig = radiusd.L_DBG
+        radiusd.radlog(rad_sig, record.msg)
+
+# Initialisation d'un logger (pour logguer unifié)
 logger = logging.getLogger('auth.py')
 logger.setLevel(logging.DEBUG)
 formatter = logging.Formatter('%(name)s: [%(levelname)s] %(message)s')
-handler = logging.handlers.SysLogHandler(address = '/dev/log')
-try:
-    handler.addFormatter(formatter)
-except AttributeError:
-    handler.formatter = formatter
+handler = RadiusdHandler()
+handler.setFormatter(formatter)
 logger.addHandler(handler)
 
 ## -*- Types de blacklists -*-
@@ -46,9 +62,6 @@ BL_REJECT = [u'bloq']
 #: place sur le vlan isolement
 BL_ISOLEMENT = [u'virus', u'autodisc_virus', u'autodisc_p2p', u'ipv6_ra']
 
-# TODO carte_etudiant: dépend si sursis ou non (regarder lc_ldap)
-# TODO LOGSSSSS
-
 #: place sur accueil
 BL_ACCUEIL = []
 
@@ -111,7 +124,7 @@ def get_machines(data, conn, is_wifi=True, proprio=None):
         try:
             mac = lc_ldap.crans_utils.format_mac(mac.decode('ascii', 'ignore'))
         except:
-            radiusd.radlog(radiusd.L_ERR, 'Cannot format MAC !')
+            logger.error('Cannot format MAC !')
             mac = None
     username = data.get('User-Name', None)
     if username:
@@ -121,10 +134,8 @@ def get_machines(data, conn, is_wifi=True, proprio=None):
 
     if mac is None:
         logger.error('Cannot read mac from AP')
-        radiusd.radlog(radiusd.L_ERR, 'Cannot read client MAC from AP !')
     if username is None:
-        logger.error('Cannot read username')
-        radiusd.radlog(radiusd.L_ERR, 'Cannot read client User-Name !')
+        logger.error('Cannot read client User-Name !')
 
     # Liste de recherches ldap à essayer, dans l'ordre
     # ** Case 1: Search by mac
@@ -218,13 +229,13 @@ def register_machine(data, machine, conn):
 
     mac = data.get('Calling-Station-Id', None)
     if mac is None:
-        radiusd.radlog(radiusd.L_ERR, 'Cannot find MAC')
+        logger.warn('Cannot find MAC for registration (aborting)')
         return
     mac = mac.decode('ascii', 'ignore').replace('"','')
     try:
         mac = lc_ldap.crans_utils.format_mac(mac).lower()
     except:
-        radiusd.radlog(radiusd.L_ERR, 'Cannot format MAC !')
+        logger.warn('Cannot format MAC for registration (aborting)')
         return
 
     with machine:
@@ -263,19 +274,17 @@ def authorize_wifi(data):
     items = get_machines(data)
 
     if not items:
-        logger.error('Nobody found')
-        radiusd.radlog(radiusd.L_ERR, 'lc_ldap: Nobody found')
+        logger.error('No machine found in lc_ldap')
         return radiusd.RLM_MODULE_NOTFOUND
 
     if len(items) > 1:
-        logger.error('Too many results')
-        radiusd.radlog(radiusd.L_ERR, 'lc_ldap: Too many results (took first)')
+        logger.warn('lc_ldap: Too many results (taking first)')
 
     machine = items[0]
 
     proprio = machine.proprio()
     if isinstance(proprio, lc_ldap.objets.AssociationCrans):
-        radiusd.radlog(radiusd.L_ERR, 'Crans machine trying to authenticate !')
+        logger.error('Crans machine trying to authenticate !')
         return radiusd.RLM_MODULE_INVALID
 
     for bl in machine.blacklist_actif():
@@ -287,8 +296,7 @@ def authorize_wifi(data):
             
 
     if not machine.get('ipsec', False):
-        radiusd.radlog(radiusd.L_ERR, 'WiFi authentication but machine has no' +
-            'password')
+        logger.error('WiFi auth but machine has no password')
         return radiusd.RLM_MODULE_REJECT
 
     password = machine['ipsec'][0].value.encode('ascii', 'ignore')
@@ -325,8 +333,7 @@ def radius_password(secret_name, machine=None):
 @use_ldap
 def authorize_nas(data, ldap):
     """Remplis le mdp d'une borne, ou d'un switch"""
-    logger.debug('nas_auth with %r' % data)
-    radiusd.radlog(radiusd.L_ERR, 'nas_auth with %r' % data)
+    logger.info('nas_auth with %r' % data)
 
     ip = data.get('NAS-Identifier', '')
     is_v6 = ':' in ip
@@ -389,7 +396,6 @@ def post_auth_wifi(data):
     log_message = '(wifi) %s -> %s [%s%s]' % \
       (port, mac, vlan_name, (reason and u': ' + reason).encode('utf-8'))
     logger.info(log_message)
-    radiusd.radlog(radiusd.L_AUTH, log_message)
 
     # Si NAS ayant des mapping particuliers, à signaler ici
     vlan_id = config.vlans[vlan_name]
@@ -419,7 +425,6 @@ def post_auth_fil(data):
     log_message = '(fil) %s -> %s [%s%s]' % \
       (port, mac, vlan_name, (reason and u': ' + reason).encode('utf-8'))
     logger.info(log_message)
-    radiusd.radlog(radiusd.L_AUTH, log_message)
 
     # Si NAS ayant des mapping particuliers, à signaler ici
     vlan_id = config.vlans[vlan_name]