Support for Hörmann garage doors

Slawomir_Ksiazek · January 17, 2020, 6:05pm

Ignore my previous post, after restart openhab service and initialize the thing from scratch, I was able to initialize BiSecure Gateway, now is online, however noticed another thing, my gates (visible as a things) still blinking (online/offline),

log shows
2020-01-17 19:04:33.957 [INFO ] [egateway.internal.BiSdkLoggerAdapter] - Received Exception Timeout waiting for PackageReceived (after waiting 5000 ms) => retrying…
2020-01-17 19:04:36.533 [INFO ] [egateway.internal.BiSdkLoggerAdapter] - Received Exception Timeout waiting for PackageReceived (after waiting 5000 ms) => retrying…
2020-01-17 19:04:40.491 [INFO ] [egateway.internal.BiSdkLoggerAdapter] - Received Exception Timeout waiting for PackageReceived (after waiting 5000 ms) => retrying…

Thanks again, Regards, Slawek

cinadr · January 19, 2020, 1:05pm

Hi,

I performed the test and emailed the results.

Thanks,
Zsolt

copystring · January 19, 2020, 4:41pm

Hey, I just came across this. Eger to try I startet right away. Sadly using the file from 16.01.2020 im running into errors installing this:
[ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing ‘openhab-binding-bisecuregateway’

This happens in a fresh install of openhab2. Tired this via docker and a normal installation.
Turned on log:set DEBUG. However nothing helpful comes out of that apart from it failing to install.

UPDATE/EDIT: Waiting for a long time. Like 10-30 minutes it eventually installs. Very odd.
SECOND UPDATE: Restarting Openhab makes the plugin disappear again… until 10-30 mins later it seems to install again.

thomas_letsch_de · January 19, 2020, 7:37pm

HI Felix,

at the moment it is very hard to investigate this problem. It could be some general problem with installing addons from jar files. Perhaps testing it with another binding as jar file (e.g. from the eclipse iot market) could test this.

Otherwise I would need some more log file entries to get a glue.

Regards,
Thomas

thomas_letsch_de · January 19, 2020, 7:39pm

@cinadr

thank you very much, I will have a closer look into the log files the next few days.
From the comments I suspect that the retry mechanism could be the source of the jumping values. If it is the case, then a fix should be not too complicated. Stay tuned

@Slawomir_Ksiazek
Thanks for the update post, I’m glad it worked after restarting.
The problem you are describing in your last post is probably the same as Zsolt also recognized. I will work over the retry mechanism and try to make it easier to manage. Lets see how it goes.

In my case the Hoermann App also looses the connection some times, do you see the same? If yes, than it could be a normal behavior of the GW and I would have to make the signalling of an offline GW much harder and wait longer.

Regards,
Thomas

copystring · January 19, 2020, 7:58pm

How would I provide a decent log?
is log:set DEBUG enough?

thomas_letsch_de · January 19, 2020, 8:13pm

log:set DEBUG is a very good start.
I have seen other logs going into the journal of the systemd service (if you are using linux).
Are you able to see logs when executing journalctl -fu openhab2?

Slawomir_Ksiazek · January 20, 2020, 4:51pm

Hi Thomas, Yes exactly, at the beginning I thought that distance between wlan gateway and the gate motor (some network connection issue), play here in the role,but i’m not fully sure. for me it looks that the application itself initiate the connections, it smell like some kind of connection probe between bisecur gateway and door/gate motor
Regards,
Slawek

thomas_letsch_de · January 20, 2020, 7:30pm

Ok, I just uploaded a new version of the binding which should handle ONLINE / OFFLINE going much better.
I also reduced some timeouts again which should make the binding respond even faster now.

Please feel free to test this new version again. I hope we are getting closer to a stable one…

copystring · January 20, 2020, 9:17pm

Today I downloaded the latest version and tried to install it. After waiting for 1 Hour or so it did not install.
Then I installed the IoT Market and from there I successfully installed other addons.

Here are both logs (with log:set DEBUG):

Slawomir_Ksiazek · January 20, 2020, 9:49pm

Sure, i will implement and test last code, I have small query, when I can expect that bisecure binding will control state of gate (open/close/unknown), May be something I overlooked ?
Thanks in advance?

Slawek

thomas_letsch_de · January 20, 2020, 9:52pm

Hi Felix,

it looks like there is a problem with the discovery of the gateway. This discovery follows a special protocol, a string is sent out per UDP into the local network and the gateway responses on it.
This seems to fail, unfortunately without error.
I uploaded a new version which should at least show an error in the log file when discovery fails. Tell if you can see some sort of TimeoutException in the logfile with the new version.

I’m not sure how to handle that problem. Inside a docker container the discovery mechanism could just not be able to send out this UDP message per broadcast into the correct network. Perhaps it is kept inside the local docker network. Or the response is not forwarded into the docker container, since it is also UDP and not a connection that is opened from inside.
Totally working without the auto discovery could be made possible, you would have to insert the gateway id and address manually. I will have a look into that possibility.

Regards,
Thomas

thomas_letsch_de · January 20, 2020, 9:59pm

A first version of a README is available under

github.com

thomasletsch/openhab-addons/blob/2.5.x/bundles/org.openhab.binding.bisecuregateway/README.md

# bisecuregateway Binding

This binding is designed to manage garage doors from Hörmann which are connected to a BiSecure Gateway.
With this binding the BiSecure gateway and all doors (and other devices) which are configured in the BiSecure Mobile App are automatically discovered. You can get the current position of the garage door and you can open or close it. It should work like any other roller shutter.

We currently do not support any teach in of other devices into the gateway.

## Supported Things

### BiSecure Gateway

This is the basic connection to the BiSecure gateway. You can set the username and password for the user to be used in the configuration of this thing.

Be aware that you should use a different user for each client connected to your BiSecure gateway. So you should not use the same client here as you use in the mobile app.
The default user name is "admin" and password "0000", which are the standard credential if nothing was changed. You should of course already have changed this!

### BiSecure Group

A BiSecure group is any device connected to the BiSecure gateway. Your garage door will appear as a BiSecure group.
The group needs no additional configuration.

This file has been truncated. show original

I will update it accordingly if we discuss things here.

@Slawomir_Ksiazek Hopefully this will answer your question

Slawomir_Ksiazek · January 20, 2020, 10:36pm

i’m not sure, what happened but seems that something wrong is with new code, after implementing from scratch last code i see BiSecure Gateway binding is online, but I can’t discover my gates

292 │ Active │ 80 │ 2.5.1.202001202145 │ openHAB Add-ons :: Bundles :: bisecuregateway Binding

logs following situation:

20-01-20 23:27:16.393 [INFO ] [egateway.internal.BiSdkLoggerAdapter] - Starting UDP Server on host 0.0.0.0 and port 4002
2020-01-20 23:27:16.444 [INFO ] [egateway.internal.BiSdkLoggerAdapter] - Gateway data: DiscoveryData(mac=04:91:62:34:76:4A, sourceAddress=/192.168.3.13, swVersion=2.5.0, hwVersion=1.0.0, protocol=MCP V3.0)
2020-01-20 23:27:21.193 [ERROR] [nternal.DiscoveryServiceRegistryImpl] - Cannot trigger scan for thing types ‘[bisecuregateway:bisecuregateway, bisecuregateway:bisecuregroup]’ on ‘BiSecureDeviceDiscoveryService’!
java.lang.IllegalStateException: Retry failed: Received Exception Timeout waiting for PackageReceived (after waiting 2000 ms)
at org.bisdk.sdk.ClientAPI.sendWithRetry(ClientAPI.kt:268) ~[?:?]
at org.bisdk.sdk.ClientAPI.getGroups(ClientAPI.kt:138) ~[?:?]
at org.openhab.binding.bisecuregateway.internal.handler.BiSecureGatewayHandler.getGroups(BiSecureGatewayHandler.java:105) ~[?:?]
at org.openhab.binding.bisecuregateway.internal.discovery.BiSecureDeviceDiscoveryService.discoverDevices(BiSecureDeviceDiscoveryService.java:77) ~[?:?]
at org.openhab.binding.bisecuregateway.internal.discovery.BiSecureDeviceDiscoveryService.startScan(BiSecureDeviceDiscoveryService.java:51) ~[?:?]
at org.eclipse.smarthome.config.discovery.AbstractDiscoveryService.startScan(AbstractDiscoveryService.java:209) ~[bundleFile:?]
at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl.startScan(DiscoveryServiceRegistryImpl.java:382) [bundleFile:?]
at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl.startScans(DiscoveryServiceRegistryImpl.java:358) [bundleFile:?]
at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl.startScan(DiscoveryServiceRegistryImpl.java:216) [bundleFile:?]
at org.eclipse.smarthome.io.rest.core.internal.discovery.DiscoveryResource.scan(DiscoveryResource.java:97) [bundleFile:?]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_222]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_222]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [bundleFile:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [bundleFile:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [bundleFile:?]
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) [bundleFile:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [bundleFile:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [bundleFile:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [bundleFile:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [bundleFile:?]
at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [bundleFile:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [bundleFile:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [bundleFile:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [bundleFile:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [bundleFile:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [bundleFile:?]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [bundleFile:?]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [bundleFile:?]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [bundleFile:?]
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [bundleFile:?]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [bundleFile:?]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [bundleFile:?]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [bundleFile:?]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [bundleFile:?]
at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [bundleFile:?]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:852) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:544) [bundleFile:9.4.20.v20190813]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [bundleFile:?]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:536) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1581) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1307) [bundleFile:9.4.20.v20190813]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) [bundleFile:?]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:482) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1549) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1204) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [bundleFile:9.4.20.v20190813]
at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [bundleFile:?]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.Server.handle(Server.java:494) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:374) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:268) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) [bundleFile:9.4.20.v20190813]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]

