Repeater 'Timed out waiting for IPL acks' messages?

Printable View

02-19-2016, 12:27 PM
wkearney99

Repeater 'Timed out waiting for IPL acks' messages?

I have a RA2 configuration with two main repeaters. I have MONITORING turned all the way up on them both.

They each report this error:

Code:

Timed out waiting for IPL acks. Bitmap of ACKs missed: 00000000 00000000 00000000 08000000

However, NOT at the same time. As in, one repeater emits the error but not the other. Meanwhile the rest of the ~DEVICE and other regular command are output in common. It does not happen in a predictable fashion nor does it appear repeatable. There does not appear to be anything wrong when this occurs.

I ask because I'd like to know if this is the only kind of message that's going to be formatted this way, or if there are other error messages like it that I'd have to catch.

Obviously different MONITORING levels would help avoid this, but I'm poking blind here trying to find out what my code is going to have to avoid, while trying to be effective.
02-22-2016, 01:06 PM
Mike S.

If you are logged in to only 1 Main Reepater are you still receiving any error, if so what errors are your seeing?
02-22-2016, 05:52 PM
wkearney99

I was logged into both, using the serial port on each. I left a session connected today and did not see the IPL error.

I did, however, see this one I've not seen before:

Code:

Diag Error On Line 339 of TCP_worker_task.cppTCP Worker took too long to Check Services

It'd be nice if error messages has some sort of structure to them, akin to how the rest of the protocol functions. Random lines of text appearing in the output are certainly something I can work around, but it adds complexity to code that wouldn't otherwise need it.

The #MONITORING,255,1 log leading up to the above error was:

Code:

FLASH WRITE FLASH WRITE ~SYSTEM,02/22/2016,13:41:43 ~DEVICE,141,2,3 ~OUTPUT,124,1,100.00 ~OUTPUT,124,29,10 ~OUTPUT,124,30,1,100.00 ~GROUP,133,3,3 ~DEVICE,58,86,9,0 ~DEVICE,138,86,9,0 ~DEVICE,130,85,9,0 ~DEVICE,114,2,3 ~GROUP,187,3,255 ~DEVICE,114,2,4 Scene Save message not sent, since nothing has changed from the last grace period level. ~GROUP,187,3,4 ~DEVICE,141,2,4 Scene Save message not sent, since nothing has changed from the last grace period level. ~OUTPUT,124,1,0.00 ~OUTPUT,124,29,11 ~OUTPUT,124,30,1,0.00 ~GROUP,133,3,4 ~DEVICE,58,86,9,1 ~DEVICE,138,86,9,1 ~DEVICE,130,85,9,1 ~DEVICE,168,2,3 Preset ID: 67cb does not pertain to a device on link 0. Do nothing ~OUTPUT,46,1,100.00 ~OUTPUT,46,29,10 ~OUTPUT,46,30,1,100.00 ~GROUP,172,3,3 ~DEVICE,114,2,3 ~GROUP,187,3,255 ~DEVICE,117,2,3 ~OUTPUT,110,1,100.00 ~OUTPUT,110,29,10 ~OUTPUT,110,30,1,100.00 ~GROUP,87,3,3 ~DEVICE,196,4,3 ~ADDRESS,0x00A26E8D ~DEVICE,196,4,4 ~ADDRESS,0x00A26E8D ~OUTPUT,110,1,0.00 ~OUTPUT,110,29,8 ~OUTPUT,110,30,1,0.00 ~DEVICE,168,2,4 Scene Save message not sent, since nothing has changed from the last grace period level. Preset ID: 67cc does not pertain to a device on link 0. Do nothing ~OUTPUT,46,1,0.00 ~OUTPUT,46,29,11 ~OUTPUT,46,30,1,0.00 ~GROUP,172,3,4 ~DEVICE,117,2,4 Scene Save message not sent, since nothing has changed from the last grace period level. ~GROUP,87,3,4 ~TIMECLOCK,53,5,22 ~TIMECLOCK,53,5,3 ~OUTPUT,115,1,50.00 ~OUTPUT,115,29,16 ~OUTPUT,115,30,1,50.00 ~OUTPUT,22,1,25.00 ~OUTPUT,22,29,16 ~OUTPUT,22,30,1,25.00 ~OUTPUT,152,1,50.00 ~OUTPUT,152,29,16 ~OUTPUT,152,30,1,50.00 ~DEVICE,158,83,9,1 ~DEVICE,159,82,9,1 ~OUTPUT,160,1,50.00 ~OUTPUT,160,29,16 ~OUTPUT,160,30,1,50.00 ~OUTPUT,197,1,100.00 ~OUTPUT,197,29,16 ~OUTPUT,197,30,1,100.00 ~DEVICE,58,84,9,1 ~DEVICE,58,86,9,0 ~DEVICE,81,83,9,1 ~DEVICE,138,84,9,1 ~DEVICE,138,86,9,0 ~DEVICE,130,84,9,1 ~DEVICE,130,85,9,0 ~DEVICE,81,84,9,1 ~DEVICE,154,86,9,0 ~DEVICE,102,82,9,1 ~DEVICE,154,82,9,1 ~DEVICE,114,2,4 Scene Save message not sent, since nothing has changed from the last grace period level. ~GROUP,187,3,4 ~DEVICE,114,2,3 ~GROUP,187,3,255 ~DEVICE,114,2,4 Scene Save message not sent, since nothing has changed from the last grace period level. ~GROUP,187,3,4 ~TIMECLOCK,53,5,8 ~TIMECLOCK,53,5,5 ~OUTPUT,115,1,100.00 ~OUTPUT,115,29,16 ~OUTPUT,115,30,1,100.00 ~OUTPUT,22,1,50.00 ~OUTPUT,22,29,16 ~OUTPUT,22,30,1,50.00 ~DEVICE,114,2,3 ~GROUP,187,3,255 ~DEVICE,138,2,3 ~ADDRESS,0x00875584 ~OUTPUT,136,1,100.00 ~OUTPUT,136,29,0 ~OUTPUT,136,30,1,100.00 ~DEVICE,138,82,9,1 ~DEVICE,159,85,9,1 ~DEVICE,117,2,3 ~OUTPUT,110,1,100.00 ~OUTPUT,110,29,10 ~OUTPUT,110,30,1,100.00 ~GROUP,87,3,3 ~DEVICE,114,2,4 Scene Save message not sent, since nothing has changed from the last grace period level. ~GROUP,187,3,4 ~DEVICE,117,2,4 ~OUTPUT,110,1,0.00 ~OUTPUT,110,29,11 ~OUTPUT,110,30,1,0.00 ~GROUP,87,3,4 FLASH WRITE FLASH WRITE ~SYSTEM,02/22/2016,17:37:03 Diag Error On Line 339 of TCP_worker_task.cppTCP Worker took too long to Check Services

