Fixed log lines to use %s and consume all arguments

b00a0d8e · Jan David Mol · 1949e063 · b00a0d8e · b00a0d8e · b00a0d8e
Commit b00a0d8e authored 4 years ago by Jan David Mol
--- a/I2Cbitbang.py
+++ b/I2Cbitbang.py
@@ -11,7 +11,7 @@ class I2Cbitbang(I2Cdevices):
          Addr=Dev['dev_address'];
 #          data2=[Addr<<1,regnr]+data;
          data2=[Addr<<1]+int2bytes(regnr)+value
-#          logging.info(data2)
+#          logging.info("%s",data2)
          I2Ccallback('SDO',0) 
          I2Ccallback('SCL',1) 
          if not(I2CbbTX(data2,I2Ccallback)): return False;
@@ -19,7 +19,7 @@ class I2Cbitbang(I2Cdevices):
          data3=[0]
          if not(I2CbbRX(data2,data3,I2Ccallback)): return False;
          if data3[0]!=0x80:
-              logging.info("Expected Ack 0x80, received:",data3); 
+              logging.error("Expected Ack 0x80, received: %s",data3); 
              return False;
          logging.info("Si4012 TX success!")
          return True;
@@ -37,7 +37,7 @@ class I2Cbitbang(I2Cdevices):
 #              data2=[regnr%256]+data2;
 #              regnr=int(regnr/256);
 #          data2=[Addr<<1,regnr]+data2;
-#          logging.info(data2,Addr,Reg['reg_addr']);
+#          logging.info("%s %s %s",data2,Addr,Reg['reg_addr']);
          if not(I2CbbTX(data2,I2Ccallback)): return False;
 #          return False;
          data2=[(Addr<<1)+1];
@@ -50,14 +50,14 @@ class I2Cbitbang(I2Cdevices):
          else: value[:]=data3[:];
          if (width!=l1*8) or (bitoffset>0): 
            value[0]=UnMask(value[0],width,bitoffset)      
-          #logging.info("Received:",data3); 
+          #logging.info("Received: %s",data3); 
          return True;
 def I2CbbTX(data2,SetBit):
          SetBit('SDIOdir',1) #Input, should be high
          if SetBit('SDI',0,True)==0: 
-                      logging.info("I2C line low!")
+                      logging.error("I2C line low!")
                      return False;
          #Start
          SetBit('SDIOdir',0) #Output = low
@@ -73,7 +73,7 @@ def I2CbbTX(data2,SetBit):
             SetBit('SDIOdir',1) #Input
             #logging.info(GetBit(SDI))
             if SetBit('SDI',0,True)==1: 
-                      logging.info("I2C: Not ACK")
+                      logging.error("I2C: Not ACK")
                      return False;
             SetBit('SCL',1)
             #logging.info(GetBit(SDI))
@@ -89,7 +89,7 @@ def I2CbbTX(data2,SetBit):
 def I2CbbRX(data1,data2,SetBit):
          SetBit('SDIOdir',1) #Input, should be high
          if SetBit('SDI',0,True)==0: 
-                      logging.info("I2C ack: line low!")
+                      logging.error("I2C ack: line low!")
                      return False;
          #Start
          SetBit('SDIOdir',0) #Output = low
@@ -106,7 +106,7 @@ def I2CbbRX(data1,data2,SetBit):
             SetBit('SDIOdir',1) #Input
             #logging.info(GetBit(SDI))
             if SetBit('SDI',0,True)==1: 
-                      logging.info("I2C: Not ACK")
+                      logging.error("I2C: Not ACK")
                      return False;
             SetBit('SCL',1)
             #logging.info(GetBit(SDI))

--- a/I2Cdevices.py
+++ b/I2Cdevices.py
@@ -45,10 +45,10 @@ class I2Cdevices(hwdev):
        return True  
      def CallMethod(self,name,params,I2Ccallback):
-#        logging.info("RCU1 call method",name)
+#        logging.info("RCU1 call method %s",name)
        for Mth in self.D['Methods']:
          if Mth['method_name']==name:
-             logging.info("RCU1 Run method",name)
+             logging.info("RCU1 Run method %s",name)
             for regs in Mth['registers']:
                for key,value in regs.items():
                  self.SetVarValue(key,value,I2Ccallback)
@@ -78,11 +78,11 @@ class I2Cdevices(hwdev):
           a=[0]
           self.I2CGet(Pin[0],Pin[1],a,I2Ccallback,1,Pin[2])
           return a[0];
-         logging.info("Set Child",child)
+         logging.info("Set Child %s",child)
         return child.GetVarValue(name,value,SetGetPin)
      def SetVarValue(self,name,value,I2Ccallback):
-            logging.info("RCU1 Set ",name,value)
+            logging.info("RCU1 Set %s=%s",name,value)
            D=self.D
            Var1=Find(D['Variables'],'var_name',name)
@@ -114,18 +114,18 @@ class I2Cdevices(hwdev):
                         if childname==c['child_name']: 
                             return self.SetChildValue(c,c['obj'],name[len(childname)+1:],value,I2Ccallback)
 #                   return hwdev.SetVarValue(self,name,value,I2Ccallback)
-                   logging.info("Unknown variable",name);
+                   logging.error("Unknown variable %s",name);
                   return False;
-            logging.info(Dev)
+            logging.info("%s",Dev)
            if scale: value=int2bytes(int(value[0]/float(scale)))
            if Find(D['I2C_devices'],'dev_name',Dev[0]):
              if not(width): width=8
              if not(bitoffset): bitoffset=0
-              logging.info('SetVar ',name,'I2C',Dev,value,'(width=',width,'bitoffset=',bitoffset,')')
+              logging.info('SetVar %s I2C %s to %s (width=%s bitoffset=%s)',name,Dev,value,width,bitoffset)
              return self.I2CSet(Dev[0],Dev[1],value,I2Ccallback,width,bitoffset)
            if Find(D['SPI_devices'],'dev_name',Dev[0]):
-              logging.info('SetVar ',name,'SPI',Dev,value)
+              logging.info('SetVar %s SPI %S to %s',name,Dev,value)
              return SPIset(D,Dev[0],Dev[1],value,I2Ccallback,dev_number)
            hwdev.SetVarValue(self,name,value,I2Ccallback)
 #        return SetVar(self.D,name,value,I2Ccallback)
@@ -133,7 +133,7 @@ class I2Cdevices(hwdev):
      def GetVarValue(self,name,value,I2Ccallback):
 #def GetVar(D,name,value,I2Ccallback,dev_number=0):
            dev_number=0;D=self.D
-            logging.info("RCU1 Get ",name,value)
+            logging.info("RCU1 Get %s=%s",name,value)
            Var1=Find(D['Variables'],'var_name',name)
            if (Var1): 
              Dev=GetField(Var1,'var_dev',dev_number)
@@ -152,27 +152,27 @@ class I2Cdevices(hwdev):
                         if childname==c['child_name']: 
                             return self.GetChildValue(c,c['obj'],name[len(childname)+1:],value,I2Ccallback)
 #                   return hwdev.SetVarValue(self,name,value,I2Ccallback)
-                   logging.info("Unknown variable",name);
+                   logging.error("Unknown variable %s",name);
                   return False
-            logging.info(Dev)
+            logging.info("%s",Dev)
            if not(width): width=8
            if not(bitoffset): bitoffset=0
            if Find(D['I2C_devices'],'dev_name',Dev[0]):
-              logging.info('GetVar ',name,'I2C',Dev,value,'(width=',width,'bitoffset=',bitoffset,')')
+              logging.info('GetVar %s I2C %s value %s (width=%s bitoffset=%s)',name,Dev,value,width,bitoffset)
              result=self.I2CGet(Dev[0],Dev[1],value,I2Ccallback,width,bitoffset)
              if not(result): return False;
              if scale: value[0]=float(value[0])*float(scale);
              return True
            if Find(D['SPI_devices'],'dev_name',Dev[0]):
