Error: No response received to RPC request. Method: ping

[nanosonde]

Hi!

After some time it seems that the CCU2 module stops working for some reason:

02/27/18 22:28:49.200 Module CCU2: MYCCU2: Could not connect to HomeMatic Wired port. Assuming HomeMatic Wired is not available.
02/27/18 22:36:18.548 Error in file Encoding/XmlrpcDecoder.cpp line 89 in function virtual std::shared_ptr<std::vector<std::shared_ptr<BaseLib::Variable> > > BaseLib::Rpc::XmlrpcDecoder::decodeRequest(std::vector<char>&, std::__cxx11::string&): expected <
02/27/18 22:36:29.700 Module CCU2: MYCCU2: Error in file PhysicalInterfaces/Ccu2.cpp line 471 in function void MyFamily::Ccu2::packetReceived(int32_t, BaseLib::TcpSocket::TcpPacket): Your client sent a request that this server could not understand.
02/27/18 22:37:25.783 Module CCU2: MYCCU2: Error: No keep alive response received (BidCoS). Reinitializing...
02/27/18 22:38:25.831 Module CCU2: MYCCU2: Error: No response received to RPC request. Method: init
02/27/18 22:38:25.831 Module CCU2: MYCCU2: Error calling "init" for HomeMatic BidCoS: No response received.
02/27/18 22:38:25.896 Module CCU2: MYCCU2: Error in file PhysicalInterfaces/Ccu2.cpp line 471 in function void MyFamily::Ccu2::packetReceived(int32_t, BaseLib::TcpSocket::TcpPacket): Your client sent a request that this server could not understand.
02/27/18 22:39:56.261 Module CCU2: MYCCU2: Error: No response received to RPC request. Method: ping
02/27/18 22:39:56.261 Module CCU2: MYCCU2: Error calling "ping" (BidCoS): No response received.
02/27/18 22:41:26.264 Module CCU2: MYCCU2: Error: No response received to RPC request. Method: ping
02/27/18 22:41:26.264 Module CCU2: MYCCU2: Error calling "ping" (BidCoS): No response received.
02/27/18 22:42:56.268 Module CCU2: MYCCU2: Error: No response received to RPC request. Method: ping
02/27/18 22:42:56.268 Module CCU2: MYCCU2: Error calling "ping" (BidCoS): No response received.
02/27/18 22:44:26.271 Module CCU2: MYCCU2: Error: No response received to RPC request. Method: ping
02/27/18 22:44:26.271 Module CCU2: MYCCU2: Error calling "ping" (BidCoS): No response received.
02/27/18 22:45:56.275 Module CCU2: MYCCU2: Error: No response received to RPC request. Method: ping
02/27/18 22:45:56.275 Module CCU2: MYCCU2: Error calling "ping" (BidCoS): No response received.

I am using RaspberryMatic 2.31.25.20180120.

[hfedcba]

Does a restart of Homegear help? Could you run Homegear in Debuglevel 5? Then the raw packets are logged.

[nanosonde]

I have used Homegear version 0.8.0-2049 since yesterday evening with Debuglevel 5. So far everything seems to be working.

The only error messages I can see:

03/01/18 22:07:16.638 Module CCU2: MYCCU2: Could not connect to HomeMatic Wired port. Assuming HomeMatic Wired is not available.
03/01/18 22:17:54.844 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/01/18 22:33:37.621 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/01/18 22:56:26.091 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/01/18 23:11:08.046 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/01/18 23:26:50.813 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/01/18 23:52:11.314 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/02/18 00:04:21.239 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/02/18 00:23:36.865 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/02/18 00:37:18.017 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/02/18 01:19:21.950 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/02/18 01:29:30.244 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/02/18 01:56:21.986 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/02/18 02:15:07.203 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/02/18 02:28:48.348 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/02/18 02:49:04.800 Module CCU2: MYCCU2: Error: No keep alive received (HM-IP). Reinitializing...
03/02/18 06:25:02.089 Info: Backing up database...
03/02/18 20:51:29.209 Script Engine Server: Error: No or invalid response received to RPC request. Method: stopDevices

