SolrDispatchFilter Request Consumption

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
3 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

SolrDispatchFilter Request Consumption

Chris Ulicny
Hi all,

I've noticed that there are quite a few INFO log entries of the form:

"...o.a.s.s.SolrDispatchFilter Could not consume full client request"

Should we be worried about these, or is there something wrong with the
requests we're making?

We aren't noticing anything unexpected in what data makes it into solr, so
it doesn't seem problematic right now.

Thanks,
Chris
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: SolrDispatchFilter Request Consumption

Shawn Heisey-2
On 8/10/2017 7:31 AM, Chris Ulicny wrote:
> I've noticed that there are quite a few INFO log entries of the form:
>
> "...o.a.s.s.SolrDispatchFilter Could not consume full client request"
>
> Should we be worried about these, or is there something wrong with the
> requests we're making?
>
> We aren't noticing anything unexpected in what data makes it into solr, so
> it doesn't seem problematic right now.

Off the top of my head, I would say that this probably means that the
client is incorrectly using the HTTP standard in some way.  What kind of
software are you using to send the requests to Solr?  The place in the
Solr code where the error happens is using the Servlet API, interfacing
into a servlet container, which is most likely going to be Jetty.  This
is the first time I've seen this, so it is not likely to be a bug on the
server side.  I'm not ruling out a bug in Solr, but I think if there
were one, the problem would be really common.  If you happen to be
running Solr in a container other than the Jetty that it is shipped
with, there might be a problem with the container.

The Solr log will contain many more lines for this log message than you
have already shared.  There will be potentially dozens of lines of a
Java stacktrace, and it may contain multiple "Caused by" sections with
more lines.  Can you share the entire thing, and let us know the precise
Solr version you're running so we can check it against the source code?
With that, it may be possible to give you more specific information
about what's going wrong.

Thanks,
Shawn

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: SolrDispatchFilter Request Consumption

Chris Ulicny
We're using version 6.3.0 with the jetty container provided. The full log
message is included below and is consistently the same. We only find this
log message when there is extended high update load on the solrcloud
(usually of small documents). Shorter bursts do not generate the same
messages. However, in either case we do not see any data loss.

All of our updates and queries come through various .NET processes.

The only information I've been able to find slightly related to the problem
might be this issue: https://github.com/eclipse/jetty.project/issues/277. I
believe it was fixed after the 9.3.8 version (and not backported) that was
packaged with 6.3.0. No idea if it is actually related though.

Thanks,
Chris

o.a.s.s.SolrDispatchFilter Could not consume full client request
java.io.IOException: Committed before 100 Continues
        at
org.eclipse.jetty.server.HttpChannelOverHttp.continue100(HttpChannelOverHttp.java:206)
        at org.eclipse.jetty.server.Request.getInputStream(Request.java:802)
        at
org.apache.solr.servlet.SolrDispatchFilter.consumeInputFully(SolrDispatchFilter.java:329)
        at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:320)
        at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:254)
        at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668)
        at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581)
        at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
        at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
        at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)
        at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1160)
        at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511)
        at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
        at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1092)
        at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
        at
org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213)
        at
org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119)
        at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
        at org.eclipse.jetty.server.Server.handle(Server.java:518)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308)
        at
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:244)
        at
org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
        at
org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
        at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:246)
        at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:156)
        at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654)
        at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
        at java.lang.Thread.run(Thread.java:745)


On Thu, Aug 10, 2017 at 10:44 AM Shawn Heisey <[hidden email]> wrote:

> On 8/10/2017 7:31 AM, Chris Ulicny wrote:
> > I've noticed that there are quite a few INFO log entries of the form:
> >
> > "...o.a.s.s.SolrDispatchFilter Could not consume full client request"
> >
> > Should we be worried about these, or is there something wrong with the
> > requests we're making?
> >
> > We aren't noticing anything unexpected in what data makes it into solr,
> so
> > it doesn't seem problematic right now.
>
> Off the top of my head, I would say that this probably means that the
> client is incorrectly using the HTTP standard in some way.  What kind of
> software are you using to send the requests to Solr?  The place in the
> Solr code where the error happens is using the Servlet API, interfacing
> into a servlet container, which is most likely going to be Jetty.  This
> is the first time I've seen this, so it is not likely to be a bug on the
> server side.  I'm not ruling out a bug in Solr, but I think if there
> were one, the problem would be really common.  If you happen to be
> running Solr in a container other than the Jetty that it is shipped
> with, there might be a problem with the container.
>
> The Solr log will contain many more lines for this log message than you
> have already shared.  There will be potentially dozens of lines of a
> Java stacktrace, and it may contain multiple "Caused by" sections with
> more lines.  Can you share the entire thing, and let us know the precise
> Solr version you're running so we can check it against the source code?
> With that, it may be possible to give you more specific information
> about what's going wrong.
>
> Thanks,
> Shawn
>
>
Loading...