[mh] Insteon_PLM -> device_id never set?

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 454-5900

Greetings,

I am a relatively new convert to Insteon and MH and for the past few
weeks, I've struggled getting my new PLM to work properly with scenes.
I am using the current svn trunk.

It seems that after updating my perl skills (last time I codded perl
extensively, it wasn't even object oriented!), I may finally be
starting to understand the problem; MH thinks the Insteon_PLM object
device_id is zero because it is unset because $PLM->device_id() is
never being called with a value to set it.  Note that though I have
insteon debugging enabled in my mh.private.ini, I never see the
"[Insteon_PLM] PLM id:" print.

I have hacked around the problem by setting deviceid to my PLM's
device ID in add_item (by calling the device_id method) when it sends
the '0260' command and after factory resetting all my KPLs and
syncing, everything seems to work.

Questions:

Why does the '0260' command seem to fail or be ignored on my PLM?  I
never seem to correctly locate the '06' return code with the '0260'
record type in _parse_data which seems to be where the device_id()
method *should* have been called to set the PLM device ID.

Is this a know problem?  My PLM is marked revision 3.1 on it's
sticker.  Is it too old or too new?  My firmware version might be 85
(see log below), but I'm not sure since the parsing the query response
fails.  Do I need a different firmware version?

Why doesn't read_table_A.pl allow us to pass the device ID on the
INSTEON_PLM line to the new method when the Insteon_PLM PLM object is
created from the .mht file?  When I called PLM->device_id() from my
user.pl file, the initial status commands seemed to fail; Thus, the
hack...  (Or have I missed something?)

Is there a programmers guide for the PLM available?  How can I obtain a
copy?

I gather that the Insteon support is being completely re-worked by
Gregg?  Is there a Subversion branch for this work?  If not, is there
a way I can contribute to this effort?

Have I properly understood the code?

I have also enhanced the Light_Item and Light_Switch_Item code.  Is
there a MH development email list or should I post patches for
discussion here?

Thanks for your help!

--Brad

Below are the first several debug lines from a fresh mh start.  I have
added some notes marked by '****'.  I presume this contains a clue
which I might even find myself if I had some documentation on the
PLM....

06/01/09 09:38:49 AM ---------- Restart ---------- 
06/01/09 09:38:49 AM [Insteon_PLM] serial:/dev/ttyS0:19200
06/01/09 09:38:49 AM Reading /home/brad/src/misterhouse/mh.private.ini and mh.ini
06/01/09 09:38:49 AM Reading 1 .mht table files: insteon.mht
06/01/09 09:38:49 AM Translating insteon.mht -> /home/brad/src/misterhouse/code/insteon.mhp
06/01/09 09:38:49 AM Initialized read_table_A.pl
06/01/09 09:38:49 AM Reading 18 code files
06/01/09 09:38:49 AM Evaluating user code
06/01/09 09:38:49 AM [Insteon_PLM] setting default xmit delay to: 0.15
06/01/09 09:38:49 AM [Insteon_PLM] setting x10 xmit delay to: 0.5

**** The following two lines were added by me to verify that my hacked in device ID set was working

06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID:  _id_check: 
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [X10_Sensor] Calling Serial_match_add_hook
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM [Insteon_PLM] -> add_item() self->device ID: 0f438A _id_check: 1
06/01/09 09:38:49 AM Called prevent_bounces count=2
06/01/09 09:38:49 AM Called prevent_bounces count=2
06/01/09 09:38:49 AM Called prevent_bounces count=2
06/01/09 09:38:49 AM [Insteon_PLM] Command stack size: 1
06/01/09 09:38:49 AM [Insteon_PLM] Command stack size: 2
06/01/09 09:38:49 AM [Insteon_PLM] Command stack size: 3
06/01/09 09:38:49 AM [Insteon_PLM] Command stack size: 4
06/01/09 09:38:49 AM [Insteon_PLM] Command stack size: 5
06/01/09 09:38:49 AM [Insteon_PLM] Command stack size: 6
06/01/09 09:38:49 AM [Insteon_PLM] Command stack size: 7
06/01/09 09:38:50 AM [Insteon_PLM] Parsing serial data: 02600f438a03058506
06/01/09 09:38:50 AM [Insteon_PLM] Prior cmd failed

**** Can someone interpret the above response for me?  Did the request
     fail?  I see my PLM device ID in there.  I gather my firmware
     version is 0x85?

06/01/09 09:38:50 AM Generating Voice commands for all Insteon objects
06/01/09 09:38:50 AM Rereading .menu code files.
06/01/09 09:38:50 AM Organizer: Calendar matches target schema and does not require upgrading
06/01/09 09:38:50 AM Organizer: Todo matches target schema and does not require upgrading
06/01/09 09:38:50 AM Organizer: Reading updated organizer calendar file now
06/01/09 09:38:50 AM Evaluating code organizer_events
06/01/09 09:38:50 AM Organizer: Reading updated organizer todo file
06/01/09 09:38:50 AM Evaluating code organizer_tasks
06/01/09 09:38:52 AM [Insteon_PLM] Prepending prior data fragment: 438a03058506
06/01/09 09:38:52 AM [Insteon_PLM] Parsing serial data: 438a0305850602621005440f19000602501005440f438a2b0000
06/01/09 09:38:52 AM [Insteon_PLM] Processing message for $mbr_lamp1
06/01/09 09:38:52 AM [Insteon_Device] received status request report for $mbr_lamp1 with on-level: 0%, hops left: 2
06/01/09 09:38:52 AM : New value 1 different than 
06/01/09 09:38:52 AM Light_Switch_Item($switch_mbr1) setby: Insteon_Link=HASH(0x9b48a98)setby name: $mbr_lamp1
06/01/09 09:38:52 AM Light_Switch_Item($switch_mbr1)::set(off, Insteon_Link=HASH(0x9b48a98)): $mbr_lamp1 was set by Insteon_PLM=HASH(0x9af70b8) p_state = off
06/01/09 09:38:52 AM [Insteon_PLM] Parsing serial data: 0262112f6c0f190006
06/01/09 09:38:52 AM Setting mixer volume to 0
06/01/09 09:38:52 AM [Insteon_PLM] Parsing serial data: 02620515890f190006
06/01/09 09:38:52 AM [Insteon_PLM] Parsing serial data: 150250112f6c0f438a2318fe
06/01/09 09:38:52 AM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
06/01/09 09:38:52 AM [Insteon_PLM] Processing message for $mbr_lamp2
06/01/09 09:38:52 AM [Insteon_Device] received status request report for $mbr_lamp2 with on-level: 100%, hops left: 0
06/01/09 09:38:52 AM [Insteon_PLM] Parsing serial data: 02500515890f438a2b1a0002620513f10f190006
06/01/09 09:38:52 AM [Insteon_PLM] Processing message for $ktch_light
06/01/09 09:38:52 AM [Insteon_Device] received status request report for $ktch_light with on-level: 0%, hops left: 2
06/01/09 09:38:52 AM Light_Switch_Item($switch_ktch) setby: Insteon_Link=HASH(0x9b4df58)setby name: $ktch_light
06/01/09 09:38:52 AM Light_Switch_Item($switch_ktch)::set(off, Insteon_Link=HASH(0x9b4df58)): $ktch_light was set by Insteon_PLM=HASH(0x9af70b8) p_state = off
06/01/09 09:38:53 AM [Insteon_PLM] Parsing serial data: 02621134f10f190006
06/01/09 09:38:53 AM [Insteon_PLM] Parsing serial data: 026211350e0f190006
06/01/09 09:38:53 AM [Insteon_PLM] Parsing serial data: 02501134f10f438a2b0800
06/01/09 09:38:53 AM [Insteon_PLM] Processing message for $lvrm_lamp
06/01/09 09:38:53 AM [Insteon_Device] received status request report for $lvrm_lamp with on-level: 0%, hops left: 2
06/01/09 09:38:53 AM [Insteon_PLM] Parsing serial data: 15
06/01/09 09:38:53 AM [Insteon_PLM] Interface extremely busy. Resending command after delaying for 0.3 second
06/01/09 09:38:53 AM [Insteon_PLM] Parsing serial data: 025011350e0f438a2b1100
06/01/09 09:38:53 AM [Insteon_PLM] Processing message for $lvrm_lamp2
06/01/09 09:38:53 AM [Insteon_Device] received status request report for $lvrm_lamp2 with on-level: 0%, hops left: 2
06/01/09 09:38:53 AM [Insteon_PLM] Parsing serial data: 0262113afd0f190006
06/01/09 09:38:54 AM [Insteon_PLM] Parsing serial data: 0250113afd0f438a2b1900
06/01/09 09:38:54 AM [Insteon_PLM] Processing message for $lvrm_lamp3
06/01/09 09:38:54 AM [Insteon_Device] received status request report for $lvrm_lamp3 with on-level: 0%, hops left: 2
06/01/09 09:38:57 AM [Insteon_Device] WARN: queue timer on $dinn_light expired. Attempting resend: status_request
06/01/09 09:38:57 AM [Insteon_PLM] Parsing serial data: 02620513f10f190006
06/01/09 09:38:58 AM [Insteon_PLM] Parsing serial data: 02500513f10f438a2b3800
06/01/09 09:38:58 AM [Insteon_PLM] Processing message for $dinn_light
06/01/09 09:38:58 AM [Insteon_Device] received status request report for $dinn_light with on-level: 0%, hops left: 2
06/01/09 09:38:58 AM Light_Switch_Item($switch_dinn) setby: Insteon_Link=HASH(0x9b4f6b0)setby name: $dinn_light
06/01/09 09:38:58 AM Light_Switch_Item($switch_dinn)::set(off, Insteon_Link=HASH(0x9b4f6b0)): $dinn_light was set by Insteon_PLM=HASH(0x9af70b8) p_state = off