HOME › Forums › Gateways › EZSrve › Actions/Timers trigger (sometimes) appropriately

Viewing 15 posts - 1 through 15 (of 16 total)
1 2 Next
  • Author
    Posts
  • Anonymous
    Inactive
    March 8, 2010 at 11:55 pm
    Post count: 131
    #40253

    I have been replacing my X10 with Insteon and am now experiencing some inconsistencies with my timer action. Basically, I would like my houselights to turn on every night at Sunset+15 minutes. When I setup everything up, the timer works correctly (it turns on at the right time and turns off at the right time), the next night nothing comes on. I can press the “Night Time” button on the switchlinc and everything turns on correctly and even the rest of the X10 devices come on (showing the EZServe is responding to the request). I have also let it go three nights in a row, just to see if it would work on one of the subsequent nights, no luck.

    Is there a way to determine why the timer is not triggering on the second evening?

    Thanks,
    Steve

    Anonymous
    Inactive
    March 9, 2010 at 1:04 am
    Post count: 1001
    #43327

    There was a problem with Actions not being reenabled after execution which is corrected by 02.06.04 or later. The symptom is an Action would run on one day but not run the next because it was not being reenabled the day before the failure. If not at that level or later, you should update using the Discovery Tool.

    To trace Action activity use Telnet. Do a RESTART to insure a clean EZServe environment. Then issue the following commands in CMD window.

    telnet
    set logfile c:temptelnet.txt
    open 192.168.2.3 10001

    EZServe
    Simplehomenet

    The logfile command is system dependent so enter whatever is applicable to your system.
    The open command specifies your EZServe IP address. Be sure to enter port 10001
    The EZServe and Simplehomenet are responses to a login request that will be prompted for after issuing the open command.

    Leave the telnet trace running while the Actions are executing correctly, until you reach the time when an Action should have run and did not. The telnet trace will show if the Action is actually triggered at the correct time and what commands were executed in response to the Effects. The trace entries are time stamped so it will be easy to see what happened at Sunset +15 when it fails. Sunrise/Sunset values are changing almost every day now so a slight change in execution time is expected.

    Anonymous
    Inactive
    March 9, 2010 at 2:57 am
    Post count: 131
    #43328

    I will do the telnet tests and see what happens. I have already tested it and it logs correctly so hopefully over the next two/three days I can test it out.

    I had already updated to 2.06 from the net last weekend so it should be recent enough. But if there is an update I will try it. Unfortunately, when I run the Disovery.jar tool it is unable to find my EZServe. I don’t know why. If you have any suggestions that would be great.

    Thanks,
    Steve

    Anonymous
    Inactive
    March 9, 2010 at 3:32 am
    Post count: 131
    #43329

    BTW… Here is the results of pressing “ON” of Scene D on the switchlinc. The effect is that the SwitchLinc turns on two insteon controlled lights, plus it tells EZServe (group 09) that it was pressed so that it can turn on a X10 device. The “OFF” version does basically the same thing but turns those lights off.

    I don’t think that there are any problems in this, but there are statements that say “Error Sending”. I don’t know that it is a problem but thought that I would post it.

    Thanks,
    Steve

    03/08/2010 22.19.07: Done: PTH_StdMsg 50, ID 12.C4.86 Flag CB, Cmd1 11, Cmd2 0
    

    