There, again, I see something doing a FLASH WRITE again. The rest are just motion sensors and timeclock actions.

I'll open a second serial connection to the other repeater and see if the IPL errors recur.
02-23-2016, 05:16 PM
wkearney99

Ok, I've had two serial connections live to both main repeaters. I have nothing making connections to the Ethernet ports on either of them. Well, nothing other than having the system configured to allow Lutron remote access and the Home+ clients. Neither of which I have used during this interval.

One repeater is sending these messages mixed with the #MONITORING 255,1 results:

Diag Error On Line 339 of TCP_worker_task.cppTCP Worker took too long to Check Services

Diag Error On Line 515 of ipl_handler_incoming_retransmittable_messages.cppA CK not available (

The last one was troubling, though, as it was sent without a trailing CRLF. The next ~DEVICE command was concatenated right on the same line of output.
02-23-2016, 09:40 PM
wkearney99

Here's a dump of what it sent follow the previous post's results. I had to edit out a fair number of lines, as the posting form here doesn't let me exceed 15. What's here are the unusual messages.

Code:

FLASH WRITE FLASH WRITE ~SYSTEM,02/22/2016,18:04:54 FLASH WRITE FLASH WRITE ~SYSTEM,02/22/2016,18:46:09 FLASH WRITE FLASH WRITE ~DEVICE,109,4,3 ~ADDRESS,0x0087BD43 ~OUTPUT,113,1,100.00 ~OUTPUT,113,29,0 ~OUTPUT,113,30,1,100.00 ~DEVICE,109,84,9,1 ~DEVICE,109,3,3 ~ADDRESS,0x0087BD43 ~OUTPUT,106,1,0.00 ~OUTPUT,106,29,0 ~OUTPUT,106,30,1,0.00 ~DEVICE,70,84,9,0 ~OUTPUT,19,1,0.00 ~OUTPUT,19,29,0 ~OUTPUT,19,30,1,0.00 ~DEVICE,109,83,9,0 ~DEVICE,81,82,9,0 ~DEVICE,99,86,9,1 ~DEVICE,109,3,3 ~ADDRESS,0x0087BD43 ~OUTPUT,80,1,50.00 ~OUTPUT,80,29,0 ~OUTPUT,80,30,1,50.00 ~OUTPUT,106,1,100.00 ~OUTPUT,106,29,0 ~OUTPUT,106,30,1,100.00 ~DEVICE,138,85,9,1 ~DEVICE,103,84,9,1 ~OUTPUT,19,1,50.00 ~OUTPUT,19,29,0 ~OUTPUT,19,30,1,50.00 ~DEVICE,109,81,9,1 ~DEVICE,109,83,9,1 ~DEVICE,70,84,9,1 ~DEVICE,109,86,9,1 ~OUTPUT,78,1,100.00 ~OUTPUT,78,29,0 ~OUTPUT,78,30,1,100.00 ~DEVICE,73,82,9,1 ~DEVICE,73,85,9,0 ~DEVICE,81,82,9,1 ~DEVICE,58,85,9,1 ~DEVICE,99,85,9,1 ~DEVICE,99,86,9,0 ~DEVICE,81,81,9,1 ~DEVICE,70,83,9,1 ~SYSTEM,02/22/2016,20:31:52 FLASH WRITE FLASH WRITE ~DEVICE,169,2,3 ~GROUP,27,3,3 ~OUTPUT,83,1,100.00 ~OUTPUT,83,29,10 ~OUTPUT,83,30,1,100.00 ~DEVICE,90,84,9,1 ~DEVICE,180,86,9,0 ~SYSTEM,02/22/2016,20:34:40 Diag Error On Line 339 of TCP_worker_task.cppTCP Worker took too long to Check Services FLASH WRITE FLASH WRITE ~SYSTEM,02/22/2016,20:41:12 FLASH WRITE FLASH WRITE ~SYSTEM,02/22/2016,22:50:18 ~DEVICE,179,2,4 ~GROUP,194,3,4 FLASH WRITE FLASH WRITE ~SYSTEM,02/22/2016,22:59:04 FLASH WRITE FLASH WRITE ~SYSTEM,02/23/2016,00:30:36 ~DEVICE,169,2,4 ~GROUP,27,3,4 ~OUTPUT,83,1,0.00 ~OUTPUT,83,29,11 ~OUTPUT,83,30,1,0.00 ~DEVICE,90,84,9,0 ~DEVICE,180,86,9,1 FLASH WRITE FLASH WRITE ~SYSTEM,02/23/2016,00:31:47 ~DEVICE,90,83,9,0 ~DEVICE,90,86,9,1 ~OUTPUT,94,1,0.00 ~OUTPUT,94,29,0 ~OUTPUT,94,30,1,0.00 ~DEVICE,169,2,3 Timed out waiting for IPL acks. Bitmap of ACKs missed: 40000000 00000000 00000000 00000000 FLASH WRITE FLASH WRITE ~SYSTEM,02/23/2016,00:40:00 Preset ID: 9e05 does not pertain to a device on link 0. Do nothing FLASH WRITE FLASH WRITE Scene Save message not sent, since nothing has changed from the last grace period level. ~TIMECLOCK,53,5,24 ~TIMECLOCK,53,5,11 Bad IP Checksum FLASH WRITE FLASH WRITE ~SYSTEM,02/23/2016,07:05:02 Diag Error On Line 515 of ipl_handler_incoming_retransmittable_messages.cppACK not available~DEVICE,169,2,3 FLASH WRITE FLASH WRITE ~SYSTEM,02/23/2016,07:57:03 FLASH WRITE FLASH WRITE ~SYSTEM,02/23/2016,08:02:20 Diag Error On Line 515 of ipl_handler_incoming_retransmittable_messages.cppACK not available~DEVICE,169,2,3 FLASH WRITE FLASH WRITE ~DEVICE,114,2,3 ~GROUP,187,3,255 ~SYSTEM,02/23/2016,08:37:40 ~DEVICE,169,2,4 ~GROUP,27,3,4 FLASH WRITE FLASH WRITE ~DEVICE,141,2,3 ~OUTPUT,124,1,100.00 ~OUTPUT,124,29,10 ~OUTPUT,124,30,1,100.00 ~GROUP,133,3,3 ~OUTPUT,124,1,0.00 ~OUTPUT,124,29,0 ~OUTPUT,124,30,1,0.00 ~DEVICE,138,6,3 ~ADDRESS,0x00875584 ~OUTPUT,134,1,0.00 ~OUTPUT,134,29,0 ~OUTPUT,134,30,1,0.00 ~OUTPUT,136,1,0.00 ~OUTPUT,136,29,0 ~OUTPUT,136,30,1,0.00 ~DEVICE,138,82,9,0 ~DEVICE,138,83,9,0 ~DEVICE,138,86,9,1 ~DEVICE,103,85,9,0 ~OUTPUT,112,1,0.00 ~OUTPUT,112,29,0 ~OUTPUT,112,30,1,0.00 ~DEVICE,159,85,9,0 ~DEVICE,130,82,9,0 ~DEVICE,109,85,9,0 ~DEVICE,58,81,9,0 ~DEVICE,58,83,9,0 ~DEVICE,130,85,9,1 ~DEVICE,100,86,9,1 ~DEVICE,58,86,9,1 ~DEVICE,81,86,9,0 ~SYSTEM,02/23/2016,08:38:57 FLASH WRITE FLASH WRITE ~SYSTEM,02/23/2016,08:58:46 FLASH WRITE FLASH WRITE Scene Save message not sent, since nothing has changed from the last grace period level. ~TIMECLOCK,53,5,25 ~DEVICE,114,2,3 ~GROUP,187,3,255 ~DEVICE,114,2,4 Scene Save message not sent, since nothing has changed from the last grace period level. ~GROUP,187,3,4 ~DEVICE,141,2,3 ~OUTPUT,124,1,100.00 ~OUTPUT,124,29,10 ~OUTPUT,124,30,1,100.00 ~GROUP,133,3,3 ~DEVICE,58,86,9,0 ~DEVICE,138,86,9,0 ~DEVICE,130,85,9,0 ~DEVICE,102,86,9,0 ~DEVICE,103,86,9,0 ~DEVICE,130,86,9,0 ~DEVICE,159,86,9,0 ~OUTPUT,124,1,0.00 ~OUTPUT,124,29,0 ~OUTPUT,124,30,1,0.00 ~DEVICE,58,86,9,1 ~DEVICE,138,86,9,1 ~DEVICE,130,85,9,1 ~DEVICE,102,86,9,1 ~DEVICE,103,86,9,1 ~DEVICE,130,86,9,1 ~DEVICE,159,86,9,1 ~DEVICE,114,2,3 ~GROUP,187,3,255 ~DEVICE,117,2,3 ~OUTPUT,110,1,100.00 ~OUTPUT,110,29,10 ~OUTPUT,110,30,1,100.00 ~DEVICE,102,86,9,0 ~DEVICE,103,86,9,0 ~DEVICE,130,86,9,0 ~DEVICE,159,86,9,0 ~GROUP,87,3,3 ~DEVICE,171,2,3 ~GROUP,2,3,3 ~OUTPUT,54,1,100.00 ~OUTPUT,54,29,10 ~OUTPUT,54,30,1,100.00 ~OUTPUT,55,1,100.00 ~OUTPUT,55,29,10 ~OUTPUT,55,30,1,100.00 ~DEVICE,69,86,9,0 ~DEVICE,102,85,9,0 ~DEVICE,73,86,9,0 ~DEVICE,114,2,4 Scene Save message not sent, since nothing has changed from the last grace period level. ~GROUP,187,3,4 ~DEVICE,117,2,4 ~OUTPUT,110,1,0.00 ~OUTPUT,110,29,11 ~OUTPUT,110,30,1,0.00 ~GROUP,87,3,4 FLASH WRITE FLASH WRITE ~SYSTEM,02/23/2016,16:13:53 FLASH WRITE FLASH WRITE FLASH WRITE FLASH WRITE ~SYSTEM,02/23/2016,16:15:29 FLASH WRITE FLASH WRITE ~SYSTEM,02/23/2016,17:04:53

I'd really like some insight as to what's calling for the FLASH WRITE results.

At some point I do plan on reducing the amount of output coming from the repeaters. I likely won't need the full amount that's coming now. But it has been insightful regarding how much additional code is going to be necessary to work around potential issues with the repeaters. Any project would need some, so this isn't unusual.
02-24-2016, 12:48 PM
Mike S.

FLASH WRITE is not a command that is used for integration and should be ignored by 3rd party systems.
02-28-2016, 08:42 AM
wkearney99

Repeatability is always important when testing. As is being methodical when changing elements involved in testing. I switched the ethernet cables going into the repeaters. Literally unplugged the cables from the repeaters and swapped them. Leaving the switch end still plugged into their same network ports.

Here's the 1st repeater's log during the swap:

Code:

NetBIOS name GULLIVER already taken NetBIOS name GULLIVER already taken NetBIOS name GULLIVER already taken Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 511 of http_private.cppTimeout sending http data. Terminating connection Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered

Then regular MONITORING output resumed.

Here's the 2nd repeater's log during the swap:

Code:

Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered Diag Error On Line 1341 of ethernet_tcp.cpp Port is not registered

And likewise, regular MONITORING output followed.

Curiously, at first glance it would appear the network errors are following the cable. Could be on to something here. I'll leave things connected this way and see if the errors continue to follow the cables. If so, the next step would be to swap out the 'suspect' cable and again watch for the errors. If they persist then I'll use a different port on the switch. It's an unmanaged switch, so it's not like I can check port statistics.

Meanwhile, what's GULLIVER and why does it think it needs to assign a NETBIOS name? Curiouser still, if I 'nbtstat -A 192.168.12.7' (the IP address of this repeater) from a PC elsewhere on the network the repeater log dumps:

Code:

NetBIOS data not for us NetBIOS data not for us NetBIOS data not for us

Right, so that's probably not relevant to anything regarding the repeater and interfacing to it, other than to know it's one of the many extra things the repeater might spit out when being monitored. I've got 30+ years experience with networks, when I start seeing NetBIOS error messages I get flashbacks to some VERY problematic setups. I'll just ignore those, for now.