Insteon PLM hangs

[Brad Bosch]

Gregg and Insteon PLM users,

What is the current understanding of the occasional PLM hangs where
the PLM LED just goes out and it stops responding?

It seems that the micro-controller inside the PLM has crashed or
something.  It won't work again until I unplug it and plug it back in
(at which time, MH generally recovers without a restart).  I know
there has been some discussion on this in the past and that some
effort has been made to avoid triggering the problem by being cautious
with command rates, etc, but I still experience these crashes at least
once a week.  As a last ditch hack to work around the bug, I am
considering putting the PLM behind an X10 appliance module with a CM11
interface (which I had retired) to allow MH to reset the PLM when it
detects this failure.

This is clearly a serious PLM firmware bug which SmartHome should fix!
But is it triggered by a bug in the the MH insteon code?  Or are we
sure we are sending only valid commands to the PLM and staying within
it's intended use cases?

I have a *lot* of Insteon hardware now and I'd like to get this fixed.
Gregg, does your new Insteon code completely eliminate this?

Has someone had a dialog with the SmartHome technical support or
developers about this?

I have included an exeprt of my log file, but, would it help to have
captures from a "serial protocol analyzer" of the traffic to/from the
PLM?  I could, easily enough, wire up an additional pair of serial
ports to log and timestamp the actual serial exchange with the PLM if
someone wants to look at it.

Some of my current potentially relevant settings:

Insteon_PLM_max_queue_time=5
Insteon_PLM_disable_throttling=1
Insteon_PLM_xmit_delay=0.15

Various changes I have tried with these, including the trottling
setting seem not to solve the problem but what are the current
recommended settings?

Debug flags for the following log exerpt are: insteon, startup,
light_item, occupancy.

Thanks,

--Brad

