Problem with REST API timing out


#1

API calls timing out

I recently installed Graylog 2.2 on a new Ubuntu Server (following the documentation) and I’m experiencing a problem that I didn’t have in version 2.1.

I can login to the web interface without any problems. I have an input set up which is successfully saving data in to Elasticsearch. The In/Out metrics at the top are working fine, and in the Indices tab the number of messages is increasing in the active write index. Accessing ES directly I can also see the data is being correctly parsed with the correct timestamps. However most of the other functions in the web interface do not seem to work. For example, whenever I try to search it just sits there for a while and then gives no results.

I am getting many messages in /var/log/graylog-server/server.log similar to the following:

2017-05-30T09:45:27.854+02:00 WARN [ProxiedResource] Unable to call http://192.168.1.1:9000/api/system/inputstates on node <8b067fd3-9bdd-4156-b843-73692acbd79e>
java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method) ~[?:1.8.0_131]
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) ~[?:1.8.0_131]
at java.net.SocketInputStream.read(SocketInputStream.java:171) ~[?:1.8.0_131]
at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:1.8.0_131]
at okio.Okio$2.read(Okio.java:138) ~[graylog.jar:?]
at okio.AsyncTimeout$2.read(AsyncTimeout.java:236) ~[graylog.jar:?]
at okio.RealBufferedSource.indexOf(RealBufferedSource.java:325) ~[graylog.jar:?]
at okio.RealBufferedSource.indexOf(RealBufferedSource.java:314) ~[graylog.jar:?]
at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:210) ~[graylog.jar:?]
at okhttp3.internal.http1.Http1Codec.readResponse(Http1Codec.java:191) ~[graylog.jar:?]
at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:132) ~[graylog.jar:?]
at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:54) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:120) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at org.graylog2.rest.RemoteInterfaceProvider.lambda$get$0(RemoteInterfaceProvider.java:59) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:179) ~[graylog.jar:?]
at okhttp3.RealCall.execute(RealCall.java:63) ~[graylog.jar:?]
at retrofit2.OkHttpCall.execute(OkHttpCall.java:174) ~[graylog.jar:?]
at org.graylog2.shared.rest.resources.ProxiedResource.lambda$null$0(ProxiedResource.java:76) ~[graylog.jar:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_131]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]
2017-05-30T09:45:29.636+02:00 WARN [ProxiedResource] Unable to call http://192.168.1.1:9000/api/system/inputstates on node <8b067fd3-9bdd-4156-b843-73692acbd79e>
java.net.SocketTimeoutException: timeout
at okio.Okio$4.newTimeoutException(Okio.java:227) ~[graylog.jar:?]
at okio.AsyncTimeout.exit(AsyncTimeout.java:284) ~[graylog.jar:?]
at okio.AsyncTimeout$2.read(AsyncTimeout.java:240) ~[graylog.jar:?]
at okio.RealBufferedSource.indexOf(RealBufferedSource.java:325) ~[graylog.jar:?]
at okio.RealBufferedSource.indexOf(RealBufferedSource.java:314) ~[graylog.jar:?]
at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:210) ~[graylog.jar:?]
at okhttp3.internal.http1.Http1Codec.readResponse(Http1Codec.java:191) ~[graylog.jar:?]
at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:132) ~[graylog.jar:?]
at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:54) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:120) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at org.graylog2.rest.RemoteInterfaceProvider.lambda$get$0(RemoteInterfaceProvider.java:59) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:179) ~[graylog.jar:?]
at okhttp3.RealCall.execute(RealCall.java:63) ~[graylog.jar:?]
at retrofit2.OkHttpCall.execute(OkHttpCall.java:174) ~[graylog.jar:?]
at org.graylog2.shared.rest.resources.ProxiedResource.lambda$null$0(ProxiedResource.java:76) ~[graylog.jar:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_131]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]
Caused by: java.net.SocketException: Socket closed
at java.net.SocketInputStream.read(SocketInputStream.java:204) ~[?:1.8.0_131]
at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:1.8.0_131]
at okio.Okio$2.read(Okio.java:138) ~[graylog.jar:?]
at okio.AsyncTimeout$2.read(AsyncTimeout.java:236) ~[graylog.jar:?]
… 29 more
2017-05-30T09:49:18.140+02:00 WARN [ProxiedResource] Unable to call http://192.168.1.1:9000/api/system/jobs on node <8b067fd3-9bdd-4156-b843-73692acbd79e>
java.net.SocketTimeoutException: timeout
at okio.Okio$4.newTimeoutException(Okio.java:227) ~[graylog.jar:?]
at okio.AsyncTimeout.exit(AsyncTimeout.java:284) ~[graylog.jar:?]
at okio.AsyncTimeout$2.read(AsyncTimeout.java:240) ~[graylog.jar:?]
at okio.RealBufferedSource.indexOf(RealBufferedSource.java:325) ~[graylog.jar:?]
at okio.RealBufferedSource.indexOf(RealBufferedSource.java:314) ~[graylog.jar:?]
at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:210) ~[graylog.jar:?]
at okhttp3.internal.http1.Http1Codec.readResponse(Http1Codec.java:191) ~[graylog.jar:?]
at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:132) ~[graylog.jar:?]
at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:54) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:120) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at org.graylog2.rest.RemoteInterfaceProvider.lambda$get$0(RemoteInterfaceProvider.java:59) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:179) ~[graylog.jar:?]
at okhttp3.RealCall.execute(RealCall.java:63) ~[graylog.jar:?]
at retrofit2.OkHttpCall.execute(OkHttpCall.java:174) ~[graylog.jar:?]
at org.graylog2.shared.rest.resources.ProxiedResource.lambda$null$0(ProxiedResource.java:76) ~[graylog.jar:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_131]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]
Caused by: java.net.SocketException: Socket closed
at java.net.SocketInputStream.read(SocketInputStream.java:204) ~[?:1.8.0_131]
at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:1.8.0_131]
at okio.Okio$2.read(Okio.java:138) ~[graylog.jar:?]
at okio.AsyncTimeout$2.read(AsyncTimeout.java:236) ~[graylog.jar:?]
… 29 more
2017-05-30T09:49:19.935+02:00 WARN [ProxiedResource] Unable to call http://192.168.1.1:9000/api/system/jobs on node <8b067fd3-9bdd-4156-b843-73692acbd79e>
java.net.SocketTimeoutException: timeout
at okio.Okio$4.newTimeoutException(Okio.java:227) ~[graylog.jar:?]
at okio.AsyncTimeout.exit(AsyncTimeout.java:284) ~[graylog.jar:?]
at okio.AsyncTimeout$2.read(AsyncTimeout.java:240) ~[graylog.jar:?]
at okio.RealBufferedSource.indexOf(RealBufferedSource.java:325) ~[graylog.jar:?]
at okio.RealBufferedSource.indexOf(RealBufferedSource.java:314) ~[graylog.jar:?]
at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:210) ~[graylog.jar:?]
at okhttp3.internal.http1.Http1Codec.readResponse(Http1Codec.java:191) ~[graylog.jar:?]
at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:132) ~[graylog.jar:?]
at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:54) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:120) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at org.graylog2.rest.RemoteInterfaceProvider.lambda$get$0(RemoteInterfaceProvider.java:59) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:67) ~[graylog.jar:?]
at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:179) ~[graylog.jar:?]
at okhttp3.RealCall.execute(RealCall.java:63) ~[graylog.jar:?]
at retrofit2.OkHttpCall.execute(OkHttpCall.java:174) ~[graylog.jar:?]
at org.graylog2.shared.rest.resources.ProxiedResource.lambda$null$0(ProxiedResource.java:76) ~[graylog.jar:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_131]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]
Caused by: java.net.SocketException: Socket closed
at java.net.SocketInputStream.read(SocketInputStream.java:204) ~[?:1.8.0_131]
at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:1.8.0_131]
at okio.Okio$2.read(Okio.java:138) ~[graylog.jar:?]
at okio.AsyncTimeout$2.read(AsyncTimeout.java:236) ~[graylog.jar:?]
… 29 more