-              logging.info('GetVar ',name,'SPI',Dev,value)
+              logging.info('GetVar %s SPI %s value %s',name,Dev,value)
              return SPIget(D,Dev[0],Dev[1],value,I2Ccallback,dev_number)
            if Find(D['I2C_bitbang'],'dev_name',Dev[0]):
-              logging.info('GetVar ',name,'I2C bb',Dev,value)
+              logging.info('GetVar %s I2C bb %s value %s',name,Dev,value)
              if not(I2Cbbget(D,Dev[0],Dev[1],value,I2Ccallback,dev_number,width,bitoffset)): return False
              if scale: value[0]=float(value[0])*float(scale);
              return True;
-            logging.info("Unknown variable",name)
+            logging.error("Unknown variable %s",name)
            return False;
 #        return GetVar(self.D,name,value,I2Ccallback)
@@ -192,11 +192,11 @@ class I2Cdevices(hwdev):
      def I2CSet(self,dev,reg,value,I2Ccallback,width=8,bitoffset=0):
      #remember of values, add new ones with mask
-      #  logging.info('I2CSet:',dev,'=',value,'(mask=',mask,')')
+      #  logging.info('I2CSet: %s=%s (mask=%s)',dev,value,mask)
        Dev=Find(self.D['I2C_devices'],'dev_name',dev)    
        Addr=Dev['dev_address']
        Reg=Find(Dev['dev_registers'],'reg_name',reg)    
-      #  logging.info(dev,reg,value)
+      #  logging.info("%s %s %s",dev,reg,value)
        if (width<8) or (bitoffset>0):
          previous=Reg.get('previous')
          if not(previous):
@@ -204,8 +204,8 @@ class I2Cdevices(hwdev):
          if not(previous):
              previous=0;
          value[0]=ApplyMask(value[0],width,bitoffset,previous);
-      #    logging.info('masked to',value)
+      #    logging.info('masked to %s',value)
-      #  logging.info("Set",dev,reg,"to",value)    
+      #  logging.info("Set %s %s to %s",dev,reg,value)    
        result=I2Ccallback(Addr,value,reg=Reg['reg_addr'],)
        #if result:        
        Reg['previous']=value[0]
@@ -216,7 +216,7 @@ class I2Cdevices(hwdev):
        Addr=Dev['dev_address']
        Reg=Find(Dev['dev_registers'],'reg_name',reg)  
        l1=int(np.floor((width+bitoffset+7)/8))
-#        logging.info(width,bitoffset,l1)
+#        logging.info("%s %s %s",width,bitoffset,l1)
        makesinglevalue=((len(value)==1) and (l1>1));
        if makesinglevalue: value2=[0 for x in range(l1)]
        else: value2=value
@@ -241,7 +241,7 @@ class I2Cdevices(hwdev):
 #        Addr=Dev['dev_address']
 #        Reg=Find(Dev['dev_registers'],'reg_name',reg)  
 #        value[0]=Reg.get('previous')
-#        logging.info("Get Value=",value[0])
+#        logging.info("Get Value=%s",value[0])
 #        if (width<8) or (bitoffset>0): 
 #            value[0]=UnMask(value[0],width,bitoffset)      
 #        return True;

--- a/I2Cswitch.py
+++ b/I2Cswitch.py
@@ -3,13 +3,13 @@ import numpy as np
 import logging
 def I2C_dummy(addr,data,reg=None,read=0):
-#            logging.info("I2C dummy",addr,data)
+#            logging.info("I2C dummy addr=%s data=%s",addr,data)
            return True;
 class I2Cswitch(hwdev):
    def SetChannel(self,channel,I2Ccallback):
        if not(hasattr(self,'CurrentChannel')): self.CurrentChannel=0
-        logging.info("SetChannel",channel,self.CurrentChannel)
+        logging.info("SetChannel %s %s",channel,self.CurrentChannel)
        if (channel)==self.CurrentChannel: return True;
        self.CurrentChannel=channel
        return I2Ccallback(self.D['dev_address'],[channel])
@@ -26,7 +26,7 @@ class I2Cswitch(hwdev):
    def GetVarValue(self,name,value,I2Ccallback):
        def I2Ccallback2(addr,data,reg=None,read=0):