03/08/2010 22.19.07: All link broadcast msg rcvd:Grp 6, Cmd 11
    

    
03/08/2010 22.19.08: Done: PTH_StdMsg 50, ID 12.C4.86 Flag 41, Cmd1 11, Cmd2 6
    

    
03/08/2010 22.19.08: In all link cleanup msg rcvd 12.C4.86, cmd 11, grpno 06
    

    
03/08/2010 22.19.08: In update dev status: dev 12.C4.86 status updated cmd 11, Grp 6
    

    
03/08/2010 22.19.08: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/08/2010 22.19.08: Error Sending
    

    
03/08/2010 22.19.08: In ActivatePostActn: Action Night Time ON,Post actn status 0
    

    
03/08/2010 22.19.08: Start polling of devices if requd
    

    
03/08/2010 22.19.08: In poll scene dev: devrec 23
    

    
03/08/2010 22.19.08: Done: MSG Code 62, ID 14.66.29 Cmd1 19, Cmd2 0 Ack 6
    

    
03/08/2010 22.19.08: In process actions: Activate effect
    

    
03/08/2010 22.19.08: In process actions: Effect to process and action Night Time ON
    

    
03/08/2010 22.19.08: In form cluster actor queue: attr name Status, attr value 0x02
    

    
03/08/2010 22.19.08: Form clustr: CB-0: [3] CB-I: [41] CB-II: [4] CB-III: [0] CB-IV: [80] CB-V: [2] CB-VI: [0] CB-VII: [0] CB-VIII: [0] CB-IX: [0]
    

    
03/08/2010 22.19.08: In process actions: Effect to process and action Night Time ON
    

    
03/08/2010 22.19.08: In form cluster actor queue: attr name Status, attr value 0xFF
    

    
03/08/2010 22.19.08: Form clustr: CB-0: [4] CB-I: [8] CB-II: [0] CB-III: [0] CB-IV: [61] CB-V: [FF] CB-VI: [0] CB-VII: [0] CB-VIII: [0] CB-IX: [0]
    

    
03/08/2010 22.19.09: Done: PTH_StdMsg 50, ID 14.66.29 Flag 2B, Cmd1 76, Cmd2 FF
    

    
03/08/2010 22.19.09: In update dev status: dev 14.66.29 status updated cmd FF, Grp FFFFFFFF
    

    
03/08/2010 22.19.09: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/08/2010 22.19.09: Error Sending
    

    
03/08/2010 22.19.09: In poll scene dev: send command to next device or resend to prev dev
    

    
03/08/2010 22.19.09: ezdevice.c - SaveDeviceXML: File Open Success!
    

    
03/08/2010 22.19.11: ReadWriteApi.c - SaveSysVarXML: File Open Success!
    

    
03/08/2010 22.19.11: ezaction.c - SaveActionsSysVarXML Done!
    

    
03/08/2010 22.19.11: In actor requst process: actor queue ActorArray0 3,ActorArray4 80,ActorArray5 2
    

    
03/08/2010 22.19.11: Done: MSG Code 63, ID 6A.00.06 Cmd1 4D, Cmd2 67 Ack 2B
    

    
03/08/2010 22.19.11: In actor resp processor: cluster api in progress for ID[6A.00.06], RespArray9[0], RespArray10[0]
    

    
03/08/2010 22.19.12: Done: MSG Code 63, ID 62.80.06 Cmd1 4D, Cmd2 67 Ack 2B
    

    
03/08/2010 22.19.12: In update dev status: dev A04 status updated cmd 2, Grp FFFFFFFF
    

    
03/08/2010 22.19.12: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/08/2010 22.19.12: Error Sending
    

    
03/08/2010 22.19.12: In actor resp processor: cluster api in progress for ID[62.80.06], RespArray9[0], RespArray10[0]
    

    
03/08/2010 22.19.12: Fn Get_ClusterAction: Case X10 Arg1[80], Arg2[2]
    

    
03/08/2010 22.19.12: In update cluster ram insstd: attr 0 value 2
    

    
03/08/2010 22.19.12: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/08/2010 22.19.12: Error Sending
    

    
03/08/2010 22.19.12: In actor requst process: actor queue ActorArray0 4,ActorArray4 61,ActorArray5 ff
    

    
03/08/2010 22.19.12: In plm msg handler: Ins grp 0x8, Grpcmd 0x11
    

    
03/08/2010 22.19.13: Done: MSG Code 61, ID 08.11.08 Cmd1 4D, Cmd2 67 Ack 2B
    

    
03/08/2010 22.19.13: In actor resp processor: cluster api in progress for ID[08.11.08], RespArray9[0], RespArray10[0]
    

    
03/08/2010 22.19.13: In get cluster action: CID 0, attrnum 0
    

    
03/08/2010 22.19.13: In update cluster ram insstd: attr 0 value FF
    

    
03/08/2010 22.19.13: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/08/2010 22.19.13: Error Sending
    

    
03/08/2010 22.19.13: Done: PTH_StdMsg 50, ID 12.C4.86 Flag 61, Cmd1 11, Cmd2 8
    

    
03/08/2010 22.19.13: Done: MSG Code 58, ID 06.C4.86 Cmd1 4D, Cmd2 67 Ack 61
    

    
03/08/2010 22.19.13: File: PLM.c Fn: PLM_Process - All Link Clean-Up Group Status/Failure Report - 58 N/Ack/Grp - 6
    

    
03/08/2010 22.19.13: In update dev status: dev 08 status updated cmd FF, Grp FFFFFFFF
    

    
03/08/2010 22.19.13: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/08/2010 22.19.13: Error Sending
    

    
03/08/2010 22.19.13: In poll scene dev: devrec 18
    

    
03/08/2010 22.19.13: Done: PTH_StdMsg 50, ID 14.66.29 Flag 61, Cmd1 11, Cmd2 8
    

    
03/08/2010 22.19.13: Done: MSG Code 62, ID 12.C4.86 Cmd1 19, Cmd2 0 Ack 6
    

    
03/08/2010 22.19.14: Done: PTH_StdMsg 50, ID 12.C4.86 Flag 2B, Cmd1 B2, Cmd2 CC
    

    
03/08/2010 22.19.14: In update dev status: dev 12.C4.86 status updated cmd CC, Grp FFFFFFFF
    

    
03/08/2010 22.19.14: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/08/2010 22.19.14: Error Sending
    

    
03/08/2010 22.19.14: In poll scene dev: send command to next device or resend to prev dev
    

    
03/08/2010 22.19.14: Done: MSG Code 62, ID 14.66.29 Cmd1 19, Cmd2 0 Ack 6
    

    
03/08/2010 22.19.14: Done: PTH_StdMsg 50, ID 14.66.29 Flag 2B, Cmd1 76, Cmd2 FF
    

    
03/08/2010 22.19.14: In update dev status: dev 14.66.29 status updated cmd FF, Grp FFFFFFFF
    

    
03/08/2010 22.19.14: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/08/2010 22.19.14: Error Sending
    

    
03/08/2010 22.19.14: In poll scene dev: send command to next device or resend to prev dev
    

    
03/08/2010 22.19.14: ezdevice.c - SaveDeviceXML: File Open Success!
    

    
03/08/2010 22.19.16: ReadWriteApi.c - SaveSysVarXML: File Open Success!
    

    
03/08/2010 22.19.16: ezaction.c - SaveActionsSysVarXML Done!
    Anonymous
    Inactive
    March 9, 2010 at 3:34 am
    Post count: 1001
    #43330

    Image 02.06 has the failure to reenable an Action. Image 02.06.04 and above fixes the problem.

    No idea why the Discovery tool would not find the EZServe. Try unplugging the EZServe for a few minutes. See if the Discovery tool finds it after the power cycle. Are you running the latest 1.1 Discovery tool? Also is the EZServe running in DHCP mode?

    Ignore the “Error sending” trace entry. It does not indicate a failure.

    Anonymous
    Inactive
    March 9, 2010 at 3:47 am
    Post count: 131
    #43331

    It is 1.1, it is in DHCP mode, I did the power cycle as you mentioned and it still does not discover it.

    BTW: SHN_Utility does connect to it correctly. But then again I can put in the IP address or the server name and it finds it via local DNS.

    Is there a way to get the 02.06.04 bin file so that I can update it manually?

    Thanks,
    Steve

    Anonymous
    Inactive
    March 9, 2010 at 4:02 am
    Post count: 1001
    #43332

    Send me an email at lwgwork@embarqmail.com with an email address where I can send you the 02.06.04 image. We should really find out why the Discovery Tool does not now see the EZServe as there is a later image available through the Discovery Tool that I do not have the image of locally. Are the PC running the Discovery Tool and the EZServe connected to the same router?

    Anonymous
    Inactive
    March 9, 2010 at 4:11 am
    Post count: 131
    #43333

    Just sent the email.

    Yes they are both on the same router. I can access EZServe through the HTML interface, the Adobe interface, telnet, and SHN_Utility. The IP address never changes as I have it setup on the router to always use the same IP address to make accessing it easier.

    Anonymous
    Inactive
    March 11, 2010 at 11:33 pm
    Post count: 131
    #43334

    Well… Unfortunately it did not work as expected.

    I upgraded to the 02.06.04 as you suggested and waited the two days. Unfortunately, last night nothing happened. So tonight I setup the telnet as you suggested and the results below show that nothing happened at the right time.

    Basically, at 18:15 you should have seen the lights go on. However, between the telnet sesssion start and the 18.26 there is nothing. I pressed the “Night Time” scene button on the Insteon controller just to provide some feedback into the telnet log and show that everything on the EZServe controller was working correctly. Basically, the Insteon scene turned on the outside lights, the indoor outlet, and let the EZServe know that the button was pushed. Then EZServe’s action (same one that should control it at 18:15) triggered the X10 device to turn on as well.

    Unfortunately, this shows that EZServe works when manually told to do so, but that the timer is not working past the first execution after a reboot.

    Any suggestions?
    Steve

    Trying W.X.Y.Z...
    
