Problem or issues reports

Plugins & Plugin Development Harmony Hub Control
61

[quote=“Cor, post:60, topic:191192”]Also with changing to to 60 seconds , I still get the error report .

Harmony Control : CMD: Failed sending command get_config to Harmony Hub - errorcode=423, errormessage=Failed to connect to Harmony Hub

Anything else I can do , or a way to troubleshoot?

Thanks,
Cor[/quote]

Hi Cor,

As you say it is working otherwise? Odd. What you can do is set the log level to Debug in the plugin and then send me parts of the log file showing the error and the lines around it.

Cheers Rene

62

[quote=“reneboer, post:1, topic:191192”]If you have any problems or issues with the plug in let me know in this topic.

Cheers Rene[/quote]

Hi

I have a bit of annoying problem. My Harmony username and password dosen’t get saved.
I fill it in, everything works just fine, then after a day or two Vera loses connection to my hub and asks for username and password again.

And thank you for this plugin, except the above it works really nice!

63

Hi Andr,
Are other settings effected when the userID and password fields get emptied? Does the device number change? If the latter your Vera seems to recreate the plugin for some reason. No idea why that would be though.

Cheers Rene

64

As you say it is working otherwise? Odd. What you can do is set the log level to Debug in the plugin and then send me parts of the log file showing the error and the lines around it.[/quote]

I have changed the setting to “debug”, but now since 2 days , I don;t get the blue error message on top anymore ( although , I am looking remotely , since I am not at home) , maybe it is solved?

What is the normal setting for the “Log level”, is that info? or error? , I forgot .

Thanks,
Cor

65

Hi Cor,

Who knows. It is still a misterious piece of hardware, a Vera :slight_smile:

The standard log level is Error.

Cheers Rene

66

I have set yesterday this debug level. How do I get the log file?

Thanks,
Cor

67

Hi Cor,

So the problem returned?

You can see the log file using http://[your vera IP]/cgi-bin/cmh/log.sh?Device=LuaUPnP

Cheers Rene

68

Hello Rene ,

I copy pasted all that had HArmony Controll in the code, I hope it helps.

Thanks,
Cor

03	01/31/17 14:26:15.306	luup_log:58: Harmony Control: Harmony device #58 is initializing! <0x76e57520>
03	01/31/17 14:26:36.969	luup_log:58: Harmony Control: Harmony device #58 is initializing! <0x76be7520>

01 01/31/17 14:26:43.180 luup_log:58: Harmony Control: Connect, failed to open socket to hub 192.168.68.13 <0x745e7520> 01 01/31/17 14:26:43.181 LuaInterface::CallFunction_Timer-5 function Harmony_Setup failed [string "--[==[..."]:1689: attempt to get length of field 'devices' (a nil value) <0x745e7520>

09	01/31/17 14:34:57.645	JobHandler_LuaUPnP::Run device 58 Harmony Control room 2 type urn:schemas-rboer-com:device:Harmony58:1 cat 3:-1 id HAM58_CNTRL parent 0/0x116daa8 upnp: 0 plugin:8066 pnp:0 mac: ip:192.168.68.13 <0x77cb1320>

[code]50 01/31/17 14:35:08.101 luup_log:58: Harmony Control: Harmony device #58 is starting up! <0x74ce9520>
50 01/31/17 14:35:08.101 luup_log:58: Harmony Control: HTTPServer 0 <0x74ce9520>
50 01/31/17 14:35:08.102 luup_log:58: Harmony Control: Harmony_CreateChildren for device <0x74ce9520>

50 01/31/17 14:35:08.278 luup_log:58: Harmony Control: No child devices to create. <0x74ce9520>
50 01/31/17 14:35:08.278 luup_log:58: Harmony Control: GetConfig <0x74ce9520>
50 01/31/17 14:35:08.279 luup_log:58: Harmony Control: Sending command cmd=get_config <0x74ce9520>[/code]

01 01/31/17 14:35:11.280 luup_log:58: Harmony Control: Connect, failed to open socket to hub 192.168.68.13 <0x74ce9520> 50 01/31/17 14:35:11.280 luup_log:58: Harmony Control: CMD: errcode=423, errmsg=Failed to connect to Harmony Hub <0x74ce9520> 50 01/31/17 14:35:11.281 luup_log:58: Harmony Control: task: CMD: Failed sending command get_config to Harmony Hub - errorcode=423, errormessage=Failed to connect to Harmony Hub <0x74ce9520> 50 01/31/17 14:35:11.281 luup_log:58: Harmony Control: GetConfig, failed to send GetConfig command... errorcode=423, errormessage=Failed to connect to Harmony Hub <0x74ce9520>