Regards, Slawek

copystring · January 21, 2020, 6:39pm

I get this now with the file from google drive. Or should I be using the one from github instead?

2020-01-21 19:37:38.125 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-binding-bisecuregateway': Unable to build resource for https://drive.google.com/uc?export=download&id=1MWIIoyLne_JNALZFg0TcE1GoTTShDO3f: Unsupported 'Bundle-ManifestVersion' value: 1

thomas_letsch_de · January 21, 2020, 7:17pm

@Slawomir_Ksiazek
There seems to be a problem with the retrieval of groups in your case. Could you please try to re-run the auto discovery and see if it works after retry?
If not, please set the binding log level to debug and send me the log files per mail to not pollute the forum too much.

@copystring
Did you download the file correctly from google drive? There should be no reference to google drive inside the bundle, so every mention of google drive is really strange. The file downloaded should be about 6,6 MB in size and if you have java JDK installed its content can be listet with “jar tvf org.openhab.binding.bisecuregateway-2.5.1-SNAPSHOT.jar”
There is no file uploaded to github currently, only the one in google drive.
Anyway, I uploaded a new version of the binding where you can set the address of the gateway in the gateway thing configuration. If the auto discovery fails, this could be a way to manually add the gateway thing. But my tests did not succeed in manually adding the thing, perhaps you have more luck…

