sendHttpGetRequest and timeout errors

I use sendHttpGetRequest in a rule to open my Nuki Smartlock.

sendHttpGetRequest("http://192.168.xx.xx:8080/lockaction?token=xxx&nukiid=xxx&action=3")

This works fine, as the Smartlock is opening the door, but almost everytime I get this error in the openhab.log:
You can see, that the ekey fingerprint fires and then the rule would immediately open the Nuki Smartlock, but the 20s timeout defined in the http.cfg isn’t met yet.

2016-11-25 11:27:28.953 [INFO ] [ab.binding.ekey.internal.EKeyBinding] - new packet arrived: RarePacket [version=3, terminalid=xxxxxxx, relayid=2, action=136, userid=0, fingerid=6(right index),
 name=0, personalid=0, serial=xxxxxxx, reserved=0, event=, terminalSerial=, time=]
2016-11-25 11:27:33.025 [INFO ] [.eclipse.smarthome.model.script.Nuki] - Der Zustand von Nuki wurde ge�ndert: OFF
2016-11-25 11:27:36.791 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: {}
java.io.IOException: java.util.concurrent.TimeoutException
	at org.eclipse.smarthome.io.net.http.HttpUtil.executeUrl(HttpUtil.java:236)
	at org.eclipse.smarthome.io.net.http.HttpUtil.executeUrl(HttpUtil.java:130)
	at org.eclipse.smarthome.io.net.http.HttpUtil.executeUrl(HttpUtil.java:86)
	at org.eclipse.smarthome.io.net.http.HttpUtil.executeUrl(HttpUtil.java:65)
	at org.eclipse.smarthome.model.script.actions.HTTP.sendHttpGetRequest(HTTP.java:40)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_111]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_111]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_111]
	at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_111]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1085)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1060)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._invokeFeature(XbaseInterpreter.java:1046)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeFeature(XbaseInterpreter.java:991)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.invokeFeature(ScriptInterpreter.java:114)[127:org.eclipse.smarthome.model.script:0.9.0.201611191809]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:901)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:864)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:223)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:203)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:446)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:227)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:203)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:459)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:243)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:203)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:446)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:227)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:203)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:463)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:243)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:203)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:446)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:227)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:203)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.evaluate(XbaseInterpreter.java:189)[143:org.eclipse.xtext.xbase:2.9.2.v20160428-1452]
	at org.eclipse.smarthome.model.script.runtime.internal.engine.ScriptImpl.execute(ScriptImpl.java:77)[128:org.eclipse.smarthome.model.script.runtime:0.9.0.201611191809]
	at org.eclipse.smarthome.model.script.engine.ScriptExecutionThread.run(ScriptExecutionThread.java:42)[127:org.eclipse.smarthome.model.script:0.9.0.201611191809]
Caused by: java.util.concurrent.TimeoutException
	at org.eclipse.jetty.client.util.FutureResponseListener.get(FutureResponseListener.java:109)
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:655)
	at org.eclipse.smarthome.io.net.http.HttpUtil.executeUrl(HttpUtil.java:219)
	... 35 more

in the http.cfg, I did set the timeout from 5000ms to 20000ms, because the Smartlock opens the door and holds the latch for a few seconds:

# timeout in milliseconds for the http requests (optional, defaults to 5000)
timeout=20000

That’s the rule:

			postUpdate(Nuki_EG_door_locked, OFF) 
			sendHttpGetRequest("http://192.168.xx.xx:8080/lockaction?token=xx&nukiid=xx&action=3")

Is there another config for the sendHttpGetRequest-method?

Unfortunately I do not think there is. I think your primary options are:

  • live with the exception in your logs since it seems to be working
  • move the call to the executeCommandLine and use curl to make the call. You can specify a timeout on that call

Ok, it’s ugly to have those ERRORs in the Log, but in the Long run, I’d like to have an error-free log, so I can have notifications if there are any with an logfile-analyzer.
on the other hand, curl seems to be a solution, but it’s no less ugly! :wink:
Thing is, if there would be some problem with the Nuki-Call, it’s a bit more complicated to get the answer (INFO or ERROR) in the openhab.log.

But thanks anyways,
Thomas.

You can submit an issue and ask a manually configured timeout be added to the binding, which is something that is probably a good idea anyway.

1 Like

see: https://github.com/eclipse/smarthome/issues/2553

As I understood this should already be fixed, but I can still see this behaviour (OH2, b5):

2017-01-06 15:05:39.937 [INFO ] [.Sollwert Warmwasser temporär setzen] - http://192.168.xx.xx/580E0B.htm?tB0v2D18310B=2A
2017-01-06 15:05:45.013 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException

The timout is set to 10000 millis.

The code is:

  var String HTTPString = "http://192.168.xx.xx/580E0B.htm?tB0v" + HexWertAlt + "18310B=" + HexWert
  logInfo("Sollwert Warmwasser temporär setzen", HTTPString);
  HTTPString.sendHttpGetRequest

My problem is, that the device is really slow, so the http-request is very often not executed within 5 seconds.

Any help would be appreciated.
Thanks
Ulrich

Just add an additional argument to the action at the end that is the timeout in milliseconds. I can’t find the documentation for the built-in ESH actions at docs.openhab.org (or anywhere else), but here @J-N-K reports updating the documentation. Link?

Thanks, that was the trick:

HTTPString.sendHttpGetRequest(10000)

Even though the ESH Designer complains…

BR
Ulrich

since at least beta5 the sendHttpGetRequest-method works with the above argument which changes the Default timeout (5000ms = 5sec) to a user-specific timeout.
Thanks everybody!

So in my case - how would this look like?

   var String URL="http://api.luftdaten.info/v1/sensor/0815/" //
   var String json = sendHttpGetRequest(URL)

Somthing like !?:
var String json = sendHttpGetRequest(URL,10000)

EDIT
Never mind.
I just found:

Expected Behavior

In the config-file (here http.cfg, openHAB2) you can define the timeout for http-binding:

# timeout in milliseconds for the http requests (optional, defaults to 5000)
timeout=20000

Yes, that looks fine.

I have in my codes such a piece:

	Url = "https://api.gigaset-elements.de/api/v1/auth/openid/begin?op=gigaset"
	try  // Verbindungsprobleme
	{
		JSONStruct = sendHttpGetRequest(Url, 9000)

Thanks for the confirmation, Ulrich!

Even though I have setup the http.cfg with
timeout=10000

but I get:
.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException: Total timeout 5000 ms elapsed

does this mean the timeout is still 5000 and my setting ignored or is the error message hard coded to 5000?!

Do you have the same line also in /var/lib/openhab2/config/org/openhab/http.config?
Sometimes it was differing from /etc/openhab2/services/http.cfg