Persistent error: "incoming message does not start with 0x02"

[jre...@gmail.com]

After two days of error-free usage of insteon-terminal with a 2413U PLM modem, I started to get persistent errors that warn: "incoming message does not start with 0x02"

Also, other problems have cropped up with commands that previously worked:

1. The command modem.getdb() would print out the database, but now it just hangs:

>>> modem.getdb()

14:28:41.536 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

2. The modem.getid() and modem.getId() commands now return nothing:

>>> modem.getid()

sent msg: OUT:Cmd:0x60|

>>> 14:35:30.101 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

getid got no reply!

>>> modem.getId()

sent msg: OUT:Cmd:0x62|toAddress:00.00.00|messageFlags:0x0F=DIRECT:3:3|command1:0x10|command2:0x00|

>>> 14:35:45.757 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

listDevices() correctly shows my switches and bulbs and modem.

I rebooted both the computer (Raspberry Pi 2 Model B running openhabian 2.0.0-1) and the modem, to no avail.

Below I'm attaching a trace where I turn off/on/off/on/off an LED bulb (though the error occurs with switches as well), as well as logs for the other two errors (modem.getid() errors and modem.getdb() hang).

Any help would be appreciated.

Thanks!

Jim

jreese-at-gmail-dot-com

=== Start of Log for 0x02 error ===

openhabian@openHABianPi:~/insteon-terminal-master $ ./insteon-terminal -nw

Insteon Terminal

Connecting

RXTX Warning:  Removing stale lock file. /var/lock/LCK..ttyUSB0

Connected

Terminal ready!

>>> setLogLevel("TRACE")

>>> 14:06:37.751 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:37.802 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:37.805 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:37.808 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:38.812 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:38.813 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:38.815 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:38.816 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:39.819 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:39.821 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:39.824 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:39.826 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:40.830 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:40.833 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:40.835 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:40.837 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:41.841 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:41.843 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:41.846 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:41.848 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

 ledBulb.off()

>>> 14:06:42.478 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 1 data: 62

14:06:42.486 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 1 data: 62

14:06:42.468 [Thread-4] DEBUG us.pfrommer.insteon.msg.IOPort - Msg written: OUT:Cmd:0x62|toAddress:32.BF.29|messageFlags:0x0F=DIRECT:3:3|command1:0x13|command2:0x00|

14:06:42.490 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

14:06:42.774 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 2 data: 0650

14:06:42.777 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 2 data: 0650

14:06:42.779 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

14:06:42.784 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 8 data: BF2941EC342F1300

14:06:42.789 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 8 data: BF2941EC342F1300

14:06:42.791 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

14:06:43.794 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:43.796 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:43.798 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:43.800 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:44.803 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:44.806 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:44.807 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:44.809 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:45.812 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:45.816 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:45.819 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:45.822 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:46.826 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:46.829 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:46.831 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:46.834 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:47.838 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:47.850 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:47.853 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:47.855 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:48.858 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:48.859 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:48.860 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:48.861 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

ledBulb.on()

>>> 14:06:49.143 [Thread-4] DEBUG us.pfrommer.insteon.msg.IOPort - Msg written: OUT:Cmd:0x62|toAddress:32.BF.29|messageFlags:0x0F=DIRECT:3:3|command1:0x11|command2:0xFF|

14:06:49.149 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 1 data: 02

14:06:49.151 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 1 data: 02

14:06:49.153 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:49.155 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 1 data: 02

14:06:49.159 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 6 data: BF290F11FF06

14:06:49.163 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 7 data: 02BF290F11FF06

14:06:49.167 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - header length expected: -1 extended: false

14:06:49.169 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - got unknown command code 29

14:06:49.449 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 1 data: 02

14:06:49.452 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 1 data: 02

14:06:49.454 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:49.463 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 1 data: 02

14:06:49.467 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 7 data: 2941EC342F11FF

14:06:49.471 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 8 data: 022941EC342F11FF

14:06:49.472 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - header length expected: -1 extended: false

14:06:49.473 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - got unknown command code 41

14:06:50.475 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:50.477 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:50.478 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:50.479 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:51.481 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:51.482 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:51.483 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:51.485 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:52.487 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:52.488 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:52.489 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:52.490 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:53.492 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:53.494 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:53.495 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:53.496 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

ledBulb.off()

