JSONRPC Server via init registrieren

drazil · August 20, 2015, 7:34pm

Hi Sathya,
bin gerade dabei via Homegear “init” Methode einen eigenen RPC Server zu registrieren.
Ich habe allerdings so einige Probleme damit.

Hier ein kurzer Auszug aus dem Logfile. Vielleicht hilft das ja bei der Fehlersuche.

08/20/15 21:21:26.806 RPC Server (Port 2001): Info: Client number 6732 is calling RPC method: init Parameters: (String) http://10.100.200.111:8080/homeautomation/jsonrpc (String) RpcClient (Integer) 16 08/20/15 21:21:30.406 HomeMatic BidCoS packet received (My-CC1101, RSSI: 0x48): 0CD08470306FDC00000000DF3E 08/20/15 21:21:30.408 Module HomeMatic BidCoS: Info: HUMIDITY on channel 1 of HomeMatic BidCoS peer 26 with serial number LEQ1214104 was set to 0x3E. 08/20/15 21:21:30.409 Module HomeMatic BidCoS: Info: TEMPERATURE on channel 1 of HomeMatic BidCoS peer 26 with serial number LEQ1214104 was set to 0x00DF. 08/20/15 21:21:36.631 RPC Server (Port 2001): Info: Connection to client number 6732 closed (3). 08/20/15 21:21:36.807 Info: Calling XML RPC method "system.listMethods" on server http://10.100.200.111 and port 8080. 08/20/15 21:21:36.807 Info: Connecting to host 10.100.200.111 on port 8080... 08/20/15 21:21:36.812 Info: Connected to host 10.100.200.111 on port 8080. Client number is: 6733 08/20/15 21:21:36.922 Error in file Modules/Base/Encoding/XMLRPCDecoder.cpp line 161 in function virtual std::shared_ptr<BaseLib::RPC::Variable> BaseLib::RPC::XMLRPCDecoder::decodeResponse(std::vector<char>&): expected < 08/20/15 21:21:36.923 Error in RPC response from 10.100.200.111 on port 8080: faultCode: -32700 faultString: Parse error. Not well formed: expected < 08/20/15 21:21:36.923 Warning: Error calling XML RPC method "system.listMethods" on server http://10.100.200.111 with port 8080. Error struct: (Struct length=2) { [faultCode] { (Integer) -32700 } [faultString] { (String) Parse error. Not well formed: expected < } }

Der Java JsonRPC Service sieht so aus

[code]package de.drazil.homegear.jsonrpc;

import java.util.ArrayList;
import java.util.List;

import com.googlecode.jsonrpc4j.JsonRpcMethod;
import com.googlecode.jsonrpc4j.JsonRpcService;

@JsonRpcService("/jsonrpc")
public class RpcService
{
@JsonRpcMethod(“system.listMethods”)
public List listMethods()
{
List methodList = new ArrayList();
methodList.add(“system.listMethods”);
methodList.add(“event”);
methodList.add(“error”);

	return methodList;
}

@JsonRpcMethod("event")
public void event(String interfaceId, Integer peerId, Integer channel, String parameterName, Object value)
{
	System.out.println("interfaceId:" + interfaceId + " peerId:" + peerId + " channel:" + channel + " parameterName:" + parameterName + " value" + value);
}

@JsonRpcMethod("event")
public void event(String interfaceId, String address, String parameterName, Object value)
{
	System.out.println("interfaceId:" + interfaceId + " address:" + address + " parameterName:" + parameterName + " value" + value);
}

@JsonRpcMethod("error")
public void error(String interfaceId, Integer level, String message)
{
	System.out.println("interfaceId:" + interfaceId + " level:" + level + " message" + message);
}

}
[/code]

Weiss gerade nicht weiter

Gruss
Guido

sathya · August 20, 2015, 7:48pm

Hallo Guido,

setz mal den Debuglevel auf 5, dann sehen wir die eigentlichen Pakete im Log. Aus irgendeinem Grund parsed Homegear die Pakete als XML. Damit JSONRPC funktioniert, muss folgendes gegeben sein:

[ul]
[li] Es muss in rpcservers.conf aktiviert sein.[/li]
[li] Das Paket muss per HTTP POST übertragen werden.[/li]
[li] “content-type” muss entweder “application/json” sein oder die Nutzlast muss mit “{” anfangen.[/li][/ul]

Viele Grüße

Sathya

drazil · August 20, 2015, 8:34pm

Hi Sathya,
habs denke ich gefunden,
init - > flags=jsonMode wird erst ab homegear 0.60 unterstützt.
Ich benutze noch 0.5.25

Hatte ich nicht gelesen

Gruss
Guido

sathya · August 20, 2015, 8:45pm

Richtig, das geht erst ab 0.6.

LG Sathya

drazil · May 26, 2016, 3:15pm

Hi Sathya,
ist schon eine Weile her.

Ich habe jetzt auch mal auf Homegear 0.6 1315 umgestellt um dann nochmal einen JSON RPC Server zu testen.

Es klappt fast.

Nach ca 1-10 Events kommt dann aber folgendes:

[code]05/26/16 17:03:12.696 RPC client: Info: Calling RPC method “event” on server 10.100.200.77.
05/26/16 17:03:12.696 RPC client: Parameters:
(String) RpcClient
(String) LEQ0846847:0
(String) LAST_PACKET_RECEIVED
(Integer) 1464274992
05/26/16 17:03:12.697 Encoding JSON integer.
05/26/16 17:03:12.697 Encoding JSON string.
05/26/16 17:03:12.697 Encoding JSON string.
05/26/16 17:03:12.697 Encoding JSON array.
05/26/16 17:03:12.697 Encoding JSON string.
05/26/16 17:03:12.697 Encoding JSON string.
05/26/16 17:03:12.697 Encoding JSON string.
05/26/16 17:03:12.697 Encoding JSON integer.
05/26/16 17:03:12.697 Debug: Calling getFileDescriptor…
05/26/16 17:03:12.697 Debug: Connecting to host 10.100.200.77 on port 8080…
05/26/16 17:03:12.701 Debug: Connected to host 10.100.200.77 on port 8080. Client number is: 6181
05/26/16 17:03:12.701 RPC client: Debug: Sending packet: POST /homeautomation/jsonrpc HTTP/1.1
User-Agent: Homegear 0.6.0-1315
Host: 10.100.200.77:8080
Content-Type: application/json
Content-Length: 117
Connection: close

{“id”:244,“jsonrpc”:“2.0”,“method”:“event”,“params”:[“RpcClient”,“LEQ0846847:0”,“LAST_PACKET_RECEIVED”,1464274992]}

05/26/16 17:03:12.775 RPC client: Error in file RPC/RpcClient.cpp line 646 in function void RPC::RpcClient::sendRequest(RPC::RemoteRpcServer*, std::vector&, std::vector&, bool, bool&): Could not parse chunk size.
05/26/16 17:03:12.775 RPC client: Removing server. Server has to send “init” again.
[/code]

Und danach kam nichts mehr weil ja der Server removed wurde. Aber warum?

Irgendeine Idee?

EDIT: Mit KeepAlive Flag habe ich auch schon probiert. Klappt aber auch nicht stabil.

Viele Grüsse
Guido

drazil · June 18, 2016, 11:02am

Irgendeine Idee?

Würde gerne an dem Thema weiterarbeiten.
Oder mache da grundsätzlich etwas falsch?

Gruss
Guido

sathya · July 5, 2016, 11:11am

Hallo Guido,

ich habe mal was geändert. Probier mal das nächste nightly. Falls es damit immer noch nicht klappt, könntest du mir das Java-Programm einmal senden?

Viele Grüße

Sathya

drazil · July 21, 2016, 3:11pm

Hi Sathya,

ich bin jetzt mal auf die folgende Version umgestiegen 0.6.3-1420

Im Anhang findest Du das aktuelle Log eines kompletten Neustarts von Homegear.
Als der Fehler wieder auftrat habe ich Homegear wieder gestoppt und das Logfile gezippt.

Die Java Sourcen kann ich Dir im Moment nicht zuschicken.
Dazu muesste ich erstmal was einfaches lauffaehiges basteln.

Aber vielleicht hilft Dir das LogFile ja auch..

Das JsonRpcServerLog File enthaelt die Ausgaben meines JsonRpc Servers.

Viele Gruesse
Guido
jsonrpc_server_log.zip (1.1 KB)
homegear_log.zip (29.2 KB)

sathya · August 2, 2016, 11:15am

Hallo Guido,

ohne das Programm/den Quelltext ist es natürlich schwieriger . Aber probieren wir es mal. Leider hat Homegear das Antwort-Paket nicht gelogt. Das Logging habe ich jetzt auf Debuglevel 5 eingebaut. Im nächsten Nightly ist es drin. Kannst du mir das Log damit noch einmal schicken? Am besten per E-Mail, dann sehe ich es sofort.

Viele Grüße

Sathya

drazil · November 5, 2016, 3:26pm

Hi Sathya,
so ich habe jetzt endlich mal eine kleine Beispiel Applikation gebaut ( eclipse Project Java/Maven)
bei der die JsonRpc Kommunikation nach einer unterschiedlichen Anzahl Events immer abbricht.Vielleicht finden wir ja jetzt den Fehler?
Im Source müssen lediglich IP Adressen und Ports angepasst werden.
Bei Fragen einfach melden.

Im Zip File findest Du das MavenProject.

homegear_test.zip (10.8 KB)

Viele Grüße
Guido

sathya · November 8, 2016, 10:40pm

Hallo @drazil,

das schaue ich mir die Tage an. Danke dir!

Ich melde mich.

Viele Grüße

Sathya

sathya · November 9, 2016, 5:34pm

Hallo @drazil,

also, das Projekt verbindet sich erfolgreich mit Homegear. Viel weiter geht es dann aber nicht, weil kein Ereignisserver in der HomegearRpcServer.java gestartet wird? Magst du das schnell korrigieren, dann schaue ich noch einmal rein?

Viele Grüße

Sathya

drazil · November 24, 2016, 11:40am

Hi Sathya,
sorry, ich hatte auch wirklich arg wenig Doku dazu geschrieben.

Wenn man das Maven Projekt baut erhält man eine Datei homeautomation.war im Target Verzeichnis.

Diese muss in einem Tomcat webapp Ordner abgelegt werden.
Tomcat dann neu starten

Jetzt sollte auch der EventServer laufen.

Danach die Klasse HomegearRpcServer starten.

Das sollte alles sein.

Viele Grüße
Guido

sathya · December 9, 2016, 2:39pm

Hallo @Guido,

ok, das schaue ich mir die Tage noch einmal an.

Viele Grüße

Sathya

sathya · December 27, 2016, 3:50pm

Hallo @drazil,

auf Anhieb bekomme ich es in einer Tomcat-Docker-Instanz nicht zum Laufen, obwohl ich soweit keine Fehlermeldung sehe - dazu sei gesagt, dass ich weder viel Erfahrung mit Java(-Entwicklung) noch Tomcat habe:

root@cd003b5d9673:/usr/local/tomcat# catalina.sh run
Using CATALINA_BASE:   /usr/local/tomcat
Using CATALINA_HOME:   /usr/local/tomcat
Using CATALINA_TMPDIR: /usr/local/tomcat/temp
Using JRE_HOME:        /opt/jdk1.8.0_111/jre
Using CLASSPATH:       /usr/local/tomcat/bin/bootstrap.jar:/usr/local/tomcat/bin/tomcat-juli.jar
27-Dec-2016 15:49:27.066 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.0.39
27-Dec-2016 15:49:27.069 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Nov 9 2016 08:48:39 UTC
27-Dec-2016 15:49:27.069 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.0.39.0
27-Dec-2016 15:49:27.070 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
27-Dec-2016 15:49:27.070 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            4.4.0-36-generic
27-Dec-2016 15:49:27.070 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
27-Dec-2016 15:49:27.070 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /opt/jdk1.8.0_111/jre
27-Dec-2016 15:49:27.071 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_111-b14
27-Dec-2016 15:49:27.071 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
27-Dec-2016 15:49:27.071 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /usr/local/tomcat
27-Dec-2016 15:49:27.071 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat
27-Dec-2016 15:49:27.072 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
27-Dec-2016 15:49:27.073 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
27-Dec-2016 15:49:27.075 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
27-Dec-2016 15:49:27.077 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
27-Dec-2016 15:49:27.077 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.endorsed.dirs=/usr/local/tomcat/endorsed
27-Dec-2016 15:49:27.077 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat
27-Dec-2016 15:49:27.077 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
27-Dec-2016 15:49:27.077 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
27-Dec-2016 15:49:27.077 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded APR based Apache Tomcat Native library 1.2.10 using APR version 1.5.1.
27-Dec-2016 15:49:27.077 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
27-Dec-2016 15:49:27.082 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized (OpenSSL 1.1.0c  10 Nov 2016)
27-Dec-2016 15:49:27.186 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-apr-8080"]
27-Dec-2016 15:49:27.195 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-apr-8009"]
27-Dec-2016 15:49:27.196 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 359 ms
27-Dec-2016 15:49:27.213 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Catalina
27-Dec-2016 15:49:27.213 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.39
27-Dec-2016 15:49:27.233 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive /usr/local/tomcat/webapps/homeautomation.war
27-Dec-2016 15:49:28.131 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
0    [localhost-startStop-1] INFO  org.springframework.web.context.ContextLoader  - Root WebApplicationContext: initialization started
75   [localhost-startStop-1] INFO  org.springframework.web.context.support.XmlWebApplicationContext  - Refreshing Root WebApplicationContext: startup date [Tue Dec 27 15:49:28 UTC 2016]; root of context hierarchy
108  [localhost-startStop-1] INFO  org.springframework.beans.factory.xml.XmlBeanDefinitionReader  - Loading XML bean definitions from class path resource [META-INF/spring/application-context.xml]
292  [localhost-startStop-1] INFO  org.springframework.web.context.ContextLoader  - Root WebApplicationContext: initialization completed in 291 ms
322  [localhost-startStop-1] INFO  org.springframework.web.servlet.DispatcherServlet  - FrameworkServlet 'dispatcher': initialization started
326  [localhost-startStop-1] INFO  org.springframework.web.context.support.XmlWebApplicationContext  - Refreshing WebApplicationContext for namespace 'dispatcher-servlet': startup date [Tue Dec 27 15:49:28 UTC 2016]; parent: Root WebApplicationContext
327  [localhost-startStop-1] INFO  org.springframework.beans.factory.xml.XmlBeanDefinitionReader  - Loading XML bean definitions from class path resource [META-INF/spring/dispatcher-servlet.xml]
[localhost-startStop-1] INFO com.googlecode.jsonrpc4j.spring.AutoJsonRpcServiceImplExporter - exporting bean [de.drazil.homegear.controller.HomegearJsonRpcEventControllerImpl#0] ---> [/jsonrpc]
873  [localhost-startStop-1] INFO  org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter  - Looking for @ControllerAdvice: WebApplicationContext for namespace 'dispatcher-servlet': startup date [Tue Dec 27 15:49:28 UTC 2016]; parent: Root WebApplicationContext
913  [localhost-startStop-1] INFO  org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter  - Looking for @ControllerAdvice: WebApplicationContext for namespace 'dispatcher-servlet': startup date [Tue Dec 27 15:49:28 UTC 2016]; parent: Root WebApplicationContext
957  [localhost-startStop-1] INFO  org.springframework.web.servlet.handler.BeanNameUrlHandlerMapping  - Mapped URL path [/jsonrpc] onto handler '/jsonrpc'
967  [localhost-startStop-1] INFO  org.springframework.web.servlet.handler.SimpleUrlHandlerMapping  - Mapped URL path [/**] onto handler 'org.springframework.web.servlet.resource.DefaultServletHttpRequestHandler#0'
978  [localhost-startStop-1] INFO  org.springframework.web.servlet.handler.SimpleUrlHandlerMapping  - Mapped URL path [/js/**] onto handler 'org.springframework.web.servlet.resource.ResourceHttpRequestHandler#0'
1022 [localhost-startStop-1] INFO  org.springframework.web.servlet.DispatcherServlet  - FrameworkServlet 'dispatcher': initialization completed in 700 ms
27-Dec-2016 15:49:29.234 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive /usr/local/tomcat/webapps/homeautomation.war has finished in 2,002 ms
27-Dec-2016 15:49:29.235 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/host-manager
27-Dec-2016 15:49:29.256 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/host-manager has finished in 21 ms
27-Dec-2016 15:49:29.256 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/examples
27-Dec-2016 15:49:29.363 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/examples has finished in 106 ms
27-Dec-2016 15:49:29.363 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/docs
27-Dec-2016 15:49:29.376 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/docs has finished in 13 ms
27-Dec-2016 15:49:29.377 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/ROOT
27-Dec-2016 15:49:29.390 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/ROOT has finished in 13 ms
27-Dec-2016 15:49:29.390 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory /usr/local/tomcat/webapps/manager
27-Dec-2016 15:49:29.405 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory /usr/local/tomcat/webapps/manager has finished in 15 ms
27-Dec-2016 15:49:29.407 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-apr-8080"]
27-Dec-2016 15:49:29.413 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-apr-8009"]
27-Dec-2016 15:49:29.414 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 2217 ms

Vielleicht ist es einfacher, wenn du mir noch einmal deine Logausgabe mit einer aktuellen Homegearversion auf Debuglevel 5 sendest. Das sollte eigentlich Aufschluss geben, was schief läuft…

Viele Grüße

Sathya