-#            logging.info("Getvarcallback",x)
+#            logging.info("Getvarcallback %s",x)
            if (read==2):
                if (cnt>0): return True;
                if not(self.SetChannel(gchannel,I2Ccallback)): return False;
@@ -52,7 +52,7 @@ class I2Cswitch(hwdev):
              for cnt,childname2 in enumerate(group['group_members']):
                    child=Find(self.D['dev_children'],'child_name',childname2)
                    if not(child): return False;
-                    logging.info("Get:",childname2)
+                    logging.info("Get: %s",childname2)
                    cchannel=1<<child['child_addr']
                    value2=value[cnt*stride:(cnt+1)*stride]
                    if not(child['obj'].GetVarValue(name[len(childname)+1:],value2,I2Ccallback2)): return False; 
@@ -79,7 +79,7 @@ class I2Cswitch(hwdev):
                channel=0;
                for childname2 in group['group_members']:
                    channel+=1<<(Find(self.D['dev_children'],'child_name',childname2)['child_addr'])
-                logging.info(channel)
+                logging.info("%s",channel)
                if not(self.SetChannel(channel,I2Ccallback)): return False; 
                for x,childname2 in enumerate(group['group_members']):
                    child=Find(self.D['dev_children'],'child_name',childname2)
@@ -91,7 +91,7 @@ class I2Cswitch(hwdev):
                for x,childname2 in enumerate(group['group_members']):
                    child=Find(self.D['dev_children'],'child_name',childname2)
                    if not(child): return False;
-                    logging.info("Set:",childname2)
+                    logging.info("Set: %s",childname2)
                    if not(self.SetChannel(1<<child['child_addr'],I2Ccallback)): return False; 
                    if not(child['obj'].SetVarValue(name[len(childname)+1:],value[x*stride:(x+1)*stride],I2Ccallback)): return false; 
                return True;

--- a/SPIbitbang1.py
+++ b/SPIbitbang1.py
@@ -14,7 +14,7 @@ class SPIbitbang1(I2Cdevices):
          data2 = ( ADC_rw << 23 ) + ( ADC_bytes << 21 ) + ( ADC_address << 8 ) + value[0]
          bit_array = "{0:{fill}24b}".format(data2, fill='0')
-      #    logging.debug(bit_array)
+      #    logging.debug("%s",bit_array)
          SetBit('CS',0) #enable
          for bit in bit_array:
              SetBit('SDO',int(bit)) 
@@ -29,7 +29,7 @@ class SPIbitbang1(I2Cdevices):
          SPI=Find(self.D['I2C_devices'],'dev_name',dev)
          Reg=Find(SPI['dev_registers'],'reg_name',reg)  
          ADC_reg_address=Reg['reg_addr']
-#          logging.debug(ADC_reg_address,CS,SDIOdir,SDI,SDO,CLK)
+#          logging.debug("%s %s %s %s %s %s",ADC_reg_address,CS,SDIOdir,SDI,SDO,CLK)
          SetBit=I2Ccallback
          ADC_bytes = 0x00
@@ -61,8 +61,8 @@ class SPIbitbang1(I2Cdevices):
          SetBit('SDIOdir',0) #output
 #          SetBit(SDO,1) 
 #          SetBit(CLK,1) 
-#          logging.debug(read_bit)
+#          logging.debug("%s",read_bit)
 #          stri = "Read back data is: {0:2x} ".format(int(read_bit, 2))
-#          logging.debug(stri)
+#          logging.debug("%s",stri)
          value[0]=int(read_bit, 2)
          return True;
--- a/SPIbitbang2.py
+++ b/SPIbitbang2.py
@@ -14,7 +14,7 @@ class SPIbitbang2(I2Cdevices):
          data2 =  ( reg_address << 9 ) + value[0]
          bit_array = "{0:{fill}16b}".format(data2, fill='0')
-      #    logging.info(bit_array)
+      #    logging.info("%s",bit_array)
          SetBit('CS',0) #enable
          for bit in bit_array:
              SetBit('SDI',int(bit)) 