>>> 14:06:54.038 [Thread-4] DEBUG us.pfrommer.insteon.msg.IOPort - Msg written: OUT:Cmd:0x62|toAddress:32.BF.29|messageFlags:0x0F=DIRECT:3:3|command1:0x13|command2:0x00|

14:06:54.042 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 1 data: 02

14:06:54.043 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 1 data: 02

14:06:54.045 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:54.047 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 1 data: 02

14:06:54.050 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 7 data: 32BF290F130006

14:06:54.054 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 8 data: 0232BF290F130006

14:06:54.055 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - header length expected: -1 extended: false

14:06:54.057 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - got unknown command code BF

14:06:54.341 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 1 data: 02

14:06:54.344 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 1 data: 02

14:06:54.346 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:54.347 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 1 data: 02

14:06:54.351 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 9 data: 32BF2941EC342F1300

14:06:54.355 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 10 data: 0232BF2941EC342F1300

14:06:54.356 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - header length expected: -1 extended: false

14:06:54.358 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - got unknown command code BF

14:06:55.360 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:55.362 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:55.363 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:55.364 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:56.366 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:56.368 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:56.369 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:56.370 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:57.373 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:57.374 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:57.375 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:57.376 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:58.379 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:58.381 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:58.382 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:58.384 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:06:59.386 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:06:59.388 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:06:59.391 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:06:59.392 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

set14:07:00.394 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:07:00.396 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:07:00.397 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:07:00.398 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

Log14:07:01.401 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:07:01.402 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:07:01.403 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:07:01.404 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

Lev14:07:02.406 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:07:02.407 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:07:02.408 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:07:02.409 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

el14:07:03.412 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:07:03.413 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:07:03.414 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:07:03.415 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

(14:07:04.418 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:07:04.420 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:07:04.425 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:07:04.427 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

"WA14:07:05.430 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:07:05.431 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:07:05.432 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:07:05.433 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

RN14:07:06.435 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:07:06.437 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:07:06.438 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:07:06.439 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

")14:07:07.441 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:07:07.442 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:07:07.443 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:07:07.445 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

>>> ledBulb.on()

>>> 14:07:17.981 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - got unknown command code 00

14:07:17.987 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

14:07:18.280 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - got unknown command code 00

14:07:18.286 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

14:07:18.289 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

ledBledBulb.off()

>>> 14:07:22.822 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - got unknown command code 00

14:07:22.827 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

14:07:23.121 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - got unknown command code 00

14:07:23.129 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

=== End of Log  for 0x02 error ===

=== Start of Log 1 for modem.getid() and getId() errors ===

openhabian@openHABianPi:~/insteon-terminal-master $ ./insteon-terminal -nw

Insteon Terminal

Connecting

RXTX Warning:  Removing stale lock file. /var/lock/LCK..ttyUSB0

Connected

Terminal ready!

>>> modem.getid()

sent msg: OUT:Cmd:0x60|

>>> 14:35:30.101 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

getid got no reply!

>>> modem.getId()

sent msg: OUT:Cmd:0x62|toAddress:00.00.00|messageFlags:0x0F=DIRECT:3:3|command1:0x10|command2:0x00|

>>> 14:35:45.757 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

14:35:45.763 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

id got no reply!

=== End of Log for modem.getid(), getId() errors ===

=== Start of Log for modem.getdb() hang ===

>>> setLogLevel("TRACE")

>>> 14:32:23.910 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:32:23.926 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:32:23.928 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:32:23.930 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

14:32:24.933 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:32:24.934 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 0 data: 

14:32:24.935 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: -1

14:32:24.935 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 0 data: 

modem.getdb()

14:32:24.950 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 1 data: 69

14:32:24.952 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 1 data: 69

14:32:24.953 [Thread-3] WARN  us.pfrommer.insteon.msg.MsgReader - incoming message does not start with 0x02

14:32:24.945 [Thread-4] DEBUG us.pfrommer.insteon.msg.IOPort - Msg written: OUT:Cmd:0x69|

14:32:24.959 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 3 data: 0257E2

14:32:24.961 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 3 data: 0257E2

14:32:24.962 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - header length expected: 2 extended: false

14:32:24.963 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: 10

14:32:24.965 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 3 data: 0257E2

14:32:24.967 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 5 data: BF29013A48

14:32:24.969 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 8 data: 0257E2BF29013A48

14:32:24.970 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - header length expected: 2 extended: false

14:32:24.971 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: 10

14:32:24.973 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 8 data: 0257E2BF29013A48

14:32:25.975 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:32:25.977 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 8 data: 0257E2BF29013A48

14:32:25.978 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - header length expected: 2 extended: false

14:32:25.978 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: 10

14:32:25.980 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 8 data: 0257E2BF29013A48

14:32:26.982 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:32:26.985 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 8 data: 0257E2BF29013A48

14:32:26.986 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - header length expected: 2 extended: false

14:32:26.986 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: 10

14:32:26.988 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 8 data: 0257E2BF29013A48

14:32:27.990 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - read buffer: len 0 data: 

14:32:27.992 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - processing data: len 8 data: 0257E2BF29013A48

14:32:27.993 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - header length expected: 2 extended: false

14:32:27.994 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - msgLen expected: 10

14:32:27.996 [Thread-3] TRACE us.pfrommer.insteon.msg.MsgReader - keeping buffer len 8 data: 0257E2BF29013A48

=== End of Log for modem.getdb() hang ===

[Daniel Pfrommer]

There are two possible explanations as it seems to be some hardware issue with the modem.

                 1) The modem is going bad, which can happen after several years of usage.

                 2) Unlikely, but it could also be that the USB cable from the modem is going bad.