08/07/09 09:05:29 PM [Insteon_PLM] Parsing serial data: 02611511ff06
08/07/09 09:05:29 PM [Insteon_PLM] Parsing serial data: 02580602500515270f438a661115
08/07/09 09:05:29 PM [Insteon_PLM] ALL-Link Cleanup reports success
08/07/09 09:05:29 PM [Insteon_Device] received command/state acknowledge from $s_kpl_bent4: cleanup and data:
08/07/09 09:05:29 PM [Insteon_PLM] Processing message for $bent_light
08/07/09 09:05:29 PM [Insteon_Device] received command/state acknowledge from $bent_light: on and data:
08/07/09 09:05:29 PM [Insteon_Device] $s_kpl_bent3::set(on, )
08/07/09 09:05:30 PM [Insteon_PLM] x10 sending code: B5 as insteon msg: 0263e100
08/07/09 09:05:30 PM [Insteon_PLM] Command stack size: 1
08/07/09 09:05:30 PM [Insteon_PLM] x10 sending code: BJ as insteon msg: 0263e280
08/07/09 09:05:30 PM [Insteon_PLM] Command stack size: 2
08/07/09 09:05:30 PM Light_Switch_Item($switch_bent3)::set(on, Insteon_Link=HASH(0x9870a28)) setby name: $bent_sw3
08/07/09 09:05:30 PM MYLOGKPL: sync_kpl_lights called for state_changed on SCALAR(0x9a42610) to on for SCALAR(0x9a906b8) set kpls in 1sec
08/07/09 09:05:30 PM [Insteon_PLM] Parsing serial data: 02611711ff06
08/07/09 09:05:30 PM [Insteon_PLM] Parsing serial data: 0263e10006
08/07/09 09:05:30 PM [Insteon_PLM] Parsing serial data: 0263e28006
Warning: Dummy_Interface #13: trying to set_receive motion
Warning: Dummy_Interface #13: trying to set_receive motion
08/07/09 09:05:30 PM XC4CJ: ktch_land_motion motion
08/07/09 09:05:30 PM Motion_Item($motion_ktch_land)::set(motion, X10_Sensor=HASH(0x983ac98)): $ktch_land_motion was set by rf
08/07/09 09:05:30 PM Ignore Check: $motion_ktch_land
08/07/09 09:05:30 PM Log check: $motion_ktch_land [1 31]
08/07/09 09:05:30 PM Presence Check: $motion_ktch_land
08/07/09 09:05:30 PM Object $switch_stwy has common edge: 1
08/07/09 09:05:30 PM Object $switch_stwy no door edge restriction active
08/07/09 09:05:30 PM Connecting room $switch_stwy count decremented (1 total)
08/07/09 09:05:30 PM Object $motion_land has common edge: 1
08/07/09 09:05:30 PM Object $motion_land no door edge restriction active
08/07/09 09:05:30 PM Connecting room $motion_land count decremented (1 total)
08/07/09 09:05:30 PM Clearing used flag for $motion_ktch_land (presence)
08/07/09 09:05:30 PM Adding 1 to room $motion_ktch_land
08/07/09 09:05:30 PM count_people: counting object $motion_entr (13 21 22): 1 (count=0)
08/07/09 09:05:30 PM count_people: counting object $motion_sbr_hall (3 33): 1 (count=1)
08/07/09 09:05:30 PM count_people: counting object $motion_deck (8 15): 1 (count=2)
08/07/09 09:05:30 PM count_people: counting object $motion_fmly (9): 1 (count=3)
08/07/09 09:05:30 PM count_people: counting object $motion_ktch_land (1 31): 1 (count=4)
08/07/09 09:05:30 PM set_by_to_target encountered these objects: $presence_ktch, $om returning
08/07/09 09:05:30 PM Light_Item($light_ktch): Light_Restriction_Item : light_ok
08/07/09 09:05:30 PM Light_Item($light_ktch):: State->predict Event->on Handler->on Final->on DelayOff->1 Setby->Presence_Monitor=HASH(0x98ab5c8) ($presence_ktch)
08/07/09 09:05:30 PM $light_ktch::set(on, $presence_ktch) -> $ktch_light
08/07/09 09:05:30 PM [Insteon_Device] $ktch_light::set(on, Light_Item=HASH(0x985f670))
08/07/09 09:05:30 PM [Insteon_PLM] Parsing serial data: 02580602500515270f438a611117
08/07/09 09:05:30 PM [Insteon_PLM] ALL-Link Cleanup reports success
08/07/09 09:05:30 PM [Insteon_Device] received command/state acknowledge from $s_kpl_bent3: cleanup and data:
08/07/09 09:05:30 PM [Insteon_PLM] Processing message for $bent_light
08/07/09 09:05:30 PM [Insteon_Device] received command/state acknowledge from $bent_light: on and data:
08/07/09 09:05:31 PM [Insteon_PLM] Command stack size: 1
08/07/09 09:05:31 PM [Insteon_Device] $s_kpl_bent3::set(on, )
08/07/09 09:05:31 PM [Insteon_PLM] x10 sending code: B5 as insteon msg: 0263e100
08/07/09 09:05:31 PM [Insteon_PLM] Command stack size: 2
08/07/09 09:05:31 PM [Insteon_PLM] x10 sending code: BJ as insteon msg: 0263e280
08/07/09 09:05:31 PM [Insteon_PLM] Command stack size: 3
08/07/09 09:05:31 PM Light_Switch_Item($switch_bent3)::set(on, Insteon_Link=HASH(0x9870a28)) setby name: $bent_sw3
08/07/09 09:05:31 PM [Insteon_PLM] Parsing serial data: 1515
08/07/09 09:05:31 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:31 PM [Insteon_PLM] Parsing serial data: 02620515890f11ff06
08/07/09 09:05:31 PM [Insteon_PLM] Parsing serial data: 02611711ff06
Warning: Dummy_Interface #11: trying to set_receive motion
Warning: Dummy_Interface #11: trying to set_receive motion
08/07/09 09:05:31 PM XC2CJ: ktch_motion motion
08/07/09 09:05:32 PM Motion_Item($motion_ktch)::set(motion, X10_Sensor=HASH(0x9839b88)): $ktch_motion was set by rf
08/07/09 09:05:32 PM Ignore Check: $motion_ktch
08/07/09 09:05:32 PM Log check: $motion_ktch [8 31 53]
08/07/09 09:05:32 PM Presence Check: $motion_ktch
08/07/09 09:05:32 PM Object $motion_deck has common edge: 8
08/07/09 09:05:32 PM Object $motion_deck was marked as a door with timeout: 10
08/07/09 09:05:32 PM Door $door_back was not opened so occupancy transfer is not allowed
08/07/09 09:05:32 PM Object $motion_ktch_land has common edge: 31
08/07/09 09:05:32 PM Object $motion_ktch_land no door edge restriction active
08/07/09 09:05:32 PM Connecting room $motion_ktch_land count decremented (1 total)
08/07/09 09:05:32 PM Clearing used flag for $motion_ktch (presence)
08/07/09 09:05:32 PM Adding 1 to room $motion_ktch
08/07/09 09:05:32 PM Clearing used flag for $motion_ktch (presence)
08/07/09 09:05:32 PM Adding 1 to room $motion_ktch2
08/07/09 09:05:32 PM Clearing used flag for $motion_ktch (presence)
08/07/09 09:05:32 PM Adding 1 to room $switch_ktch
08/07/09 09:05:32 PM Clearing used flag for $motion_ktch (presence)
08/07/09 09:05:32 PM Adding 1 to room $door_back
08/07/09 09:05:32 PM count_people: counting object $motion_entr (13 21 22): 1 (count=0)
08/07/09 09:05:32 PM count_people: counting object $motion_sbr_hall (3 33): 1 (count=1)
08/07/09 09:05:32 PM count_people: counting object $motion_ktch (8 31 53): 1 (count=2)
08/07/09 09:05:32 PM count_people: counting object $motion_deck (8 15): 1 (count=3)
08/07/09 09:05:32 PM count_people: counting object $motion_fmly (9): 1 (count=4)
08/07/09 09:05:32 PM set_by_to_target encountered these objects: $presence_ktch, $om returning
08/07/09 09:05:32 PM Light_Item($light_ktch): Light_Restriction_Item : light_ok
08/07/09 09:05:32 PM Light_Item($light_ktch):: State->occupied Event->on Handler->on Final->on DelayOff->0 Setby->Presence_Monitor=HASH(0x98ab5c8) ($presence_ktch)
08/07/09 09:05:32 PM $light_ktch::set(on, $presence_ktch) -> $ktch_light
08/07/09 09:05:32 PM [Insteon_PLM] Command stack size: 2
08/07/09 09:05:32 PM [Insteon_Device] $ktch_light::set(on, Light_Item=HASH(0x985f670))
08/07/09 09:05:32 PM [Insteon_PLM] Parsing serial data: 02500515890f438a2711ff
08/07/09 09:05:32 PM [Insteon_PLM] Processing message for $ktch_light
08/07/09 09:05:32 PM [Insteon_Device] received command/state acknowledge from $ktch_light: on and data: ff
08/07/09 09:05:32 PM Light_Switch_Item($switch_ktch)::set(on, Insteon_Link=HASH(0x985f420)) setby name: $ktch_light
08/07/09 09:05:32 PM MYLOGKPL: sync_kpl_lights called for state_changed on SCALAR(0x95b2298) to on for SCALAR(0x9698fb8) set kpls in 1sec
08/07/09 09:05:32 PM [Insteon_PLM] Parsing serial data: 0263e10006
08/07/09 09:05:32 PM [Insteon_PLM] Parsing serial data: 0263e28006
08/07/09 09:05:32 PM Motion_Item($motion_ktch2)::set(alert, RF_Item=HASH(0x984c780)): $ktch2_motion was set by rf
08/07/09 09:05:32 PM Ignore Check: $motion_ktch2
08/07/09 09:05:32 PM Log check: $motion_ktch2 [8 31 53]
08/07/09 09:05:32 PM Door $door_back was not opened so occupancy transfer is not allowed
08/07/09 09:05:32 PM Door $door_back was not opened so occupancy transfer is not allowed
08/07/09 09:05:32 PM Door $door_back was not opened so occupancy transfer is not allowed
08/07/09 09:05:32 PM Door $door_back was not opened so occupancy transfer is not allowed
08/07/09 09:05:32 PM Door $door_back was not opened so occupancy transfer is not allowed
08/07/09 09:05:33 PM [Insteon_PLM] Command stack size: 1
08/07/09 09:05:33 PM [Insteon_Device] $s_kpl_dinn3::set(on, )
08/07/09 09:05:33 PM Light_Switch_Item($switch_dinn3)::set(on, Insteon_Link=HASH(0x9865a88)) setby name: $dinn_sw3
08/07/09 09:05:33 PM [Insteon_PLM] Parsing serial data: 02620515890f11ff06
08/07/09 09:05:33 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:33 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:33 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:33 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
Warning: Dummy_Interface #21: trying to set_receive motion
Warning: Dummy_Interface #21: trying to set_receive motion
08/07/09 09:05:34 PM XDEDJ: land_motion motion
08/07/09 09:05:34 PM Motion_Item($motion_land)::set(motion, X10_Sensor=HASH(0x9848eb0)): $land_motion was set by rf
08/07/09 09:05:34 PM Ignore Check: $motion_land
08/07/09 09:05:34 PM Log check: $motion_land [1 7 14 16]
08/07/09 09:05:34 PM Presence Check: $motion_land
08/07/09 09:05:34 PM Stealing presence from extra room $motion_ktch
08/07/09 09:05:34 PM Moving to intermediate room $motion_ktch_land
08/07/09 09:05:34 PM Presence Check: $motion_ktch_land
08/07/09 09:05:34 PM Object $motion_ktch has common edge: 31
08/07/09 09:05:34 PM Object $motion_ktch no door edge restriction active
08/07/09 09:05:34 PM Connecting room $motion_ktch count decremented (1 total)
08/07/09 09:05:34 PM Object $motion_ktch2 has common edge: 31
08/07/09 09:05:34 PM Object $motion_ktch2 no door edge restriction active
08/07/09 09:05:34 PM Connecting room $motion_ktch2 count decremented (1 total)
08/07/09 09:05:34 PM Object $switch_ktch has common edge: 31
08/07/09 09:05:34 PM Object $switch_ktch no door edge restriction active
08/07/09 09:05:34 PM Connecting room $switch_ktch count decremented (1 total)
08/07/09 09:05:34 PM Object $door_back has common edge: 31
08/07/09 09:05:34 PM Object $door_back no door edge restriction active
08/07/09 09:05:34 PM Connecting room $door_back count decremented (1 total)
08/07/09 09:05:34 PM Clearing used flag for $motion_ktch_land (presence)
08/07/09 09:05:34 PM Adding 1 to room $motion_ktch_land
08/07/09 09:05:34 PM Presence Check: $motion_land
08/07/09 09:05:34 PM Object $motion_ktch_land has common edge: 1
08/07/09 09:05:34 PM Object $motion_ktch_land no door edge restriction active
08/07/09 09:05:34 PM Connecting room $motion_ktch_land count decremented (1 total)
08/07/09 09:05:34 PM Clearing used flag for $motion_land (presence)
08/07/09 09:05:34 PM Adding 1 to room $switch_stwy
08/07/09 09:05:34 PM Clearing used flag for $motion_land (presence)
08/07/09 09:05:34 PM Adding 1 to room $motion_land
08/07/09 09:05:34 PM count_people: counting object $motion_entr (13 21 22): 1 (count=0)
08/07/09 09:05:34 PM count_people: counting object $switch_stwy (1 7 14 16): 1 (count=1)
08/07/09 09:05:34 PM count_people: counting object $motion_sbr_hall (3 33): 1 (count=2)
08/07/09 09:05:34 PM count_people: counting object $motion_deck (8 15): 1 (count=3)
08/07/09 09:05:34 PM count_people: counting object $motion_fmly (9): 1 (count=4)
08/07/09 09:05:34 PM set_by_to_target encountered these objects: $presence_land, $om returning
08/07/09 09:05:34 PM Light_Item($light_stwy): Light_Restriction_Item : light_ok
08/07/09 09:05:34 PM Light_Item($light_stwy):: State->occupied Event->on Handler->on Final->on DelayOff->0 Setby->Presence_Monitor=HASH(0x98ab7e8) ($presence_land)
08/07/09 09:05:34 PM $light_stwy::set(on, $presence_land) -> $stwy_light
08/07/09 09:05:34 PM [Insteon_PLM] Command stack size: 1
08/07/09 09:05:34 PM [Insteon_Device] $stwy_light::set(on, Light_Item=HASH(0x9869928))
08/07/09 09:05:34 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:34 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:34 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:34 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:35 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:35 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:35 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:35 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:35 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:35 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:36 PM Motion_Item($motion_drvw)::set(off, Timer=HASH(0x966a548))
08/07/09 09:05:36 PM $motion_drvw::set(still, ) -> $drvw_motion
Warning: Dummy_Interface #0: trying to set_receive still
08/07/09 09:05:36 PM [Insteon_PLM] Parsing serial data: 1515
08/07/09 09:05:36 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:36 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:36 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:36 PM [Insteon_Device] WARN: queue timer on $s_kpl_bent3 expired. Attempting resend: on
08/07/09 09:05:36 PM [Insteon_PLM] Command stack size: 2
08/07/09 09:05:37 PM [Insteon_PLM] Parsing serial data: 1515
08/07/09 09:05:37 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:37 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:37 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:38 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:38 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
Warning: Dummy_Interface #11: trying to set_receive motion
Warning: Dummy_Interface #11: trying to set_receive motion
08/07/09 09:05:38 PM XC2CJ: ktch_motion motion
08/07/09 09:05:38 PM Motion_Item($motion_ktch)::set(motion, X10_Sensor=HASH(0x9839b88)): $ktch_motion was set by rf
08/07/09 09:05:38 PM Ignore Check: $motion_ktch
08/07/09 09:05:38 PM Ignored activity from: $motion_ktch
08/07/09 09:05:38 PM [Insteon_Device] WARN: queue timer on $ktch_light expired. Trying next command if queued.
08/07/09 09:05:38 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:38 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:38 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:38 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
Warning: Dummy_Interface #12: trying to set_receive motion
Warning: Dummy_Interface #12: trying to set_receive motion
08/07/09 09:05:38 PM XC3CJ: bent_motion motion
08/07/09 09:05:38 PM Motion_Item($motion_bent)::set(motion, X10_Sensor=HASH(0x983a458)): $bent_motion was set by rf
08/07/09 09:05:38 PM Ignore Check: $motion_bent
08/07/09 09:05:38 PM Log check: $motion_bent [9 10 18 19]
08/07/09 09:05:38 PM Presence Check: $motion_bent
08/07/09 09:05:38 PM Object $motion_fmly has common edge: 9
08/07/09 09:05:38 PM Object $motion_fmly no door edge restriction active
08/07/09 09:05:38 PM Connecting room $motion_fmly count decremented (1 total)
08/07/09 09:05:38 PM Object $fmly_cmd has common edge: 9
08/07/09 09:05:38 PM Object $fmly_cmd no door edge restriction active
08/07/09 09:05:38 PM Connecting room $fmly_cmd count decremented (1 total)
08/07/09 09:05:38 PM Clearing used flag for $motion_bent (presence)
08/07/09 09:05:38 PM Adding 1 to room $motion_bent
08/07/09 09:05:38 PM count_people: counting object $motion_entr (13 21 22): 1 (count=0)
08/07/09 09:05:38 PM count_people: counting object $switch_stwy (1 7 14 16): 1 (count=1)
08/07/09 09:05:38 PM count_people: counting object $motion_sbr_hall (3 33): 1 (count=2)
08/07/09 09:05:38 PM count_people: counting object $motion_deck (8 15): 1 (count=3)
08/07/09 09:05:38 PM count_people: counting object $motion_bent (9 10 18 19): 1 (count=4)
08/07/09 09:05:38 PM set_by_to_target encountered these objects: $presence_bent, $om returning
08/07/09 09:05:38 PM Light_Item($light_bent): Light_Restriction_Item : light_ok
08/07/09 09:05:38 PM Light_Item($light_bent):: State->occupied Event->on Handler->on Final->on DelayOff->0 Setby->Presence_Monitor=HASH(0x98a6f00) ($presence_bent)
08/07/09 09:05:38 PM $light_bent::set(on, $presence_bent) -> $bent_light
08/07/09 09:05:38 PM [Insteon_PLM] Command stack size: 3
08/07/09 09:05:38 PM [Insteon_Device] $bent_light::set(on, Light_Item=HASH(0x986f4d0))
08/07/09 09:05:39 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:39 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
Warning: Dummy_Interface #22: trying to set_receive motion
Warning: Dummy_Interface #22: trying to set_receive motion
08/07/09 09:05:39 PM XDGDJ: lvrm_motion motion
08/07/09 09:05:39 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:39 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:39 PM Motion_Item($motion_lvrm)::set(motion, X10_Sensor=HASH(0x9849ac0)): $lvrm_motion was set by rf
08/07/09 09:05:39 PM Ignore Check: $motion_lvrm
08/07/09 09:05:39 PM Log check: $motion_lvrm [14 17]
08/07/09 09:05:39 PM Presence Check: $motion_lvrm
08/07/09 09:05:39 PM Object $switch_stwy has common edge: 14
08/07/09 09:05:39 PM Object $switch_stwy no door edge restriction active
08/07/09 09:05:39 PM Connecting room $switch_stwy count decremented (1 total)
08/07/09 09:05:39 PM Object $motion_land has common edge: 14
08/07/09 09:05:39 PM Object $motion_land no door edge restriction active
08/07/09 09:05:39 PM Connecting room $motion_land count decremented (1 total)
08/07/09 09:05:39 PM Clearing used flag for $motion_lvrm (presence)
08/07/09 09:05:39 PM Adding 1 to room $switch_lvrm2
08/07/09 09:05:39 PM Clearing used flag for $motion_lvrm (presence)
08/07/09 09:05:39 PM Adding 1 to room $motion_lvrm
08/07/09 09:05:39 PM Clearing used flag for $motion_lvrm (presence)
08/07/09 09:05:39 PM Adding 1 to room $motion_lvrm2
08/07/09 09:05:39 PM Clearing used flag for $motion_lvrm (presence)
08/07/09 09:05:39 PM Adding 1 to room $switch_lvrm
08/07/09 09:05:39 PM count_people: counting object $switch_lvrm2 (14 17): 1 (count=0)
08/07/09 09:05:39 PM count_people: counting object $motion_entr (13 21 22): 1 (count=1)
08/07/09 09:05:39 PM count_people: counting object $motion_sbr_hall (3 33): 1 (count=2)
08/07/09 09:05:39 PM count_people: counting object $motion_deck (8 15): 1 (count=3)
08/07/09 09:05:39 PM count_people: counting object $motion_bent (9 10 18 19): 1 (count=4)
08/07/09 09:05:39 PM set_by_to_target encountered these objects: $presence_lvrm, $om returning
08/07/09 09:05:39 PM Light_Item($light_lvrm2): Light_Restriction_Item : light_ok
08/07/09 09:05:39 PM Light_Item($light_lvrm2):: State->occupied Event->on Handler->on Final->on DelayOff->0 Setby->Presence_Monitor=HASH(0x98ab188) ($presence_lvrm)
08/07/09 09:05:39 PM $light_lvrm2::set(on, $presence_lvrm) -> $lvrm_lamp2
08/07/09 09:05:39 PM [Insteon_PLM] Command stack size: 4
08/07/09 09:05:39 PM [Insteon_Device] $lvrm_lamp2::set(on, Light_Item=HASH(0x9887980))
08/07/09 09:05:39 PM set_by_to_target encountered these objects: $presence_lvrm, $om returning
08/07/09 09:05:39 PM Light_Item($light_lvrm): Light_Restriction_Item : light_ok
08/07/09 09:05:39 PM Light_Item($light_lvrm):: State->occupied Event->on Handler->on Final->on DelayOff->0 Setby->Presence_Monitor=HASH(0x98ab188) ($presence_lvrm)
08/07/09 09:05:39 PM $light_lvrm::set(on, $presence_lvrm) -> $lvrm_lamp
08/07/09 09:05:39 PM [Insteon_PLM] Command stack size: 5
08/07/09 09:05:39 PM [Insteon_Device] $lvrm_lamp::set(on, Light_Item=HASH(0x9887080))
08/07/09 09:05:39 PM set_by_to_target encountered these objects: $presence_lvrm, $om returning
08/07/09 09:05:39 PM Light_Item($light_lvrm3): Light_Restriction_Item : light_ok
08/07/09 09:05:39 PM Light_Item($light_lvrm3):: State->occupied Event->on Handler->on Final->on DelayOff->0 Setby->Presence_Monitor=HASH(0x98ab188) ($presence_lvrm)
08/07/09 09:05:39 PM $light_lvrm3::set(on, $presence_lvrm) -> $lvrm_lamp3
08/07/09 09:05:39 PM [Insteon_PLM] Command stack size: 6
08/07/09 09:05:39 PM [Insteon_Device] $lvrm_lamp3::set(on, Light_Item=HASH(0x9888de0))
08/07/09 09:05:39 PM set_by_to_target encountered these objects: $presence_lvrm, $om returning
08/07/09 09:05:39 PM Light_Item($light_stwy): Light_Restriction_Item : light_ok
08/07/09 09:05:39 PM Light_Item($light_stwy):: State->occupied Event->on Handler->on Final->on DelayOff->0 Setby->Presence_Monitor=HASH(0x98ab188) ($presence_lvrm)
08/07/09 09:05:39 PM $light_stwy::set(on, $presence_lvrm) -> $stwy_light
08/07/09 09:05:39 PM [Insteon_PLM] Attempt to queue command already in queue; skipping ...
08/07/09 09:05:39 PM [Insteon_Device] $stwy_light::set(on, Light_Item=HASH(0x9869928))
08/07/09 09:05:39 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:39 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:40 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:40 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:40 PM Motion_Item($motion_lvrm2)::set(alert, RF_Item=HASH(0x984efd8)): $lvrm2_motion was set by rf
08/07/09 09:05:40 PM Ignore Check: $motion_lvrm2
08/07/09 09:05:40 PM Log check: $motion_lvrm2 [14 17]
08/07/09 09:05:40 PM [Insteon_PLM] Parsing serial data: 1515
08/07/09 09:05:40 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:41 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:41 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:41 PM [Insteon_PLM] Parsing serial data: 1515
08/07/09 09:05:41 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:42 PM [Insteon_PLM] Parsing serial data: 1515
08/07/09 09:05:42 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
08/07/09 09:05:42 PM [Insteon_PLM] Parsing serial data: 15
08/07/09 09:05:42 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
Warning: Dummy_Interface #19: trying to set_receive motion
Warning: Dummy_Interface #19: trying to set_receive motion
08/07/09 09:05:42 PM XDBDJ: lndy_motion motion
08/07/09 09:05:42 PM Motion_Item($motion_lndy)::set(motion, X10_Sensor=HASH(0x9845eb0)): $lndy_motion was set by rf
08/07/09 09:05:42 PM Ignore Check: $motion_lndy
08/07/09 09:05:42 PM Log check: $motion_lndy [11]
08/07/09 09:05:42 PM Presence Check: $motion_lndy
08/07/09 09:05:42 PM Stealing presence from extra room $motion_bent
08/07/09 09:05:42 PM Moving to intermediate room $motion_bhal
08/07/09 09:05:42 PM Presence Check: $motion_bhal
08/07/09 09:05:42 PM Object $motion_bent has common edge: 19
08/07/09 09:05:42 PM Object $motion_bent no door edge restriction active
08/07/09 09:05:42 PM Connecting room $motion_bent count decremented (1 total)
08/07/09 09:05:42 PM Clearing used flag for $motion_bhal (presence)
08/07/09 09:05:42 PM Adding 1 to room $motion_bhal
08/07/09 09:05:42 PM Presence Check: $motion_lndy
08/07/09 09:05:42 PM Object $motion_bhal has common edge: 11
08/07/09 09:05:42 PM Object $motion_bhal no door edge restriction active
08/07/09 09:05:42 PM Connecting room $motion_bhal count decremented (1 total)
08/07/09 09:05:42 PM Clearing used flag for $motion_lndy (presence)
08/07/09 09:05:42 PM Adding 1 to room $motion_lndy
08/07/09 09:05:42 PM count_people: counting object $switch_lvrm2 (14 17): 1 (count=0)
08/07/09 09:05:42 PM count_people: counting object $motion_entr (13 21 22): 1 (count=1)
08/07/09 09:05:42 PM count_people: counting object $motion_sbr_hall (3 33): 1 (count=2)
08/07/09 09:05:42 PM count_people: counting object $motion_deck (8 15): 1 (count=3)
08/07/09 09:05:42 PM count_people: counting object $motion_lndy (11): 1 (count=4)
08/07/09 09:05:42 PM set_by_to_target encountered these objects: $presence_lndy, $om returning
08/07/09 09:05:42 PM Light_Item($light_lndy): Light_Restriction_Item : light_ok
08/07/09 09:05:42 PM Light_Item($light_lndy):: State->occupied Event->on Handler->on Final->on DelayOff->0 Setby->Presence_Monitor=HASH(0x98abc28) ($presence_lndy)
08/07/09 09:05:42 PM $light_lndy::set(on, $presence_lndy) -> $lndy_light
08/07/09 09:05:42 PM [Insteon_PLM] Command stack size: 7
08/07/09 09:05:42 PM [Insteon_Device] $lndy_light::set(on, Light_Item=HASH(0x987e6d8))
08/07/09 09:05:42 PM [Insteon_PLM] Parsing serial data: 1515
08/07/09 09:05:42 PM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second

