Garadget binding error

peabody · December 21, 2019, 8:13am

For the last couple of weeks I have been getting the below error in the garadget binding.
any help to point me in the right direction would be great, as I am not sure where to start.

I have already tried:
removing and reinstalling the binding without any change.
I have even upgraded from openhab 2.3 --> 2.4 (probably a bit extreme, upgrade was needed anyway)
without any change.

the installed binding version is:
openhab-binding-garadget1 │ 1.13.0 │ x │ Started │ openhab-addons-2.4.0 │ Garadget Binding

error in openhab.log
2019-12-21 19:04:00.249 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread Garadget Refresh Service
java.lang.NullPointerException: null
at org.openhab.binding.garadget.internal.Connection.sendCommand(Connection.java:225) ~[?:?]
at org.openhab.binding.garadget.internal.Connection.sendCommand(Connection.java:182) ~[?:?]
at org.openhab.binding.garadget.internal.Connection.getDevices(Connection.java:150) ~[?:?]
at org.openhab.binding.garadget.internal.GaradgetBinding.execute(GaradgetBinding.java:200) ~[?:?]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:144) ~[196:org.openhab.core.compat1x:2.4.0]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:166) [196:org.openhab.core.compat1x:2.4.0]

H102 · December 21, 2019, 3:47pm

You may want to upgrade to 2.5, the latest stable version and 2.4 is over a year old.

peabody · December 24, 2019, 4:34am

thanks for the feedback, but I am not normally an early adopter.
From what I can understand the official release of 2.5 has only been out for 2 weeks

I have manually installed the 2.5 garadget binding (1.14.0), But I am still getting the same error.

namraccr · December 24, 2019, 5:32am

This occurs because the binding is calling getDevices when no tokens exist.

Are you sure your configuration is valid?

I implemented a change that should circumvent the null-pointer exception.
Try this jar and see if it fixes the issue?

peabody · December 24, 2019, 8:44am

Thanks namraccr for your quick response.