[code]50 01/31/17 14:35:08.101 luup_log:58: Harmony Control: Harmony device #58 is starting up! <0x74ce9520>
50 01/31/17 14:35:08.101 luup_log:58: Harmony Control: HTTPServer 0 <0x74ce9520>
50 01/31/17 14:35:08.102 luup_log:58: Harmony Control: Harmony_CreateChildren for device <0x74ce9520>

50 01/31/17 14:35:08.278 luup_log:58: Harmony Control: No child devices to create. <0x74ce9520>
50 01/31/17 14:35:08.278 luup_log:58: Harmony Control: GetConfig <0x74ce9520>
50 01/31/17 14:35:08.279 luup_log:58: Harmony Control: Sending command cmd=get_config <0x74ce9520>[/code]

01 01/31/17 14:35:11.280 luup_log:58: Harmony Control: Connect, failed to open socket to hub 192.168.68.13 <0x74ce9520> 50 01/31/17 14:35:11.280 luup_log:58: Harmony Control: CMD: errcode=423, errmsg=Failed to connect to Harmony Hub <0x74ce9520> 50 01/31/17 14:35:11.281 luup_log:58: Harmony Control: task: CMD: Failed sending command get_config to Harmony Hub - errorcode=423, errormessage=Failed to connect to Harmony Hub <0x74ce9520> 50 01/31/17 14:35:11.281 luup_log:58: Harmony Control: GetConfig, failed to send GetConfig command... errorcode=423, errormessage=Failed to connect to Harmony Hub <0x74ce9520> 01 01/31/17 14:35:11.282 LuaInterface::CallFunction_Timer-5 function Harmony_Setup failed [string "--[==[..."]:1689: attempt to get length of field 'devices' (a nil value) <0x74ce9520>

69

Thanks Cor,

