Debug a hanging startup

Setup, Configuration and Use Scripts & Rules
1

Whenever my rules file gets opened before the communication with RFXCOM is made then startup hangs and I have to forcably cancel it and openhab.log (last 2 lines) looks like this:

2016-04-01 14:15:41.002 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'default.rules’
2016-04-01 14:15:41.388 [INFO ] [.b.r.internal.RFXComConnection] - Connecting to RFXCOM [serialPort=’/dev/ttyUSB100’ ].

If openhab.log looks like this, startup continues without problems:

2016-04-01 14:17:55.423 [INFO ] [.b.r.internal.RFXComConnection] - Connecting to RFXCOM [serialPort=’/dev/ttyUSB100’ ].
2016-04-01 14:17:57.247 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model ‘default.rules’

FYI, the rules file has a system started rule to set a number of switches to initial values but none have anything to do with communication using RFXCOM

Any suggestions on how to debug and possibly fix it are appreciated.

2

Do you have debug level logging enabled? If not, I’d recommend that as a first step.

3

have you tried disabling the system started rule? I found odd inconsistent startup problems when I had one…

4

I have done extensive testing, with and without debug and reviewed both openhab.log and the event.log.

On one occasion it got over the hang after about 4 minutes(the Activated message from RFXCOM binding was shown at that time). This was a rather interesting trace, in the event log it showed that the first statement (from the system started rule) was executed and the second and subsequent ones after the4 minute hang. The RFXCOM data listener showed data received but they never hit the event log. Since I suspected the RFXCOM binding I upgraded the binding to 1.8.2, but the hang also happened on this on.

Because it appeared the hang was temporary, I decide to finish testing and move on. But then I discovered the next morning that one of the other things that may happen in the hang situation is that not all rules files are loaded, openhab log say they are empty while they are not. I had seen that in the past but since I used at that time a refresh rule script I disregarded it since it had no effect. But some time ago I stopped using the refresh rule script and then the consequence is that a part of the automation is not running as I discovered.

Have now upgraded RFXCOM to the 1.9.0 snapshot (for other reasons) and if I see the problem again, I will report an issue on it.