@@ -29,7 +29,7 @@ class SPIbitbang2(I2Cdevices):
          SPI=Find(self.D['I2C_devices'],'dev_name',dev)
          Reg=Find(SPI['dev_registers'],'reg_name',reg)  
          reg_address=(Reg['reg_addr'] if Reg else int(reg))
-#          logging.info(ADC_reg_address,CS,SDIOdir,SDI,SDO,CLK)
+#          logging.info("%s %s %s %s %s %s",ADC_reg_address,CS,SDIOdir,SDI,SDO,CLK)
          SetBit=I2Ccallback
          ADC_bytes = 0x00
@@ -59,8 +59,8 @@ class SPIbitbang2(I2Cdevices):
          SetBit('CS',1) #disable
 #          SetBit(SDO,1) 
 #          SetBit(CLK,1) 
-#          logging.info(read_bit)
+#          logging.info("%s",read_bit)
          stri = "Read back data is: {0:2x} ".format(int(read_bit, 2))
-          logging.info(stri)
+          logging.info("%s",stri)
          value[0]=int(read_bit, 2)
          return True;
--- a/hwdev.py
+++ b/hwdev.py
@@ -6,7 +6,7 @@ import logging
 YAMLDIR='YAML/'
 class hwdev:
    def __init__(self,configfile):
-        logging.info("Loading:",configfile)
+        logging.info("Loading: %s",configfile)
        self.D=yaml.load(open(YAMLDIR+configfile))
        self.loadchildren(self.D)
    def loadchildren(self,D):
@@ -17,12 +17,12 @@ class hwdev:
          childname=(c['child_name']+"_" if c.get('child_name') else '');
          objnm=c['child_dev']
          yamlname=c['child_conf']
-          logging.info("Add child:",childname,objnm,yamlname)
+          logging.info("Add child: %s %s %s",childname,objnm,yamlname)
          i = importlib.import_module(objnm)
          for name, obj in inspect.getmembers(i,inspect.isclass):
              if name==objnm:
 #                  yamlname=(c['conf_name'] if c.get('conf_name') else nm)
-#                  logging.debug("  Load child:",childname," conf=",yamlname+".yaml")
+#                  logging.debug("  Load child: %s conf=%s.yaml",childname,yamlname)
                  c['obj']=obj(yamlname+".yaml")
                  self.children.append([childname,c['obj']])
@@ -51,7 +51,7 @@ class hwdev:
    def CallMethod(self,name,params,I2Ccallback):
        childname=name.split('_')[0]
        for cname,child in self.children:
-#            logging.debug("hwdev callmethod",cname,childname)
+#            logging.debug("hwdev callmethod %s %s",cname,childname)
            if cname=="": child.CallMethod(name,params,I2Ccallback)
            elif cname[:-1]==childname: return child.CallMethod(name[len(childname)+1:],params,I2Ccallback)
        return False

--- a/opcuaserv.py
+++ b/opcuaserv.py
@@ -49,13 +49,13 @@ if True:
 #Vars={}
 #Vars[1]='123'
-#logging.info(Vars)
+#logging.info("%s", Vars)
 #exit()
 def ValCallback(nodeid,force=False):
    vname,myvar,oldvalue=Vars_R[nodeid.Identifier]
-#    logging.info("Value callback",vname)
+#    logging.info("Value callback %s",vname)
 #    vname=vname[vname.find('_')+1:]
-#    logging.info("RCU variable:",vname,oldvalue)
+#    logging.info("RCU variable: %s=%s",vname,oldvalue)
 #    X=RCU1.Getvar2(vname)
 #    if not(running): 
    if False: 
@@ -64,10 +64,10 @@ def ValCallback(nodeid,force=False):
        return myvar
    timenow=datetime.utcnow()
    timediff=(timenow-myvar.SourceTimestamp).total_seconds()
-#    logging.info(timediff)
+#    logging.info("%s",timediff)
    if not(force) and timediff<90: return myvar;
    res=P1.GetVarValue(vname,oldvalue)
