Announcement

Collapse
No announcement yet.

Problems with recent firmware serial and/or USB PLMs under Linux

Collapse
This topic is closed.
X
X
Collapse
 
  • Page of 1
  • Filter
  • Time
  • Show
Clear All
new posts
Previous template Next
    #1

    Problems with recent firmware serial and/or USB PLMs under Linux

    Having issues with NAK retries for both USB and serial PLMs, recently purchased (past 30 days) from Smarthome. Sample log follows. Doesn't always occur but am seeing about 20% failure rate for comms to all devices, even those plugged into same outlet as the PLM. Bad enough that it can block startup entirely.

    I've tried it both inside an ESXi VM running on an Intel(R) Xeon(R) CPU D-1541 @ 2.10GHz (USB) and on metal on a Intel(R) Atom(TM) CPU C2750 @ 2.40GHz. Same problem either way. OS is Ubuntu 16.04.1, mono-runtime is 4.2.1.102+dfsg2-7ubuntu4.

    I have a third serial PLM I can try, though the swapout on my 63 device network is pretty painful. Any ideas? I've tried replacing the computer and the PLM type.

    Code:
    Plugin: Insteon Instance:  starting...
Connecting to server at 127.0.0.1...
09:43:24:1589:[Info]->Plugin Insteon has connected. IP:127.0.0.1:43410
Connected, waiting to be initialized...
09:43:24:3993:[Insteon]->Host System: 10.11.111.5 (tinyhs) 3.0.0.280
09:43:24:4016:[Insteon]->Plugin HSPI_Insteon.exe version: 3.0.6.4
09:43:24:4051:[Insteon]->Insteon Support library (Insteon.dll) version: 1.0.6.3
09:43:24:4061:[Insteon]->RegisterCallback Completed
09:43:24:4070:[Insteon]->Enter InitIO
09:43:24:4093:[Insteon]->Enter InitPlugin
09:43:24:4110:[Insteon]->Global initialization of plug-in required, starting up.
09:43:24:4126:[Insteon]->Initializing Insteon hardware interface...
09:43:24:4133:[Insteon]->In ProcessRawReceiveThread
09:43:24:4159:[Insteon]->Initializing Interface...
09:43:24:4189:[Insteon]->In PLMBuffer_ProcessBufferThread
09:43:24:4541:[Insteon]->Sending command 02 60 to Interface, (Expecting 6 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:43:25:0559:[Insteon]->..Got NAK from the Interface for command
09:43:25:0572:[Insteon]->..Retry #1 required.  Pausing 250ms for Interface to clear...
09:43:25:2501:[Insteon]->Received STX 0x50 (Raw Insteon Rec):28 67 1B 41 03 A8 2F 00 FF
09:43:25:8492:[Insteon]->..Got Interface Response 02 60 41 03 A8 03 11 9E 06
09:43:25:8510:[Insteon]->Sending command 02 60 to Interface, (Expecting 6 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:43:26:4489:[Insteon]->..Got NAK from the Interface for command
09:43:26:4507:[Insteon]->..Retry #1 required.  Pausing 250ms for Interface to clear...
09:43:27:0490:[Insteon]->..Got Interface Response 02 60 41 03 A8 03 11 9E 06
09:43:27:0732:[Insteon]->RF PLM contacted on /dev/ttyS0 with an Insteon address of 41.03.A8 and firmware version 9E
09:43:27:0775:[Insteon]->Sending command 02 6B 48 to RF PLM, (Expecting 0 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:43:27:3487:[Insteon]->..Got NAK from the RF PLM for command
09:43:27:3498:[Insteon]->..Retry #1 required.  Pausing 250ms for RF PLM to clear...
09:43:27:6487:[Insteon]->..Got NAK from the RF PLM for command
09:43:27:6499:[Insteon]->..Retry #2 required.  Pausing 300ms for RF PLM to clear...
09:43:28:0494:[Insteon]->..Got NAK from the RF PLM for command
09:43:28:0521:[Insteon]->Insteon hardware interface initialization failed.
09:43:28:0548:[Insteon]->Exit InitIO
09:43:28:0558:[Insteon]->Could not set the Interface configuration. Init failed.
09:43:28:0716:[Plug-In]->Finished initializing plug-in Insteon
09:43:28:1499:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:28:2487:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:28:3487:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:28:4487:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:28:5488:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:28:6487:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:28:7487:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:28:8488:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:28:9489:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:29:0488:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:29:1488:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:29:2488:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:29:3502:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:29:4489:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:29:5488:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:29:6489:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:29:7489:[Insteon]->Port_DataReceived Error: Specified port is not open.
09:43:29:8489:[Insteon]->Port_DataReceived Error: Specified port is not open.
    ...and here's some status update attempts, some of which go well, some of which do not...

    Code:
    09:51:54:8977:[Insteon]->Requesting Insteon status (Polling) for device Basement Stair Lights (19.51.2B)
09:51:54:9006:[Insteon]->Attempting to update the status for Basement Stair Lights (19.51.2B)
09:51:54:9016:[Insteon]->Sending command 02 62 19 51 2B 0F 19 00 to RF PLM, (Expecting 0 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:51:54:9504:[Insteon]->..Got NAK from the RF PLM for command
09:51:54:9514:[Insteon]->..Retry #1 required.  Pausing 250ms for RF PLM to clear...
09:51:55:2504:[Insteon]->..Got RF PLM Response 02 62 19 51 2B 0F 19 00 06
09:51:57:3510:[Insteon]->Received STX 0x50 (Raw Insteon Rec):19 51 2B 41 03 A8 2B 00 00
09:51:57:3554:[Insteon]->Database recently heard delta value for device 19.51.2B is current.
09:51:57:3565:[Insteon]->Received a Direct ACK from Basement Stair Lights (19.51.2B): 19 51 2B 41 03 A8 2B 00 00
09:51:57:3576:[Insteon]->Database delta value of 0 for device 19.51.2B is current.  No changes since last database update.
09:51:57:3599:[Insteon]->StandardDeviceClass ProcessStatus called with Level:0
09:51:57:3782:[Insteon]->Setting status and value for device 19.51.2B:1. Old status:0 Old Value:0, New Status:3 New Value:0
09:51:58:4054:[Insteon]->Timed poll for Insteon device Seabright LEDs (11.41.5E), Last contact 12/17/2016 9:36:46 PM. Polling interval of 10 min. reached, polling...
09:51:58:4084:[Insteon]->Requesting Insteon status (Polling) for device Seabright LEDs (11.41.5E)
09:51:58:4124:[Insteon]->Attempting to update the status for Seabright LEDs (11.41.5E)
09:51:58:4138:[Insteon]->Sending command 02 62 11 41 5E 0F 19 00 to RF PLM, (Expecting 0 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:51:58:4509:[Insteon]->..Got NAK from the RF PLM for command
09:51:58:4523:[Insteon]->..Retry #1 required.  Pausing 250ms for RF PLM to clear...
09:51:58:7510:[Insteon]->..Got NAK from the RF PLM for command
09:51:58:7526:[Insteon]->..Retry #2 required.  Pausing 300ms for RF PLM to clear...
09:51:59:1512:[Insteon]->..Got RF PLM Response 02 62 11 41 5E 0F 19 00 06
09:52:02:1544:[Insteon]->Did not receive a response from Seabright LEDs (11.41.5E). Try #1 failed.
09:52:02:1554:[Insteon]->Sending command 02 62 11 41 5E 0F 19 00 to RF PLM, (Expecting 0 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:52:02:2515:[Insteon]->..Got NAK from the RF PLM for command
09:52:02:2526:[Insteon]->..Retry #1 required.  Pausing 250ms for RF PLM to clear...
09:52:02:5515:[Insteon]->..Got NAK from the RF PLM for command
09:52:02:5525:[Insteon]->..Retry #2 required.  Pausing 300ms for RF PLM to clear...
09:52:02:9514:[Insteon]->..Got NAK from the RF PLM for command
09:52:02:9524:[Insteon]->**Internal transmit attempt failed for CMD: 00 00 00 11 41 5E 0F 19 00
09:52:02:9532:[Insteon]->Sending command 02 62 11 41 5E 0F 19 00 to RF PLM, (Expecting 0 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:52:03:2514:[Insteon]->..Got NAK from the RF PLM for command
09:52:03:2522:[Insteon]->..Retry #1 required.  Pausing 250ms for RF PLM to clear...
09:52:03:3518:[Insteon]->Received STX 0x50 (Raw Insteon Rec):11 41 5E 41 03 A8 2B 00 80
09:52:03:3543:[Insteon]->Received a Direct ACK from Seabright LEDs (11.41.5E): 11 41 5E 41 03 A8 2B 00 80
09:52:03:6519:[Insteon]->..Got RF PLM Response 02 62 11 41 5E 0F 19 00 06
09:52:03:6536:[Insteon]->Database recently heard delta value for device 11.41.5E is current.
09:52:03:6544:[Insteon]->Database delta value of 0 for device 11.41.5E is current.  No changes since last database update.
09:52:03:6553:[Insteon]->StandardDeviceClass ProcessStatus called with Level:128
09:52:03:6647:[Insteon]->Setting status and value for device 11.41.5E:1. Old status:0 Old Value:0, New Status:4 New Value:50
09:52:04:6771:[Insteon]->Timed poll for Insteon device MBR Closet Light (1A.01.4A), Last contact 12/17/2016 9:37:36 PM. Polling interval of 10 min. reached, polling...
09:52:04:6812:[Insteon]->Requesting Insteon status (Polling) for device MBR Closet Light (1A.01.4A)
09:52:04:6852:[Insteon]->Attempting to update the status for MBR Closet Light (1A.01.4A)
09:52:04:6865:[Insteon]->Sending command 02 62 1A 01 4A 0F 19 00 to RF PLM, (Expecting 0 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:52:04:7523:[Insteon]->..Got NAK from the RF PLM for command
09:52:04:7535:[Insteon]->..Retry #1 required.  Pausing 250ms for RF PLM to clear...
09:52:05:0523:[Insteon]->..Got NAK from the RF PLM for command
09:52:05:0539:[Insteon]->..Retry #2 required.  Pausing 300ms for RF PLM to clear...
09:52:05:4526:[Insteon]->..Got NAK from the RF PLM for command
09:52:05:4541:[Insteon]->**Internal transmit attempt failed for CMD: 00 00 00 1A 01 4A 0F 19 00
09:52:05:4557:[Insteon]->Sending command 02 62 1A 01 4A 0F 19 00 to RF PLM, (Expecting 0 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:52:05:7528:[Insteon]->..Got NAK from the RF PLM for command
09:52:05:7545:[Insteon]->..Retry #1 required.  Pausing 250ms for RF PLM to clear...
09:52:06:0528:[Insteon]->..Got NAK from the RF PLM for command
09:52:06:0545:[Insteon]->..Retry #2 required.  Pausing 300ms for RF PLM to clear...
09:52:06:4527:[Insteon]->..Got NAK from the RF PLM for command
09:52:06:4542:[Insteon]->**Internal transmit attempt failed for CMD: 00 00 00 1A 01 4A 0F 19 00
09:52:06:4559:[Insteon]->Sending command 02 62 1A 01 4A 0F 19 00 to RF PLM, (Expecting 0 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:52:06:5529:[Insteon]->Received STX 0x50 (Raw Insteon Rec):11 41 5E 41 03 A8 2B 00 80
09:52:06:5577:[Insteon]->Received a Direct ACK from Seabright LEDs (11.41.5E): 11 41 5E 41 03 A8 2B 00 80
09:52:06:7529:[Insteon]->..Got RF PLM Response 02 62 1A 01 4A 0F 19 00 06
09:52:09:2585:[Insteon]->Did not receive a response from MBR Closet Light (1A.01.4A). Try #3 failed.
09:52:09:2599:[Insteon]->Sending command 02 62 1A 01 4A 0F 19 00 to RF PLM, (Expecting 0 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:52:09:3533:[Insteon]->..Got NAK from the RF PLM for command
09:52:09:3550:[Insteon]->..Retry #1 required.  Pausing 250ms for RF PLM to clear...
09:52:09:6534:[Insteon]->..Got NAK from the RF PLM for command
09:52:09:6550:[Insteon]->..Retry #2 required.  Pausing 300ms for RF PLM to clear...
09:52:10:0534:[Insteon]->..Got NAK from the RF PLM for command
09:52:10:0552:[Insteon]->**Internal transmit attempt failed for CMD: 00 00 00 1A 01 4A 0F 19 00
09:52:10:0570:[Insteon]->Sending command 02 62 1A 01 4A 0F 19 00 to RF PLM, (Expecting 0 bytes extra back) Pre-Payload ACK:False, NAK is ok:False
09:52:10:3541:[Insteon]->..Got NAK from the RF PLM for command
09:52:10:3558:[Insteon]->..Retry #1 required.  Pausing 250ms for RF PLM to clear...
09:52:10:6536:[Insteon]->..Got NAK from the RF PLM for command
09:52:10:6553:[Insteon]->..Retry #2 required.  Pausing 300ms for RF PLM to clear...
09:52:11:0536:[Insteon]->..Got NAK from the RF PLM for command
09:52:11:0553:[Insteon]->**Internal transmit attempt failed for CMD: 00 00 00 1A 01 4A 0F 19 00
09:52:11:0572:[Insteon]->Did not get any status response from 1A.01.4A after 5 tries. No change to database delta value.
09:52:11:0789:[Insteon]->Setting status and value for device 1A.01.4A:1. Old status:0 Old Value:0, New Status:17 New Value: 0
09:52:11:3534:[Insteon]->Received STX 0x50 (Raw Insteon Rec):1A 01 4A 41 03 A8 2F 00 FF
09:52:11:3567:[Insteon]->Received a Direct ACK from MBR Closet Light (1A.01.4A): 1A 01 4A 41 03 A8 2F 00 FF
    Tags: None
    #2
    this can occur if a device on the network is malfunctioning (sending lots of cmds or bad msgs) and the PLM is trying to receive them. Or a noise device is causing issues.
    Mark

    HS3 Pro 4.2.19.5
    Hardware: Insteon Serial PLM | AD2USB for Vista Alarm | HAI Omnistat2 | 1-Wire HA7E | RFXrec433 | Dahua Cameras | LiftMaster Internet Gateway | Tuya Smart Plugs
    Plugins: Insteon (mine) | Vista Alarm (mine) | Omnistat 3 | Ultra1Wire3 | RFXCOM | HS MyQ | BLRadar | BLDenon | Tuya | Jon00 Charting | Jon00 Links
    Platform: Windows Server 2022 Standard, i5-12600K/3.7GHz/10 core, 16GB RAM, 500GB SSD

    Comment

      #3
      Any ideas on how to view traffic so I can figure out what device it might be?

      Comment

        #4
        you can't view it. but if plm led flashes a lot when you aren't doing anything this may be an indicator.

        make sure you have filters on noisy devices like UPSs, computers, etc that are one the same circuit as the plm.

        There are several threads in this forum about hunting down noisy devices or signal eaters.
        Mark

        HS3 Pro 4.2.19.5
        Hardware: Insteon Serial PLM | AD2USB for Vista Alarm | HAI Omnistat2 | 1-Wire HA7E | RFXrec433 | Dahua Cameras | LiftMaster Internet Gateway | Tuya Smart Plugs
        Plugins: Insteon (mine) | Vista Alarm (mine) | Omnistat 3 | Ultra1Wire3 | RFXCOM | HS MyQ | BLRadar | BLDenon | Tuya | Jon00 Charting | Jon00 Links
        Platform: Windows Server 2022 Standard, i5-12600K/3.7GHz/10 core, 16GB RAM, 500GB SSD

        Comment

          #5
          Sure, I've done all this. It's worked for years up until upgrading to a recent version is what I'm saying. There's four filters on the devices that seem to eat signal, mainly two UPSes, a refrigerator, and a water pump. It was upgrading to a recent plugin beta that seemed to cause the failures. Nothing else has changed.

          I've configured a couple of devices to blink on Insteon traffic, and don't see much when the plugin isn't doing polling.

          I'm grateful for the plugin having worked this long, but having put this much investment into it and all the devices wish there was something that could give a bit of debug beyond just "turn things off until you find out what's causing the failure" and "these devices are 'cheap' and tend to fail every couple of years." I know that's not in your court.

          Comment

            #6
            what about a reset and reprogram on the plm? or a factory reset

            or can you save your current setup/config and rollback to the previous plugin version, and retest
            Mark

            HS3 Pro 4.2.19.5
            Hardware: Insteon Serial PLM | AD2USB for Vista Alarm | HAI Omnistat2 | 1-Wire HA7E | RFXrec433 | Dahua Cameras | LiftMaster Internet Gateway | Tuya Smart Plugs
            Plugins: Insteon (mine) | Vista Alarm (mine) | Omnistat 3 | Ultra1Wire3 | RFXCOM | HS MyQ | BLRadar | BLDenon | Tuya | Jon00 Charting | Jon00 Links
            Platform: Windows Server 2022 Standard, i5-12600K/3.7GHz/10 core, 16GB RAM, 500GB SSD

            Comment

              #7
              btw, I use an AirView9 to see RF traffic on the 915Mhz range when I think I have rf comm issues. I just don't know of anything similar for the powerline other than a scope which don't tend to be cheap. Smarthome has a insteon diag tool, but I've never used it.
              Mark

              HS3 Pro 4.2.19.5
              Hardware: Insteon Serial PLM | AD2USB for Vista Alarm | HAI Omnistat2 | 1-Wire HA7E | RFXrec433 | Dahua Cameras | LiftMaster Internet Gateway | Tuya Smart Plugs
              Plugins: Insteon (mine) | Vista Alarm (mine) | Omnistat 3 | Ultra1Wire3 | RFXCOM | HS MyQ | BLRadar | BLDenon | Tuya | Jon00 Charting | Jon00 Links
              Platform: Windows Server 2022 Standard, i5-12600K/3.7GHz/10 core, 16GB RAM, 500GB SSD

              Comment

              Previous template Next
              Working...
              X