[SOLVED] Sitemap not updating (probably because rest events api hangs)

Tags: #<Tag:0x00007f4349ff1d68>

I have the problem that my items in the rest api do not update when changed. I probably traced it down to the rest api, because following urls hang:

https://open.hab/rest/sitemaps/events/c159cfc8-ffd0-4cb6-971f-79c51083b8fd?sitemap=SITEMAPNAME&pageid=0000

Those requests never finish and never respond with any data. If I change something (like the even uuid to a random one) I get a json 404 response. So it seems to work, but correct request simply time out it seems.

Using openhab 2.4 on arch linux, directly connected to openhab (without any proxy).

Logs?

openhab.log and events.log show no sign of logging activity when this happens. I think I have to set the logging level of the rest api to debug? Can you give me a hint which class it is? Eg …

log:set DEBUG org.openhab.rest.api <-- which class here for the rest api?

I don’t know what the path is to turn up logging for the rest API. I’d log into the console and just turn everything to TRACE and look for errors.

I tried it, though the logs are really full and maybe I missed something but:

When the request starts, this is printed:

2019-05-06 09:42:26.856 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SocketChannelEndPoint@60c17c24{/0:0:0:0:0:0:0:1:42500<->/0:0:0:0:0:0:0:1:8443,OPEN,fill=-,flush=-,to=30000/30000}{io=0/0,kio=0,kro=1}->SslConnection@2bebf775{NOT_HANDSHAKING,eio=-1/-1,di=-1}=>HttpConnection@11589bd4[p=HttpParser{s=END,0 of -1},g=HttpGenerator@778b3edc{s=COMMITTED}]=>HttpChannelOverHttp@66e01ab1{r=1,c=true,a=ASYNC_WAIT,uri=https://URL/rest/sitemaps/events/02416c92-b01e-419f-84b2-cc11e0721fa6?sitemap=home&pageid=01060504,age=439378} idle timeout check, elapsed: 30000 ms, remaining: 0 ms
[...]
2019-05-06 09:42:26.856 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SocketChannelEndPoint@60c17c24{/0:0:0:0:0:0:0:1:42500<->/0:0:0:0:0:0:0:1:8443,OPEN,fill=-,flush=-,to=30000/30000}{io=0/0,kio=0,kro=1}->SslConnection@2bebf775{NOT_HANDSHAKING,eio=-1/-1,di=-1}=>HttpConnection@11589bd4[p=HttpParser{s=END,0 of -1},g=HttpGenerator@778b3edc{s=COMMITTED}]=>HttpChannelOverHttp@66e01ab1{r=1,c=true,a=ASYNC_WAIT,uri=https://URL/rest/sitemaps/events/02416c92-b01e-419f-84b2-cc11e0721fa6?sitemap=home&pageid=01060504,age=439378} idle timeout expired
[...]
2019-05-06 09:42:26.857 [DEBUG] [rg.eclipse.jetty.io.AbstractEndPoint] - Ignored idle endpoint SocketChannelEndPoint@60c17c24{/0:0:0:0:0:0:0:1:42500<->/0:0:0:0:0:0:0:1:8443,OPEN,fill=-,flush=-,to=30001/30000}{io=0/0,kio=0,kro=1}->SslConnection@2bebf775{NOT_HANDSHAKING,eio=-1/-1,di=-1}=>HttpConnection@11589bd4[p=HttpParser{s=END,0 of -1},g=HttpGenerator@778b3edc{s=COMMITTED}]=>HttpChannelOverHttp@66e01ab1{r=1,c=true,a=ASYNC_WAIT,uri=https://URL/rest/sitemaps/events/02416c92-b01e-419f-84b2-cc11e0721fa6?sitemap=home&pageid=01060504,age=439379}

The connection hangs in the browser. When the request times out, the following message is shown:

java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
        at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:166) [75:org.eclipse.jetty.io:9.4.11.v20180605]
        at org.eclipse.jetty.io.IdleTimeout$1.run(IdleTimeout.java:50) [75:org.eclipse.jetty.io:9.4.11.v20180605]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2019-05-06 09:41:56.862 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - ignored: WriteFlusher@687b05a5{IDLE}->null
java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
        at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:166) [75:org.eclipse.jetty.io:9.4.11.v20180605]
        at org.eclipse.jetty.io.IdleTimeout$1.run(IdleTimeout.java:50) [75:org.eclipse.jetty.io:9.4.11.v20180605]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]

Is this of any help?

I think I got it working now:

I noticed the ipv6 loopback address 0:0:0:0:0:0:0:1in the logs. Though I don’t use ipv6 in my home network. Went to Paperui --> System --> Network and disabled “Use Ipv6”. Looks like this did the trick.

3 Likes

This might be something worth filing an issue on at https://github.com/openhab/openhab-core. See How to file an Issue.

I’m glad you found the problem and solved it. But there does look like something that needs to be fixed.