hollie / misterhouse

Perl open source home automation program. It's fun, it's free, and it's entirely geeky.
243 stars 130 forks source link

Irrigation stopped working #460

Closed tbclark3 closed 10 years ago

tbclark3 commented 10 years ago

As of the Aug 5 update, any attempt to open or close a valve on the irrigation controller results in the following error message: 08/06/14 05:10:59 [Insteon_PLM]: ERROR!! Command sent to PLM 026219ace40540ffffffffffffffff is of an incorrect length. Message not sent. The status command still works.

krkeegan commented 10 years ago

Hmm, it is still working just fine for me. From the limited debug, the message that is trying to be sent doesn't even exist. I would need to see more of the log details preceding this to have any idea what is going on.

tbclark3 commented 10 years ago

Thanks Kevin.

There isn't much in the log preceding, but here are some examples. There isn't anything in the other logs.

08/06/14 05:02:57 menu_run: g=mh m=irrigation i=2 s=0 => action: Turn on valve '1' 08/06/14 05:02:57 Running: Turn on valve 1 08/06/14 05:02:57 [Insteon_PLM]: ERROR!! Command sent to PLM 026219ace40a40ffffffffffffffff is of an incorrect length. Message not sent. 08/06/14 05:03:19 menu_run: g=mh m=irrigation i=1 s=0 => action: Turn off valve '1' 08/06/14 05:03:19 Running: Turn off valve 1 08/06/14 05:03:19 [Insteon_PLM]: ERROR!! Command sent to PLM 026219ace40a41ffffffffffffffff is of an incorrect length. Message not sent.

I can think of one other things that was unusual. After upgrading, I ran a "Scan all link tables" --and, for the first time ever, the irrigation module did not fail. Here is the relevant bit from the log:

08/05/14 20:18:58 [Scan all link tables] Now scanning: $irrigation (45 of 45) 08/05/14 20:18:58 [Insteon::ALDB_i2] $irrigation reading ALDB at location: 0x0000 08/05/14 20:18:59 [Insteon::BaseInterface] DEBUG: PLM command:insteon_ext_received; Device command:read_write_aldb; type:direct; group: 08/05/14 20:18:59 [Insteon::ALDB_i2] $irrigation reading ALDB at location: 0x3ff7 08/05/14 20:19:00 [Insteon::BaseInterface] DEBUG: PLM command:insteon_ext_received; Device command:read_write_aldb; type:direct; group: 08/05/14 20:19:00 [Insteon::ALDB_i2] $irrigation completed link memory scan: status: good 08/05/14 20:19:01 [Insteon::BaseObject] received status for $irrigation with on-level: 11%, hops left: 1 08/05/14 20:19:01 [Insteon::BaseObject] $irrigation::set_receive(on, $PLM) 08/05/14 20:19:01 [Insteon::BaseObject] The Link Table Version for $irrigation has been updated to version number 09 08/05/14 20:19:01 [Scan all link tables] Completed scanning of all regular items.

This is what scanning the irrigation module usually does: 05/08/14 20:22:18 [Scan all link tables] Now scanning: $irrigation (45 of 45) 05/08/14 20:22:18 [Insteon::ALDB_i2] $irrigation reading ALDB at location: 0x0000 05/08/14 20:22:20 [Insteon::BaseInterface] DEBUG: PLM command:insteon_ext_received; Device command:read_write_aldb; type:direct; group: 05/08/14 20:22:20 [Insteon::ALDB_i2] $irrigation reading ALDB at location: 0x3ff7 05/08/14 20:22:20 [Insteon::BaseObject] WARN!! encountered a nack message () for $irrigation ... skipping 05/08/14 20:22:20 [Insteon::BaseObject] WARN: Now calling message failure callback: &Insteon::_get_next_linkscan_failure(0) 05/08/14 20:22:20 [Scan all link tables] WARN: failure occurred when scanning $irrigation. Moving on...

I reverted back to the code that previously worked, and it also failed with the same error. I'm wondering if something could have changed in the irrigation relay. Unless you have a different suggestion, I think I will do a factory reset on the irrigation relay when I get home and re-link it.

BTW, I really appreciate all of the improvements you have made to the Insteon code. It's really phenomenal!

On Wed, Aug 6, 2014 at 9:15 AM, Kevin Robert Keegan < notifications@github.com> wrote:

Hmm, it is still working just fine for me. From the limited debug, the message that is trying to be sent doesn't even exist. I would need to see more of the log details preceding this to have any idea what is going on.

— Reply to this email directly or view it on GitHub https://github.com/hollie/misterhouse/issues/460#issuecomment-51358397.

krkeegan commented 10 years ago

I should have been more clear, set the debug level for insteon to level 4:

Debug=Insteon:4 That will produce much more logging detail. Then try and turn on a valve.

krkeegan commented 10 years ago

Ahh, I figured it out. My example voice commands are wrong. They should be changed to:

$v_valve_on = new Voice_Cmd "Turn on valve [1,2,3,4,5,6,7,8]";
if (my $valve = state_now $v_valve_on) {
    set_valve $irrigation "0$valve", "on";
}

$v_valve_off = new Voice_Cmd "Turn off valve [1,2,3,4,5,6,7,8]";
if (my $valve = state_now $v_valve_off) {
    set_valve $irrigation "0$valve", "off";
}

The $valve--; line is wrong.

tbclark3 commented 10 years ago

Thanks! I will try it when I get home and let you know what happens.

On Wed, Aug 6, 2014 at 12:22 PM, Kevin Robert Keegan < notifications@github.com> wrote:

Ahh, I figured it out. My example voice commands are wrong. They should be changed to:

$v_valve_on = new Voice_Cmd "Turn on valve [1,2,3,4,5,6,7,8]"; if (my $valve = state_now $v_valve_on) { set_valve $irrigation "0$valve", "on"; }

$v_valve_off = new Voice_Cmd "Turn off valve [1,2,3,4,5,6,7,8]"; if (my $valve = state_now $v_valve_off) { set_valve $irrigation "0$valve", "off"; }

The $valve--; line is wrong.

— Reply to this email directly or view it on GitHub https://github.com/hollie/misterhouse/issues/460#issuecomment-51383666.

tbclark3 commented 10 years ago

Yes, that fixed it. I guess the valve enumeration changed from 0-7 to 1-8 at some point. Thanks for your help!