Hello,

I have a plugin with a serial communication based on the Simple Serial Plugin.
This plugin reads and treats data continuously. Unfortunately, I have a bug occurring every 6 or 7 hours (the serial connection is closed, so I think this bug raise an exception) ... So it's not easy to debug

Is there a solution to know which line of code cause the exception ?

What does the Event Log show around the time it fails (copy/paste what you see)?

Hello Matt,

I have a main loop to read data :

Code: Select all

      try:
         self.plugin.debugLog("Starting concurrent serial communications.")
         while True:   
            while not commandQueue.empty():
               command = commandQueue.get()
               if command == "stopconcurrentSerialThread":
                  self.plugin.debugLog("Raising exception to stop concurrent thread.")
                  raise self.StopThread
            
            validatedMessages = self.readTeleinfoMessage(serialConnection)
            self.decodeResponse(devId, validatedMessages)

      except self.StopThread:
         self.plugin.debugLog("closing connection to device ")
         pass
      except Exception, e:
         self.plugin.exceptionLog()
      except:
         self.plugin.exceptionLog()
      finally:
         self.plugin.debugLog("closed connection to device")
         serialConnection.close()
         pass

The log only shows "closed connection to device", so I think this means an exception has been raised, and it gone through the finally statement to close the serial connection.

By adding some checkpoints in my code - pluginLog("Checkpoint 1") - I identified where is the bug. It's in the readTeleinfoMessage() method, I have a loop waiting for a specific character :

Code: Select all

while '\x02' not in trame:
   trame = serialConnection.readline()

Sometimes - as said every 5 or 6 hours - this code raise an exception. I don't understand why ... I tried to add a sleep command in the loop, but the result is identical.

It is strange that the only thing logged is "closed connection to device." If an exception was thrown then one of those to except handler cases should be catching it and then logging the exception details, so I'm not sure how it is getting past that logic (and not logging any additional details).

The pyserial source suggests setting a timeout for the serial connection when using readline().

The serial connection could also be getting dropped, especially if you have it plugged into a USB hub or your Mac goes to sleep. Making serial communication robust can be a bit tricky. You might want to glance through the plugin.py and easydaq.py source files in the EasyDAQ USB Relay Cards plugin. Whenever it detects anything that might be a serial communication failure/hiccup:

Code: Select all

      except serial.SerialException, exc:
         self.plugin.handleCommException(dev, exc)      # enters silent retry mode
      except termios.error, exc:
         self.plugin.handleCommException(dev, exc)      # enters silent retry mode
      except OSError, exc:
         self.plugin.handleCommException(dev, exc)      # enters silent retry mode

I have it start an automatic serial reconnect mechanism that tries to reestablish the serial communication every few seconds. The result is you can physically disconnect the hardware from the Mac and then when it is reconnected the plugin automatically gets everything up and working again.

I'm really annoyed, I tried a lot of things (and it's very long because I have to wait several hours to see the result), and the bug is not solved ...

As indicated Matt, I added some code in the main loop to catch the exception and start a reconnect method but it seems to go directly into the finally statement as I have nothing in the log except "closed connection to device" :

Code: Select all

      except self.StopThread:
         pass
      except serial.SerialException, exc:
         #self.plugin.handleCommException(dev, exc)      # enters silent retry mode
         self.plugin.debugLog("Exception : " + str(exc))
         pass
      except termios.error, exc:
         #self.plugin.handleCommException(dev, exc)      # enters silent retry mode
         self.plugin.debugLog("Exception : " + str(exc))
         pass
      except OSError, exc:
         #self.plugin.handleCommException(dev, exc)      # enters silent retry mode
         self.plugin.debugLog("Exception : " + str(exc))
         pass
      except Exception, exc:
         self.plugin.exceptionLog()                  # shouldn't happen; bail out
      except:
         self.plugin.exceptionLog()                  # shouldn't happen; bail out
      finally:
         self.plugin.debugLog("closed connection to device")
         serialConnection.close()

I added a timeout to work with readline(), not better.
I tried to replace readline() by something like : while serialConnection.read(1) == '\r\n', not better.

I have no more idea at this time ...

I wonder if:

Code: Select all

self.plugin.exceptionLog()

is failing for some reason. Try adding some more debug logging to the last 2 exception handlers to see if it is getting into one of them and failing on exceptionLog():

Code: Select all

      except Exception, exc:
         self.plugin.debugLog("inside1A")
         self.plugin.exceptionLog()                  # shouldn't happen; bail out
         self.plugin.debugLog("inside1B")
      except:
         self.plugin.debugLog("inside2A")
         self.plugin.exceptionLog()                  # shouldn't happen; bail out
         self.plugin.debugLog("inside2B")

Hey,
One good and one bad news ...

The good one : I know what is the cause of my problem - my device is in the garage, and my Mac Mini with Indigo is in the living room. Between them, I use an USB to RJ45 extender like this. This extender causes the device connection closing. Unfortunately, I can't move the Mac Mini to the garage ...

The bad news : I modified the code as you said Matt, but I have always in the log "closed connection to device" ... So it seems it goes directly to the finally statement ... I don't know how I can implement your reconnect mechanism.

Try adding the:

Code: Select all

self.plugin.debugLog("inside _ SOME UNIQUE ID")

As the first line after all of the except: clauses (not just the 2 I mentioned above). It is possible that it is hitting one of the other ones and the debugLog() is failing because the case of str(exc) is failing first. So let's log just a simple line first to try to see which one. Once we know what type of exception is being thrown, we can dig further into what the exception handler is failing.

Same result

Juju wrote:... I know what is the cause of my problem - my device is in the garage, and my Mac Mini with Indigo is in the living room. Between them, I use an USB to RJ45 extender... ...This extender causes the device connection closing. Unfortunately, I can't move the Mac Mini to the garage...

I have had similar issues with USB over Cat-5 extenders and solved the problem by installing a USB hub between the remote device and the far end USB over Cat-5 driver.

Not better.
Is it a powered USB hub ? Perhaps this problem is due to a lack of power ? I will try to find a power adaptor for the hub.

Juju wrote:Not better.
Is it a powered USB hub ?

Sorry, I should have said so. Yes it needs to be powered.

Juju... You might try looking in the Console log to see if any of your plugin errors are being logged there. For some reason, it looks like messages that Indigo does not see are still recorded in the Console log.

I will have a look in the Console log.
Tried a powered USB hub, same result. tried another one, same result ...
As it is now clear the problem come from the extender, I'm looking at other extender types. I think I will try with this type of device : link.

Something strange : on the USB hub, I have connected my power meter (FTDI chip) and a USB/serial ports adaptor with 4 serial ports (FTDI chip too). There is no exception raised for the power meter connected directly with USB, there is a termios exception raised for a (virtual !) easydaq card connected on a serial port from the adaptor, and an exception (except Exception, exc:) for a PLCBUS (virtual too ! - another plugin I'm working on) device connected on a serial port from the adaptor ...

Some news : works fine with this USB over Cat-5 extender ! So my problem was caused by a bad device ...

I took time to implement the automatic reconnecting process from the easydaq plugin. It is based on the detection of an exception during the main loop. Unfortunately I haven't a better result concerning this topic.
For all my others devices connected through a serial port to an USB/serial adapter, an exception is raised, but not for this one connected directly with USB...