Do you get the same error message when running openhab or is this a strictly insteonplm-related problem? The two projects share some low-level message parsing code so if the openhab binding gets the error as well we can relatively safely rule out software issues as the openhab binding is well-tested. 

[jre...@gmail.com]

1. It's a brand-new modem, just purchased and unboxed.

2. I'm using the USB cable that came with the modem, but I can try another one when I return home tomorrow night.

3. I've only been using your insteon-terminal, but I can try openHAB to see if its binding gets the same error.

Thanks for the reply. I'll let you know what I find.

Jim

PS - Great software, BTW. I really appreciate it when someone like you puts in a lot of effort to understand the underlying protocol(s) and provide an easier way to navigate/manipulate them.

[Bernd Pfrommer]

We are quickly running out of possible explanations. One more thing: have you checked that nothing else is running on the host that may be accessing the serial (usb) port as well? Maybe something that gets started at boot, and so survives reboot?

Can you afford to install insteon terminal on another machine, like your desktop?  That's a great excuse to set up a GNU/Linux partition for dual booting your machine :)

[Jim Reese]

I haven't had a chance to use a new USB cable or try the openHAB bindings, but I will tonight or tomorrow.

I have a dozen or so Linux boxen, but the one I'm using for the instead terminal is an RPi 2 running openhabian that's a fresh, unconfigured install, so I don't think anything else is trying to use the USB port. I can try it on other RPis as well as on Ubuntu (I can also see if it will run on OS X).

Best, 

Jim

--
You received this message because you are subscribed to a topic in the Google Groups "insteon-terminal" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/insteon-terminal/MvghA7tswKs/unsubscribe.
To unsubscribe from this group and all its topics, send an email to insteon-terminal+unsubscribe@googlegroups.com.
To post to this group, send email to insteon-terminal@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/insteon-terminal/b1af756c-4913-4810-bbbb-79ee46d843ff%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Dale Sheehan]

almost 3 years later I know...

adding this tidbit form my own exoerience.

I was having a very similar experience. struggled for a day thinking it was hardware or database correputions. Verified it was not hardware or databases by installing and running insteon Terminal on another computer and had 0 issues.

Turned out that I had just done a bad job of stopping OpenHAB from talking to the modem while I was using Insteon Termial.

So, for anyone that finds this thread with that error, I would add just that you also ensure you only have one thing talking to your modem at a time.

Dale

[Bernd Pfrommer]

Thanks for posting. Good for people googling on that subject....

[David Slight]

Wanted to reiterate that this helped me no end - I had left my Raspberry Pi running as well as my phone with Home Assistant running - stopped them both and all the messages vanished, and the Terminal was wonderfully responsive. No more WARN, 0x02 not recognized etc.  I guess these are just from all the other traffic on the network that the termianl sees.
Happy weekend.

[Ariel Fishman]

David -- this is TOTALLY helping me as well! I couldn't figure out where the errors wer coming from and it turns out I am doing the exact same thing! I turned off Raspberry pi and the messages went away.