Connected to EZServe.
    
Escape character is '^]'.
    

    
Welcome to SimpleHomeNet Debug Mode
    

    

    
login: EZServe
    

    
Password: *************
    

    
Debug Mode started for EZServe
    

    

    
03/11/2010 18.26.42: Done: PTH_StdMsg 50, ID 12.C4.86 Flag CB, Cmd1 11, Cmd2 0
    

    
03/11/2010 18.26.42: All link broadcast msg rcvd:Grp 6, Cmd 11
    

    
03/11/2010 18.26.42: Done: PTH_StdMsg 50, ID 12.C4.86 Flag 41, Cmd1 11, Cmd2 6
    

    
03/11/2010 18.26.42: In all link cleanup msg rcvd 12.C4.86, cmd 11, grpno 06
    

    
03/11/2010 18.26.42: In update dev status: dev 12.C4.86 status updated cmd 11, Grp 6
    

    
03/11/2010 18.26.42: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/11/2010 18.26.42: Error Sending
    

    
03/11/2010 18.26.42: In ActivatePostActn: Action Night Time ON,Post actn status 0
    

    
03/11/2010 18.26.42: Start polling of devices if requd
    

    
03/11/2010 18.26.42: In poll scene dev: devrec 23
    

    
03/11/2010 18.26.42: Done: MSG Code 62, ID 14.66.29 Cmd1 19, Cmd2 0 Ack 6
    

    
03/11/2010 18.26.42: In process actions: Activate effect
    

    
03/11/2010 18.26.43: In process actions: Effect to process and action Night Time ON
    

    
03/11/2010 18.26.43: In form cluster actor queue: attr name Status, attr value 0x02
    

    
03/11/2010 18.26.43: Form clustr: CB-0: [3] CB-I: [41] CB-II: [4] CB-III: [0] CB-IV: [80] CB-V: [2] CB-VI: [0] CB-VII: [0] CB-VIII: [0] CB-IX: [0]
    

    
03/11/2010 18.26.43: In process actions: Effect to process and action Night Time ON
    

    
03/11/2010 18.26.43: In form cluster actor queue: attr name Status, attr value 0xFF
    

    
03/11/2010 18.26.43: Done: PTH_StdMsg 50, ID 14.66.29 Flag 2B, Cmd1 76, Cmd2 FF
    

    
03/11/2010 18.26.43: In update dev status: dev 14.66.29 status updated cmd FF, Grp FFFFFFFF
    

    
03/11/2010 18.26.43: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/11/2010 18.26.43: Error Sending
    

    
03/11/2010 18.26.43: In poll scene dev: send command to next device or resend to prev dev
    

    
03/11/2010 18.26.43: ezdevice.c - SaveDeviceXML: File Open Success!
    

    
03/11/2010 18.26.45: In refresh_v.c: new update 11, old update 0
    

    
03/11/2010 18.26.45: In refresh_v.c: new update FF, old update 0
    

    
03/11/2010 18.26.45: ReadWriteApi.c - SaveSysVarXML: File Open Success!
    

    
03/11/2010 18.26.45: ezaction.c - SaveActionsSysVarXML Done!
    

    
03/11/2010 18.26.46: Form clustr: CB-0: [4] CB-I: [8] CB-II: [0] CB-III: [0] CB-IV: [61] CB-V: [FF] CB-VI: [0] CB-VII: [0] CB-VIII: [0] CB-IX: [0]
    

    
03/11/2010 18.26.46: In actor requst process: actor queue ActorArray0 3,ActorArray4 80,ActorArray5 2
    

    
03/11/2010 18.26.46: Done: MSG Code 63, ID 6A.00.06 Cmd1 4D, Cmd2 67 Ack 2B
    

    
03/11/2010 18.26.46: In actor resp processor: cluster api in progress for ID[6A.00.06], RespArray9[0], RespArray10[0]
    

    
03/11/2010 18.26.46: Done: MSG Code 63, ID 62.80.06 Cmd1 4D, Cmd2 67 Ack 2B
    

    
03/11/2010 18.26.46: In update dev status: dev A04 status updated cmd 2, Grp FFFFFFFF
    

    
03/11/2010 18.26.46: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/11/2010 18.26.46: Error Sending
    

    
03/11/2010 18.26.46: In actor resp processor: cluster api in progress for ID[62.80.06], RespArray9[0], RespArray10[0]
    

    
03/11/2010 18.26.46: Fn Get_ClusterAction: Case X10 Arg1[80], Arg2[2]
    

    
03/11/2010 18.26.46: In update cluster ram insstd: attr 0 value 2
    

    
03/11/2010 18.26.47: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/11/2010 18.26.47: Error Sending
    

    
03/11/2010 18.26.47: In actor requst process: actor queue ActorArray0 4,ActorArray4 61,ActorArray5 ff
    

    
03/11/2010 18.26.47: In plm msg handler: Ins grp 0x8, Grpcmd 0x11
    

    
03/11/2010 18.26.47: Done: MSG Code 61, ID 08.11.08 Cmd1 4D, Cmd2 67 Ack 2B
    

    
03/11/2010 18.26.47: In actor resp processor: cluster api in progress for ID[08.11.08], RespArray9[0], RespArray10[0]
    

    
03/11/2010 18.26.47: In get cluster action: CID 0, attrnum 0
    

    
03/11/2010 18.26.47: In update cluster ram insstd: attr 0 value FF
    

    
03/11/2010 18.26.47: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/11/2010 18.26.47: Error Sending
    

    
03/11/2010 18.26.48: Done: PTH_StdMsg 50, ID 12.C4.86 Flag 61, Cmd1 11, Cmd2 8
    

    
03/11/2010 18.26.48: Done: MSG Code 58, ID 06.C4.86 Cmd1 4D, Cmd2 67 Ack 61
    

    
03/11/2010 18.26.48: File: PLM.c Fn: PLM_Process - All Link Clean-Up Group Status/Failure Report - 58 N/Ack/Grp - 6
    

    
03/11/2010 18.26.48: In update dev status: dev 08 status updated cmd FF, Grp FFFFFFFF
    

    
03/11/2010 18.26.48: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/11/2010 18.26.48: Error Sending
    

    
03/11/2010 18.26.48: In poll scene dev: devrec 18
    

    
03/11/2010 18.26.48: Done: PTH_StdMsg 50, ID 14.66.29 Flag 61, Cmd1 11, Cmd2 8
    

    
03/11/2010 18.26.48: Done: MSG Code 62, ID 12.C4.86 Cmd1 19, Cmd2 0 Ack 6
    

    
03/11/2010 18.26.48: Done: PTH_StdMsg 50, ID 12.C4.86 Flag 2B, Cmd1 B2, Cmd2 CC
    

    
03/11/2010 18.26.48: In update dev status: dev 12.C4.86 status updated cmd CC, Grp FFFFFFFF
    

    
03/11/2010 18.26.48: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/11/2010 18.26.48: Error Sending
    

    
03/11/2010 18.26.48: In poll scene dev: send command to next device or resend to prev dev
    

    
03/11/2010 18.26.48: Done: MSG Code 62, ID 14.66.29 Cmd1 19, Cmd2 0 Ack 6
    

    
03/11/2010 18.26.49: Done: PTH_StdMsg 50, ID 14.66.29 Flag 2B, Cmd1 76, Cmd2 FF
    

    
03/11/2010 18.26.49: In update dev status: dev 14.66.29 status updated cmd FF, Grp FFFFFFFF
    

    
03/11/2010 18.26.49: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/11/2010 18.26.49: Error Sending
    

    
03/11/2010 18.26.49: In poll scene dev: send command to next device or resend to prev dev
    

    
03/11/2010 18.26.49: ezdevice.c - SaveDeviceXML: File Open Success!
    

    
03/11/2010 18.26.50: ReadWriteApi.c - SaveSysVarXML: File Open Success!
    

    
03/11/2010 18.26.50: ezaction.c - SaveActionsSysVarXML Done!
    

    
03/11/2010 18.26.50: In refresh_v.c: new update 2, old update 3
    

    
03/11/2010 18.26.50: In refresh_v.c: new update CC, old update 11
    

    
03/11/2010 18.26.50: In refresh_v.c: new update FF, old update 0
    Anonymous
    Inactive
    March 12, 2010 at 1:13 am
    Post count: 1001
    #43335

    A few things to verify. Start the Harmony client and check the Sunset time at the bottom of the screen for the expected value. Check the Days of the Week for the Action to be sure a day was not missed. Have the telnet trace cover the Action that worked through a failure. If this is another variant of the problem with Actions not being reenabled the Action that performed the Effects as expected is actually where the failure occurred. Need a telnet trace that covers the day before where the Action triggered to be sure it completed all the required steps. If a reenable is missed, it will not trigger the next day.

    Post the Action, it might have something special that I can attempt to recreate.

    Anonymous
    Inactive
    March 12, 2010 at 1:26 pm
    Post count: 131
    #43336

    Here are the “easy” answers to your questions:
    Harmon Client Test: Time correct (8:22AM, sunset 17:59) therefore action should kick off at 6:14pm.
    Days of week: All checked
    Action file:

    I am going to setup a few tests this afternoon before the sunset+15 rules kick in to see if I can replicate it in a shorter period of time. Worse case scenario is that at sunset+15 I will turn telnet on and let it run a few days.

    Thanks,
    Steve

    Anonymous
    Inactive
    March 12, 2010 at 1:51 pm
    Post count: 1001
    #43337

    Thanks for posting the Action. I will setup something similar here to see if I can recreate as well. The Conditions are a little different from the Action that was determined to be failing at 02.06 so it could be another variant but I did not think the Conditions were causing the problem. If the telnet trace covers a few days it will likely be too big to post. Send it to the same email you have been using.

    You might try reversing the Effects, putting the X10 Effect second, or adding a 1 or 2 second delay to the Insteon Effect. I have nothing to know the combination is a problem but the PLM does not buffer commands. If there is a timing issue between X10 and Insteon commands causing an intermittant rejection of one of the Effects it might affect reenabling the Action.

    Anonymous
    Inactive
    March 12, 2010 at 2:48 pm
    Post count: 131
    #43338

    The good/bad news is that I can replicate this very easily and without having to wait a full day between tests. What I did:

    1. Added two conditions to both the ON and the OFF actions.
    ON Condition 1: Absolute Time = 9:00 AM
    ON Condition 2: Absolute Time = 9:15 AM
    OFF Condition 1: Absolute Time = 9:05 AM
    OFF Condition 2: Absolute Time = 9:20 AM

    2. Restarted (via browser) the EZServe device.

    3. Turned on telnet logging (see below).

    What occurred:
    @ 9:00AM Lights Turned ON
    @ 9:05AM Lights Turned OFF
    @ 9:15AM —- NOTHING

    This is exactly what has happened in the last few days. After a restart I can cycle through a ON/OFF or an OFF/ON, but it can not get to the next action (eg, ON/OFF/ON or OFF/ON/OFF).

    Here is the telnet results

    Trying W.X.Y.Z...
    