The last entry is caused from systemctl stop homegear.

[hfedcba]

Do you also have BidCoS devices? If not I did some changes today which also might help you. Do you only have HM IP actuators?

[nanosonde]

I have both device types: BidCos and HMIP

Yes, I have just seen the commit.

[nanosonde]

I will close this issue for now. In the WebGUI of RaspberryMatic I had "Service Messages" from all BidCos devices that they were not reachable from 27.02.2018 22:07.

So I assume that the interface process RFD had some issue somehow.

A small note: I also had my Homematic Edomi LBS running in the backgound and their XMLRPC server was also registered at the CCU.

[nanosonde]

There still seems to be something wrong.

03/10/18 20:33:24.326 Module CCU2: MYCCU2: Error in file PhysicalInterfaces/Ccu2.cpp line 487 in function void MyFamily::Ccu2::packetReceived(int32_t, BaseLib::TcpSocket::TcpPacket): Your client sent a request that this server could not understand.
03/10/18 20:34:49.849 Module CCU2: MYCCU2: Error: No keep alive response received (BidCoS). Reinitializing...
03/10/18 20:35:49.896 Module CCU2: MYCCU2: Error: No response received to RPC request. Method: init
03/10/18 20:35:49.896 Module CCU2: MYCCU2: Error calling "init" for HomeMatic BidCoS: No response received.
03/10/18 20:35:50.004 Module CCU2: MYCCU2: Error in file PhysicalInterfaces/Ccu2.cpp line 487 in function void MyFamily::Ccu2::packetReceived(int32_t, BaseLib::TcpSocket::TcpPacket): Your client sent a request that this server could not understand.

After this happens HG CCU2 events are not received anymore. Furthermore, apps like pocketHomeControl cannot connect to the CCU2 anymore. The WebGUI of the CCU2 hangs when trying to see the status of the devices.

After stopping HG, the WebGUI and pocketHomeControl can show the device status again. But the WebGUI shows that all HM devices had a communication problem. Only HM, not HMIP devices.

It seems that the HG CCU2 module disturbs the CCU2 rfd somehow.

The CCU2 is RaspberryMatic 2.31.25.20180225 which works flawlessly when not using it with the HG CCU2 module.

The CCU2 log says:

Mar 10 20:33:47 homematic-raspi user.err rfd: XmlRpcClient error calling event({[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0023049:2","BOOT",true}]}) on binary://192.168.10.14:9000/RPC2:
Mar 10 20:33:47 homematic-raspi user.err rfd: XmlRpc transport error
Mar 10 20:34:07 homematic-raspi user.err rfd: XmlRpcClient error calling event({[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0023049:2","ENERGY_COUNTER",382.500000}],[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0023049:2","POWER",0.000000}],[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0023049:2","CURRENT",0.000000}],[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0023049:2","VOLTAGE",232.000000}],[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0023049:2","FREQUENCY",49.970000}]}) on binary://192.168.10.14:9000/RPC2:
Mar 10 20:34:07 homematic-raspi user.err rfd: XmlRpc transport error
Mar 10 20:34:27 homematic-raspi user.err rfd: XmlRpcClient error calling event({[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","CENTRAL","PONG","Homegear_BidCoS_192.168.10.14_9000"}]}) on binary://192.168.10.14:9000/RPC2:
Mar 10 20:34:27 homematic-raspi user.err rfd: XmlRpc transport error
Mar 10 20:34:47 homematic-raspi user.err rfd: XmlRpcClient error calling event({[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0571943:2","BOOT",true}],[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0571943:2","ENERGY_COUNTER",54476.800000}],[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0571943:2","POWER",0.040000}],[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0571943:2","CURRENT",0.000000}],[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0571943:2","VOLTAGE",232.900000}],[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","OEQ0571943:2","FREQUENCY",49.970000}],[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","CENTRAL","PONG","Homegear_BidCoS_192.168.10.14_9000"}]}) on binary://192.168.10.14:9000/RPC2:
Mar 10 20:34:47 homematic-raspi user.err rfd: XmlRpc transport error
Mar 10 20:35:09 homematic-raspi user.err rfd: XmlRpcClient error calling event({[methodName:"event",params:{"Homegear_BidCoS_192.168.10.14_9000","CENTRAL","PONG","Homegear_BidCoS_192.168.10.14_9000"}]}) on binary://192.168.10.14:9000/RPC2:
Mar 10 20:35:09 homematic-raspi user.err rfd: XmlRpc transport error

[hfedcba]

ok, I changed two things. When "init" failed, there was indeed no reconnect - not good. In addition I added the packet to the error message, in case the error still occurs. Could you try the next nightly?

Thanks and cheers,

Sathya

[nanosonde]

Hi! I have just tried the new nightly. Now the CCU2 module does not seem to work anymore. Always after starting HG, I get the following error:

03/12/18 10:41:14.578 Module CCU2: MYCCU2: Info: CCU (0) is calling RPC method system.listMethods
03/12/18 10:41:14.580 Module CCU2: MYCCU2: Info: CCU (0) is calling RPC method listDevices
03/12/18 10:41:14.628 Module CCU2: MYCCU2: Info: Init complete.
03/12/18 10:41:14.699 Module CCU2: MYCCU2: Error in file PhysicalInterfaces/Ccu2.cpp line 572 in function void MyFamily::Ccu2::packetReceived(int32_t, BaseLib::TcpSocket::TcpPacket): Your client sent a request that this server could not understand. Packet was: 504F535420
2F20485454502F312E310D0A436F6E74656E742D4C656E6774683A203138330D0A486F73743A203139322E3136382E31302E31343A393030300D0A436F6E6E656374696F6E3A204B6565702D416C6976650D0A557365722D4167656E743A204170616368652D48747470436C69656E742F342E352E3220284A6176612F312E382E305F313632290
D0A0D0A3C3F786D6C2076657273696F6E3D22312E302220656E636F64696E673D2249534F2D383835392D31223F3E3C6D6574686F6443616C6C3E3C6D6574686F644E616D653E6C697374446576696365733C2F6D6574686F644E616D653E3C706172616D733E3C706172616D3E3C76616C75653E486F6D65676561725F484D49505F3139322E31
36382E31302E31345F393030303C2F76616C75653E3C2F706172616D3E3C2F706172616D733E3C2F6D6574686F6443616C6C3E

[hfedcba]

That happens, if you don't have a CCU to test :\.

Should be fixed in the next nightly. Sorry.

[nanosonde]

Homegear version 0.8.0-2100 is running since 3 days now. No further error occured again so far.

[hfedcba]

Perfect! There still is an issue with HomeMatic IP on one installation. When that is fixed, I will close this issue. Thanks for testing!!! Please update to the current nightly version - with 2100 there won't be a reconnect when you restart your CCU/RaspberryMatic.

[nanosonde]

Homegear version 0.8.0-2106 is running since 4 days now.

Problem: I do not see any errors in the log, but all HM devices stopped producing any event in HG. However, the HMIP devices still work. Events are there.

All other application with have registered as XMLRPC server at the CCU still work without any problem. So I assume that there is still an issue in theis module.

Just restarting HG helps.

Note: There are also no service messages in the CCU WebGUI about unreachable HM devices!

[Halderim]

Well I can provide some more log for this issue. I am on HG 2113 and after around 5 minutes after a restart of HG communication with the ccu2 stops in the direction CCU2 -> homegear

https://pastebin.com/hHi6M1CW

[hfedcba]

Sorry for the late reply. Large binary packets (> 1024 bytes) were not processed correctly. In the next nightly that error should be fixed and HM devices should correctly produce events again.

[hfedcba]

I assume the issue is fixed.