From 8d2abd1c62be8534c9625d209c2e12c2b95a05f8 Mon Sep 17 00:00:00 2001
From: Kim Huebel <dg9vh@darc.de>
Date: Sat, 10 Apr 2021 11:11:16 +0100
Subject: [PATCH] Implementing different LogLevels (FileLog) Also added short
 description in Readme.MD

---
 README.md        | 10 ++++++
 YSFReflector     | 84 ++++++++++++++++++++++++++++--------------------
 YSFReflector.ini |  2 +-
 3 files changed, 61 insertions(+), 35 deletions(-)

diff --git a/README.md b/README.md
index f91b7c6..322d298 100644
--- a/README.md
+++ b/README.md
@@ -60,3 +60,13 @@ This results in having only one logfile for each program and having it rotated b
 If you are using the php-based Dashbord by DG9VH (https://github.com/dg9vh/YSFReflector-Dashboard) please leave it at `FileRotate=1`, if you are using the websockets based version (recommended at https://github.com/dg9vh/WSYSFDash) you can use `FileRotate=0`. Take care to configure the dashboard's logtailer.ini in sync to this.
 
 To configure log rotation in Linux take a look at https://www.tecmint.com/install-logrotate-to-manage-log-rotation-in-linux/.
+
+### Setting FileLevel in Logging
+actually the FileLevel-Logging is done in 3 variant loglevels: 0 to 2. Here is a short description what is logged in the different levels:
+
+* Level 2: Only messages on startup and error-messages are logged
+* Level 1: All from level 2 plus normal messages created when running the reflector. This level is recommended if you are running a dashboard with the reflector.
+* Level 0: All from level 1 and 2 plus some additional information about remote-commands not needed in regular situations. This level shows the full log.
+
+
+
diff --git a/YSFReflector b/YSFReflector
index 6a9aa9d..9791755 100755
--- a/YSFReflector
+++ b/YSFReflector
@@ -129,19 +129,19 @@ def ElencoNodi(cl):
     time.sleep(120)
     cl_lo = []
     if (len(cl) == 0):
-      printlog('No repeaters/gateways linked')
+      printlog(1, 'No repeaters/gateways linked')
     else:
-      printlog('Currently linked repeaters/gateways:')
+      printlog(1, 'Currently linked repeaters/gateways:')
       for c in cl:
-        printlog('     ' + c[2].ljust(10) + ': ' + str(c[0]) + ':' + str(c[1]) + ' ' + str(c[3]) + '/60 : ' + datetime.utcfromtimestamp(c[6]).strftime("%Y-%m-%d %H:%M:%S"))
+        printlog(1, '     ' + c[2].ljust(10) + ': ' + str(c[0]) + ':' + str(c[1]) + ' ' + str(c[3]) + '/60 : ' + datetime.utcfromtimestamp(c[6]).strftime("%Y-%m-%d %H:%M:%S"))
         if (c[5] == 1):
           cl_lo.append(c)
       if (len(cl_lo) == 0):
-        printlog('No repeaters/gateways muted')
+        printlog(1, 'No repeaters/gateways muted')
       else:
-        printlog('Currently muted repeaters/gateways:')
+        printlog(1, 'Currently muted repeaters/gateways:')
         for c in cl_lo:
-          printlog('     ' + c[2].ljust(10) + ': ' + str(c[0]) + ':' + str(c[1]) + ' ' + str(c[3]) + '/60')     
+          printlog(1, '     ' + c[2].ljust(10) + ': ' + str(c[0]) + ':' + str(c[1]) + ' ' + str(c[3]) + '/60')     
 
 
 def TimeoutNodi(cl):
@@ -150,7 +150,7 @@ def TimeoutNodi(cl):
     for c in cl:
       c[3] += 1
       if (c[3] > 60):
-        printlog('Removing ' + c[2].ljust(10) + ' (' + c[0] + ':' + str(c[1]) + ') disappeared')
+        printlog(1, 'Removing ' + c[2].ljust(10) + ' (' + c[0] + ':' + str(c[1]) + ') disappeared')
         cl.remove(c)
 
 
@@ -160,7 +160,7 @@ def TimeoutTX(t, t_lock, r_lock, lista_lh, lista_lhd):
       t[1] += 0.1
     if ((t[1] > 1.0) and (t[0] != 0)):
       t[0] = 0  
-      printlog('Network watchdog has expired')
+      printlog(1, 'Network watchdog has expired')
       inserisci_lista(lista_lh, [check_string(t[2]), check_string(t[3]), check_string(t[4]), t[5], datetime.utcfromtimestamp(t[6]).strftime("%d-%m-%Y %H-%M-%S"), round(time.time() - t[6]) ], 20)
       inserisci_listaD(lista_lhd, [check_string(t[2]), check_string(t[3]), check_string(t[4]), t[5], datetime.utcfromtimestamp(t[6]).strftime("%d-%m-%Y %H-%M-%S"), round(time.time() - t[6]) ], 20)
       t[1] = 0
@@ -179,7 +179,7 @@ def TimeoutTX(t, t_lock, r_lock, lista_lh, lista_lhd):
         
     for x in pop_list:
         t_lock.pop(x)   
-        printlog('Removed from blockeds queue ' + str(x))
+        printlog(1, 'Removed from blockeds queue ' + str(x))
     time.sleep(0.1)  
 
 
@@ -266,7 +266,7 @@ def blacklist(f_bl, t_reload, cli):
         GW_TMP = []
         IP_TMP = []
         WL_TMP = []
-        printlog('Reload the Blacklist from File')
+        printlog(1, 'Reload the Blacklist from File')
         for row in file:
           content = row.strip()
           
@@ -303,19 +303,19 @@ def blacklist(f_bl, t_reload, cli):
                 ipl = ip2long(ipa)
               except:
                 ipl = 0
-                printlog('Invalid hostname ' + c_split[1])
+                printlog(2, 'Invalid hostname ' + c_split[1])
               if (ipl > 0):  
                 if (not inlist(IP_TMP, ipl)):
                   bisect.insort(IP_TMP, ipl)
                           
         file.close() 
       except Exception as ex:
-        printlog('Failed to load Blacklist from File ' + str(ex) )
+        printlog(2, 'Failed to load Blacklist from File ' + str(ex) )
       BLACK_LIST = BL_TMP.copy()
       WHITE_LIST = WL_TMP.copy()
       GW_BL = GW_TMP.copy()
       IP_BL = IP_TMP.copy()
-      printlog('Loaded ' + str(len(BLACK_LIST)) + '/CS ' + str(len(WHITE_LIST)) + '/AL ' + str(len(GW_BL)) + '/GW ' + str(len(IP_BL)) + '/IP')
+      printlog(1, 'Loaded ' + str(len(BLACK_LIST)) + '/CS ' + str(len(WHITE_LIST)) + '/AL ' + str(len(GW_BL)) + '/GW ' + str(len(IP_BL)) + '/IP')
       f_time_old = f_time
       update_clients(cli)
     else:
@@ -341,6 +341,16 @@ def ReadConfig(f,p):
     file_rotate = config['Log']['FileRotate']
   except:
     file_rotate = "1" # to keep file-rotation by default with timestamp
+  
+  try:
+    display_level = int(config['Log']['DisplayLevel'])
+  except:
+    display_level = 1
+    
+  try:
+    file_level = int(config['Log']['FileLevel'])
+  except:
+    file_level = 1
 
   try:
     en_ext_cmd = int(config['Log']['EnableExtendedCommands'])
@@ -385,6 +395,8 @@ def ReadConfig(f,p):
   p.append(file_rotate)        # 8
   p.append(CheckRE)            # 9
   p.append(en_ext_cmd)         #10
+  p.append(display_level)      #11
+  p.append(file_level)         #12
 
 
     
@@ -450,11 +462,11 @@ def RunServer(config):
     recvPackets = queue.Queue()
 
     print('Starting pYSFReflector-' + version)
-    printlog('Starting pYSFReflector-' + version)
+    printlog(2, 'Starting pYSFReflector-' + version)
     if (en_ext_cmd == 1):
-      printlog('Extended Commands Enabled')
+      printlog(2, 'Extended Commands Enabled')
     else:
-      printlog('Extended Commands Disabled')  
+      printlog(2, 'Extended Commands Disabled')  
     threading.Thread(target=RecvData,args=(s,recvPackets)).start()
     threading.Thread(target=ElencoNodi,args=(clients,)).start()
     threading.Thread(target=TimeoutNodi,args=(clients,)).start()
@@ -485,13 +497,13 @@ def RunServer(config):
                 c=[addr[0], addr[1], (data[4:14]).decode().strip(), 0, id, lonly, time.time()]
                 id += 1
                 clients.append(c)
-                printlog('Adding ' + c[2].ljust(10) + ' (' + c[0] + ':' + str(c[1]) + ')')
+                printlog(1, 'Adding ' + c[2].ljust(10) + ' (' + c[0] + ':' + str(c[1]) + ')')
               s.sendto(b'YSFPREFLECTOR ',addr)
            
             if (cmd == b'YSFU'):
                for c in clients:
                 if ((c[0] == addr[0]) and (c[1] == addr[1])):
-                  printlog('Removing ' + c[2].ljust(10) + ' (' + c[0] + ':' + str(c[1]) + ') unlinked')
+                  printlog(1, 'Removing ' + c[2].ljust(10) + ' (' + c[0] + ':' + str(c[1]) + ') unlinked')
                   clients.remove(c)
                   break
               
@@ -522,14 +534,14 @@ def RunServer(config):
                   # time start
                   tx[6] = time.time()
                   id_str += 1   
-                  printlog('Received data from ' + tx[3].ljust(10) +   ' to ' +  tx[4].ljust(10) + ' at ' +  tx[2].ljust(10))
+                  printlog(1, 'Received data from ' + tx[3].ljust(10) +   ' to ' +  tx[4].ljust(10) + ' at ' +  tx[2].ljust(10))
                   
               else:
                 if (id_corr not in rx_lock):
                   rx_lock.append(id_corr)  
                   inserisci_lista(BL, [check_string(data[4:14].decode().strip()) + '/' + block_r, check_string(data[14:24].decode().strip()), check_string(data[24:34].decode().strip()), -1, datetime.utcfromtimestamp(time.time()).strftime("%d-%m-%Y %H-%M-%S"), -1 ], 20)
                   inserisci_listaD(BLD, [check_string(data[4:14].decode().strip()) + '/' + block_r, check_string(data[14:24].decode().strip()), check_string(data[24:34].decode().strip()), -1, datetime.utcfromtimestamp(time.time()).strftime("%d-%m-%Y %H-%M-%S"), -1 ], 20)
-                  printlog('Data from ' + data[14:24].decode().strip().ljust(10) + ' at ' + data[4:14].decode().strip().ljust(10) + ' blocked/' + block_r)
+                  printlog(1, 'Data from ' + data[14:24].decode().strip().ljust(10) + ' at ' + data[4:14].decode().strip().ljust(10) + ' blocked/' + block_r)
                 rx_lock_tout[id_corr] = 0  
               
               if ((id_corr == tx[0]) and (id_corr != 0)):    
@@ -541,7 +553,7 @@ def RunServer(config):
             
               if ((data[34] & 0x01) == 0x01):
                 if (tx[0] != 0):
-                  printlog('Received end of transmission')
+                  printlog(1, 'Received end of transmission')
                   inserisci_lista(LH, [check_string(tx[2]), check_string(tx[3]), check_string(tx[4]), tx[5], datetime.utcfromtimestamp(tx[6]).strftime("%d-%m-%Y %H-%M-%S"), round(time.time() - tx[6]) ], 20)
                   inserisci_listaD(LHD, [check_string(tx[2]), check_string(tx[3]), check_string(tx[4]), tx[5], datetime.utcfromtimestamp(tx[6]).strftime("%d-%m-%Y %H-%M-%S"), round(time.time() - tx[6]) ], 20)
                 tx[0] = 0
@@ -552,7 +564,7 @@ def RunServer(config):
                 tx[6] = 0
                   
             if (cmd == b'YSFS'):
-              printlog('YSF server status enquiry from ' + addr[0] + ':' + str(addr[1]))
+              printlog(0, 'YSF server status enquiry from ' + addr[0] + ':' + str(addr[1]))
               if (len(clients) > 999):
                 num_cli = 999
               else:
@@ -562,12 +574,12 @@ def RunServer(config):
 
                   
             if (cmd == b'YSFV'):
-              printlog('Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
+              printlog(0, 'Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
               info = 'YSFV' + 'pYSFReflector' + ' ' + version
               s.sendto(str.encode(info),addr)  
  
             if (cmd == b'YSFI'):
-              printlog('Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
+              printlog(0, 'Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
              # info = 'YSFV' + 'pYSFReflector' + ' ' + version
              # s.sendto(str.encode(info),addr)  
                          
@@ -576,42 +588,42 @@ def RunServer(config):
             ## Extended Commands ##
             if (en_ext_cmd == 1):
               if (cmd == b'QSRU'):
-                printlog('Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
+                printlog(0, 'Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
                 info = 'ASRU;' + str(round(time.time()-time_start)) + ';'
                 s.sendto(str.encode(info),addr) 
                     
               if (cmd == b'QSRI'):
-                printlog('Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
+                printlog(0, 'Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
                 info = 'ASRI;' + str(refl_id) + ':' + refl_name + ':' + refl_desc + ':' + 'pYSFReflector' + ':' + version + ':' + str(CheckRE) + ';'
                 s.sendto(str.encode(info),addr) 
             
               if (cmd == b'QGWL'):
-                printlog('Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
+                printlog(0, 'Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
                 info = 'AGWL;' + lista_gw(clients) 
                 s.sendto(str.encode(info),addr) 
                
               if (cmd == b'QLHL'):
-                printlog('Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
+                printlog(0, 'Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
                 info = 'ALHL;' + lista_invio(LH) 
                 s.sendto(str.encode(info),addr)    
 
               if (cmd == b'QREJ'):
-                printlog('Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
+                printlog(0, 'Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
                 info = 'AREJ;' + lista_invio(BL) 
                 s.sendto(str.encode(info),addr)        
                
               if (cmd == b'QLHD'):
-                printlog('Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
+                printlog(0, 'Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
                 info = 'ALHD;' + lista_invio(LHD) 
                 s.sendto(str.encode(info),addr)    
 
               if (cmd == b'QRED'):
-                printlog('Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
+                printlog(0, 'Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
                 info = 'ARED;' + lista_invio(BLD) 
                 s.sendto(str.encode(info),addr)        
 
               if (cmd == b'QACL'):
-                printlog('Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
+                printlog(0, 'Received command ' + cmd.decode() + ' from: ' + addr[0] + ':' + str(addr[1]))
                 s_info = ''
                 info = 'AACL;CS/' + str(len(BLACK_LIST)) + '|' + 'AL/' + str(len(WHITE_LIST)) + '|' +  'GW/' + str(len(GW_BL)) + '|' +  'IP/' + str(len(IP_BL)) + ';'
                 i = 0
@@ -655,10 +667,11 @@ def RunServer(config):
     s.close()
 
       
-def printlog(mess):
+def printlog(log_level, mess):
   global filelog
   global log_basename
   global file_rotate
+  global file_level
   if file_rotate == "1":
     log_file = log_basename + '-' + str(datetime.utcnow().strftime('%Y-%m-%d')) + '.log'
   else:
@@ -670,7 +683,8 @@ def printlog(mess):
       filelog = open(log_file,'x')
   except:
     pass     
-  str_log = check_string('M: ' + str(datetime.utcnow().strftime('%Y-%m-%d %H:%M:%S.%f'))[:-3] + ' ' + mess) 
+  if file_level <= log_level:
+    str_log = check_string('M: ' + str(datetime.utcnow().strftime('%Y-%m-%d %H:%M:%S.%f'))[:-3] + ' ' + mess) 
   try:
     filelog.write(str_log + '\n') 
     filelog.flush()
@@ -701,6 +715,8 @@ except:
   
 log_basename = config[3] + '/' + config[4]
 file_rotate = config[8]
+display_level = config[11]
+file_level = config[12]
 ### log
 if file_rotate == "1":
   log_file = log_basename + '-' + str(datetime.utcnow().strftime('%Y-%m-%d')) + '.log'
diff --git a/YSFReflector.ini b/YSFReflector.ini
index 31dbcf3..f39eef6 100644
--- a/YSFReflector.ini
+++ b/YSFReflector.ini
@@ -13,7 +13,7 @@ Description=<reflector description>
 # Logging levels, 0=No logging
 # not managed
 DisplayLevel=1
-# not managed
+#Set this to 0 to have full logging capabilities, 1 for normal log and 2 for very silent log
 FileLevel=1
 FilePath=/var/log
 FileRoot=YSFReflector