Re: [mh] Is this a defective switchlink dimmer, or a software bug?

[Gregg L. <gr...@li...>]

Marc MERLIN wrote:
> My two devices are off:
> 14/04/2009 20:22:43  Running: br2 sw status
> 14/04/2009 20:22:43  [Insteon_PLM] Parsing serial data: 02620f0f9a0f190006
> 14/04/2009 20:22:43  [Insteon_PLM] Parsing serial data: 02500f0f9a0ed9ee2b1f00
> 14/04/2009 20:22:43  [Insteon_PLM] Processing message for $br2_sw
> 14/04/2009 20:22:43  [Insteon_Device] received status request report for $br2_sw with on-level: 0%, hops left: 2
> 14/04/2009 20:22:43  MYLOG6: br2_sw turned off, unsetting master timer for br2_sw
> 14/04/2009 20:22:56  Running: br2 lamp status
> 14/04/2009 20:22:56  [Insteon_PLM] Parsing serial data: 02620f71940f190006
> 14/04/2009 20:22:56  [Insteon_PLM] Parsing serial data: 02500f71940ed9ee2b0800
> 14/04/2009 20:22:56  [Insteon_PLM] Processing message for $br2_lamp
> 14/04/2009 20:22:56  [Insteon_Device] received status request report for $br2_lamp with on-level: 0%, hops left: 2
> 14/04/2009 20:22:56  MYLOG6: br2_lamp turned off, unsetting master timer for br2_lamp
> 
> 
> Then, I have:
> SCENE_MEMBER, br2_lamp, br2_sw, 100%, 2s
> SCENE_MEMBER, lvr_kpl_br2_lamp, br2_sw
> SCENE_MEMBER, br2_sw, lvr_kpl_br2_lamp, 100%, 2s
> SCENE_MEMBER, br2_lamp, lvr_kpl_br2_lamp, 100%, 2s
> 
> 
> I activate the KPL:
> 14/04/2009 20:23:03  [Insteon_PLM] Processing message for $lvr_kpl_br2_lamp
> 14/04/2009 20:23:03  [Insteon_Device] $lvr_kpl_br2_lamp::set(on, Insteon_Link=HASH(0x9ca8708))
> 14/04/2009 20:23:03   br2_sw newly set to 100% set by $lvr_kpl_br2_lamp
> 14/04/2009 20:23:03  MYLOGS: br2_sw newly set to 100% set by $lvr_kpl_br2_lamp
> 14/04/2009 20:23:03   br2_lamp newly set to 100% set by $lvr_kpl_br2_lamp
> 14/04/2009 20:23:03  MYLOGS: br2_lamp newly set to 100% set by $lvr_kpl_br2_lamp
> 14/04/2009 20:23:03  MYLOG6: br2_sw turned on, (re)setting master timer to 240mn
> 14/04/2009 20:23:03  MYLOG6: set_master_timer for br2_sw to 240mn
> 14/04/2009 20:23:03  MYLOG6: br2_lamp turned on, (re)setting master timer to 120mn
> 14/04/2009 20:23:03  MYLOG6: set_master_timer for br2_lamp to 120mn
> 14/04/2009 20:23:03  [Insteon_PLM] Parsing serial data: 02500994250ed9ee411106
> 14/04/2009 20:23:03  [Insteon_Device] command:11; type:cleanup; group: 06
> 14/04/2009 20:23:03  [Insteon_Device] found: on
> 14/04/2009 20:23:03  [Insteon_PLM] Processing message for $lvr_kpl_br2_lamp
> 
> 
> So things look ok, right?
> Except not, br2_sw is only at 6% and I get this every time:
> 
> 14/04/2009 20:23:27  Running: br2 sw status
> 14/04/2009 20:23:27  [Insteon_PLM] Parsing serial data: 02620f0f9a0f190006
> 14/04/2009 20:23:37  [Insteon_Device] WARN: queue timer on $br2_sw expired. Attempting resend: status_request
> 14/04/2009 20:23:37  [Insteon_PLM] Parsing serial data: 02620f0f9a0f190006
> 14/04/2009 20:23:38  [Insteon_PLM] Parsing serial data: 02500f0f9a0ed9ee2b1f11
> 14/04/2009 20:23:38  [Insteon_PLM] Processing message for $br2_sw
> 14/04/2009 20:23:38  [Insteon_Device] received status request report for $br2_sw with on-level: 6%, hops left: 2

There is always a possibility that the link table for br2_sw is somehow 
garbled such that it thinks "on" when receiving the link message from 
lvr_kpl_br2 means set to 6%.  You might double check by performing a 
full link scan on br2_sw (or it's root device if that's the case).

> That said, turning it off doesn't look too good either:
> 14/04/2009 20:29:23  Running: br2 sw off
> 14/04/2009 20:29:23  [Insteon_Device] $br2_sw::set(off, Voice_Cmd=HASH(0x9d24908))
> 14/04/2009 20:29:23  [Insteon_PLM] Parsing serial data: 02620f0f9a0f130006
> 14/04/2009 20:29:24  [Insteon_PLM] Parsing serial data: 02500f0f9a0ed9ee2b1300
> 14/04/2009 20:29:24  [Insteon_PLM] Processing message for $br2_sw
> 14/04/2009 20:29:24  [Insteon_Device] received command/state acknowledge from $br2_sw: off and data: 00
> 14/04/2009 20:29:24   br2_sw newly set to off set by $br2_sw_v w/off timer: 239.2mn
> 14/04/2009 20:29:24  MYLOGS: br2_sw newly set to off set by $br2_sw_v w/off timer: 239.2mn
> 14/04/2009 20:29:24  MYLOG6: br2_sw turned off, unsetting master timer for br2_sw
> 14/04/2009 20:29:34  Running: br2 sw status
> 14/04/2009 20:29:34  [Insteon_PLM] Parsing serial data: 02620f0f9a0f190006
> 14/04/2009 20:29:35  [Insteon_PLM] Parsing serial data: 02500f0f
> 14/04/2009 20:29:35  [Insteon_PLM] Prepending prior data fragment: 02500f0f
> 14/04/2009 20:29:35  [Insteon_PLM] Parsing serial data: 02500f0f9a0ed9ee2b1f2a
> 14/04/2009 20:29:35  [Insteon_PLM] Processing message for $br2_sw
> 14/04/2009 20:29:35  [Insteon_Device] received status request report for $br2_sw with on-level: 16%, hops left: 2
> 
> So, do I have a faulty switch, or is that potentially a software bug?

The direct off command is much more telling.  Please try only sending 
direct on and off commands to br2_sw to see if you consistently get 
something other than the dim level (if anything other than 100%) sent. 
And, although I'm really stretching here, consider replacing whatever 
bulb you might have w/ a "standard" incandescent one (e.g., 60W) (even 
if that's what you already have).  If you consistently get poor results 
using the direct messages, I would tend toward thinking that the device 
is defective.