------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
________________________________________________________
To unsubscribe from this list, go to: http://sourceforge.net/mail/?group_id=1365

[Gregg Liming]

Hi Brad,

Brad Bosch wrote:

> What is the current understanding of the occasional PLM hangs where
> the PLM LED just goes out and it stops responding?

At one time, I thought that I knew.  But, I'm no longer convinced.  FWIW
(and, likely minimal), I haven't had a "hang-up" in months.  If I had to
conjecture, it's likely some sort of timing issue that occurs.  What I
don't know is whether "we" can truly do anything about it.

> It seems that the micro-controller inside the PLM has crashed or
> something.  It won't work again until I unplug it and plug it back in
> (at which time, MH generally recovers without a restart).  I know
> there has been some discussion on this in the past and that some
> effort has been made to avoid triggering the problem by being cautious
> with command rates, etc,z

At one point, I was pretty sure that I can almost create it at will by
deluging the controller.  But, it's been a while and I'm no longer at a
point that I can properly "hammer" in a controlled way.

> but I still experience these crashes at least
> once a week.  As a last ditch hack to work around the bug, I am
> considering putting the PLM behind an X10 appliance module with a CM11
> interface (which I had retired) to allow MH to reset the PLM when it
> detects this failure.
>
> This is clearly a serious PLM firmware bug which SmartHome should fix!