This is the clue:
LuaInterface::CallFunction_Timer-5 function Harmony_Setup failed [string “–[==[…”]:1689: attempt to get length of field ‘devices’ (a nil value)

I will look at a fix and let you know.

Cheers Rene

70

I see the clue: “Failed”…but everything else ??? :-X ??? ???

Thanks for your time! ;D

Cor

71

[quote=“Cor, post:70, topic:191192”]I see the clue: “Failed”…but everything else ??? :-X ??? ???

Thanks for your time! ;D

Cor[/quote]

Actually… The clue may be “failed to connect” and “failed to open socket”.

Your Harmony Hub may be in a weird state… Before you start on a long and arduous hunt for problems, power cycle your hub and your Vera… and then retest.

72

Hi Cor,

I posted the update to at least avoid the code error. You can force the update with this URL http://:3480/data_request?id=action&serviceId=urn:micasaverde-com:serviceId:HomeAutomationGateway1&action=CreatePlugin&PluginNum=8066&Version=33092

When you will have to issue please double check the Harmony Hub IP address by looking at the information on your Phone app. Also make sure the Vera and Harmony are on the same network.

Cheers Rene

73

@ cybrmage: thanks; I allready tried that several times , but the error still came back.

@ Rene: I just updated to 2.14 and so far so good! The Ip adress is fixed , not sure If i did it via the Harmony app , otherwise I made a static Ip adress via my router. Vera and HArmony are on the same network.

Although I have several acces points arround could that be an issue?
There are 2 acces point in my house , one open and one with a security code wpa … The Harmony should be on the this one. Than there is another acces point outside , which an be detected inside as well , but that one has the same SSID and WPA code as the other ones. Do I need to investigate this further? ( they are all on the same lan 192,168.68.x)

Thanks,
Cor

74

Crap , now I got another one:

Harmony Control : CMD: Failed sending command start_activity to Harmony Hub - errorcode=100, errormessage=Continu

06 02/02/17 21:37:46.101 Device_Variable::m_szValue_set device: 58 service: urn:rboer-com:serviceId:Harmony1 variable: IconSet was: 0 now: 2 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x7437b520> 06 02/02/17 21:37:46.142 Device_Variable::m_szValue_set device: 58 service: urn:rboer-com:serviceId:Harmony1 variable: LastCommandTime was: 21:36:46 Thu, 02 Feb 2017 now: 21:37:46 Thu, 02 Feb 2017 #hooks: 0 upnp: 0 skip: 0 v:0x12e0308/NONE duplicate:0 <0x7437b520> 06 02/02/17 21:37:46.143 Device_Variable::m_szValue_set device: 58 service: urn:rboer-com:serviceId:Harmony1 variable: IconSet was: 2 now: 0 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x7437b520>

06 02/02/17 21:38:46.101 Device_Variable::m_szValue_set device: 58 service: urn:rboer-com:serviceId:Harmony1 variable: IconSet was: 0 now: 2 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x7437b520> 06 02/02/17 21:38:46.142 Device_Variable::m_szValue_set device: 58 service: urn:rboer-com:serviceId:Harmony1 variable: LastCommandTime was: 21:37:46 Thu, 02 Feb 2017 now: 21:38:46 Thu, 02 Feb 2017 #hooks: 0 upnp: 0 skip: 0 v:0x12e0308/NONE duplicate:0 <0x7437b520> 06 02/02/17 21:38:46.142 Device_Variable::m_szValue_set device: 58 service: urn:rboer-com:serviceId:Harmony1 variable: IconSet was: 2 now: 0 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x7437b520>

??? ???

Thanks,
Cor

75

Hi Cor,

As log as the Hub keeps connecting to the same WiFi access point it should get the same IP address and you should be ok. If it jumps access points it will also get other IP addresses assigned normally, unless you have a very fancy WiFi network at home ;).

The error message has been cut on in the message bar. So not sure what the error is, but it comes from the Hub so that it itself if positive. If you put the Log level at Debug in the plugin settings it will write those messages to the log file as well with the full details.

The snippet on the IconSet and LastCommandTime is showing normal polling activity. So that looks healthy too.

Cheers Rene

76

Hello Rene;

All my devices have a static Ip adress by mac number. Even it it changes accespoint (on the same LAN and same SSID) my router has Openwrt and there I can insert the Ip adresses.

The error 423 is gone now , but an other error pops up:

When I change activity I get this error:

Harmony Control : CMD: Failed sending command start_activity to Harmony Hub - errorcode=100, errormessage=Continue

In the luaupnp log:

08 02/07/17 0:02:02.169 JobHandler_LuaUPnP::HandleActionRequest device: 58 service: urn:rboer-com:serviceId:Harmony1 action: StartActivity <0x6f5d8520> 08 02/07/17 0:02:02.170 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=58 <0x6f5d8520> 08 02/07/17 0:02:02.170 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:rboer-com:serviceId:Harmony1 <0x6f5d8520> 08 02/07/17 0:02:02.170 JobHandler_LuaUPnP::HandleActionRequest argument action=StartActivity <0x6f5d8520> 08 02/07/17 0:02:02.170 JobHandler_LuaUPnP::HandleActionRequest argument newActivityID=14614194 <0x6f5d8520> 06 02/07/17 0:02:02.173 Device_Variable::m_szValue_set device: 58 service: urn:rboer-com:serviceId:Harmony1 variable: IconSet was: 0 now: 2 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x773e1320> 50 02/07/17 0:02:02.173 luup_log:58: Harmony Control: StartActivity, newActivityID : 14614194 <0x773e1320> 50 02/07/17 0:02:02.174 luup_log:58: Harmony Control: StartActivity, ActivityID : 14614194 <0x773e1320> 50 02/07/17 0:02:02.174 luup_log:58: Harmony Control: Sending command cmd=start_activity <0x773e1320> 50 02/07/17 0:02:02.607 luup_log:58: Harmony Control: Get message <0x773e1320> 06 02/07/17 0:02:02.900 Device_Variable::m_szValue_set device: 58 service: urn:rboer-com:serviceId:Harmony1 variable: LinkStatus was: Ok now: Error #hooks: 0 upnp: 0 skip: 0 v:0x13be028/NONE duplicate:0 <0x773e1320> 50 02/07/17 0:02:02.901 luup_log:58: Harmony Control: CMD: errcode=100, errmsg=Continue <0x773e1320> 50 02/07/17 0:02:02.901 luup_log:58: Harmony Control: task: CMD: Failed sending command start_activity to Harmony Hub - errorcode=100, errormessage=Continue <0x773e1320> 50 02/07/17 0:02:02.902 luup_log:58: Harmony Control: StartActivity, ERROR failed to start Activity... errorcode=100, errormessage=Continuedone=1:total=11:deviceId=27818251 <0x773e1320> 06 02/07/17 0:02:02.902 Device_Variable::m_szValue_set device: 58 service: urn:rboer-com:serviceId:Harmony1 variable: IconSet was: 2 now: 1 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x773e1320> 04 02/07/17 0:02:02.903 <0x773e1320> 06 02/07/17 0:02:05.050 Device_Variable::m_szValue_set device: 32 service: urn:ynca-com:serviceId:Receiver1 variable: MainInput was: AUDIO1 now: HDMI1 #hooks: 2 upnp: 0 skip: 0 v:0x12fe888/NONE duplicate:0 <0x6f3d8520> 07 02/07/17 0:02:05.051 Event::Evaluate 1 scene Subwoofer ON is true users: allow:1 <0x6f3d8520> 08 02/07/17 0:02:05.051 Scene::RunScene running 5 Subwoofer ON <0x6f3d8520> 08 02/07/17 0:02:05.051 JobHandler_LuaUPnP::HandleActionRequest device: 101 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x6f3d8520> 08 02/07/17 0:02:05.052 JobHandler_LuaUPnP::HandleActionRequest argument newTargetValue=1 <0x6f3d8520> 06 02/07/17 0:02:05.052 Device_Variable::m_szValue_set device: 101 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 0 now: 1 #hooks: 0 upnp: 0 skip: 0 v:0x12baf88/NONE duplicate:0 <0x6f3d8520> 07 02/07/17 0:02:05.054 Event::Evaluate 3 scene Subwoofer off is false repeat 0/1 <0x6f3d8520> 06 02/07/17 0:02:05.062 Device_Variable::m_szValue_set device: 32 service: urn:ynca-com:serviceId:Receiver1 variable: MainDecoderSelect was: Unavailable now: Auto #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x6f3d8520> 50 02/07/17 0:02:05.063 luup_log:32: YamahaReceiver: Un-handled MAIN Function: ENHANCER <0x6f3d8520> 50 02/07/17 0:02:05.064 luup_log:32: YamahaReceiver: Un-handled MAIN Function: STRAIGHT <0x6f3d8520> 06 02/07/17 0:02:05.100 Device_Variable::m_szValue_set device: 58 service: urn:rboer-com:serviceId:Harmony1 variable: IconSet was: 1 now: 0 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x74419520> 01 02/07/17 0:02:05.179 got CAN <0x75e19520> 02 02/07/17 0:02:05.180 ZWaveSerial::Send m_iFrameID 1106 got a CAN -- Dongle is in a bad state. Wait 1 second before continuing to let it try to recover. <0x76219520> 06 02/07/17 0:02:06.100 Device_Variable::m_szValue_set device: 101 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 0 now: 1 #hooks: 4 upnp: 0 skip: 0 v:0x12baff0/NONE duplicate:0 <0x76819520> 06 02/07/17 0:02:06.444 Device_Variable::m_szValue_set device: 101 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 1 now: 1 #hooks: 4 upnp: 0 skip: 0 v:0x12baff0/NONE duplicate:1 <0x76819520> 04 02/07/17 0:02:06.445 <0x76819520> 50 02/07/17 0:02:07.673 luup_log:32: YamahaReceiver: Un-handled System Function: LIPSYNCSELINFO <0x6f3d8520> 50 02/07/17 0:02:07.684 luup_log:32: YamahaReceiver: Un-handled System Function: LIPSYNCTOTALDELAYINFO <0x6f3d8520> 50 02/07/17 0:02:16.101 luup_log:58: Harmony Control: PollCurrentActivity busy or too close to Activity change <0x74419520> 04 02/07/17 0:02:19.452 <0x76819520> 02 02/07/17 0:02:19.453 Device_Basic::AddPoll 136 poll list full, deleting old one <0x76819520>

Any clue here what might be wrong?

Thans,
Cor

77

Hi Cor,

I found why this is a problem. Your activity 14614194 has a total of 11 steps it needs to complete and the current logic works upto 9 steps (single digit). I will work on a fix.

Cheers Rene

78

Ah , I see. , although I get the error , it seems to work all fine.

Thanks for putting your time in this app!

Cor

79

Hi Cor,

These are the files for version 2.15 that should have this fixed. I also added a new setting : Wait on Activity start complete . The default is Yes and this is how it was before. When set to No, the plugin will not wait for the activity sequence to complete, but update the CurrentActivity directly. Because of this I had to make the polling for the Current activity pause for a minute after changing the activity to avoid the Current activity value from bouncing and possibly creating false triggers. This minute should be enough as long as no activity take longer than a minute to complete, but I hope even your 11 steps are quicker than that :wink:

Please give this a go and let me know.

Cheers Rene

Note: attachement removed. Is included in latest version.

80

Hello Rene,

I just tried to update the plugin, not sure If I did it correctly:
Apps>> develop apps >>luup files
Uploaded those 3 files.

Restarted vera plus , but I still see version 2.14 , not 2.15 . Am i doing something wrong?

And as a bonus I got the :"Harmony Control : CMD: Failed sending command get_current_activity_id to Harmony Hub - errorcode=423, errormessage=Failed to connect to Harmony Hub
again ???

Cor