Connected to EZServe.
    
Escape character is '^]'.
    

    
Welcome to SimpleHomeNet Debug Mode
    

    

    
login: EZServe
    

    
Password: ***************
    

    
Debug Mode started for EZServe
    

    

    
03/12/2010 09.00.00: In process actions: Activate effect
    

    
03/12/2010 09.00.00: In process actions: Effect to process and action Night Time ON
    

    
03/12/2010 09.00.00: In form cluster actor queue: attr name Status, attr value 0x02
    

    
03/12/2010 09.00.00: Form clustr: CB-0: [3] CB-I: [41] CB-II: [4] CB-III: [0] CB-IV: [80] CB-V: [2] CB-VI: [0] CB-VII: [0] CB-VIII: [0] CB-IX: [0]
    

    
03/12/2010 09.00.00: In process actions: Effect to process and action Night Time ON
    

    
03/12/2010 09.00.00: In form cluster actor queue: attr name Status, attr value 0xFF
    

    
03/12/2010 09.00.00: Form clustr: CB-0: [4] CB-I: [8] CB-II: [0] CB-III: [0] CB-IV: [61] CB-V: [FF] CB-VI: [0] CB-VII: [0] CB-VIII: [0] CB-IX: [0]
    

    
03/12/2010 09.00.00: In actor requst process: actor queue ActorArray0 3,ActorArray4 80,ActorArray5 2
    

    
03/12/2010 09.00.00: Done: MSG Code 63, ID 6A.00.06 Cmd1 5, Cmd2 63 Ack 6
    

    
03/12/2010 09.00.00: In actor resp processor: cluster api in progress for ID[6A.00.06], RespArray9[0], RespArray10[0]
    

    
03/12/2010 09.00.01: Done: MSG Code 63, ID 62.80.06 Cmd1 5, Cmd2 63 Ack 6
    

    
03/12/2010 09.00.01: In update dev status: dev A04 status updated cmd 2, Grp FFFFFFFF
    

    
03/12/2010 09.00.01: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.00.01: Error Sending
    

    
03/12/2010 09.00.01: In actor resp processor: cluster api in progress for ID[62.80.06], RespArray9[0], RespArray10[0]
    

    
03/12/2010 09.00.01: Fn Get_ClusterAction: Case X10 Arg1[80], Arg2[2]
    

    
03/12/2010 09.00.01: In update cluster ram insstd: attr 0 value 2
    

    
03/12/2010 09.00.01: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.00.01: Error Sending
    

    
03/12/2010 09.00.01: In actor requst process: actor queue ActorArray0 4,ActorArray4 61,ActorArray5 ff
    

    
03/12/2010 09.00.01: In plm msg handler: Ins grp 0x8, Grpcmd 0x11
    

    
03/12/2010 09.00.01: Done: MSG Code 61, ID 08.11.08 Cmd1 5, Cmd2 63 Ack 6
    

    
03/12/2010 09.00.01: In actor resp processor: cluster api in progress for ID[08.11.08], RespArray9[0], RespArray10[0]
    

    
03/12/2010 09.00.01: In get cluster action: CID 0, attrnum 0
    

    
03/12/2010 09.00.02: In update cluster ram insstd: attr 0 value FF
    

    
03/12/2010 09.00.02: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.00.02: Error Sending
    

    
03/12/2010 09.00.02: Done: PTH_StdMsg 50, ID 12.C4.86 Flag 61, Cmd1 11, Cmd2 8
    

    
03/12/2010 09.00.02: Done: MSG Code 58, ID 06.C4.86 Cmd1 4D, Cmd2 67 Ack 61
    

    
03/12/2010 09.00.02: File: PLM.c Fn: PLM_Process - All Link Clean-Up Group Status/Failure Report - 58 N/Ack/Grp - 6
    

    
03/12/2010 09.00.02: In update dev status: dev 08 status updated cmd FF, Grp FFFFFFFF
    

    
03/12/2010 09.00.02: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.00.02: Error Sending
    

    
03/12/2010 09.00.02: In poll scene dev: devrec 18
    

    
03/12/2010 09.00.02: Done: PTH_StdMsg 50, ID 14.66.29 Flag 61, Cmd1 11, Cmd2 8
    

    
03/12/2010 09.00.02: Done: MSG Code 62, ID 12.C4.86 Cmd1 19, Cmd2 0 Ack 6
    

    
03/12/2010 09.00.03: Done: PTH_StdMsg 50, ID 12.C4.86 Flag 2B, Cmd1 B2, Cmd2 CC
    

    
03/12/2010 09.00.03: In update dev status: dev 12.C4.86 status updated cmd CC, Grp FFFFFFFF
    

    
03/12/2010 09.00.03: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.00.03: Error Sending
    

    
03/12/2010 09.00.03: In poll scene dev: send command to next device or resend to prev dev
    

    
03/12/2010 09.00.03: Done: MSG Code 62, ID 14.66.29 Cmd1 19, Cmd2 0 Ack 6
    

    
03/12/2010 09.00.03: Done: PTH_StdMsg 50, ID 14.66.29 Flag 2B, Cmd1 76, Cmd2 FF
    

    
03/12/2010 09.00.03: In update dev status: dev 14.66.29 status updated cmd FF, Grp FFFFFFFF
    

    
03/12/2010 09.00.03: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.00.03: Error Sending
    

    
03/12/2010 09.00.03: In poll scene dev: send command to next device or resend to prev dev
    

    
03/12/2010 09.00.03: ezdevice.c - SaveDeviceXML: File Open Success!
    

    
03/12/2010 09.00.04: ReadWriteApi.c - SaveSysVarXML: File Open Success!
    

    
03/12/2010 09.00.04: ezaction.c - SaveActionsSysVarXML Done!
    

    
03/12/2010 09.05.00: In process actions: Activate effect
    

    
03/12/2010 09.05.00: In process actions: Effect to process and action Night Time OFF
    

    
03/12/2010 09.05.00: In form cluster actor queue: attr name Status, attr value 0x03
    

    
03/12/2010 09.05.00: Form clustr: CB-0: [3] CB-I: [41] CB-II: [4] CB-III: [0] CB-IV: [80] CB-V: [3] CB-VI: [0] CB-VII: [0] CB-VIII: [0] CB-IX: [0]
    

    
03/12/2010 09.05.00: In process actions: Effect to process and action Night Time OFF
    

    
03/12/2010 09.05.00: In form cluster actor queue: attr name Status, attr value 0x00
    

    
03/12/2010 09.05.00: Form clustr: CB-0: [4] CB-I: [8] CB-II: [0] CB-III: [0] CB-IV: [61] CB-V: [0] CB-VI: [0] CB-VII: [0] CB-VIII: [0] CB-IX: [0]
    

    
03/12/2010 09.05.00: In actor requst process: actor queue ActorArray0 3,ActorArray4 80,ActorArray5 3
    

    
03/12/2010 09.05.00: Done: MSG Code 63, ID 6A.00.06 Cmd1 4D, Cmd2 67 Ack 2B
    

    
03/12/2010 09.05.00: In actor resp processor: cluster api in progress for ID[6A.00.06], RespArray9[0], RespArray10[0]
    

    
03/12/2010 09.05.01: Done: MSG Code 63, ID 63.80.06 Cmd1 4D, Cmd2 67 Ack 2B
    

    
03/12/2010 09.05.01: In update dev status: dev A04 status updated cmd 3, Grp FFFFFFFF
    

    
03/12/2010 09.05.01: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.05.01: Error Sending
    

    
03/12/2010 09.05.01: In actor resp processor: cluster api in progress for ID[63.80.06], RespArray9[0], RespArray10[0]
    

    
03/12/2010 09.05.01: Fn Get_ClusterAction: Case X10 Arg1[80], Arg2[3]
    

    
03/12/2010 09.05.01: In update cluster ram insstd: attr 0 value 3
    

    
03/12/2010 09.05.01: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.05.01: Error Sending
    

    
03/12/2010 09.05.01: In actor requst process: actor queue ActorArray0 4,ActorArray4 61,ActorArray5 0
    

    
03/12/2010 09.05.01: In plm msg handler: Ins grp 0x8, Grpcmd 0x13
    

    
03/12/2010 09.05.01: Done: MSG Code 61, ID 08.13.08 Cmd1 4D, Cmd2 67 Ack 2B
    

    
03/12/2010 09.05.01: In actor resp processor: cluster api in progress for ID[08.13.08], RespArray9[0], RespArray10[0]
    

    
03/12/2010 09.05.01: In get cluster action: CID 0, attrnum 0
    

    
03/12/2010 09.05.02: In update cluster ram insstd: attr 0 value 0
    

    
03/12/2010 09.05.02: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.05.02: Error Sending
    

    
03/12/2010 09.05.02: Done: PTH_StdMsg 50, ID 12.C4.86 Flag 61, Cmd1 13, Cmd2 8
    

    
03/12/2010 09.05.02: Done: MSG Code 58, ID 06.C4.86 Cmd1 4D, Cmd2 67 Ack 61
    

    
03/12/2010 09.05.02: File: PLM.c Fn: PLM_Process - All Link Clean-Up Group Status/Failure Report - 58 N/Ack/Grp - 6
    

    
03/12/2010 09.05.02: In update dev status: dev 08 status updated cmd 0, Grp FFFFFFFF
    

    
03/12/2010 09.05.02: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.05.02: Error Sending
    

    
03/12/2010 09.05.02: In poll scene dev: devrec 18
    

    
03/12/2010 09.05.02: Done: PTH_StdMsg 50, ID 14.66.29 Flag 61, Cmd1 13, Cmd2 8
    

    
03/12/2010 09.05.02: Done: MSG Code 62, ID 12.C4.86 Cmd1 19, Cmd2 0 Ack 6
    

    
03/12/2010 09.05.03: Done: PTH_StdMsg 50, ID 12.C4.86 Flag 2B, Cmd1 B2, Cmd2 0
    

    
03/12/2010 09.05.03: In update dev status: dev 12.C4.86 status updated cmd 0, Grp FFFFFFFF
    

    
03/12/2010 09.05.03: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.05.03: Error Sending
    

    
03/12/2010 09.05.03: In poll scene dev: send command to next device or resend to prev dev
    

    
03/12/2010 09.05.03: Done: MSG Code 62, ID 14.66.29 Cmd1 19, Cmd2 0 Ack 6
    

    
03/12/2010 09.05.03: Done: PTH_StdMsg 50, ID 14.66.29 Flag 2B, Cmd1 76, Cmd2 0
    

    
03/12/2010 09.05.03: In update dev status: dev 14.66.29 status updated cmd 0, Grp FFFFFFFF
    

    
03/12/2010 09.05.03: In form cluster rep insstd: tot attr 1, cid 0
    

    
03/12/2010 09.05.03: Error Sending
    

    
03/12/2010 09.05.03: In poll scene dev: send command to next device or resend to prev dev
    

    
03/12/2010 09.05.03: ezdevice.c - SaveDeviceXML: File Open Success!
    

    
03/12/2010 09.05.05: ReadWriteApi.c - SaveSysVarXML: File Open Success!
    

    
03/12/2010 09.05.05: ezaction.c - SaveActionsSysVarXML Done!
    Anonymous
    Inactive
    March 12, 2010 at 4:10 pm
    Post count: 1001
    #43339

    This looks like the problem on 02.06 except there was no X10 Effect in that mix. Effect2 is turning on a Scene (which is consistent with what was failing on 02.06) with no trace entry indicating the Action was marked active after all the Scene processing completed. I am running 02.06.12 and will test this scenario on that image to see if it fails on the latest image.

    Just to confirm what I get from the trace the Scene is Unit/Group 8 with two devices ….
    12.C4.86 is turned on to Bright level 0xCC – following Query confirms device turned on at that level
    14.66.29 is turned on to Bright level 0xFF – following Query confirms device turned on at that level

    The OFF Action turns both the devices Off.

    Anonymous
    Inactive
    March 12, 2010 at 4:21 pm
    Post count: 131
    #43340

    Yes, your assumptions are correct.

    Also, if you need my devices.xml please let me know.

  • Author
    Posts
Viewing 15 posts - 1 through 15 (of 16 total)
1 2 Next
  • You must be logged in to reply to this topic.