no argument

> But is it triggered by a bug in the the MH insteon code?  

My preference would be an answer of "yes"--if only it could be
identified w/ debug.  Until then, I've never seen anything pointing
specifically to mh.

What is not at all clear to me is whether anything of mh's ability tries
to control insteon devices.  I don't mean to just deflect; but, I just
haven't seen other substantive controlling examples.

> Or are we
> sure we are sending only valid commands to the PLM and staying within
> it's intended use cases?

I'm as sure as I can.  I don't know that that really means anything
though.  And, likely the eventual new queuing code *might* mitigate the
as yet unknown problem.

> I have a *lot* of Insteon hardware now and I'd like to get this fixed.
> Gregg, does your new Insteon code completely eliminate this?

Although, it's "new", I'd suggest that it's more "half-baked" as the
more important issues w/ command queuing have not been implemented.  So,
for a practical matter, the answer is no.

On the other hand, I haven't had an issue w/ the PLM in many months.

> Has someone had a dialog with the SmartHome technical support or
> developers about this?

I have not.  I'm not sure what I would say other than "your device
locked up and I had to unplug it and push back it into the wall".  I can
only assume that they would clap hands and exclaim "job well done!".

Yes, help desk causes me to become "clammy".

> I have included an exeprt of my log file, but, would it help to have
> captures from a "serial protocol analyzer" of the traffic to/from the
> PLM?