copystring · January 21, 2020, 7:49pm

The filesize is correct.
The link that appears in the log (https://drive.google.com/uc?export=download&id=1MWIIoyLne_JNALZFg0TcE1GoTTShDO3f) links to org.openhab.binding.ebus-2.4.0.21.kar
Is that used by your addon?

EDIT: I can open the file and view its contents no problem.

Slawomir_Ksiazek · January 21, 2020, 8:44pm

Hi Thomas

Based on the you last iteration of code from today

295 │ Active │ 80 │ 2.5.1.202001211827 │ openHAB Add-ons :: Bundles :: bisecuregateway Binding

openhab.log at discover time shows

"2020-01-21 21:39:07.566 [INFO ] [egateway.internal.BiSdkLoggerAdapter] - Starting UDP Server on host 0.0.0.0 and port 4002
2020-01-21 21:39:07.602 [INFO ] [egateway.internal.BiSdkLoggerAdapter] - Gateway data: DiscoveryData(mac=04:91:62:34:76:4A, sourceAddress=/192.168.3.13, swVersion=2.5.0, hwVersion=1.0.0, protocol=MCP V3.0)
2020-01-21 21:39:12.190 [WARN ] [overy.BiSecureDeviceDiscoveryService] - Could not discover BiSecure groups, cause: java.lang.IllegalStateException: Retry failed: Received Exception Timeout waiting for PackageReceived (after waiting 2000 ms)
2020-01-21 21:39:29.741 [INFO ] [egateway.internal.BiSdkLoggerAdapter] - Starting UDP Server on host 0.0.0.0 and port 4002
2020-01-21 21:39:29.771 [INFO ] [egateway.internal.BiSdkLoggerAdapter] - Gateway data: DiscoveryData(mac=04:91:62:34:76:4A, sourceAddress=/192.168.3.13, swVersion=2.5.0, hwVersion=1.0.0, protocol=MCP V3.0)
"

Will upload debug logs

Slawek

Slawomir_Ksiazek · January 21, 2020, 8:50pm

Hi Thomas

Here are the debug logs

sniped from openhab.log

cat openhab.log |grep -i debug
2020-01-21 21:46:43.956 [DEBUG] [very.BiSecureGatewayDiscoveryService] - StartScan called
2020-01-21 21:46:43.997 [DEBUG] [overy.BiSecureDeviceDiscoveryService] - getting devices on 04-91-62-34-76-4A
2020-01-21 21:46:44.001 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending package command: Command(code=6 (6), name=‘JMCP’), tag: 26, token: 96A33E2F, payload: {“CMD”:“GET_GROUPS”}, isResponse=false, checksum=-48
2020-01-21 21:46:44.005 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilEmptyQueue
2020-01-21 21:46:44.008 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilEmptyQueue finished
2020-01-21 21:46:44.014 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilMessageProcessed
2020-01-21 21:46:44.063 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending transport container 00000000000504916234764A001D1A96A33E2F067B22434D44223A224745545F47524F555053227D9027
2020-01-21 21:46:44.066 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending done
2020-01-21 21:46:44.068 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilMessageProcessed finished
2020-01-21 21:46:44.072 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Waiting for answer with tag 26
2020-01-21 21:46:44.076 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilPackageReceived
2020-01-21 21:46:46.084 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received Exception Timeout waiting for PackageReceived (after waiting 2000 ms) (which probably comes from a timeout while reading). This happens after a while (about 2min), the GW just stops responding => retrying…
2020-01-21 21:46:46.087 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Reconnecting
2020-01-21 21:46:46.091 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Connecting…
2020-01-21 21:46:46.130 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received exception while waiting for bytes: java.io.IOException: Stream closed.
2020-01-21 21:46:49.196 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Connected
2020-01-21 21:46:49.199 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Reading from socket…
2020-01-21 21:46:49.200 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending package command: Command(code=16 (10), name=‘LOGIN’), tag: 27, token: 00000000, payload: 0561646D696E31323334, isResponse=false, checksum=-5
2020-01-21 21:46:49.206 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilEmptyQueue
2020-01-21 21:46:49.209 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilEmptyQueue finished
2020-01-21 21:46:49.212 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilMessageProcessed
2020-01-21 21:46:49.250 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending transport container 00000000000504916234764A00131B00000000100561646D696E313233341673
2020-01-21 21:46:49.252 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending done
2020-01-21 21:46:49.265 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilMessageProcessed finished
2020-01-21 21:46:49.268 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Waiting for answer with tag 27
2020-01-21 21:46:49.270 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilPackageReceived
2020-01-21 21:46:49.458 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received from socket: 04916234764A000000000006000E1B000000009000FF36983DC3A9
2020-01-21 21:46:49.460 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received: sender: 04916234764A, receiver: 000000000006, pack: command: Command(code=16 (10), name=‘LOGIN’), tag: 27, token: 00000000, payload: 00FF36983D, isResponse=true, checksum=-61, checksum: A9
2020-01-21 21:46:49.461 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Reading from socket…
2020-01-21 21:46:49.473 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilPackageReceived finished
2020-01-21 21:46:49.475 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Answer for tag 27: sender: 04916234764A, receiver: 000000000006, pack: command: Command(code=16 (10), name=‘LOGIN’), tag: 27, token: 00000000, payload: 00FF36983D, isResponse=true, checksum=-61, checksum: A9
2020-01-21 21:46:49.477 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received: sender: 04916234764A, receiver: 000000000006, pack: command: Command(code=16 (10), name=‘LOGIN’), tag: 27, token: 00000000, payload: 00FF36983D, isResponse=true, checksum=-61, checksum: A9
2020-01-21 21:46:49.479 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received answer of LOGIN command => setting senderId and token
2020-01-21 21:46:49.480 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending package command: Command(code=6 (6), name=‘JMCP’), tag: 26, token: FF36983D, payload: {“CMD”:“GET_GROUPS”}, isResponse=false, checksum=-48
2020-01-21 21:46:49.482 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilEmptyQueue
2020-01-21 21:46:49.484 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilEmptyQueue finished
2020-01-21 21:46:49.486 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilMessageProcessed
2020-01-21 21:46:49.505 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending transport container 00000000000604916234764A001D1AFF36983D067B22434D44223A224745545F47524F555053227DF443
2020-01-21 21:46:49.506 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending done
2020-01-21 21:46:49.538 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilMessageProcessed finished
2020-01-21 21:46:49.539 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Waiting for answer with tag 26
2020-01-21 21:46:49.541 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilPackageReceived
2020-01-21 21:46:51.571 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received Exception Timeout waiting for PackageReceived (after waiting 2000 ms) (which probably comes from a timeout while reading). This happens after a while (about 2min), the GW just stops responding => retrying…
2020-01-21 21:46:51.573 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Reconnecting
2020-01-21 21:46:51.575 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Connecting…
2020-01-21 21:46:51.578 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Connected
2020-01-21 21:46:51.580 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Reading from socket…
2020-01-21 21:46:51.580 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending package command: Command(code=16 (10), name=‘LOGIN’), tag: 28, token: 00000000, payload: 0561646D696E31323334, isResponse=false, checksum=-5
2020-01-21 21:46:51.583 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilEmptyQueue
2020-01-21 21:46:51.585 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilEmptyQueue finished
2020-01-21 21:46:51.587 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilMessageProcessed
2020-01-21 21:46:51.630 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending transport container 00000000000604916234764A00131C00000000100561646D696E313233341776
2020-01-21 21:46:51.631 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending done
2020-01-21 21:46:51.639 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilMessageProcessed finished
2020-01-21 21:46:51.640 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Waiting for answer with tag 28
2020-01-21 21:46:51.642 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilPackageReceived
2020-01-21 21:46:51.758 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received from socket: 04916234764A000000000006000E1C00000000900057C471B5FBA1
2020-01-21 21:46:51.759 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received: sender: 04916234764A, receiver: 000000000006, pack: command: Command(code=16 (10), name=‘LOGIN’), tag: 28, token: 00000000, payload: 0057C471B5, isResponse=true, checksum=-5, checksum: A1
2020-01-21 21:46:51.760 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Reading from socket…
2020-01-21 21:46:51.794 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilPackageReceived finished
2020-01-21 21:46:51.796 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Answer for tag 28: sender: 04916234764A, receiver: 000000000006, pack: command: Command(code=16 (10), name=‘LOGIN’), tag: 28, token: 00000000, payload: 0057C471B5, isResponse=true, checksum=-5, checksum: A1
2020-01-21 21:46:51.797 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received: sender: 04916234764A, receiver: 000000000006, pack: command: Command(code=16 (10), name=‘LOGIN’), tag: 28, token: 00000000, payload: 0057C471B5, isResponse=true, checksum=-5, checksum: A1
2020-01-21 21:46:51.799 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received answer of LOGIN command => setting senderId and token
2020-01-21 21:46:51.801 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending package command: Command(code=6 (6), name=‘JMCP’), tag: 26, token: 57C471B5, payload: {“CMD”:“GET_GROUPS”}, isResponse=false, checksum=-48
2020-01-21 21:46:51.802 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilEmptyQueue
2020-01-21 21:46:51.804 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilEmptyQueue finished
2020-01-21 21:46:51.806 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilMessageProcessed
2020-01-21 21:46:51.832 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending transport container 00000000000604916234764A001D1A57C471B5067B22434D44223A224745545F47524F555053227D2B22
2020-01-21 21:46:51.833 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Sending done
2020-01-21 21:46:51.857 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - waitUntilMessageProcessed finished
2020-01-21 21:46:55.293 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received from socket: 04916234764A00000000000600741A57C471B5865B7B226964223A302C226E616D65223A226272616D6131222C22706F727473223A5B7B226964223A302C2274797065223A317D5D7D2C7B226964223A312C226E616D65223A226272616D6132222C22706F727473223A5B7B226964223A312C2274797065223A317D5D7D5DFC55
2020-01-21 21:46:55.294 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Received: sender: 04916234764A, receiver: 000000000006, pack: command: Command(code=6 (6), name=‘JMCP’), tag: 26, token: 57C471B5, payload: 5B7B226964223A302C226E616D65223A226272616D6131222C22706F727473223A5B7B226964223A302C2274797065223A317D5D7D2C7B226964223A312C226E616D65223A226272616D6132222C22706F727473223A5B7B226964223A312C2274797065223A317D5D7D5D, isResponse=true, checksum=-4, checksum: 55
2020-01-21 21:46:55.295 [DEBUG] [egateway.internal.BiSdkLoggerAdapter] - Reading from socket…

Regards, Slawek

thomas_letsch_de · January 22, 2020, 3:59pm

@Slawomir_Ksiazek
Thanks for the logs. The login works and the GetState fails most of the time with a timeout exception.
This could be caused by the timeout set at a too low value. Currently its 2 seconds. I uploaded a new version of the binding where you can overwrite this timeout value in the bridge configuration.

@copystring
Since the BiSecure binding does not use the ebus binding, I suppose this message has nothing to do with the problems of the BiSecure binding install. You could try to do a manual adding of the gateway thing. If this does not work, we have to dig deeper…