I have installed the attached binding and am now getting the below error
[WARN ] [ng.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.

I have double checked my device ID with the garadget app and the deviceId is correct.

peabody · December 24, 2019, 9:08am

not sure if this is needed or not, but I can not connect/resolve the http://garag.io website (as per the instructions on the garadget binding page (https://www.openhab.org/v2.4/addons/bindings/garadget1/)

namraccr · December 24, 2019, 4:28pm

You should post your configuration and a debug log. This is still sounding like a configuration problem…

peabody · December 25, 2019, 9:56pm

As requested here is the debug log and garadget.cfg file:

output from debug

2019-12-26 08:46:23.809 [TRACE] [ng.garadget.internal.GaradgetBinding] - Polling Garadget devices
2019-12-26 08:46:23.810 [TRACE] [binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
2019-12-26 08:46:23.811 [DEBUG] [binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
2019-12-26 08:46:23.813 [WARN ] [ng.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.

garadget.cfg

# the username for accessing your account (required, replace with your own)
username=XXXXXXX@gmail.com

# the password for accessing your account (required, replace with your own)
# it is your responsbility to ensure that no one can access your username or password
password=XXXXXXXXXXXX

# Rate at which to check if poll is to run, in ms (optional, defaults to 5000)
#garadget:granularity=5000

# Data refresh interval in ms (optional, defaults to 180000)
#garadget:refresh=180000
refresh=60000
#refresh=30000

# Time in ms to wait after successful update to garadget state (optional, defaults to 11000)
#quickpoll=11000

# Time in ms to allow an API request to complete (optional, defaults to 5000)
#timeout=5000

namraccr · December 25, 2019, 11:18pm

4 lines is not a log.

Do you see this in the output?

Processing login: statusCode=...

peabody · December 26, 2019, 7:14am

When I put the garadget binding into trace mode the above output is all I get.
I understand that 4 lines do not make a log, however I don’t like spamming the forum with too much junk info, and I also want to make sure that the log file does not contain any personal config info.
Sorry if I didn’t post the right amount of detail.

no I do not see

Processing login: statusCode=...

Below is a excerpt from the karaf console log tail.
I only see the pre-stated errors every minute (which is the polling interval in the garadget.cfg file

17:48:16.149 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0.517 to 0
17:48:41.792 [INFO ] [smarthome.event.ItemStateChangedEvent] - Motion_GF_Entry changed from ON to OFF
17:48:59.084 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:47:58.971+1100 to 2019-12-26T17:48:58.972+1100
17:49:15.157 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zwave:device:160df32f443:node7' has been updated.
17:49:15.940 [INFO ] [smarthome.event.ItemStateChangedEvent] - Battery_GF_Out1 changed from 74.0 to 76
17:49:21.501 [INFO ] [smarthome.event.ItemStateChangedEvent] - Temp_GF_Out1 changed from 24.0 to 23.5
17:49:59.090 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:48:58.972+1100 to 2019-12-26T17:49:58.974+1100
17:50:31.037 [INFO ] [smarthome.event.ItemStateChangedEvent] - Motion_GF_Entry changed from OFF to ON
17:50:44.287 [INFO ] [smarthome.event.ItemStateChangedEvent] - nest_thermo_last_connection changed from 2019-12-26T17:44:58.830+1100 to 2019-12-26T17:50:44.130+1100
17:50:59.097 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:49:58.974+1100 to 2019-12-26T17:50:58.976+1100
17:51:24.842 [INFO ] [smarthome.event.ItemStateChangedEvent] - Light_GF_Laundry changed from ON to OFF
17:51:59.102 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:50:58.976+1100 to 2019-12-26T17:51:58.979+1100
17:52:41.789 [INFO ] [smarthome.event.ItemStateChangedEvent] - Motion_GF_Entry changed from ON to OFF
17:52:59.100 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:51:58.979+1100 to 2019-12-26T17:52:58.981+1100
17:53:59.096 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:52:58.981+1100 to 2019-12-26T17:53:58.983+1100
17:54:59.100 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:53:58.983+1100 to 2019-12-26T17:54:58.985+1100
17:55:52.138 [INFO ] [ab.core.service.AbstractActiveService] - Garadget Refresh Service has been started
17:55:59.097 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:54:58.985+1100 to 2019-12-26T17:55:58.986+1100
17:56:14.343 [INFO ] [smarthome.event.ItemStateChangedEvent] - Light_GF_Deck_Current changed from 0.01 to 0.007
17:56:26.408 [INFO ] [smarthome.event.ItemStateChangedEvent] - Motion_GF_Hall changed from ON to OFF
17:56:52.149 [WARN ] [ing.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.
17:56:59.103 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:55:58.986+1100 to 2019-12-26T17:56:58.987+1100
17:57:52.158 [TRACE] [ing.garadget.internal.GaradgetBinding] - Polling Garadget devices
17:57:52.161 [TRACE] [.binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
17:57:52.165 [DEBUG] [.binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
17:57:52.170 [WARN ] [ing.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.
17:57:59.109 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:56:58.987+1100 to 2019-12-26T17:57:58.989+1100
17:58:52.180 [TRACE] [ing.garadget.internal.GaradgetBinding] - Polling Garadget devices
17:58:52.183 [TRACE] [.binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
17:58:52.186 [DEBUG] [.binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
17:58:52.190 [WARN ] [ing.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.
17:58:59.108 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:57:58.989+1100 to 2019-12-26T17:58:58.991+1100
17:59:52.200 [TRACE] [ing.garadget.internal.GaradgetBinding] - Polling Garadget devices
17:59:52.206 [TRACE] [.binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
17:59:52.211 [DEBUG] [.binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
17:59:52.214 [WARN ] [ing.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.
17:59:59.104 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:58:58.991+1100 to 2019-12-26T17:59:58.993+1100
18:00:52.224 [TRACE] [ing.garadget.internal.GaradgetBinding] - Polling Garadget devices
18:00:52.229 [TRACE] [.binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
18:00:52.234 [DEBUG] [.binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
18:00:52.238 [WARN ] [ing.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.
18:00:57.362 [INFO ] [smarthome.event.ItemCommandEvent     ] - Item 'Light_GF_Office_CeilingB' received command ON
18:00:57.366 [INFO ] [arthome.event.ItemStatePredictedEvent] - Light_GF_Office_CeilingB predicted to become ON
18:00:57.373 [INFO ] [smarthome.event.ItemStateChangedEvent] - Light_GF_Office_CeilingB changed from 0 to 100
18:00:59.110 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T17:59:58.993+1100 to 2019-12-26T18:00:58.997+1100
18:01:52.247 [TRACE] [ing.garadget.internal.GaradgetBinding] - Polling Garadget devices
18:01:52.250 [TRACE] [.binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
18:01:52.252 [DEBUG] [.binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
18:01:52.254 [WARN ] [ing.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.
18:02:08.168 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-26T18:00:58.997+1100 to 2019-12-26T18:02:08.164+1100
18:02:18.960 [INFO ] [smarthome.event.ItemStateChangedEvent] - Temperature changed from 22.22 to 21.82
18:02:18.965 [INFO ] [smarthome.event.ItemStateChangedEvent] - UV_Index changed from 3 to 2

namraccr · December 26, 2019, 1:45pm

I updated the jar file to include a WARN message showing the login failure code.
In TRACE mode, you’ll also get the response body.

Login failure. Status code = ??
Failure response: ??

peabody · December 26, 2019, 8:41pm

sorry but I still am only getting the same errors.

07:28:29.044 [INFO ] [ab.core.service.AbstractActiveService] - Garadget Refresh Service has been started
07:29:00.110 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-27T07:28:00.104+1100 to 2019-12-27T07:29:00.104+1100
07:29:29.060 [TRACE] [ing.garadget.internal.GaradgetBinding] - Polling Garadget devices
07:29:29.063 [TRACE] [.binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
07:29:29.066 [DEBUG] [.binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
07:29:29.070 [WARN ] [ing.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.
07:30:00.110 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-27T07:29:00.104+1100 to 2019-12-27T07:30:00.105+1100
07:30:02.109 [INFO ] [smarthome.event.ItemStateChangedEvent] - Light_GF_Deck_Current changed from 0.01 to 0.007
07:30:29.078 [TRACE] [ing.garadget.internal.GaradgetBinding] - Polling Garadget devices
07:30:29.079 [TRACE] [.binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
07:30:29.082 [DEBUG] [.binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
07:30:29.085 [WARN ] [ing.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.
07:31:00.110 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-27T07:30:00.105+1100 to 2019-12-27T07:31:00.105+1100
07:31:29.095 [TRACE] [ing.garadget.internal.GaradgetBinding] - Polling Garadget devices
07:31:29.097 [TRACE] [.binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
07:31:29.099 [DEBUG] [.binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
07:31:29.103 [WARN ] [ing.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.
07:32:09.493 [INFO ] [smarthome.event.ItemStateChangedEvent] - Date changed from 2019-12-27T07:31:00.105+1100 to 2019-12-27T07:32:09.486+1100
07:32:18.551 [INFO ] [smarthome.event.ItemStateChangedEvent] - Temperature changed from 13.01 to 13.56
07:32:18.566 [INFO ] [smarthome.event.ItemStateChangedEvent] - UV_Index changed from 0 to 1
07:32:18.567 [INFO ] [smarthome.event.ItemStateChangedEvent] - LastUpdate changed from 2019-12-27T07:02:18.561+1100 to 2019-12-27T07:32:18.545+1100
07:32:18.569 [INFO ] [smarthome.event.ItemStateChangedEvent] - Pressure changed from 1019.70 to 1019.80
07:32:18.570 [INFO ] [smarthome.event.ItemStateChangedEvent] - Humidity changed from 88.00 to 85.00
07:32:18.572 [INFO ] [smarthome.event.ItemStateChangedEvent] - ObservationTime changed from 2019-12-27T07:02:18.000+1100 to 2019-12-27T07:32:18.000+1100
07:32:29.111 [TRACE] [ing.garadget.internal.GaradgetBinding] - Polling Garadget devices
07:32:29.114 [TRACE] [.binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
07:32:29.117 [DEBUG] [.binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
07:32:29.118 [WARN ] [ing.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.

Binding is set to TRACE mode

openhab> log:get org.openhab.binding.garadget
TRACE

namraccr · December 27, 2019, 2:44am

I suggest stopping the binding. You should see this output:

Processing logout response: statusCode=...

I then suggest clearing the cache before restarting the binding. That will then theoretically generate the login sequence…

peabody · December 27, 2019, 6:29am

I have:

stopped openhab
cleared the cache
restarted openhab
started the garadget binding (in debug mode)

here is the output.

17:15:07.889 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0.534 to 0
17:15:08.819 [DEBUG] [org.openhab.binding.garadget         ] - BundleEvent INSTALLED - org.openhab.binding.garadget
17:15:08.881 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0 to 0.566
17:15:08.964 [DEBUG] [org.openhab.binding.garadget         ] - BundleEvent RESOLVED - org.openhab.binding.garadget
17:15:08.984 [DEBUG] [org.openhab.binding.garadget         ] - BundleEvent STARTING - org.openhab.binding.garadget
17:15:09.000 [DEBUG] [org.openhab.binding.garadget         ] - ServiceEvent REGISTERED - {org.osgi.service.cm.ManagedService}={service.id=420, service.bundleid=228, service.scope=singleton} - org.openhab.binding.garadget
17:15:09.037 [DEBUG] [radget.internal.GaradgetBindingConfig] - Loaded Garadget config for item 'doorState' : 1 subscribers, 1 publishers
17:15:09.047 [DEBUG] [radget.internal.GaradgetBindingConfig] - Loaded Garadget config for item 'doorStatus_status' : 1 subscribers, 0 publishers
17:15:09.058 [DEBUG] [radget.internal.GaradgetBindingConfig] - Loaded Garadget config for item 'doorStatus' : 1 subscribers, 0 publishers
17:15:09.061 [DEBUG] [radget.internal.GaradgetBindingConfig] - Loaded Garadget config for item 'doorConfig' : 1 subscribers, 0 publishers
17:15:09.064 [DEBUG] [radget.internal.GaradgetBindingConfig] - Loaded Garadget config for item 'netConfig' : 1 subscribers, 0 publishers
17:15:09.074 [DEBUG] [org.openhab.binding.garadget         ] - ServiceEvent REGISTERED - {org.openhab.model.item.binding.BindingConfigReader, org.openhab.binding.garadget.GaradgetBindingProvider, org.openhab.core.autoupdate.AutoUpdateBindingProvider}={service.id=421, service.bundleid=228, service.scope=bundle, component.name=org.openhab.binding.garadget.genericbindingprovidervider, component.id=256} - org.openhab.binding.garadget
17:15:09.377 [TRACE] [.binding.garadget.internal.Connection] - sendCommand: funcName=createToken
17:15:09.403 [TRACE] [.binding.garadget.internal.Connection] - content='grant_type=password&username=XXXXXXXX%40gmail.com&password=XXXXX&expires_in=0', contentType='application/x-www-form-urlencoded'
17:15:09.408 [DEBUG] [.binding.garadget.internal.Connection] - About to execute 'https://api.particle.io/oauth/token'
17:15:09.884 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0.566 to 0
17:15:09.945 [INFO ] [smarthome.event.ItemStateChangedEvent] - Motion_FFGame1 changed from OFF to ON
17:15:11.424 [INFO ] [smarthome.event.ItemStateChangedEvent] - Motion_FFGame2 changed from OFF to ON
17:15:19.277 [INFO ] [smarthome.event.ItemStateChangedEvent] - Motion_GF_Hall changed from OFF to ON
17:15:20.944 [INFO ] [smarthome.event.ItemStateChangedEvent] - Temp_GF_Entry changed from 22.4 to 22.5
17:15:21.319 [INFO ] [smarthome.event.ItemStateChangedEvent] - Humid_GF_Entry changed from 73.0 to 72
17:15:22.674 [INFO ] [smarthome.event.ItemStateChangedEvent] - Lumin_GF_Entry changed from 153.0 to 146
17:15:22.835 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zwave:device:160df32f443:node6' has been updated.
17:15:25.880 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0 to 0.564
17:15:26.448 [INFO ] [smarthome.event.ItemStateChangedEvent] - Lumin_GF_Entry changed from 146 to 147
17:15:26.880 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0.564 to 0
17:15:28.444 [DEBUG] [.binding.garadget.internal.Connection] - {}
java.net.UnknownHostException: api.particle.io
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:184) ~[?:?]
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:?]
        at java.net.Socket.connect(Socket.java:589) ~[?:?]
        at sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:673) ~[?:?]
        at sun.security.ssl.SSLSocketImpl.<init>(SSLSocketImpl.java:477) ~[?:?]
        at sun.security.ssl.SSLSocketFactoryImpl.createSocket(SSLSocketFactoryImpl.java:153) ~[?:?]
        at org.apache.commons.httpclient.protocol.SSLProtocolSocketFactory.createSocket(SSLProtocolSocketFactory.java:82) ~[195:org.apache.servicemix.bundles.commons-httpclient:3.1.0.7]
        at org.apache.commons.httpclient.protocol.SSLProtocolSocketFactory.createSocket(SSLProtocolSocketFactory.java:127) ~[195:org.apache.servicemix.bundles.commons-httpclient:3.1.0.7]
        at org.apache.commons.httpclient.HttpConnection.open(HttpConnection.java:707) ~[195:org.apache.servicemix.bundles.commons-httpclient:3.1.0.7]
        at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:387) ~[195:org.apache.servicemix.bundles.commons-httpclient:3.1.0.7]
        at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171) ~[195:org.apache.servicemix.bundles.commons-httpclient:3.1.0.7]
        at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397) ~[195:org.apache.servicemix.bundles.commons-httpclient:3.1.0.7]
        at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323) ~[195:org.apache.servicemix.bundles.commons-httpclient:3.1.0.7]
        at org.openhab.binding.garadget.internal.Connection.sendCommand(Connection.java:296) [228:org.openhab.binding.garadget:1.15.0.201912261342]
        at org.openhab.binding.garadget.internal.Connection.login(Connection.java:107) [228:org.openhab.binding.garadget:1.15.0.201912261342]
        at org.openhab.binding.garadget.internal.GaradgetBinding.modified(GaradgetBinding.java:132) [228:org.openhab.binding.garadget:1.15.0.201912261342]
        at org.openhab.binding.garadget.internal.GaradgetBinding.activate(GaradgetBinding.java:94) [228:org.openhab.binding.garadget:1.15.0.201912261342]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.apache.felix.scr.impl.inject.methods.BaseMethod.invokeMethod(BaseMethod.java:228) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.inject.methods.BaseMethod.access$500(BaseMethod.java:41) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.inject.methods.BaseMethod$Resolved.invoke(BaseMethod.java:664) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.inject.methods.BaseMethod.invoke(BaseMethod.java:510) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:317) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:307) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:334) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:114) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:947) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:919) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) [39:org.apache.felix.scr:2.1.2]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [?:?]
        at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) [?:?]
        at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) [?:?]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) [?:?]
        at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) [?:?]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) [?:?]
        at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry$1.run(ServiceRegistry.java:805) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry$1.run(ServiceRegistry.java:1) [?:?]
        at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:803) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) [?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:346) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:302) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125) [39:org.apache.felix.scr:2.1.2]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry$1.run(ServiceRegistry.java:805) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry$1.run(ServiceRegistry.java:1) [?:?]
        at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:803) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) [?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:661) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:427) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:381) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:263) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) [39:org.apache.felix.scr:2.1.2]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) [?:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) [?:?]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) [?:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher$1.run(EquinoxEventPublisher.java:124) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher$1.run(EquinoxEventPublisher.java:1) [?:?]
        at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:122) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) [?:?]
        at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) [?:?]
        at org.eclipse.osgi.container.Module.start(Module.java:467) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) [?:?]
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [10:org.apache.felix.fileinstall:3.6.4]
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [10:org.apache.felix.fileinstall:3.6.4]
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:520) [10:org.apache.felix.fileinstall:3.6.4]
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [10:org.apache.felix.fileinstall:3.6.4]
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [10:org.apache.felix.fileinstall:3.6.4]
17:15:28.485 [INFO ] [ab.core.service.AbstractActiveService] - Garadget Refresh Service has been started
17:15:28.487 [TRACE] [ing.garadget.internal.GaradgetBinding] - Polling Garadget devices
17:15:28.490 [TRACE] [.binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
17:15:28.492 [DEBUG] [.binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
17:15:28.496 [DEBUG] [org.openhab.binding.garadget         ] - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler}={password=XXXXXX, service.id=423, service.bundleid=228, service.scope=bundle, event.topics=openhab/command/*, refresh=60000, username=XXXXXX, service.pid=org.openhab.garadget, component.name=org.openhab.binding.garadget.binding, component.id=255} - org.openhab.binding.garadget
17:15:28.502 [WARN ] [ing.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 37xxxxxxxxxxxxxxxxxxxxx3; skipping.
17:15:28.517 [DEBUG] [org.openhab.binding.garadget         ] - BundleEvent STARTED - org.openhab.binding.garadget
17:15:28.882 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0 to 0.549
17:15:29.887 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0.549 to 0
17:15:31.729 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:160df32f443:node6' changed from ONLINE: Node initialising: REQUEST_NIF to ONLINE
17:15:35.828 [INFO ] [smarthome.event.ItemStateChangedEvent] - Temp_FFGame2 changed from 23.1 to 22.9
17:15:35.881 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0 to 0.512
17:15:36.242 [INFO ] [smarthome.event.ItemStateChangedEvent] - Humid_FFGame2 changed from 71.0 to 70
17:15:36.887 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0.512 to 0
17:15:37.767 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zwave:device:160df32f443:node4' has been updated.
17:15:38.355 [INFO ] [smarthome.event.ItemStateChangedEvent] - Temp_FFGame2 changed from 22.9 to 23
17:15:46.187 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0 to 0.541
17:15:46.880 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0.541 to 0
17:15:54.885 [INFO ] [smarthome.event.ItemStateChangedEvent] - Washing_Machine_Power changed from 0 to 0.537
17:15:55.114 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'zwave:device:160df32f443:node14' has been updated.

namraccr · December 27, 2019, 5:50pm

17:15:09.408 [DEBUG] [.binding.garadget.internal.Connection] - About to execute 'https://api.particle.io/oauth/token'
17:15:28.444 [DEBUG] [.binding.garadget.internal.Connection] - {}
java.net.UnknownHostException: api.particle.io

So that’s quite clear. Can I assume you’ve fixed this now?

peabody · December 28, 2019, 12:45am

thanks namraccr for all your help.
you have pointed me in the right direction.
I have it all sorted now

Falk · April 5, 2020, 10:56am

I also have a problem with the login. System is OH2.5.3, binding is 1.15.0.201912261342 (the one linked above). I have tried the credentials via https://www.garadget.com/my/login.php and even have the password reset. These new credentials are also given in the log (obviously deleted here).

2020-04-05 12:43:11.327 [TRACE] [binding.garadget.internal.Connection] - content='grant_type=password&username=[USERNAME]&password=[PASSWORD]&expires_in=0', contentType='application/x-www-form-urlencoded'
2020-04-05 12:43:11.327 [DEBUG] [binding.garadget.internal.Connection] - About to execute 'https://api.particle.io/oauth/token'
2020-04-05 12:43:11.834 [DEBUG] [binding.garadget.internal.Connection] - Method failed: HTTP/1.1 400 Bad Request
2020-04-05 12:43:11.835 [DEBUG] [binding.garadget.internal.Connection] - Body of response: {"error":"invalid_grant","error_description":"User credentials are invalid"}
2020-04-05 12:43:11.835 [TRACE] [binding.garadget.internal.Connection] - Processing login: statusCode=400, responseBody={"error":"invalid_grant","error_description":"User credentials are invalid"}
2020-04-05 12:43:11.836 [WARN ] [binding.garadget.internal.Connection] - Login failure. Status code = 400
2020-04-05 12:43:11.836 [TRACE] [binding.garadget.internal.Connection] - Failure response: {"error":"invalid_grant","error_description":"User credentials are invalid"}
2020-04-05 12:43:11.837 [INFO ] [b.core.service.AbstractActiveService] - Garadget Refresh Service has been started
2020-04-05 12:43:11.837 [TRACE] [ng.garadget.internal.GaradgetBinding] - Polling Garadget devices
2020-04-05 12:43:11.838 [TRACE] [binding.garadget.internal.Connection] - sendCommand: funcName=getDevices
2020-04-05 12:43:11.839 [DEBUG] [binding.garadget.internal.Connection] - Unable to execute getDevices command; no tokens exist
2020-04-05 12:43:11.839 [WARN ] [ng.garadget.internal.GaradgetBinding] - Unable to poll variables for deviceId 46001c001151353338363333; skipping.
2020-04-05 12:43:11.841 [INFO ] [b.core.service.AbstractActiveService] - Expire Refresh Service has been shut down

I also deleted cache and tmp, restarted but always get the same error.
What else can I do?

Falk · April 6, 2020, 11:45pm

additional info: I know, it looks like as I am not even getting the credentials right. However, following strange behavior:

i can log off and in via the Web-Interface
i logged off via the iOS garadget app and can not log in again. Even when trying a password reset, my username (eMail address) is not recognized.

I found the same problem being discussed recently here in the garadget community. I am not a developer, but results seems to be
“Looks like Header for user agent is required”.

Is this something this binding should be capable of as well?
Where in OH is the token stored? I do have a backup of an old userdata-folder and may be able to restore the token in case it is somewhere there.

Edit: my login problem via the iOS App was due to an outdated app. Uninstalling and installing again solved this issue. The OH problem remains.

HaKuNa · April 7, 2020, 5:29am

see here:

lefi · June 20, 2020, 8:42am

Hi namraccr! I had the binding working until yesterday, and now I got the same error messages after a restart. I installed the binding above, and got a status code = 400 message. What does it mean?

Thanks,
Levente