If I run

curl -u user:password http://192.168.1.1:9000/api/system/inputstates

on the server it returns the expected JSON results. There are no communication problems.

I have tried almost every conceivable permutation of settings for rest_listen_uri, web_listen_uri, rest_transport_uri and web_endpoint_uri.

My current server.conf settings are:

rest_listen_uri = http://0.0.0.0:9000/api/
web_listen_uri = http://0.0.0.0:9000/

with rest_transport_uri and web_endpoint_uri both commented out, but nothing seems to work.
I am not using HTTPS.

Any advice as to what I might be doing wrong?

Environment

  • Graylog Version: 2.2.3
  • Elasticsearch Version: 2.4.5
  • MongoDB Version: 2.6.10
  • Operating System: Ubuntu 16.04.2 LTS
  • Browser version: Firefox 51.0.1

#2

Still no idea how to get this working. Anyone any ideas?


(Jan Doberstein) #3

what is the load of your Graylog System?
How many Messages are you ingesting?


(dennis) #4

Do you have one or more Graylog servers? Is your Graylog server at 192.168.1.1 reachable by itself and all other nodes on 192.168.1.1:9000?


#5

In answer to your questions, yes only one Graylog/ES server and as I said before:

so it doesn’t seem to be a reachability problem. We are ingesting on average just under a million messages a day.

I’m not sure what happened, but it just started working again. We didn’t change any settings, but after a day or two the timeout errors just stopped and it seems to be functioning normally now.

My best guess is it was struggling with resources?

The server has 9000MB ram with 4500MB allocated to the ES heap so that should be plenty.
We had just migrated about 50GB of data from the old production server by taking a snapshot with ES, scp-ing it over, and restoring it to the new machine. Maybe ES needed some time to manage all the new data? Although if ES were struggling, I wouldn’t expect the curl command to port 9000 to give an instant reply, and other queries sent directly to ES on port 9200 seemed to be fine - it really did seem to be an issue with the Graylog web interface.

Anyway, maybe it was something completely different, but I can’t seem to reproduce the problem now.
Thank you for your suggestions anyway.


(Jan Doberstein) #6

if your worker threads are busy with other works connections to the API can time out.

Just to give you an idea on this.


#7

Ah I see, so it’s because Graylog and ES are both running on java?


(Jan Doberstein) #8

that is the reason you are able to configure the threads.

and no, that is not because it is written in java.


#9

I’m sorry what I thought you meant was ES and Graylog were both sharing threads in the same JVM, and so when ES worker threads are busy, then Graylog API times out. It seems that’s not what you meant?

I’m afraid I don’t understand then. How can activity within ES cause the Graylog API to timeout.

The documentation only has one line on threads and it doesn’t really explain what the purpose of threads is at all. How should I have configured it, and how would that have prevented time outs? I ask because it would be nice to know for sure that the problem doesn’t reoccur.

Thank you for your patience.


(system) #10

This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.