I don't know what to look for when I don't have an idea as to what the
problem is.  To be honest, you have so much other debug "stuff", that
your log file is difficult to analyze that I gave up.  I realize that
you're addressing a different protocol, but I probably won't look at it
if I don't have some sense to a pattern to look for.

> I could, easily enough, wire up an additional pair of serial
> ports to log and timestamp the actual serial exchange with the PLM if
> someone wants to look at it.
>
> Some of my current potentially relevant settings:
>
> Insteon_PLM_max_queue_time=5
> Insteon_PLM_disable_throttling=1
> Insteon_PLM_xmit_delay=0.15
>
> Various changes I have tried with these, including the trottling
> setting seem not to solve the problem but what are the current
> recommended settings?

I use the same settings.

Sorry to not provide the silver bullet.

Gregg

------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
________________________________________________________
To unsubscribe from this list, go to: http://sourceforge.net/mail/?group_id=1365

[Rick Bolen (GM)]

I was experiencing this on occasion but haven't hung in months. I have a
power meter  monitor "chatting" on the AC wires also, and I always
thought that was  a candidate for  wedging the PLM.

I also bought a second PLM with a newer firmware revision but haven't
put that into the production environment yet.

It would be helpful if Smartlabs could offer some debugging capability.
Since you're experiencing this regularly, you might setup to log the
serial data and monitor the AC line signal quality (if possible). If you
had the facility to do this, you would be an excellent candidate for
helping SmartLabs improve their product.

