From: Kevin R. K. <ke...@kr...> - 2013-02-23 02:51:02
|
Michael, So a number of the subs that you have in ALDB_i2 are nearly identical to the same subs in ALDB_i1. As I am sure you know, in some the only different is the print_log output. This even includes large complicated subs such as delete_orphan_links. Are you considering moving the nearly identical subs up into Insteon::AllLinkDatabase? Otherwise I am concerned that we will be forced to update fixes in two places. Kevin |
From: Michael S. <mi...@st...> - 2013-02-23 13:30:29
|
Hi Kevin, Are you considering moving the nearly identical subs up into Insteon::AllLinkDatabase? For sure. I intentionally duplicated the i1 functions and then carefully modified them in the most minimal ways. The intention all along is to collapse many of them into the base allLinkDatabase class. I'm only waiting to stabilize the i2 features. My goal was to avoid complaints about breaking the i1 code. I knew the i1 code was unstable and didn't want to be the last person to touch it <http://www.netfunny.com/rhf/jokes/94q2/probsolveflow.html> J Luckily for me you have done a tremendous job of cleaning up the i1 logic and made both significantly better in the process. I just need to decide when it is the right time to pull it all together. For now I've been watching changes you check in to hollie/master for the common functions and duplicating them. Do you think I should merge them now? Sincerely, Michael. From: Kevin Robert Keegan [mailto:ke...@kr...] Sent: Friday, February 22, 2013 8:51 PM To: The main list for the MisterHouse home automation program Subject: [mh] Insteon: i2_aldb_support combine nearly identical aldb sub routines Michael, So a number of the subs that you have in ALDB_i2 are nearly identical to the same subs in ALDB_i1. As I am sure you know, in some the only different is the print_log output. This even includes large complicated subs such as delete_orphan_links. Are you considering moving the nearly identical subs up into Insteon::AllLinkDatabase? Otherwise I am concerned that we will be forced to update fixes in two places. Kevin |
From: Kevin R. K. <ke...@kr...> - 2013-02-23 16:46:17
|
Ah, good. The only issues I am having with the i2cs code seem to be caused by my own stupidity. Everything else seems to be working fine. Is Marc still having problems? It may be about time to merge it all. The bummer is that all of the aldb delta stuff will not merge if we move whole sub routines. Do we need to merge the aldb delta work into your i2 code as it is now. And then move everything? The checks for preventing mh from writing to a device that is out of sync are in add_link delete_link update_link. On Feb 23, 2013 5:30 AM, "Michael Stovenour" <mi...@st...> wrote: > Hi Kevin, **** > > ** ** > > Are you considering moving the nearly identical subs up > into Insteon::AllLinkDatabase?**** > > ** ** > > For sure. I intentionally duplicated the i1 functions and then carefully > modified them in the most minimal ways. The intention all along is to > collapse many of them into the base allLinkDatabase class. I’m only > waiting to stabilize the i2 features. My goal was to avoid complaints > about breaking the i1 code. I knew the i1 code was unstable and didn’t > want to be the last person to touch it<http://www.netfunny.com/rhf/jokes/94q2/probsolveflow.html> > J Luckily for me you have done a tremendous job of cleaning up the i1 > logic and made both significantly better in the process. I just need to > decide when it is the right time to pull it all together. For now I’ve > been watching changes you check in to hollie/master for the common > functions and duplicating them.**** > > ** ** > > Do you think I should merge them now?**** > > ** ** > > Sincerely, > Michael. **** > > ** ** > > *From:* Kevin Robert Keegan [mailto:ke...@kr...] > *Sent:* Friday, February 22, 2013 8:51 PM > *To:* The main list for the MisterHouse home automation program > *Subject:* [mh] Insteon: i2_aldb_support combine nearly identical aldb > sub routines**** > > ** ** > > Michael,**** > > ** ** > > So a number of the subs that you have in ALDB_i2 are nearly identical to > the same subs in ALDB_i1. As I am sure you know, in some the only > different is the print_log output. This even includes large complicated > subs such as delete_orphan_links.**** > > ** ** > > Are you considering moving the nearly identical subs up > into Insteon::AllLinkDatabase? Otherwise I am concerned that we will be > forced to update fixes in two places.**** > > ** ** > > Kevin**** > |
From: Michael S. <mi...@st...> - 2013-02-23 17:13:19
|
From: Kevin Robert Keegan [mailto:ke...@kr...] Sent: Saturday, February 23, 2013 10:46 AM To: Michael Stovenour Cc: The main list for the MisterHouse home automation program Subject: RE: [mh] Insteon: i2_aldb_support combine nearly identical aldb sub routines Ah, good. The only issues I am having with the i2cs code seem to be caused by my own stupidity. Everything else seems to be working fine. Is Marc still having problems? [Michael Stovenour] I think he will if he tries it. There is still an issue with the command timer that I need to diagnose. It may be about time to merge it all. [Michael Stovenour] I tend to think we should wait until I figure out the command timeout issue I'm seeing. (Ironically the other issue I'm having that pegs the hop counts at 3 is causing a lot of duplicate and dropped messages which easily reproduces Marc's environment) The bummer is that all of the aldb delta stuff will not merge if we move whole sub routines. Do we need to merge the aldb delta work into your i2 code as it is now. And then move everything? The checks for preventing mh from writing to a device that is out of sync are in add_link delete_link update_link. [Michael Stovenour] Yes I think merging your code into the ALDB_i1 routines first is the best bet. I'll then be able to clearly see the changes between i1 and i2 with a visual diff of the functions. On Feb 23, 2013 5:30 AM, "Michael Stovenour" <mi...@st...> wrote: Hi Kevin, Are you considering moving the nearly identical subs up into Insteon::AllLinkDatabase? For sure. I intentionally duplicated the i1 functions and then carefully modified them in the most minimal ways. The intention all along is to collapse many of them into the base allLinkDatabase class. I'm only waiting to stabilize the i2 features. My goal was to avoid complaints about breaking the i1 code. I knew the i1 code was unstable and didn't want to be the last person to touch it <http://www.netfunny.com/rhf/jokes/94q2/probsolveflow.html> J Luckily for me you have done a tremendous job of cleaning up the i1 logic and made both significantly better in the process. I just need to decide when it is the right time to pull it all together. For now I've been watching changes you check in to hollie/master for the common functions and duplicating them. Do you think I should merge them now? Sincerely, Michael. From: Kevin Robert Keegan [mailto:ke...@kr...] Sent: Friday, February 22, 2013 8:51 PM To: The main list for the MisterHouse home automation program Subject: [mh] Insteon: i2_aldb_support combine nearly identical aldb sub routines Michael, So a number of the subs that you have in ALDB_i2 are nearly identical to the same subs in ALDB_i1. As I am sure you know, in some the only different is the print_log output. This even includes large complicated subs such as delete_orphan_links. Are you considering moving the nearly identical subs up into Insteon::AllLinkDatabase? Otherwise I am concerned that we will be forced to update fixes in two places. Kevin |
From: Marc M. <ma...@me...> - 2013-02-23 23:06:12
|
On Sat, Feb 23, 2013 at 11:14:17AM -0600, Michael Stovenour wrote: > Is Marc still having problems? > > [Michael Stovenour] I think he will if he tries it. There is still an issue with the > command timer that I need to diagnose. Yeah, I didn't try anything new yet, since it didn't seem that all the problem I had had been solved yet. Michael also wanted me to keep my broken network so that I could validate that his new code fixes the issues. But if you'd like me to try one of the trees (official, or Michael's), let me know. Marc -- "A mouse is a device used to point at the xterm you want to type in" - A.S.R. Microsoft is to operating systems .... .... what McDonalds is to gourmet cooking Home page: http://marc.merlins.org/ |
From: Michael S. <mi...@st...> - 2013-02-26 15:09:22
|
On Feb 23, 2013 5:06 PM Marc wrote, > > On Sat, Feb 23, 2013 at 11:14:17AM -0600, Michael Stovenour wrote: > > Is Marc still having problems? > > > > [Michael Stovenour] I think he will if he tries it. There is still an issue with the > > command timer that I need to diagnose. > > Yeah, I didn't try anything new yet, since it didn't seem that all the > problem I had had been solved yet. Michael also wanted me to keep my broken > network so that I could validate that his new code fixes the issues. > But if you'd like me to try one of the trees (official, or Michael's), let > me know. Would you mind pulling my latest i2_aldb_support branch updates then trying the PLM scan all device link tables? I think there is still a command timeout issue if messages arrive out of order (due to retransmissions) but I can't reproduce it here. If you don't get a final message like the one below then the scan didn't complete normally. [Scan all link tables] All tables have completed scanning If you can reproduce the failure I'll push some more code with a bunch of debug logging. Otherwise we might just move on for now and revisit it later. Sincerely, Michael |
From: Marc M. <ma...@me...> - 2013-02-27 01:18:46
|
On Tue, Feb 26, 2013 at 08:59:59AM -0600, Michael Stovenour wrote: > Would you mind pulling my latest i2_aldb_support branch updates then trying the PLM scan > all device link tables? I think there is still a command timeout issue if messages arrive > out of order (due to retransmissions) but I can't reproduce it here. If you don't get a > final message like the one below then the scan didn't complete normally. > > [Scan all link tables] All tables have completed scanning > > If you can reproduce the failure I'll push some more code with a bunch of debug logging. > Otherwise we might just move on for now and revisit it later. Sure thing, there you go. I'm wondering if you merge your code with Kevin's hop count code whether that will work around the problem, but indeed there is still a problem. First scan failed in the middle with: 26/02/2013 12:51:33 [Scan all link tables] Now scanning: $br2_lamp (7 of 27) 26/02/2013 12:51:34 [Insteon::ALDB_i2] DEBUG4: Start of scan; initializing aldb structure 26/02/2013 12:51:36 [Insteon::ALDB_i2] DEBUG4: scan done; adding last address [0fe7] to empty array 26/02/2013 12:51:36 [Insteon::ALDB_i2] $br2_lamp completed aldb scan: status: good 26/02/2013 12:51:36 [Scan all link tables] Now scanning: $fmr_kpl (8 of 27) 26/02/2013 12:51:37 [Insteon::ALDB_i2] DEBUG3: $br2_lamp [0x0fe7] received: 0001010fe701000000000000000000 for _mem_activity= _mem_action= 26/02/2013 12:51:37 [Insteon::ALDB_i2] $br2_lamp: unhandled _mem_action= 26/02/2013 12:51:58 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:16 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:23 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:34 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:51 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:52 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:53 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:57 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:53:15 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:53:16 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:53:22 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:53:53 [Scan all link tables] Now scanning: $fmr_slav (9 of 27) 26/02/2013 12:53:54 [Insteon::ALDB_i2] DEBUG4: Start of scan; initializing aldb structure 26/02/2013 12:53:55 [Insteon::ALDB_i2] DEBUG3: $fmr_slav [0x0fef] ack not received. ignoring message 26/02/2013 12:54:31 Running: PLM scan all device link tables 26/02/2013 12:54:31 [Scan all linktables] WARN: link already underway. Ignoring request for new scan ... full log here: http://marc.merlins.org/tmp/print.log.scanfailed Second scan, I'm not sure how it failed: 26/02/2013 12:57:05 [Scan all link tables] Now scanning: $PLM (1 of 27) 26/02/2013 12:57:48 [Scan all link tables] Now scanning: $mbr_kpl (2 of 27) 26/02/2013 12:58:36 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $mbr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:58:40 [Scan all link tables] Now scanning: $mbr_lamp2 (3 of 27) 26/02/2013 12:58:41 [Insteon::ALDB_i2] DEBUG4: Start of scan; initializing aldb structure 26/02/2013 12:58:44 [Insteon::ALDB_i2] DEBUG3: $mbr_lamp2 [0x0fd7] ack not received. ignoring message 26/02/2013 13:00:00 Running: AllDevices Scan 26/02/2013 13:00:26 Running: compcloset fan on 26/02/2013 13:02:00 Running: AllDevices Status full log here: http://marc.merlins.org/tmp/print.log.scanfailed2 And I then went back to git master, and did a full scan that completed. Kevin, on the plus side your code changes in master have been working for me so far. Actually I had issues getting a scan to completion and your new hop count seems to help: 26/02/2013 16:31:44 Running: PLM scan all device link tables 26/02/2013 16:31:44 [Scan all link tables] Now scanning: $PLM (1 of 27) 26/02/2013 16:32:00 Running: AllDevices Status 26/02/2013 16:32:27 [Scan all link tables] Now scanning: $mbr_kpl (2 of 27) 26/02/2013 16:33:19 [Scan all link tables] Now scanning: $mbr_lamp2 (3 of 27) 26/02/2013 16:33:33 [Scan all link tables] Now scanning: $mbr_lamp3 (4 of 27) 26/02/2013 16:33:41 [Scan all link tables] Now scanning: $mbr_outside (5 of 27) 26/02/2013 16:33:52 [Scan all link tables] Now scanning: $br2_sw (6 of 27) 26/02/2013 16:34:08 [Scan all link tables] Now scanning: $br2_lamp (7 of 27) 26/02/2013 16:34:14 [Scan all link tables] Now scanning: $fmr_kpl (8 of 27) 26/02/2013 16:34:41 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:34:58 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:35:22 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:36:34 [Scan all link tables] Now scanning: $fmr_slav (9 of 27) 26/02/2013 16:36:34 [Scan all link tables] Now scanning: $fmr_lamp (10 of 27) 26/02/2013 16:37:04 [Scan all link tables] Now scanning: $fmr_outside (11 of 27) 26/02/2013 16:37:27 [Scan all link tables] Now scanning: $entryway (12 of 27) 26/02/2013 16:37:55 [Scan all link tables] Now scanning: $lvr_kpl (13 of 27) 26/02/2013 16:39:01 [Insteon_PLM] DEBUG2: PLM command timer expired but no transmission in place. Moving on... 26/02/2013 16:40:32 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:40:33 [Insteon::BaseMessage] WARN: now resending obj=$lvr_kpl; command=peek; extra=4F after 1 attempts. 26/02/2013 16:41:32 [Scan all link tables] Now scanning: $lvr_lamp (14 of 27) 26/02/2013 16:41:40 [Insteon::BaseInterface] WARN: received a message from $lvr_lamp in response to a peek command, but the command code d4 is incorrect. Ignorring received message. 26/02/2013 16:41:44 [Scan all link tables] Now scanning: $yard_lights (15 of 27) 26/02/2013 16:41:44 [Insteon::BaseInterface] Warn! Unable to locate object for source: 0a99e6 and group: 26/02/2013 16:41:59 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $yard_lights but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:42:02 [Scan all link tables] Now scanning: $kitchen_kpl (16 of 27) 26/02/2013 16:43:16 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:43:16 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:43:33 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:43:34 [Insteon::BaseMessage] WARN: now resending obj=$kitchen_kpl; command=peek; extra=F6 after 1 attempts. 26/02/2013 16:44:14 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:45:00 Running: AllDevices Scan 26/02/2013 16:45:38 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:46:25 [Scan all link tables] Now scanning: $dining_kpl (17 of 27) 26/02/2013 16:46:28 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:46:29 [Insteon::BaseMessage] WARN: now resending obj=$dining_kpl; command=peek; extra=F0 after 1 attempts. 26/02/2013 16:47:00 Running: AllDevices Status 26/02/2013 16:49:31 [Insteon::BaseMessage] WARN: now resending obj=$dining_kpl; command=peek; extra=96 after 1 attempts. 26/02/2013 16:49:35 [Insteon::BaseMessage] WARN: now resending obj=$dining_kpl; command=peek; extra=96 after 2 attempts. 26/02/2013 16:49:58 [Scan all link tables] Now scanning: $garage1_neon_kpl (19 of 27) 26/02/2013 16:51:09 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:51:10 [Insteon::BaseMessage] WARN: now resending obj=$garage1_neon_kpl; command=peek; extra=43 after 1 attempts. 26/02/2013 16:52:03 [Scan all link tables] Now scanning: $garage2_neon_kpl (20 of 27) 26/02/2013 16:52:15 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:52:16 [Insteon::BaseMessage] WARN: now resending obj=$garage2_neon_kpl; command=peek; extra=ED after 1 attempts. 26/02/2013 16:52:34 [Insteon::BaseInterface] WARN: received a message from $garage2_neon_kpl in response to a set_address_msb command, but the command code 2b is incorrect. Ignorring received message. 26/02/2013 16:52:53 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:52:54 [Insteon::BaseMessage] WARN: now resending obj=$garage2_neon_kpl; command=peek; extra=91 after 1 attempts. 26/02/2013 16:53:10 [Scan all link tables] Now scanning: $gar_outlights_kpl (21 of 27) 26/02/2013 16:54:02 [Scan all link tables] Now scanning: $iolinc_gardoor2 (22 of 27) 26/02/2013 16:54:07 [Scan all link tables] Now scanning: $iolinc_garside (23 of 27) 26/02/2013 16:54:11 [Scan all link tables] Now scanning: $fan_fmr (24 of 27) 26/02/2013 16:54:12 [Scan all link tables] Now scanning: $fan_mbr (25 of 27) 26/02/2013 16:54:12 [Scan all link tables] Now scanning: $fan_gar_roof (26 of 27) 26/02/2013 16:54:13 [Scan all link tables] Now scanning: $fan_gar_ceiling (27 of 27) 26/02/2013 16:54:14 [Scan all link tables] All tables have completed scanning full log here: http://marc.merlins.org/tmp/print.log.scanok Hope this helps. Marc -- "A mouse is a device used to point at the xterm you want to type in" - A.S.R. Microsoft is to operating systems .... .... what McDonalds is to gourmet cooking Home page: http://marc.merlins.org/ |
From: Kevin R. K. <ke...@kr...> - 2013-02-27 05:47:07
|
OK, so I looked at the first failure. Michael, I think I understand what you mean by out of sequence messages. I see that the link data packet arrives before the ack. You have the code set to ignore link data packets that arrive before the ack message. Then the ack arrives and nothing happens. I am surmising that something is clearing the current_message including the timeout(command). I see this line in _process_command that allows an ACK message to clear the current message: if (substr($msg{extra},4,2) eq '01') { It looks like all of the ACKs have 00 for cmd2. As a result, it looks like ACKs are clearing messages. On Tue, Feb 26, 2013 at 5:17 PM, Marc MERLIN <ma...@me...> wrote: > On Tue, Feb 26, 2013 at 08:59:59AM -0600, Michael Stovenour wrote: > > Would you mind pulling my latest i2_aldb_support branch updates then > trying the PLM scan > > all device link tables? I think there is still a command timeout issue > if messages arrive > > out of order (due to retransmissions) but I can't reproduce it here. If > you don't get a > > final message like the one below then the scan didn't complete normally. > > > > [Scan all link tables] All tables have completed scanning > > > > If you can reproduce the failure I'll push some more code with a bunch > of debug logging. > > Otherwise we might just move on for now and revisit it later. > > Sure thing, there you go. > > I'm wondering if you merge your code with Kevin's hop count code whether > that will work > around the problem, but indeed there is still a problem. > > First scan failed in the middle with: > 26/02/2013 12:51:33 [Scan all link tables] Now scanning: $br2_lamp (7 of > 27) > 26/02/2013 12:51:34 [Insteon::ALDB_i2] DEBUG4: Start of scan; > initializing aldb structure > 26/02/2013 12:51:36 [Insteon::ALDB_i2] DEBUG4: scan done; adding last > address [0fe7] to empty array > 26/02/2013 12:51:36 [Insteon::ALDB_i2] $br2_lamp completed aldb scan: > status: good > 26/02/2013 12:51:36 [Scan all link tables] Now scanning: $fmr_kpl (8 of > 27) > 26/02/2013 12:51:37 [Insteon::ALDB_i2] DEBUG3: $br2_lamp [0x0fe7] > received: 0001010fe701000000000000000000 for _mem_activity= _mem_action= > 26/02/2013 12:51:37 [Insteon::ALDB_i2] $br2_lamp: unhandled _mem_action= > 26/02/2013 12:51:58 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:16 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:23 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:34 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:51 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:52 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:53 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:57 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:53:15 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:53:16 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:53:22 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:53:53 [Scan all link tables] Now scanning: $fmr_slav (9 of > 27) > 26/02/2013 12:53:54 [Insteon::ALDB_i2] DEBUG4: Start of scan; > initializing aldb structure > 26/02/2013 12:53:55 [Insteon::ALDB_i2] DEBUG3: $fmr_slav [0x0fef] ack not > received. ignoring message > 26/02/2013 12:54:31 Running: PLM scan all device link tables > 26/02/2013 12:54:31 [Scan all linktables] WARN: link already underway. > Ignoring request for new scan ... > > full log here: http://marc.merlins.org/tmp/print.log.scanfailed > > > Second scan, I'm not sure how it failed: > 26/02/2013 12:57:05 [Scan all link tables] Now scanning: $PLM (1 of 27) > 26/02/2013 12:57:48 [Scan all link tables] Now scanning: $mbr_kpl (2 of > 27) > 26/02/2013 12:58:36 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $mbr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:58:40 [Scan all link tables] Now scanning: $mbr_lamp2 (3 of > 27) > 26/02/2013 12:58:41 [Insteon::ALDB_i2] DEBUG4: Start of scan; > initializing aldb structure > 26/02/2013 12:58:44 [Insteon::ALDB_i2] DEBUG3: $mbr_lamp2 [0x0fd7] ack > not received. ignoring message > 26/02/2013 13:00:00 Running: AllDevices Scan > 26/02/2013 13:00:26 Running: compcloset fan on > 26/02/2013 13:02:00 Running: AllDevices Status > > full log here: http://marc.merlins.org/tmp/print.log.scanfailed2 > > And I then went back to git master, and did a full scan that completed. > Kevin, on the plus side your code changes in master have been working for > me so far. Actually > I had issues getting a scan to completion and your new hop count seems to > help: > > 26/02/2013 16:31:44 Running: PLM scan all device link tables > 26/02/2013 16:31:44 [Scan all link tables] Now scanning: $PLM (1 of 27) > 26/02/2013 16:32:00 Running: AllDevices Status > 26/02/2013 16:32:27 [Scan all link tables] Now scanning: $mbr_kpl (2 of > 27) > 26/02/2013 16:33:19 [Scan all link tables] Now scanning: $mbr_lamp2 (3 of > 27) > 26/02/2013 16:33:33 [Scan all link tables] Now scanning: $mbr_lamp3 (4 of > 27) > 26/02/2013 16:33:41 [Scan all link tables] Now scanning: $mbr_outside (5 > of 27) > 26/02/2013 16:33:52 [Scan all link tables] Now scanning: $br2_sw (6 of 27) > 26/02/2013 16:34:08 [Scan all link tables] Now scanning: $br2_lamp (7 of > 27) > 26/02/2013 16:34:14 [Scan all link tables] Now scanning: $fmr_kpl (8 of > 27) > 26/02/2013 16:34:41 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:34:58 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:35:22 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:36:34 [Scan all link tables] Now scanning: $fmr_slav (9 of > 27) > 26/02/2013 16:36:34 [Scan all link tables] Now scanning: $fmr_lamp (10 of > 27) > 26/02/2013 16:37:04 [Scan all link tables] Now scanning: $fmr_outside (11 > of 27) > 26/02/2013 16:37:27 [Scan all link tables] Now scanning: $entryway (12 of > 27) > 26/02/2013 16:37:55 [Scan all link tables] Now scanning: $lvr_kpl (13 of > 27) > 26/02/2013 16:39:01 [Insteon_PLM] DEBUG2: PLM command timer expired but > no transmission in place. Moving on... > 26/02/2013 16:40:32 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:40:33 [Insteon::BaseMessage] WARN: now resending > obj=$lvr_kpl; command=peek; extra=4F after 1 attempts. > 26/02/2013 16:41:32 [Scan all link tables] Now scanning: $lvr_lamp (14 of > 27) > 26/02/2013 16:41:40 [Insteon::BaseInterface] WARN: received a message > from $lvr_lamp in response to a peek command, but the command code d4 is > incorrect. Ignorring received message. > 26/02/2013 16:41:44 [Scan all link tables] Now scanning: $yard_lights (15 > of 27) > 26/02/2013 16:41:44 [Insteon::BaseInterface] Warn! Unable to locate > object for source: 0a99e6 and group: > 26/02/2013 16:41:59 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $yard_lights but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:42:02 [Scan all link tables] Now scanning: $kitchen_kpl (16 > of 27) > 26/02/2013 16:43:16 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:43:16 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:43:33 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:43:34 [Insteon::BaseMessage] WARN: now resending > obj=$kitchen_kpl; command=peek; extra=F6 after 1 attempts. > 26/02/2013 16:44:14 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:45:00 Running: AllDevices Scan > 26/02/2013 16:45:38 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:46:25 [Scan all link tables] Now scanning: $dining_kpl (17 > of 27) > 26/02/2013 16:46:28 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:46:29 [Insteon::BaseMessage] WARN: now resending > obj=$dining_kpl; command=peek; extra=F0 after 1 attempts. > 26/02/2013 16:47:00 Running: AllDevices Status > 26/02/2013 16:49:31 [Insteon::BaseMessage] WARN: now resending > obj=$dining_kpl; command=peek; extra=96 after 1 attempts. > 26/02/2013 16:49:35 [Insteon::BaseMessage] WARN: now resending > obj=$dining_kpl; command=peek; extra=96 after 2 attempts. > 26/02/2013 16:49:58 [Scan all link tables] Now scanning: > $garage1_neon_kpl (19 of 27) > 26/02/2013 16:51:09 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:51:10 [Insteon::BaseMessage] WARN: now resending > obj=$garage1_neon_kpl; command=peek; extra=43 after 1 attempts. > 26/02/2013 16:52:03 [Scan all link tables] Now scanning: > $garage2_neon_kpl (20 of 27) > 26/02/2013 16:52:15 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:52:16 [Insteon::BaseMessage] WARN: now resending > obj=$garage2_neon_kpl; command=peek; extra=ED after 1 attempts. > 26/02/2013 16:52:34 [Insteon::BaseInterface] WARN: received a message > from $garage2_neon_kpl in response to a set_address_msb command, but the > command code 2b is incorrect. Ignorring received message. > 26/02/2013 16:52:53 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:52:54 [Insteon::BaseMessage] WARN: now resending > obj=$garage2_neon_kpl; command=peek; extra=91 after 1 attempts. > 26/02/2013 16:53:10 [Scan all link tables] Now scanning: > $gar_outlights_kpl (21 of 27) > 26/02/2013 16:54:02 [Scan all link tables] Now scanning: $iolinc_gardoor2 > (22 of 27) > 26/02/2013 16:54:07 [Scan all link tables] Now scanning: $iolinc_garside > (23 of 27) > 26/02/2013 16:54:11 [Scan all link tables] Now scanning: $fan_fmr (24 of > 27) > 26/02/2013 16:54:12 [Scan all link tables] Now scanning: $fan_mbr (25 of > 27) > 26/02/2013 16:54:12 [Scan all link tables] Now scanning: $fan_gar_roof > (26 of 27) > 26/02/2013 16:54:13 [Scan all link tables] Now scanning: $fan_gar_ceiling > (27 of 27) > 26/02/2013 16:54:14 [Scan all link tables] All tables have completed > scanning > > full log here: http://marc.merlins.org/tmp/print.log.scanok > > Hope this helps. > > Marc > -- > "A mouse is a device used to point at the xterm you want to type in" - > A.S.R. > Microsoft is to operating systems .... > .... what McDonalds is to gourmet > cooking > Home page: http://marc.merlins.org/ > |
From: Michael S. <mi...@st...> - 2013-02-27 17:26:29
|
Nice catch. I'll look at this tonight when I get home. From: Kevin Robert Keegan [mailto:ke...@kr...] Sent: Tuesday, February 26, 2013 11:46 PM To: Marc MERLIN Cc: Michael Stovenour; The main list for the MisterHouse home automation program Subject: Re: [mh] Insteon: i2_aldb_support combine nearly identical aldb sub routines OK, so I looked at the first failure. Michael, I think I understand what you mean by out of sequence messages. I see that the link data packet arrives before the ack. You have the code set to ignore link data packets that arrive before the ack message. Then the ack arrives and nothing happens. I am surmising that something is clearing the current_message including the timeout(command). I see this line in _process_command that allows an ACK message to clear the current message: if (substr($msg{extra},4,2) eq '01') { It looks like all of the ACKs have 00 for cmd2. As a result, it looks like ACKs are clearing messages. On Tue, Feb 26, 2013 at 5:17 PM, Marc MERLIN <ma...@me...> wrote: On Tue, Feb 26, 2013 at 08:59:59AM -0600, Michael Stovenour wrote: > Would you mind pulling my latest i2_aldb_support branch updates then trying the PLM scan > all device link tables? I think there is still a command timeout issue if messages arrive > out of order (due to retransmissions) but I can't reproduce it here. If you don't get a > final message like the one below then the scan didn't complete normally. > > [Scan all link tables] All tables have completed scanning > > If you can reproduce the failure I'll push some more code with a bunch of debug logging. > Otherwise we might just move on for now and revisit it later. Sure thing, there you go. I'm wondering if you merge your code with Kevin's hop count code whether that will work around the problem, but indeed there is still a problem. First scan failed in the middle with: 26/02/2013 12:51:33 [Scan all link tables] Now scanning: $br2_lamp (7 of 27) 26/02/2013 12:51:34 [Insteon::ALDB_i2] DEBUG4: Start of scan; initializing aldb structure 26/02/2013 12:51:36 [Insteon::ALDB_i2] DEBUG4: scan done; adding last address [0fe7] to empty array 26/02/2013 12:51:36 [Insteon::ALDB_i2] $br2_lamp completed aldb scan: status: good 26/02/2013 12:51:36 [Scan all link tables] Now scanning: $fmr_kpl (8 of 27) 26/02/2013 12:51:37 [Insteon::ALDB_i2] DEBUG3: $br2_lamp [0x0fe7] received: 0001010fe701000000000000000000 for _mem_activity= _mem_action= 26/02/2013 12:51:37 [Insteon::ALDB_i2] $br2_lamp: unhandled _mem_action= 26/02/2013 12:51:58 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:16 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:23 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:34 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:51 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:52 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:53 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:52:57 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:53:15 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:53:16 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:53:22 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:53:53 [Scan all link tables] Now scanning: $fmr_slav (9 of 27) 26/02/2013 12:53:54 [Insteon::ALDB_i2] DEBUG4: Start of scan; initializing aldb structure 26/02/2013 12:53:55 [Insteon::ALDB_i2] DEBUG3: $fmr_slav [0x0fef] ack not received. ignoring message 26/02/2013 12:54:31 Running: PLM scan all device link tables 26/02/2013 12:54:31 [Scan all linktables] WARN: link already underway. Ignoring request for new scan ... full log here: http://marc.merlins.org/tmp/print.log.scanfailed Second scan, I'm not sure how it failed: 26/02/2013 12:57:05 [Scan all link tables] Now scanning: $PLM (1 of 27) 26/02/2013 12:57:48 [Scan all link tables] Now scanning: $mbr_kpl (2 of 27) 26/02/2013 12:58:36 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $mbr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 12:58:40 [Scan all link tables] Now scanning: $mbr_lamp2 (3 of 27) 26/02/2013 12:58:41 [Insteon::ALDB_i2] DEBUG4: Start of scan; initializing aldb structure 26/02/2013 12:58:44 [Insteon::ALDB_i2] DEBUG3: $mbr_lamp2 [0x0fd7] ack not received. ignoring message 26/02/2013 13:00:00 Running: AllDevices Scan 26/02/2013 13:00:26 Running: compcloset fan on 26/02/2013 13:02:00 Running: AllDevices Status full log here: http://marc.merlins.org/tmp/print.log.scanfailed2 And I then went back to git master, and did a full scan that completed. Kevin, on the plus side your code changes in master have been working for me so far. Actually I had issues getting a scan to completion and your new hop count seems to help: 26/02/2013 16:31:44 Running: PLM scan all device link tables 26/02/2013 16:31:44 [Scan all link tables] Now scanning: $PLM (1 of 27) 26/02/2013 16:32:00 Running: AllDevices Status 26/02/2013 16:32:27 [Scan all link tables] Now scanning: $mbr_kpl (2 of 27) 26/02/2013 16:33:19 [Scan all link tables] Now scanning: $mbr_lamp2 (3 of 27) 26/02/2013 16:33:33 [Scan all link tables] Now scanning: $mbr_lamp3 (4 of 27) 26/02/2013 16:33:41 [Scan all link tables] Now scanning: $mbr_outside (5 of 27) 26/02/2013 16:33:52 [Scan all link tables] Now scanning: $br2_sw (6 of 27) 26/02/2013 16:34:08 [Scan all link tables] Now scanning: $br2_lamp (7 of 27) 26/02/2013 16:34:14 [Scan all link tables] Now scanning: $fmr_kpl (8 of 27) 26/02/2013 16:34:41 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:34:58 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:35:22 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:36:34 [Scan all link tables] Now scanning: $fmr_slav (9 of 27) 26/02/2013 16:36:34 [Scan all link tables] Now scanning: $fmr_lamp (10 of 27) 26/02/2013 16:37:04 [Scan all link tables] Now scanning: $fmr_outside (11 of 27) 26/02/2013 16:37:27 [Scan all link tables] Now scanning: $entryway (12 of 27) 26/02/2013 16:37:55 [Scan all link tables] Now scanning: $lvr_kpl (13 of 27) 26/02/2013 16:39:01 [Insteon_PLM] DEBUG2: PLM command timer expired but no transmission in place. Moving on... 26/02/2013 16:40:32 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:40:33 [Insteon::BaseMessage] WARN: now resending obj=$lvr_kpl; command=peek; extra=4F after 1 attempts. 26/02/2013 16:41:32 [Scan all link tables] Now scanning: $lvr_lamp (14 of 27) 26/02/2013 16:41:40 [Insteon::BaseInterface] WARN: received a message from $lvr_lamp in response to a peek command, but the command code d4 is incorrect. Ignorring received message. 26/02/2013 16:41:44 [Scan all link tables] Now scanning: $yard_lights (15 of 27) 26/02/2013 16:41:44 [Insteon::BaseInterface] Warn! Unable to locate object for source: 0a99e6 and group: 26/02/2013 16:41:59 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $yard_lights but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:42:02 [Scan all link tables] Now scanning: $kitchen_kpl (16 of 27) 26/02/2013 16:43:16 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:43:16 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:43:33 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:43:34 [Insteon::BaseMessage] WARN: now resending obj=$kitchen_kpl; command=peek; extra=F6 after 1 attempts. 26/02/2013 16:44:14 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:45:00 Running: AllDevices Scan 26/02/2013 16:45:38 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! IGNORING received message!! 26/02/2013 16:46:25 [Scan all link tables] Now scanning: $dining_kpl (17 of 27) 26/02/2013 16:46:28 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:46:29 [Insteon::BaseMessage] WARN: now resending obj=$dining_kpl; command=peek; extra=F0 after 1 attempts. 26/02/2013 16:47:00 Running: AllDevices Status 26/02/2013 16:49:31 [Insteon::BaseMessage] WARN: now resending obj=$dining_kpl; command=peek; extra=96 after 1 attempts. 26/02/2013 16:49:35 [Insteon::BaseMessage] WARN: now resending obj=$dining_kpl; command=peek; extra=96 after 2 attempts. 26/02/2013 16:49:58 [Scan all link tables] Now scanning: $garage1_neon_kpl (19 of 27) 26/02/2013 16:51:09 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:51:10 [Insteon::BaseMessage] WARN: now resending obj=$garage1_neon_kpl; command=peek; extra=43 after 1 attempts. 26/02/2013 16:52:03 [Scan all link tables] Now scanning: $garage2_neon_kpl (20 of 27) 26/02/2013 16:52:15 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:52:16 [Insteon::BaseMessage] WARN: now resending obj=$garage2_neon_kpl; command=peek; extra=ED after 1 attempts. 26/02/2013 16:52:34 [Insteon::BaseInterface] WARN: received a message from $garage2_neon_kpl in response to a set_address_msb command, but the command code 2b is incorrect. Ignorring received message. 26/02/2013 16:52:53 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 26/02/2013 16:52:54 [Insteon::BaseMessage] WARN: now resending obj=$garage2_neon_kpl; command=peek; extra=91 after 1 attempts. 26/02/2013 16:53:10 [Scan all link tables] Now scanning: $gar_outlights_kpl (21 of 27) 26/02/2013 16:54:02 [Scan all link tables] Now scanning: $iolinc_gardoor2 (22 of 27) 26/02/2013 16:54:07 [Scan all link tables] Now scanning: $iolinc_garside (23 of 27) 26/02/2013 16:54:11 [Scan all link tables] Now scanning: $fan_fmr (24 of 27) 26/02/2013 16:54:12 [Scan all link tables] Now scanning: $fan_mbr (25 of 27) 26/02/2013 16:54:12 [Scan all link tables] Now scanning: $fan_gar_roof (26 of 27) 26/02/2013 16:54:13 [Scan all link tables] Now scanning: $fan_gar_ceiling (27 of 27) 26/02/2013 16:54:14 [Scan all link tables] All tables have completed scanning full log here: http://marc.merlins.org/tmp/print.log.scanok Hope this helps. Marc -- "A mouse is a device used to point at the xterm you want to type in" - A.S.R. Microsoft is to operating systems .... .... what McDonalds is to gourmet cooking Home page: http://marc.merlins.org/ |
From: Kevin R. K. <ke...@kr...> - 2013-02-27 17:56:50
|
I had one other realization this morning while driving to work. The code in AllLinkDatabase.pm ignores an i2 Link Data packet that arrives before the ACK packet. However, the clearing of the current message is done back in _process_command. Is _process_command informed that the out of order Link Data packet is ignored? If it isn't, then _process_command is clearing the current message even though the sub in ALDB is expecting a subsequent Link Data packet to arrive. This is all just from memory, so if you already have this contingency covered then my apologies. On Wed, Feb 27, 2013 at 9:26 AM, Michael Stovenour <mi...@st...>wrote: > Nice catch. I’ll look at this tonight when I get home. **** > > ** ** > > *From:* Kevin Robert Keegan [mailto:ke...@kr...] > *Sent:* Tuesday, February 26, 2013 11:46 PM > *To:* Marc MERLIN > *Cc:* Michael Stovenour; The main list for the MisterHouse home > automation program > *Subject:* Re: [mh] Insteon: i2_aldb_support combine nearly identical > aldb sub routines**** > > ** ** > > OK, so I looked at the first failure. Michael, I think I understand what > you mean by out of sequence messages. I see that the link data packet > arrives before the ack. You have the code set to ignore link data packets > that arrive before the ack message. Then the ack arrives and nothing > happens. I am surmising that something is clearing the current_message > including the timeout(command).**** > > ** ** > > I see this line in _process_command that allows an ACK message to clear > the current message:**** > > if (substr($msg{extra},4,2) eq '01') {**** > > ** ** > > It looks like all of the ACKs have 00 for cmd2. As a result, it looks > like ACKs are clearing messages.**** > > ** ** > > On Tue, Feb 26, 2013 at 5:17 PM, Marc MERLIN <ma...@me...> wrote:* > *** > > On Tue, Feb 26, 2013 at 08:59:59AM -0600, Michael Stovenour wrote: > > Would you mind pulling my latest i2_aldb_support branch updates then > trying the PLM scan > > all device link tables? I think there is still a command timeout issue > if messages arrive > > out of order (due to retransmissions) but I can't reproduce it here. If > you don't get a > > final message like the one below then the scan didn't complete normally. > > > > [Scan all link tables] All tables have completed scanning > > > > If you can reproduce the failure I'll push some more code with a bunch > of debug logging. > > Otherwise we might just move on for now and revisit it later.**** > > Sure thing, there you go. > > I'm wondering if you merge your code with Kevin's hop count code whether > that will work > around the problem, but indeed there is still a problem. > > First scan failed in the middle with: > 26/02/2013 12:51:33 [Scan all link tables] Now scanning: $br2_lamp (7 of > 27) > 26/02/2013 12:51:34 [Insteon::ALDB_i2] DEBUG4: Start of scan; > initializing aldb structure > 26/02/2013 12:51:36 [Insteon::ALDB_i2] DEBUG4: scan done; adding last > address [0fe7] to empty array > 26/02/2013 12:51:36 [Insteon::ALDB_i2] $br2_lamp completed aldb scan: > status: good > 26/02/2013 12:51:36 [Scan all link tables] Now scanning: $fmr_kpl (8 of > 27) > 26/02/2013 12:51:37 [Insteon::ALDB_i2] DEBUG3: $br2_lamp [0x0fe7] > received: 0001010fe701000000000000000000 for _mem_activity= _mem_action= > 26/02/2013 12:51:37 [Insteon::ALDB_i2] $br2_lamp: unhandled _mem_action= > 26/02/2013 12:51:58 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:16 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:23 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:34 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:51 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:52 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:53 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:52:57 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:53:15 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:53:16 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:53:22 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:53:53 [Scan all link tables] Now scanning: $fmr_slav (9 of > 27) > 26/02/2013 12:53:54 [Insteon::ALDB_i2] DEBUG4: Start of scan; > initializing aldb structure > 26/02/2013 12:53:55 [Insteon::ALDB_i2] DEBUG3: $fmr_slav [0x0fef] ack not > received. ignoring message > 26/02/2013 12:54:31 Running: PLM scan all device link tables > 26/02/2013 12:54:31 [Scan all linktables] WARN: link already underway. > Ignoring request for new scan ... > > full log here: http://marc.merlins.org/tmp/print.log.scanfailed > > > Second scan, I'm not sure how it failed: > 26/02/2013 12:57:05 [Scan all link tables] Now scanning: $PLM (1 of 27) > 26/02/2013 12:57:48 [Scan all link tables] Now scanning: $mbr_kpl (2 of > 27) > 26/02/2013 12:58:36 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $mbr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 12:58:40 [Scan all link tables] Now scanning: $mbr_lamp2 (3 of > 27) > 26/02/2013 12:58:41 [Insteon::ALDB_i2] DEBUG4: Start of scan; > initializing aldb structure > 26/02/2013 12:58:44 [Insteon::ALDB_i2] DEBUG3: $mbr_lamp2 [0x0fd7] ack > not received. ignoring message > 26/02/2013 13:00:00 Running: AllDevices Scan > 26/02/2013 13:00:26 Running: compcloset fan on > 26/02/2013 13:02:00 Running: AllDevices Status > > full log here: http://marc.merlins.org/tmp/print.log.scanfailed2 > > And I then went back to git master, and did a full scan that completed. > Kevin, on the plus side your code changes in master have been working for > me so far. Actually > I had issues getting a scan to completion and your new hop count seems to > help: > > 26/02/2013 16:31:44 Running: PLM scan all device link tables > 26/02/2013 16:31:44 [Scan all link tables] Now scanning: $PLM (1 of 27) > 26/02/2013 16:32:00 Running: AllDevices Status > 26/02/2013 16:32:27 [Scan all link tables] Now scanning: $mbr_kpl (2 of > 27) > 26/02/2013 16:33:19 [Scan all link tables] Now scanning: $mbr_lamp2 (3 of > 27) > 26/02/2013 16:33:33 [Scan all link tables] Now scanning: $mbr_lamp3 (4 of > 27) > 26/02/2013 16:33:41 [Scan all link tables] Now scanning: $mbr_outside (5 > of 27) > 26/02/2013 16:33:52 [Scan all link tables] Now scanning: $br2_sw (6 of 27) > 26/02/2013 16:34:08 [Scan all link tables] Now scanning: $br2_lamp (7 of > 27) > 26/02/2013 16:34:14 [Scan all link tables] Now scanning: $fmr_kpl (8 of > 27) > 26/02/2013 16:34:41 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:34:58 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:35:22 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $fmr_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:36:34 [Scan all link tables] Now scanning: $fmr_slav (9 of > 27) > 26/02/2013 16:36:34 [Scan all link tables] Now scanning: $fmr_lamp (10 of > 27) > 26/02/2013 16:37:04 [Scan all link tables] Now scanning: $fmr_outside (11 > of 27) > 26/02/2013 16:37:27 [Scan all link tables] Now scanning: $entryway (12 of > 27) > 26/02/2013 16:37:55 [Scan all link tables] Now scanning: $lvr_kpl (13 of > 27) > 26/02/2013 16:39:01 [Insteon_PLM] DEBUG2: PLM command timer expired but > no transmission in place. Moving on... > 26/02/2013 16:40:32 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:40:33 [Insteon::BaseMessage] WARN: now resending > obj=$lvr_kpl; command=peek; extra=4F after 1 attempts. > 26/02/2013 16:41:32 [Scan all link tables] Now scanning: $lvr_lamp (14 of > 27) > 26/02/2013 16:41:40 [Insteon::BaseInterface] WARN: received a message > from $lvr_lamp in response to a peek command, but the command code d4 is > incorrect. Ignorring received message. > 26/02/2013 16:41:44 [Scan all link tables] Now scanning: $yard_lights (15 > of 27) > 26/02/2013 16:41:44 [Insteon::BaseInterface] Warn! Unable to locate > object for source: 0a99e6 and group: > 26/02/2013 16:41:59 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $yard_lights but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:42:02 [Scan all link tables] Now scanning: $kitchen_kpl (16 > of 27) > 26/02/2013 16:43:16 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:43:16 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:43:33 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:43:34 [Insteon::BaseMessage] WARN: now resending > obj=$kitchen_kpl; command=peek; extra=F6 after 1 attempts. > 26/02/2013 16:44:14 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:45:00 Running: AllDevices Scan > 26/02/2013 16:45:38 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! > IGNORING received message!! > 26/02/2013 16:46:25 [Scan all link tables] Now scanning: $dining_kpl (17 > of 27) > 26/02/2013 16:46:28 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:46:29 [Insteon::BaseMessage] WARN: now resending > obj=$dining_kpl; command=peek; extra=F0 after 1 attempts. > 26/02/2013 16:47:00 Running: AllDevices Status > 26/02/2013 16:49:31 [Insteon::BaseMessage] WARN: now resending > obj=$dining_kpl; command=peek; extra=96 after 1 attempts. > 26/02/2013 16:49:35 [Insteon::BaseMessage] WARN: now resending > obj=$dining_kpl; command=peek; extra=96 after 2 attempts. > 26/02/2013 16:49:58 [Scan all link tables] Now scanning: > $garage1_neon_kpl (19 of 27) > 26/02/2013 16:51:09 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:51:10 [Insteon::BaseMessage] WARN: now resending > obj=$garage1_neon_kpl; command=peek; extra=43 after 1 attempts. > 26/02/2013 16:52:03 [Scan all link tables] Now scanning: > $garage2_neon_kpl (20 of 27) > 26/02/2013 16:52:15 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:52:16 [Insteon::BaseMessage] WARN: now resending > obj=$garage2_neon_kpl; command=peek; extra=ED after 1 attempts. > 26/02/2013 16:52:34 [Insteon::BaseInterface] WARN: received a message > from $garage2_neon_kpl in response to a set_address_msb command, but the > command code 2b is incorrect. Ignorring received message. > 26/02/2013 16:52:53 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > 26/02/2013 16:52:54 [Insteon::BaseMessage] WARN: now resending > obj=$garage2_neon_kpl; command=peek; extra=91 after 1 attempts. > 26/02/2013 16:53:10 [Scan all link tables] Now scanning: > $gar_outlights_kpl (21 of 27) > 26/02/2013 16:54:02 [Scan all link tables] Now scanning: $iolinc_gardoor2 > (22 of 27) > 26/02/2013 16:54:07 [Scan all link tables] Now scanning: $iolinc_garside > (23 of 27) > 26/02/2013 16:54:11 [Scan all link tables] Now scanning: $fan_fmr (24 of > 27) > 26/02/2013 16:54:12 [Scan all link tables] Now scanning: $fan_mbr (25 of > 27) > 26/02/2013 16:54:12 [Scan all link tables] Now scanning: $fan_gar_roof > (26 of 27) > 26/02/2013 16:54:13 [Scan all link tables] Now scanning: $fan_gar_ceiling > (27 of 27) > 26/02/2013 16:54:14 [Scan all link tables] All tables have completed > scanning > > full log here: http://marc.merlins.org/tmp/print.log.scanok > > Hope this helps.**** > > > Marc > -- > "A mouse is a device used to point at the xterm you want to type in" - > A.S.R. > Microsoft is to operating systems .... > .... what McDonalds is to gourmet > cooking > Home page: http://marc.merlins.org/**** > > ** ** > |
From: Kevin R. K. <ke...@kr...> - 2013-03-01 20:10:37
|
Marc, I contributed a few changes to Michael's i2_aldb code last night that I think will solve at least your scan_all_links problem. When you have a chance, try pulling this git branch: krkeegan/misterhouse/i2_aldb_ack_handling Kevin On Wed, Feb 27, 2013 at 9:55 AM, Kevin Robert Keegan <ke...@kr...>wrote: > I had one other realization this morning while driving to work. > > The code in AllLinkDatabase.pm ignores an i2 Link Data packet that arrives > before the ACK packet. However, the clearing of the current message is > done back in _process_command. Is _process_command informed that the out of > order Link Data packet is ignored? If it isn't, then _process_command is > clearing the current message even though the sub in ALDB is expecting a > subsequent Link Data packet to arrive. > > This is all just from memory, so if you already have this contingency > covered then my apologies. > > > On Wed, Feb 27, 2013 at 9:26 AM, Michael Stovenour <mi...@st...>wrote: > >> Nice catch. I’ll look at this tonight when I get home. **** >> >> ** ** >> >> *From:* Kevin Robert Keegan [mailto:ke...@kr...] >> *Sent:* Tuesday, February 26, 2013 11:46 PM >> *To:* Marc MERLIN >> *Cc:* Michael Stovenour; The main list for the MisterHouse home >> automation program >> *Subject:* Re: [mh] Insteon: i2_aldb_support combine nearly identical >> aldb sub routines**** >> >> ** ** >> >> OK, so I looked at the first failure. Michael, I think I understand what >> you mean by out of sequence messages. I see that the link data packet >> arrives before the ack. You have the code set to ignore link data packets >> that arrive before the ack message. Then the ack arrives and nothing >> happens. I am surmising that something is clearing the current_message >> including the timeout(command).**** >> >> ** ** >> >> I see this line in _process_command that allows an ACK message to clear >> the current message:**** >> >> if (substr($msg{extra},4,2) eq '01') {**** >> >> ** ** >> >> It looks like all of the ACKs have 00 for cmd2. As a result, it looks >> like ACKs are clearing messages.**** >> >> ** ** >> >> On Tue, Feb 26, 2013 at 5:17 PM, Marc MERLIN <ma...@me...> wrote: >> **** >> >> On Tue, Feb 26, 2013 at 08:59:59AM -0600, Michael Stovenour wrote: >> > Would you mind pulling my latest i2_aldb_support branch updates then >> trying the PLM scan >> > all device link tables? I think there is still a command timeout issue >> if messages arrive >> > out of order (due to retransmissions) but I can't reproduce it here. >> If you don't get a >> > final message like the one below then the scan didn't complete normally. >> > >> > [Scan all link tables] All tables have completed scanning >> > >> > If you can reproduce the failure I'll push some more code with a bunch >> of debug logging. >> > Otherwise we might just move on for now and revisit it later.**** >> >> Sure thing, there you go. >> >> I'm wondering if you merge your code with Kevin's hop count code whether >> that will work >> around the problem, but indeed there is still a problem. >> >> First scan failed in the middle with: >> 26/02/2013 12:51:33 [Scan all link tables] Now scanning: $br2_lamp (7 of >> 27) >> 26/02/2013 12:51:34 [Insteon::ALDB_i2] DEBUG4: Start of scan; >> initializing aldb structure >> 26/02/2013 12:51:36 [Insteon::ALDB_i2] DEBUG4: scan done; adding last >> address [0fe7] to empty array >> 26/02/2013 12:51:36 [Insteon::ALDB_i2] $br2_lamp completed aldb scan: >> status: good >> 26/02/2013 12:51:36 [Scan all link tables] Now scanning: $fmr_kpl (8 of >> 27) >> 26/02/2013 12:51:37 [Insteon::ALDB_i2] DEBUG3: $br2_lamp [0x0fe7] >> received: 0001010fe701000000000000000000 for _mem_activity= _mem_action= >> 26/02/2013 12:51:37 [Insteon::ALDB_i2] $br2_lamp: unhandled _mem_action= >> 26/02/2013 12:51:58 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:52:16 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:52:23 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:52:34 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:52:51 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:52:52 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:52:53 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:52:57 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:53:15 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:53:16 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:53:22 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:53:53 [Scan all link tables] Now scanning: $fmr_slav (9 of >> 27) >> 26/02/2013 12:53:54 [Insteon::ALDB_i2] DEBUG4: Start of scan; >> initializing aldb structure >> 26/02/2013 12:53:55 [Insteon::ALDB_i2] DEBUG3: $fmr_slav [0x0fef] ack >> not received. ignoring message >> 26/02/2013 12:54:31 Running: PLM scan all device link tables >> 26/02/2013 12:54:31 [Scan all linktables] WARN: link already underway. >> Ignoring request for new scan ... >> >> full log here: http://marc.merlins.org/tmp/print.log.scanfailed >> >> >> Second scan, I'm not sure how it failed: >> 26/02/2013 12:57:05 [Scan all link tables] Now scanning: $PLM (1 of 27) >> 26/02/2013 12:57:48 [Scan all link tables] Now scanning: $mbr_kpl (2 of >> 27) >> 26/02/2013 12:58:36 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $mbr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 12:58:40 [Scan all link tables] Now scanning: $mbr_lamp2 (3 >> of 27) >> 26/02/2013 12:58:41 [Insteon::ALDB_i2] DEBUG4: Start of scan; >> initializing aldb structure >> 26/02/2013 12:58:44 [Insteon::ALDB_i2] DEBUG3: $mbr_lamp2 [0x0fd7] ack >> not received. ignoring message >> 26/02/2013 13:00:00 Running: AllDevices Scan >> 26/02/2013 13:00:26 Running: compcloset fan on >> 26/02/2013 13:02:00 Running: AllDevices Status >> >> full log here: http://marc.merlins.org/tmp/print.log.scanfailed2 >> >> And I then went back to git master, and did a full scan that completed. >> Kevin, on the plus side your code changes in master have been working for >> me so far. Actually >> I had issues getting a scan to completion and your new hop count seems to >> help: >> >> 26/02/2013 16:31:44 Running: PLM scan all device link tables >> 26/02/2013 16:31:44 [Scan all link tables] Now scanning: $PLM (1 of 27) >> 26/02/2013 16:32:00 Running: AllDevices Status >> 26/02/2013 16:32:27 [Scan all link tables] Now scanning: $mbr_kpl (2 of >> 27) >> 26/02/2013 16:33:19 [Scan all link tables] Now scanning: $mbr_lamp2 (3 >> of 27) >> 26/02/2013 16:33:33 [Scan all link tables] Now scanning: $mbr_lamp3 (4 >> of 27) >> 26/02/2013 16:33:41 [Scan all link tables] Now scanning: $mbr_outside (5 >> of 27) >> 26/02/2013 16:33:52 [Scan all link tables] Now scanning: $br2_sw (6 of >> 27) >> 26/02/2013 16:34:08 [Scan all link tables] Now scanning: $br2_lamp (7 of >> 27) >> 26/02/2013 16:34:14 [Scan all link tables] Now scanning: $fmr_kpl (8 of >> 27) >> 26/02/2013 16:34:41 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 16:34:58 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 16:35:22 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $fmr_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 16:36:34 [Scan all link tables] Now scanning: $fmr_slav (9 of >> 27) >> 26/02/2013 16:36:34 [Scan all link tables] Now scanning: $fmr_lamp (10 >> of 27) >> 26/02/2013 16:37:04 [Scan all link tables] Now scanning: $fmr_outside >> (11 of 27) >> 26/02/2013 16:37:27 [Scan all link tables] Now scanning: $entryway (12 >> of 27) >> 26/02/2013 16:37:55 [Scan all link tables] Now scanning: $lvr_kpl (13 of >> 27) >> 26/02/2013 16:39:01 [Insteon_PLM] DEBUG2: PLM command timer expired but >> no transmission in place. Moving on... >> 26/02/2013 16:40:32 [Insteon_PLM] DEBUG3: Interface extremely busy. >> Resending command after delaying for 1 second >> 26/02/2013 16:40:33 [Insteon::BaseMessage] WARN: now resending >> obj=$lvr_kpl; command=peek; extra=4F after 1 attempts. >> 26/02/2013 16:41:32 [Scan all link tables] Now scanning: $lvr_lamp (14 >> of 27) >> 26/02/2013 16:41:40 [Insteon::BaseInterface] WARN: received a message >> from $lvr_lamp in response to a peek command, but the command code d4 is >> incorrect. Ignorring received message. >> 26/02/2013 16:41:44 [Scan all link tables] Now scanning: $yard_lights >> (15 of 27) >> 26/02/2013 16:41:44 [Insteon::BaseInterface] Warn! Unable to locate >> object for source: 0a99e6 and group: >> 26/02/2013 16:41:59 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $yard_lights but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 16:42:02 [Scan all link tables] Now scanning: $kitchen_kpl >> (16 of 27) >> 26/02/2013 16:43:16 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 16:43:16 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 16:43:33 [Insteon_PLM] DEBUG3: Interface extremely busy. >> Resending command after delaying for 1 second >> 26/02/2013 16:43:34 [Insteon::BaseMessage] WARN: now resending >> obj=$kitchen_kpl; command=peek; extra=F6 after 1 attempts. >> 26/02/2013 16:44:14 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 16:45:00 Running: AllDevices Scan >> 26/02/2013 16:45:38 [Insteon::BaseInterface] WARN: received insteon >> ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! >> IGNORING received message!! >> 26/02/2013 16:46:25 [Scan all link tables] Now scanning: $dining_kpl (17 >> of 27) >> 26/02/2013 16:46:28 [Insteon_PLM] DEBUG3: Interface extremely busy. >> Resending command after delaying for 1 second >> 26/02/2013 16:46:29 [Insteon::BaseMessage] WARN: now resending >> obj=$dining_kpl; command=peek; extra=F0 after 1 attempts. >> 26/02/2013 16:47:00 Running: AllDevices Status >> 26/02/2013 16:49:31 [Insteon::BaseMessage] WARN: now resending >> obj=$dining_kpl; command=peek; extra=96 after 1 attempts. >> 26/02/2013 16:49:35 [Insteon::BaseMessage] WARN: now resending >> obj=$dining_kpl; command=peek; extra=96 after 2 attempts. >> 26/02/2013 16:49:58 [Scan all link tables] Now scanning: >> $garage1_neon_kpl (19 of 27) >> 26/02/2013 16:51:09 [Insteon_PLM] DEBUG3: Interface extremely busy. >> Resending command after delaying for 1 second >> 26/02/2013 16:51:10 [Insteon::BaseMessage] WARN: now resending >> obj=$garage1_neon_kpl; command=peek; extra=43 after 1 attempts. >> 26/02/2013 16:52:03 [Scan all link tables] Now scanning: >> $garage2_neon_kpl (20 of 27) >> 26/02/2013 16:52:15 [Insteon_PLM] DEBUG3: Interface extremely busy. >> Resending command after delaying for 1 second >> 26/02/2013 16:52:16 [Insteon::BaseMessage] WARN: now resending >> obj=$garage2_neon_kpl; command=peek; extra=ED after 1 attempts. >> 26/02/2013 16:52:34 [Insteon::BaseInterface] WARN: received a message >> from $garage2_neon_kpl in response to a set_address_msb command, but the >> command code 2b is incorrect. Ignorring received message. >> 26/02/2013 16:52:53 [Insteon_PLM] DEBUG3: Interface extremely busy. >> Resending command after delaying for 1 second >> 26/02/2013 16:52:54 [Insteon::BaseMessage] WARN: now resending >> obj=$garage2_neon_kpl; command=peek; extra=91 after 1 attempts. >> 26/02/2013 16:53:10 [Scan all link tables] Now scanning: >> $gar_outlights_kpl (21 of 27) >> 26/02/2013 16:54:02 [Scan all link tables] Now scanning: >> $iolinc_gardoor2 (22 of 27) >> 26/02/2013 16:54:07 [Scan all link tables] Now scanning: $iolinc_garside >> (23 of 27) >> 26/02/2013 16:54:11 [Scan all link tables] Now scanning: $fan_fmr (24 of >> 27) >> 26/02/2013 16:54:12 [Scan all link tables] Now scanning: $fan_mbr (25 of >> 27) >> 26/02/2013 16:54:12 [Scan all link tables] Now scanning: $fan_gar_roof >> (26 of 27) >> 26/02/2013 16:54:13 [Scan all link tables] Now scanning: >> $fan_gar_ceiling (27 of 27) >> 26/02/2013 16:54:14 [Scan all link tables] All tables have completed >> scanning >> >> full log here: http://marc.merlins.org/tmp/print.log.scanok >> >> Hope this helps.**** >> >> >> Marc >> -- >> "A mouse is a device used to point at the xterm you want to type in" - >> A.S.R. >> Microsoft is to operating systems .... >> .... what McDonalds is to gourmet >> cooking >> Home page: http://marc.merlins.org/**** >> >> ** ** >> > > |
From: Marc M. <ma...@me...> - 2013-03-01 18:51:42
|
On Fri, Mar 01, 2013 at 09:13:20AM -0800, Kevin Robert Keegan wrote: > Marc, > > I contributed a few changes to Michael's i2_aldb code last night that I > think will solve at least your scan_all_links problem. > > When you have a chance, try pulling this git branch: > > krkeegan/misterhouse/i2_aldb_ack_handling Sure thing. If anyone else wants to try, the exact commands: gargamel:/var/local/src/misterhouse# git clone git://github.com/krkeegan/misterhouse mh-krkeegan Cloning into 'mh-krkeegan'... remote: Counting objects: 21355, done. remote: Compressing objects: 100% (7356/7356), done. remote: Total 21355 (delta 13700), reused 21318 (delta 13665) Receiving objects: 100% (21355/21355), 13.92 MiB | 3.41 MiB/s, done. Resolving deltas: 100% (13700/13700), done. gargamel:/var/local/src/misterhouse# cd mh-krkeegan gargamel:/var/local/src/misterhouse/mh-krkeegan# git checkout i2_aldb_ack_handling Branch i2_aldb_ack_handling set up to track remote branch i2_aldb_ack_handling from origin. Switched to a new branch 'i2_aldb_ack_handling' No dice unfortunately: 01/03/2013 09:36:09 Running: PLM scan all device link tables 01/03/2013 09:36:09 [Scan all link tables] Now scanning: $PLM (1 of 27) 01/03/2013 09:36:39 [Scan all link tables] Now scanning: $mbr_kpl (2 of 27) 01/03/2013 09:36:52 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $mbr_kpl but cannot correlate to sent message! IGNORING received message!! 01/03/2013 09:36:56 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $mbr_kpl but cannot correlate to sent message! IGNORING received message!! 01/03/2013 09:37:11 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $mbr_kpl but cannot correlate to sent message! IGNORING received message!! 01/03/2013 09:37:32 [Scan all link tables] Now scanning: $mbr_lamp2 (3 of 27) 01/03/2013 09:37:32 [Insteon::ALDB_i2] DEBUG4: Start of scan; initializing aldb structure 01/03/2013 09:37:35 [Insteon::ALDB_i2] DEBUG3: $mbr_lamp2 [0x0fd7] ack not received. ignoring message 01/03/2013 09:37:38 [Insteon::Message] Now adding hop count of 2 to hop history of $mbr_lamp2 01/03/2013 09:37:38 [Insteon::ALDB_i2] DEBUG3: $mbr_lamp2 [0x0fd7] received duplicate ack. Ignoring. 01/03/2013 09:37:39 [Insteon::BaseObject] received command/state acknowledge from $mbr_lamp2: read_write_aldb and data: 00 01/03/2013 09:37:39 [Insteon::ALDB_i2] DEBUG3: $mbr_lamp2 [0x0fcf] ack not received. ignoring message Full log: http://marc.merlins.org/tmp/print.log-krkeegan.txt Hope this helps. Marc -- "A mouse is a device used to point at the xterm you want to type in" - A.S.R. Microsoft is to operating systems .... .... what McDonalds is to gourmet cooking Home page: http://marc.merlins.org/ |
From: Kevin R. K. <ke...@kr...> - 2013-03-01 21:05:33
|
Marc, I made one small tweak. If you have a chance, pull an update and try that again. Kevin |
From: Marc M. <ma...@me...> - 2013-03-01 21:21:45
|
On Fri, Mar 01, 2013 at 10:29:38AM -0800, Kevin Robert Keegan wrote: > Marc, I made one small tweak. If you have a chance, pull an update and try > that again. And we have liftoff! :) Thanks for not giving up: 01/03/2013 11:23:49 [Scan all link tables] Now scanning: $fan_gar_roof (26 of 27) 01/03/2013 11:23:50 [Insteon::ALDB_i2] DEBUG4: Start of scan; initializing aldb structure 01/03/2013 11:23:50 [Insteon::ALDB_i2] DEBUG4: scan done; adding last address [00ff] to empty array 01/03/2013 11:23:50 [Insteon::ALDB_i2] $fan_gar_roof completed aldb scan: status: good 01/03/2013 11:23:50 [Scan all link tables] Now scanning: $fan_gar_ceiling (27 of 27) 01/03/2013 11:23:51 [Insteon::ALDB_i2] DEBUG4: Start of scan; initializing aldb structure 01/03/2013 11:23:51 [Insteon::ALDB_i2] DEBUG4: scan done; adding last address [00ff] to empty array 01/03/2013 11:23:51 [Insteon::ALDB_i2] $fan_gar_ceiling completed aldb scan: status: good 01/03/2013 11:23:51 [Scan all link tables] All tables have completed scanning The full log is here: http://marc.merlins.org/tmp/print.log-krkeegan2.txt I've exerpted some more interesting bits in case they help validate the code you added. Specifically: 01/03/2013 11:23:09 [Insteon::BaseInterface] Warn! Unable to locate object for source: 07fe8b and group: 01/03/2013 12:45:12 [Insteon::BaseObject] Ignoring unsupported command from $iolinc_gardoor2 A few more after I filtered the expected stuff: 01/03/2013 11:02:48 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $mbr_kpl but cannot correlate to sent message! IGNORING received message!! 01/03/2013 11:02:56 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $mbr_kpl but cannot correlate to sent message! IGNORING received message!! 01/03/2013 11:03:49 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 01/03/2013 11:03:56 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 01/03/2013 11:04:06 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 01/03/2013 11:04:55 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $fmr_kpl but cannot correlate to sent message! IGNORING received message!! 01/03/2013 11:05:58 [Insteon::ALDB_i2] DEBUG4: duplicate link found; adding address [0faf] to duplicates array 01/03/2013 11:05:59 [Insteon::ALDB_i2] DEBUG4: duplicate link found; adding address [0fa7] to duplicates array 01/03/2013 11:06:02 [Insteon::ALDB_i2] DEBUG4: duplicate link found; adding address [0f9f] to duplicates array 01/03/2013 11:06:02 [Insteon::ALDB_i2] DEBUG4: duplicate link found; adding address [0f97] to duplicates array 01/03/2013 11:06:09 [Insteon::ALDB_i2] DEBUG4: duplicate link found; adding address [0fbf] to duplicates array 01/03/2013 11:06:18 [Insteon::ALDB_i2] DEBUG3: $fmr_outside [0x0fa7] ack not received. ignoring message 01/03/2013 11:06:20 [Insteon::Message] Now adding hop count of 2 to hop history of $fmr_outside 01/03/2013 11:06:21 [Insteon::ALDB_i2] DEBUG3: $fmr_outside [0x0fa7] received duplicate ack. Ignoring. 01/03/2013 11:06:22 [Insteon::ALDB_i2] DEBUG3: $fmr_outside [0x0f9f] ack not received. ignoring message 01/03/2013 11:06:24 [Insteon::Message] Now adding hop count of 3 to hop history of $fmr_outside 01/03/2013 11:06:25 [Insteon::ALDB_i2] DEBUG3: $fmr_outside [0x0f9f] received duplicate ack. Ignoring. 01/03/2013 11:06:28 [Insteon::ALDB_i2] DEBUG3: $entryway [0x0fdf] ack not received. ignoring message 01/03/2013 11:06:31 [Insteon::Message] Now adding hop count of 2 to hop history of $entryway 01/03/2013 11:06:31 [Insteon::ALDB_i2] DEBUG3: $entryway [0x0fdf] received duplicate ack. Ignoring. 01/03/2013 11:10:43 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 01/03/2013 11:10:44 [Insteon::BaseMessage] WARN: now resending obj=$kitchen_kpl; command=peek; extra=C0 after 1 attempts. 01/03/2013 11:10:44 [Insteon::Message] Now adding hop count of 2 to hop history of $kitchen_kpl 01/03/2013 11:12:26 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $kitchen_kpl but cannot correlate to sent message! IGNORING received message!! 01/03/2013 11:14:17 [Insteon_PLM] DEBUG3: Interface extremely busy. Resending command after delaying for 1 second 01/03/2013 11:14:18 [Insteon::BaseMessage] WARN: now resending obj=$kitchen_kpl; command=peek; extra=F3 after 1 attempts. 01/03/2013 11:14:18 [Insteon::Message] Now adding hop count of 2 to hop history of $kitchen_kpl 01/03/2013 11:16:50 [Insteon_PLM] DEBUG2: Sending obj=$fan_fmr; command=on; extra=FF incurred delay of 0.07 seconds; starting hop-count: 1 01/03/2013 11:19:01 [Insteon_PLM] DEBUG2: PLM command timer expired but no transmission in place. Moving on... 01/03/2013 11:19:55 [Insteon::BaseMessage] WARN: now resending obj=$garage1_neon_kpl; command=peek; extra=D4 after 1 attempts. 01/03/2013 11:19:55 [Insteon::Message] Now adding hop count of 2 to hop history of $garage1_neon_kpl 01/03/2013 11:21:56 [Insteon::BaseMessage] WARN: now resending obj=$garage2_neon_kpl; command=peek; extra=85 after 1 attempts. 01/03/2013 11:22:03 [Insteon::BaseMessage] WARN: now resending obj=$garage2_neon_kpl; command=peek; extra=87 after 1 attempts. 01/03/2013 11:22:11 [Insteon::BaseMessage] WARN: now resending obj=$garage2_neon_kpl; command=peek; extra=79 after 1 attempts. 01/03/2013 11:22:20 [Insteon::BaseInterface] WARN: received insteon ACK/NACK message from $garage2_neon_kpl but cannot correlate to sent message! IGNORING received message!! 01/03/2013 11:23:09 [Insteon::BaseInterface] Warn! Unable to locate object for source: 07fe8b and group: 01/03/2013 11:23:51 [Scan all link tables] All tables have completed scanning 01/03/2013 11:25:20 [Insteon_PLM] DEBUG2: Sending obj=$fan_fmr; command=off; extra=00 incurred delay of 0.00 seconds; starting hop-count: 1 01/03/2013 12:45:12 [Insteon::BaseObject] Ignoring unsupported command from $iolinc_gardoor2 Hope this helps, either way that's definitely a big plus for me :) Marc -- "A mouse is a device used to point at the xterm you want to type in" - A.S.R. Microsoft is to operating systems .... .... what McDonalds is to gourmet cooking Home page: http://marc.merlins.org/ |
From: Kevin R. K. <ke...@kr...> - 2013-03-01 21:27:17
|
Awesome. The interesting messages you posted, are nothing to be too concerned about, they show that MH is functioning properly and catching a number of small glitches. I get a number of these as well. My general comments: > 01/03/2013 11:23:09 [Insteon::BaseInterface] Warn! Unable to locate > object for source: 07fe8b and group: > 01/03/2013 12:45:12 [Insteon::BaseObject] Ignoring unsupported command > from $iolinc_gardoor2 > These are likely the result of corrupt messages, MH caught them so no big deal. 2 messages in a scan your size seems about ordinary. > 01/03/2013 11:02:48 [Insteon::BaseInterface] WARN: received insteon > ACK/NACK message from $mbr_kpl but cannot correlate to sent message! > IGNORING received message!! > These are generally duplicate messages. I get quite a few of these as well. They occur more frequently as the hop_count for a device increases. Which is why keeping the hop_count as low as possible is ideal. The new code in MH does a good job of preventing these from causing issues. > 01/03/2013 11:05:58 [Insteon::ALDB_i2] DEBUG4: duplicate link found; > adding address [0faf] to duplicates array > These show duplicate links in your i2 devices. Probably as a result of being a guinea pig. If you want to try an AUDIT Delete Orphans followed by a Delete Orphans it should clear this up. > 01/03/2013 11:06:18 [Insteon::ALDB_i2] DEBUG3: $fmr_outside [0x0fa7] ack > not received. ignoring message > 01/03/2013 11:06:21 [Insteon::ALDB_i2] DEBUG3: $fmr_outside [0x0fa7] > received duplicate ack. Ignoring. > These happen when the i2 messages arrive out of order. Not a big deal, they also happen. > 01/03/2013 11:06:24 [Insteon::Message] Now adding hop count of 3 to hop > history of $fmr_outside > Either a message needed to be resent or a message arrived in which all 3 hops had been used. Not a big deal, but this device is probably at the edge of your network. 01/03/2013 11:10:43 [Insteon_PLM] DEBUG3: Interface extremely busy. > Resending command after delaying for 1 second > These don't happen very often anymore, but not a big deal. > 01/03/2013 11:19:01 [Insteon_PLM] DEBUG2: PLM command timer expired but > no transmission in place. Moving on... > This is a strange one, I will look into this. > 01/03/2013 12:45:12 [Insteon::BaseObject] Ignoring unsupported command > from $iolinc_gardoor2 > I don't have an io_linc and the current code doesn't strictly support it, so getting an error from this is not surprising. I will see if there is something we can do to resolve these. |
From: Marc M. <ma...@me...> - 2013-03-01 22:48:08
|
On Fri, Mar 01, 2013 at 01:27:03PM -0800, Kevin Robert Keegan wrote: > Awesome. > > The interesting messages you posted, are nothing to be too concerned about, I wasn't concerned about them :) I just knew that you might be interested in seeing some of them since they validate some of the newer code that was added. > > 01/03/2013 11:02:48 [Insteon::BaseInterface] WARN: received insteon > > ACK/NACK message from $mbr_kpl but cannot correlate to sent message! > > IGNORING received message!! > > These are generally duplicate messages. I get quite a few of these as > well. They occur more frequently as the hop_count for a device increases. > Which is why keeping the hop_count as low as possible is ideal. The new > code in MH does a good job of preventing these from causing issues. Yes, I noticed that. Thanks for that. > > 01/03/2013 11:05:58 [Insteon::ALDB_i2] DEBUG4: duplicate link found; > > adding address [0faf] to duplicates array > > These show duplicate links in your i2 devices. Probably as a result of > being a guinea pig. If you want to try an AUDIT Delete Orphans followed by > a Delete Orphans it should clear this up. That's indeed what I'm going to do next. It's the first time I can finally run sync all links and delete orphans :) > > 01/03/2013 11:19:01 [Insteon_PLM] DEBUG2: PLM command timer expired but > > no transmission in place. Moving on... > > This is a strange one, I will look into this. Yeah, these have never been too good in my experience. > > 01/03/2013 12:45:12 [Insteon::BaseObject] Ignoring unsupported command > > from $iolinc_gardoor2 > > I don't have an io_linc and the current code doesn't strictly support it, > so getting an error from this is not surprising. I will see if there is > something we can do to resolve these. Agreed. I had never seen it so far, so I though I'd report it just in case. I only use my iolinc to toggle a relay, not to sense. I'll try sync all links now to see what happens, and maybe even delete orphans :) Marc -- "A mouse is a device used to point at the xterm you want to type in" - A.S.R. Microsoft is to operating systems .... .... what McDonalds is to gourmet cooking Home page: http://marc.merlins.org/ |
From: Kevin R. K. <ke...@kr...> - 2013-03-01 23:16:20
|
On Fri, Mar 1, 2013 at 2:48 PM, Marc MERLIN <ma...@me...> wrote: > > > 01/03/2013 11:19:01 [Insteon_PLM] DEBUG2: PLM command timer expired > but > > > no transmission in place. Moving on... > > > > This is a strange one, I will look into this. > > Yeah, these have never been too good in my experience. I looked at this, I am not clear why this happened, but I confess this is buried much deeper in MH then I have ever ventured. Right above it, it notes that there was a pause of 6 seconds, yet the print_log doesn't she such a delay. It also looks like you have some custom user code that ran just before this. You might want to inspect that code and see if it is doing anything funny. > > > 01/03/2013 12:45:12 [Insteon::BaseObject] Ignoring unsupported command > > > from $iolinc_gardoor2 > > > > I don't have an io_linc and the current code doesn't strictly support it, > > so getting an error from this is not surprising. I will see if there is > > something we can do to resolve these. > > Agreed. I had never seen it so far, so I though I'd report it just in case. > I only use my iolinc to toggle a relay, not to sense. > > I also looked at this. The unknown message is an extended message with the command code FF. This is the last possible command code, and I am unable to find any reference to its existence online. I would surmise that it contains data concerning its state, but the amount of data seems excessive, unless it is trying to send analog data. Or it could just be a corrupt packet. One of these days I will get an iolink and try and diagnose what it can do. |
From: Marc M. <ma...@me...> - 2013-03-02 00:16:41
|
Oh, slightly related question: Is there a setting in the driver to tell it to scan for other APs if the signal dips below 35/70? Right now, it goes down to 20, and waits quite a while before finally realizing there is another AP right there with the same ESSID and waiting for a connection. I'm sure there is a way to make it switch earlier, but I'm not sure if it's in the driver or in wpa_supplicant Thanks, Marc -- "A mouse is a device used to point at the xterm you want to type in" - A.S.R. Microsoft is to operating systems .... .... what McDonalds is to gourmet cooking Home page: http://marc.merlins.org/ |
From: Michael S. <mi...@st...> - 2013-03-02 16:30:41
|
Kevin, Thank you very much for finding this recent I2 bug! Now for next steps. I think we need to: 1) Combine the substantially similar i1 and i2 functions and move them into the base AllLinkDatabase package 2) Test some more but hopefully not a lot 3) Merge the code into hollie/master The issue below will likely be in the general Insteon support not necessarily an I2 specific bug. The more code changes we make in non-I2 areas the harder it will be to merge the changes later. There are already a couple that I think will be tricky to get right during the merge. At a minimum I could work on pulling the I1/I2 common functions together, then we can decide when to merge to hollie/master. I just ask that we don't get too crazy fixing more stuff until we pull it all together. If you all want to debug a few more things then I'll hold off on collapsing the i1/i2 functions. Let me know. Sincerely, Michael From: Kevin Robert Keegan [mailto:ke...@kr...] Sent: Friday, March 01, 2013 5:16 PM To: Marc MERLIN Cc: Michael Stovenour; The main list for the MisterHouse home automation program Subject: Re: [mh] Insteon: i2_aldb_support combine nearly identical aldb sub routines On Fri, Mar 1, 2013 at 2:48 PM, Marc MERLIN <ma...@me...> wrote: > > 01/03/2013 11:19:01 [Insteon_PLM] DEBUG2: PLM command timer expired but > > no transmission in place. Moving on... > > This is a strange one, I will look into this. Yeah, these have never been too good in my experience. I looked at this, I am not clear why this happened, but I confess this is buried much deeper in MH then I have ever ventured. Right above it, it notes that there was a pause of 6 seconds, yet the print_log doesn't she such a delay. It also looks like you have some custom user code that ran just before this. You might want to inspect that code and see if it is doing anything funny. > > 01/03/2013 12:45:12 [Insteon::BaseObject] Ignoring unsupported command > > from $iolinc_gardoor2 > > I don't have an io_linc and the current code doesn't strictly support it, > so getting an error from this is not surprising. I will see if there is > something we can do to resolve these. Agreed. I had never seen it so far, so I though I'd report it just in case. I only use my iolinc to toggle a relay, not to sense. I also looked at this. The unknown message is an extended message with the command code FF. This is the last possible command code, and I am unable to find any reference to its existence online. I would surmise that it contains data concerning its state, but the amount of data seems excessive, unless it is trying to send analog data. Or it could just be a corrupt packet. One of these days I will get an iolink and try and diagnose what it can do. |
From: Kevin R. K. <ke...@kr...> - 2013-03-02 16:54:54
|
On Sat, Mar 2, 2013 at 8:13 AM, Michael Stovenour <mi...@st...>wrote: > 1) **Combine the substantially similar i1 and i2 functions and move > them into the base AllLinkDatabase package > > **2) **Test some more but hopefully not a lot**** > > **3) **Merge the code into hollie/master > > If you all want to debug a few more things then I’ll hold off on > collapsing the i1/i2 functions. Let me know. > I think it is time to start collapsing. Marc's issue was the last known i2 specific bug. What is your plan on the ALDB_Delta? We can either merge it in before the collapse or after, it seems like either way someone is going to have to do some manual work. Kevin |
From: Michael S. <mi...@st...> - 2013-03-02 20:55:11
|
On Mar 2, 2013 10:55 AM Kevin wrote, On Sat, Mar 2, 2013 at 8:13 AM, Michael Stovenour <mi...@st...> wrote: 1) Combine the substantially similar i1 and i2 functions and move them into the base AllLinkDatabase package 2) Test some more but hopefully not a lot 3) Merge the code into hollie/master If you all want to debug a few more things then I'll hold off on collapsing the i1/i2 functions. Let me know. I think it is time to start collapsing. Marc's issue was the last known i2 specific bug. What is your plan on the ALDB_Delta? We can either merge it in before the collapse or after, it seems like either way someone is going to have to do some manual work. I haven't looked at this in depth but it seems intuitive that we should pull the functions together first. Otherwise I suspect we might need to make the changes in multiple places then merge the changes while figuring out how to make it all work. If you disagree I'll follow your lead. |
From: Kevin R. K. <ke...@kr...> - 2013-03-02 21:04:07
|
I really have no idea on how to do it, I was hoping that you had an idea. How good is git about finding similar lines that have moved significantly?? If it can do a reasonable job, then we should merge the current i1/i2 routines and move them into the base AllLink class. This will require a fair amount of work, but you may be the best qualified since you know what you had to change in the i2 code. Then once everything is merged, I can try and merge the ALDD_Delta code. Hopefully it will still be able to locate the relevant portions of sub add_link delete_link and so forth. On Sat, Mar 2, 2013 at 12:54 PM, Michael Stovenour <mi...@st...>wrote: > On Mar 2, 2013 10:55 AM Kevin wrote,**** > > ** ** > > On Sat, Mar 2, 2013 at 8:13 AM, Michael Stovenour <mi...@st...> > wrote:**** > > 1) Combine the substantially similar i1 and i2 functions and move > them into the base AllLinkDatabase package**** > > 2) Test some more but hopefully not a lot**** > > 3) Merge the code into hollie/master **** > > If you all want to debug a few more things then I’ll hold off on > collapsing the i1/i2 functions. Let me know.**** > > ** ** > > I think it is time to start collapsing. Marc's issue was the last known > i2 specific bug. **** > > ** ** > > What is your plan on the ALDB_Delta? We can either merge it in before the > collapse or after, it seems like either way someone is going to have to do > some manual work.**** > > ** ** > > I haven’t looked at this in depth but it seems intuitive that we should > pull the functions together first. Otherwise I suspect we might need to > make the changes in multiple places then merge the changes while figuring > out how to make it all work. If you disagree I’ll follow your lead.**** > > ** ** > > ** ** > |
From: Michael S. <mi...@st...> - 2013-03-02 21:24:32
|
On Sat, Mar 2, 2013 3:04 PM Kevin wrote, I really have no idea on how to do it, I was hoping that you had an idea. How good is git about finding similar lines that have moved significantly?? If it can do a reasonable job, then we should merge the current i1/i2 routines and move them into the base AllLink class. This will require a fair amount of work, but you may be the best qualified since you know what you had to change in the i2 code. Then once everything is merged, I can try and merge the ALDD_Delta code. Hopefully it will still be able to locate the relevant portions of sub add_link delete_link and so forth. Hum, you bring up a good point. I don't think that git will be able to find the deltas between ALDD_Delta and a couple of collapsed i1/i2 functions. Would you like to try merging the ALDD_Delta code into my existing i2_aldb_support branch? I'll then collapse the functions from there. |
From: Kevin R. K. <ke...@kr...> - 2013-03-02 21:26:23
|
Sure, the rebased version was just merged this morning, so it should merge in fine. The downside is it puts a lot more of the manual work on you. On Sat, Mar 2, 2013 at 1:24 PM, Michael Stovenour <mi...@st...>wrote: > On Sat, Mar 2, 2013 3:04 PM Kevin wrote,**** > > ** ** > > I really have no idea on how to do it, I was hoping that you had an idea.* > *** > > ** ** > > How good is git about finding similar lines that have moved > significantly?? If it can do a reasonable job, then we should merge the > current i1/i2 routines and move them into the base AllLink class. This > will require a fair amount of work, but you may be the best qualified since > you know what you had to change in the i2 code.**** > > ** ** > > Then once everything is merged, I can try and merge the ALDD_Delta code. > Hopefully it will still be able to locate the relevant portions of sub > add_link delete_link and so forth.**** > > ** ** > > Hum, you bring up a good point… I don’t think that git will be able to > find the deltas between ALDD_Delta and a couple of collapsed i1/i2 > functions. Would you like to try merging the ALDD_Delta code into my > existing i2_aldb_support branch? I’ll then collapse the functions from > there.**** > |