-    logging.info("Read callback",vname,": Result:",res,oldvalue)
+    logging.info("Read callback %s: Result: %s Value: %s",vname,res,oldvalue)
    if res:
        myvar.Value.Value=(oldvalue[0] if len(oldvalue)==1 else oldvalue)
        myvar.SourceTimestamp = datetime.utcnow()
@@ -82,11 +82,11 @@ class SubHandler(object):
    """
    def datachange_notification(self, node, val, data):
-#        logging.info("Python: New data change event", node, val,data)
+        #        logging.info("Python: New data change event: %s %s %s", node, val,data)
        if not(running): return
        vname,myvar=Vars_W[node.nodeid.Identifier]
        val=(val if isinstance(val, list) else [val] )
-        logging.info("Write callback",vname,val)
+        logging.info("Write callback %s=%s",vname,val)
        P1.SetVarValue(vname,val)
        #readback
 #        if True:
@@ -105,11 +105,11 @@ class SubHandler(object):
    def event_notification(self, event):
-        logging.debug("Python: New event", event)
+        logging.debug("Python: New event %s", event)
 def CallMethod(ObjectID,name):
-        logging.debug("Callmethod",name)
+        logging.debug("Callmethod %s",name)
        P1.CallMethod(name,None)
@@ -129,19 +129,19 @@ def AddVar(name,dtype=0,RW=0,cnt=1):
            myvar = (PCCobj.add_variable(idx, vname, 0.0) if cnt<=1 else PCCobj.add_variable(idx, vname, cnt*[0.0]))
        else:
            myvar = (PCCobj.add_variable(idx, vname, 0)   if cnt<=1 else PCCobj.add_variable(idx, vname, cnt*[0]))
-        logging.info("Variable added: ",vname)
+        logging.info("Variable added: %s",vname)
        Vars_R[myvar.nodeid.Identifier]=[name,myvar.get_data_value(),varvalue2]
        ValCallback(myvar.nodeid,force=True)
-#        logging.info(myvar.get_value())
+#        logging.info("%s",myvar.get_value())
        if not args.no_lib_hack:
            server.set_attribute_callback(myvar.nodeid, ValCallback)
 #        varvalue=myvar.get_data_value().Value
 #        Vars_R[myvar.nodeid.Identifier][2]=varvalue
-#        logging.info(varvalue2,varvalue)
+#        logging.info("%s %s",varvalue2,varvalue)
   if RW in [2,3]:
        vname=name+"_RW";
-        logging.info("Variable added: ",vname)#,'=',varvalue2)
+        logging.info("Variable added: %s",vname)#,'=',varvalue2)
        myvar2 = PCCobj.add_variable(idx, vname, (varvalue2[0] if len(varvalue2)==1 else varvalue2))
        myvar2.set_writable()
        Vars_W[myvar2.nodeid.Identifier]=[name,myvar2.get_data_value()]
@@ -151,7 +151,7 @@ def AddVar(name,dtype=0,RW=0,cnt=1):
 def AddMethod(name):
        vname=name;
        myvar = PCCobj.add_method(idx, vname, lambda ObjectId : CallMethod(ObjectId,name), [],[] )
-        logging.info("AddMethod:",vname)
+        logging.info("AddMethod: %s",vname)
 logging.info("Start server");
 server.start()

--- a/pypcc.py
+++ b/pypcc.py
@@ -12,7 +12,7 @@ def I2C1server(addr,data,reg=None,read=0):
       if read==3:
           time.sleep(data[0]/1000.)
           return True
-#       logging.debug("I2C",addr,reg,data,read)
+#       logging.debug("I2C addr=%s reg=%s data=%s read=%s",addr,reg,data,read)
       bus=pylibi2c.I2CDevice('/dev/i2c-1',addr)
       if read==1:
         length=len(data)

--- a/pypcc_test.py
+++ b/pypcc_test.py
@@ -3,7 +3,7 @@ import time
 import logging
 def I2C1server(addr,data,reg=None,read=0):
-       logging.info("I2C:",addr,data,reg,read)
+       logging.info("I2C: addr=%s data=%s reg=%s read=%s",addr,data,reg,read)
       return True;
 class pypcc(hwdev):