It would be quite an involved setup to be able to capture both serial
and AC waveform data, but I believe that's what it might take to squash
this bug.

Good luck,

Rick



Brad Bosch wrote:
> Gregg and Insteon PLM users,
>
> What is the current understanding of the occasional PLM hangs where
> the PLM LED just goes out and it stops responding?
>
>  


------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
________________________________________________________
To unsubscribe from this list, go to: http://sourceforge.net/mail/?group_id=1365

[Pierre Belanger-2]

Why wouldn't Smartlabs give a contract to a Linux programmer?

Maybe we should put money in a basket and find someone with or without
the help from Insteon?

There are plenty around, easy to locate (just grep in the Linux source
code) and just waiting for a company to give them some money -- make
the source code public and it will automatically be ported to many
Unix flavors for free.

I have the USB model not even using it... well last time I tried to
make it work something wasn't working.  Basically my mh project is on
ice since ~ 3-4 years ... maybe I need to get the PLM model but when I
read that it hangs, that really turns me down.

Pierre B.

> Good luck,
>
> Rick
>
>
>
> Brad Bosch wrote:
>> Gregg and Insteon PLM users,
>>
>> What is the current understanding of the occasional PLM hangs where
>> the PLM LED just goes out and it stops responding?
>>
>>
>
>
> ------------------------------------------------------------------------------
> Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
> trial. Simplify your report design, integration and deployment - and focus on
> what you do best, core application coding. Discover what's new with
> Crystal Reports now.  http://p.sf.net/sfu/bobj-july
> ________________________________________________________
> To unsubscribe from this list, go to: http://sourceforge.net/mail/?group_id=1365
>
>

