Graylog2 / Graylog2/graylog2-server

Lookup table timeout causes processing to stall

Open
#5,862 2 comments 0 reactions 0 assignees View on GitHub
improvement processing
Dominant language
Java
Stars
8.1k
Forks
1.1k
Avg merge
1d 20h
Merged PRs (30d)
217

Description

Yesterday otx.alienvault.com was down for a few minutes, and in that time the proessing buffer was filling up but no messages were being processed, not even ones the Threat Intellgence pipeline wasn't attached to. I think I've seen this before with a DSV lookup table being called from a pipeline so I think it's a lookup table timeout or pipeline issue rather than a Threat Intelligence Plugin one.

The log showed lots of messages like this:
```
2019-04-10T16:26:35.052+01:00 ERROR [OTXDataAdapter] OTX IPv4 request error for key <120.52.152.19>
java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method) ~[?:1.8.0_191]
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) ~[?:1.8.0_191]
at java.net.SocketInputStream.read(SocketInputStream.java:171) ~[?:1.8.0_191]
at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:1.8.0_191]
at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) ~[?:1.8.0_191]
at sun.security.ssl.InputRecord.read(InputRecord.java:503) ~[?:1.8.0_191]
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:975) ~[?:1.8.0_191]
at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1367) ~[?:1.8.0_191]
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1395) ~[?:1.8.0_191]
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1379) ~[?:1.8.0_191]
at okhttp3.internal.connection.RealConnection.connectTls(RealConnection.java:318) ~[graylog.jar:?]
at okhttp3.internal.connection.RealConnection.establishProtocol(RealConnection.java:282) ~[graylog.jar:?]
at okhttp3.internal.connection.RealConnection.connect(RealConnection.java:167) ~[graylog.jar:?]
at okhttp3.internal.connection.StreamAllocation.findConnection(StreamAllocation.java:257) ~[graylog.jar:?]
at okhttp3.internal.connection.StreamAllocation.findHealthyConnection(StreamAllocation.java:135) ~[graylog.jar:?]
at okhttp3.internal.connection.StreamAllocation.newStream(StreamAllocation.java:114) ~[graylog.jar:?]
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:42) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121) ~[graylog.jar:?]
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121) ~[graylog.jar:?]
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[graylog.jar:?]
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:126) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[graylog.jar:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121) ~[graylog.jar:?]
at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:200) ~[graylog.jar:?]
at okhttp3.RealCall.execute(RealCall.java:77) ~[graylog.jar:?]
at org.graylog.plugins.threatintel.adapters.otx.OTXDataAdapter.doGet(OTXDataAdapter.java:215) ~[?:?]
at org.graylog2.plugin.lookup.LookupDataAdapter.get(LookupDataAdapter.java:123) ~[graylog.jar:?]
at org.graylog2.lookup.LookupTable.lambda$lookup$0(LookupTable.java:72) ~[graylog.jar:?]
at org.graylog2.lookup.caches.GuavaLookupCache$InstrumentedCache.get(GuavaLookupCache.java:238) [graylog.jar:?]
at org.graylog2.lookup.caches.GuavaLookupCache.get(GuavaLookupCache.java:103) [graylog.jar:?]
at org.graylog2.lookup.LookupTable.lookup(LookupTable.java:72) [graylog.jar:?]
at org.graylog2.lookup.LookupTableService$Function.lookup(LookupTableService.java:534) [graylog.jar:?]
at org.graylog.plugins.threatintel.functions.otx.AbstractOTXLookupFunction.lookupIntel(AbstractOTXLookupFunction.java:50) [graylog-plugin-threatintel-3.0.1.jar:?]
at org.graylog.plugins.threatintel.functions.otx.AbstractOTXLookupFunction.lookupIP(AbstractOTXLookupFunction.java:42) [graylog-plugin-threatintel-3.0.1.jar:?]
at org.graylog.plugins.threatintel.functions.otx.OTXIPLookupFunction.evaluate(OTXIPLookupFunction.java:57) [graylog-plugin-threatintel-3.0.1.jar:?]
at org.graylog.plugins.threatintel.functions.otx.OTXIPLookupFunction.evaluate(OTXIPLookupFunction.java:29) [graylog-plugin-threatintel-3.0.1.jar:?]
at org.graylog.plugins.pipelineprocessor.ast.expressions.FunctionExpression.evaluateUnsafe(FunctionExpression.java:63) [graylog.jar:?]
at org.graylog.plugins.pipelineprocessor.ast.expressions.Expression.evaluate(Expression.java:41) [graylog.jar:?]
at org.graylog.plugins.pipelineprocessor.ast.statements.VarAssignStatement.evaluate(VarAssignStatement.java:33) [graylog.jar:?]
at org.graylog.plugins.pipelineprocessor.ast.statements.VarAssignStatement.evaluate(VarAssignStatement.java:22) [graylog.jar:?]
at org.graylog.plugins.pipelineprocessor.processors.PipelineInterpreter.evaluateStatement(PipelineInterpreter.java:377) [graylog.jar:?]
at org.graylog.plugins.pipelineprocessor.processors.PipelineInterpreter.executeRuleActions(PipelineInterpreter.java:364) [graylog.jar:?]
at org.graylog.plugins.pipelineprocessor.processors.PipelineInterpreter.evaluateStage(PipelineInterpreter.java:305) [graylog.jar:?]
at org.graylog.plugins.pipelineprocessor.processors.PipelineInterpreter.processForResolvedPipelines(PipelineInterpreter.java:263) [graylog.jar:?]
at org.graylog.plugins.pipelineprocessor.processors.PipelineInterpreter.process(PipelineInterpreter.java:143) [graylog.jar:?]
at org.graylog.plugins.pipelineprocessor.processors.PipelineInterpreter.process(PipelineInterpreter.java:99) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.handleMessage(ProcessBufferProcessor.java:114) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.dispatchMessage(ProcessBufferProcessor.java:100) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:77) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:42) [graylog.jar:?]
at com.lmax.disruptor.WorkProcessor.run(WorkProcessor.java:143) [graylog.jar:?]
at com.codahale.metrics.InstrumentedThreadFactory$InstrumentedRunnable.run(InstrumentedThreadFactory.java:66) [graylog.jar:?]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]
```

I had to detach the pipeline from the stream and restart Graylog to get it to process messages again.

## Expected Behavior
Processing should continue after the timeout with the lookup table returning NULL or some other value for the value, and the pipeline processing should continue.

## Current Behavior
Graylog fills up the processing buffer but does not process any messages, even ones not using the pipeline/lookup table which is timing out.

## Context
Can't see any new logs!

## Your Environment
* Graylog Version: 3.0.1
* Elasticsearch Version: 6.7.1
* MongoDB Version: 3.6.3
* Operating System: Ubuntu 18.04 LTS
* Browser version: Firefox 66.0

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.