------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
________________________________________________________
To unsubscribe from this list, go to: http://sourceforge.net/mail/?group_id=1365

[Garry Doucette]

There's excellent support for the serial PLM in Misterhouse.

http://www.smarthome.com/2412S/PowerLinc-INSTEON-Modem-Serial/p.aspx

I've been running this one for about 2.5 years and it's never hung on me.

Garry

-----Original Message-----
From: Pierre Belanger [mailto:belanger@...]
Sent: Thursday, September 03, 2009 1:10 AM
To: The main list for the MisterHouse home automation program
Subject: Re: [mh] Insteon PLM hangs

Why wouldn't Smartlabs give a contract to a Linux programmer?

Maybe we should put money in a basket and find someone with or without the
help from Insteon?

There are plenty around, easy to locate (just grep in the Linux source
code) and just waiting for a company to give them some money -- make the
source code public and it will automatically be ported to many Unix flavors
for free.

I have the USB model not even using it... well last time I tried to make it
work something wasn't working.  Basically my mh project is on ice since ~
3-4 years ... maybe I need to get the PLM model but when I read that it
hangs, that really turns me down.

Pierre B.

> Good luck,
>
> Rick
>
>
>
> Brad Bosch wrote:
>> Gregg and Insteon PLM users,
>>
>> What is the current understanding of the occasional PLM hangs where
>> the PLM LED just goes out and it stops responding?
>>
>>
>
>
> ----------------------------------------------------------------------
> -------- Let Crystal Reports handle the reporting - Free Crystal
> Reports 2008 30-Day trial. Simplify your report design, integration
> and deployment - and focus on what you do best, core application
> coding. Discover what's new with Crystal Reports now.  
> http://p.sf.net/sfu/bobj-july 
> ________________________________________________________
> To unsubscribe from this list, go to:
> http://sourceforge.net/mail/?group_id=1365
>
>

----------------------------------------------------------------------------
--
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus
on what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
________________________________________________________
To unsubscribe from this list, go to:
http://sourceforge.net/mail/?group_id=1365



------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
________________________________________________________
To unsubscribe from this list, go to: http://sourceforge.net/mail/?group_id=1365

[Marc MERLIN-7]

On Thu, Sep 03, 2009 at 04:09:56AM -0400, Pierre Belanger wrote:
> I have the USB model not even using it... well last time I tried to
> make it work something wasn't working.  Basically my mh project is on
> ice since ~ 3-4 years ... maybe I need to get the PLM model but when I
> read that it hangs, that really turns me down.

I think it only hangs for a few people sometimes. Hangs are bad, but
it's far from widespread. I'm pretty sure it's hardware version dependent,
so not all PLMs have this problem, likely most don't.

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 & security ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/

------------------------------------------------------------------------------
Let Crystal Reports handle the reporting - Free Crystal Reports 2008 30-Day
trial. Simplify your report design, integration and deployment - and focus on
what you do best, core application coding. Discover what's new with
Crystal Reports now.  http://p.sf.net/sfu/bobj-july
________________________________________________________
To unsubscribe from this list, go to: http://sourceforge.net/mail/?group_id=1365

[Jim Duda]

I have just recently starting experience this myself.  I've had to
power cycle my PLM twice in the last two weeks.

For what it's worth, I've never had this problem before.  I've
been using my PLM for almost a year without any issues.

I can tell you that I brought my first KeypadLinc online just
3 weeks ago.

Maybe the introduction of a KPL is a clue?

Jim


------------------------------------------------------------------------------
Come build with us! The BlackBerry® Developer Conference in SF, CA
is the only developer event you need to attend this year. Jumpstart your
developing skills, take BlackBerry mobile applications to market and stay
ahead of the curve. Join us from November 9-12, 2009. Register now!
http://p.sf.net/sfu/devconf
________________________________________________________
To unsubscribe from this list, go to: http://sourceforge.net/mail/?group_id=1365