You are viewing a plain text version of this content. The canonical link for it is here.
Posted to solr-user@lucene.apache.org by Solr User <pu...@gmail.com> on 2019/10/02 20:53:32 UTC
Solr standalone timeouts after upgrading to SOLR 7
Hello all,
We recently moved to SOLR 7 from SOLR 6 about 2 weeks ago. Once each week
(including today) we experienced query timeout issues with corresponding GC
events. There was a spike in CPU up to 66% which is not something we
previously saw w/ Solr 6. From the SOLR logs it looks like something inside
the JVM has happend, SOLR is reporting closed connections from Jetty. Our
data size is relatively small but we do run 5 cores within the one Jetty
instance. There index sizes are anywhere between 200Mb to 2GB
Our memory consumption is relatively low:
"free":"296.1 MB",
"total":"569.6 MB",
"max":"9.6 GB",
"used":"273.5 MB (%2.8)",
We had a spike in traffic about 5 minutes prior to some longer GC events
(similar situation last week).
Any help would be appreciated. Below is my current system info along with a
GC log snippet and the corresponding SOLR log error.
*System info:*
AMZ2 linux
8 core 32 GB Mem
*Java:* 1.8.0_222-ea 25.222-b03
*Solr: *solr-spec-version":"7.7.2"
*Start options: *
"-Xms512m",
"-Xmx10g",
"-XX:NewRatio=3",
"-XX:SurvivorRatio=4",
"-XX:TargetSurvivorRatio=90",
"-XX:MaxTenuringThreshold=8",
"-XX:+UseConcMarkSweepGC",
"-XX:ConcGCThreads=4",
"-XX:ParallelGCThreads=4",
"-XX:+CMSScavengeBeforeRemark",
"-XX:PretenureSizeThreshold=64m",
"-XX:+UseCMSInitiatingOccupancyOnly",
"-XX:CMSInitiatingOccupancyFraction=50",
"-XX:CMSMaxAbortablePrecleanTime=6000",
"-XX:+CMSParallelRemarkEnabled",
"-XX:+ParallelRefProcEnabled",
"-XX:-OmitStackTraceInFastThrow",
"-verbose:gc",
"-XX:+PrintHeapAtGC",
"-XX:+PrintGCDetails",
"-XX:+PrintGCDateStamps",
"-XX:+PrintGCTimeStamps",
"-XX:+PrintTenuringDistribution",
"-XX:+PrintGCApplicationStoppedTime",
"-XX:+UseGCLogFileRotation",
"-XX:NumberOfGCLogFiles=9",
"-XX:GCLogFileSize=20M",
"-Xss256k",
"-Dsolr.log.muteconsole"
Here is an example of from the GC log:
2019-10-02T16:03:15.888+0000: 265318.624: [Full GC (Allocation
Failure) 2019-10-02T16:03:15.888+0000: 265318.624:
[CMS2019-10-02T16:03:16.134+0000: 26
5318.870: [CMS-concurrent-mark: 1.773/1.783 secs] [Times: user=13.14
sys=0.00, real=1.78 secs]
(concurrent mode failure): 7864319K->7864319K(7864320K), 9.5890129
secs] 10048895K->8863021K(10048896K), [Metaspace:
53159K->53159K(1097728K)], 9.5892061 secs] [Times: user=10.31
sys=0.00, real=9.59 secs]
Heap after GC invocations=296656 (full 546):
par new generation total 2184576K, used 998701K
[0x0000000540000000, 0x00000005e0000000, 0x00000005e0000000)
eden space 1747712K, 57% used [0x0000000540000000,
0x000000057cf4b4f0, 0x00000005aaac0000)
from space 436864K, 0% used [0x00000005aaac0000,
0x00000005aaac0000, 0x00000005c5560000)
to space 436864K, 0% used [0x00000005c5560000,
0x00000005c5560000, 0x00000005e0000000)
concurrent mark-sweep generation total 7864320K, used 7864319K
[0x00000005e0000000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace used 53159K, capacity 54766K, committed 55148K,
reserved 1097728K
class space used 5589K, capacity 5950K, committed 6000K, reserved 1048576K
}
2019-10-02T16:03:25.477+0000: 265328.214: Total time for which
application threads were stopped: 9.5906157 seconds, Stopping threads
took: 0.0001274 seconds
*With the following from the SOLR log: *
[ x:core] o.a.s.s.HttpSolrCall Unable to write response, client
closed connection or we are s
hutting down
org.eclipse.jetty.io.EofException: Closed
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:665)
~[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c
1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fef
c589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
at java.io.OutputStream.write(OutputStream.java:116) ~[?:1.8.0_222-ea]
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
~[?:1.8.0_222-ea]
at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
~[?:1.8.0_222-ea]
at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
~[?:1.8.0_222-ea]
at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
~[?:1.8.0_222-ea]
at org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94
- j
anhoy - 2019-05-28 23:37:52]
at org.apache.solr.common.util.FastWriter.flushBuffer(FastWriter.java:154)
~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
94 - janhoy - 2019-05-28 23:37:52]
at org.apache.solr.response.TextResponseWriter.close(TextResponseWriter.java:82)
~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
a415b94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:68)
~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
a415b94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
~[solr-core-7.7.2.jar:7.7.2 d4c30fc285
6154f2c1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94 -
janh
oy - 2019-05-28 23:37:48]
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
70a415b94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
70a415b94 - janhoy - 2019-05-28 23:37:48]
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v2018111
4]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
[jetty-security-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
*Eventually we are receiving an actual ERROR *
o.a.s.s.HttpSolrCall null:java.io.IOException:
java.util.concurrent.TimeoutExceptio
n: Idle timeout expired: 122014/120000 ms
at org.eclipse.jetty.util.SharedBlockingCallback$Blocker.block(SharedBlockingCallback.java:235)
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:217)
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:628)
at org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
at org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
at java.io.OutputStream.write(OutputStream.java:116)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
at org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
at org.apache.solr.common.util.FastWriter.write(FastWriter.java:54)
at org.apache.solr.response.JSONWriter._writeChar(JSONWriter.java:173)
at org.apache.solr.common.util.JsonTextWriter.writeStr(JsonTextWriter.java:86)
at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:52)
at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
at org.apache.solr.common.util.JsonTextWriter.writeJsonIter(JsonTextWriter.java:194)
at org.apache.solr.common.util.JsonTextWriter.writeArray(JsonTextWriter.java:270)
at org.apache.solr.common.util.TextWriter.writeArray(TextWriter.java:154)
at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:80)
at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
at org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
at org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
at org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
at org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
at org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
at org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
at org.apache.solr.response.JSONWriter.writeResponse(JSONWriter.java:73)
at org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:66)
at org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
at org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
Re: Solr standalone timeouts after upgrading to SOLR 7
Posted by Walter Underwood <wu...@wunderwood.org>.
Just set Xms and Xmx the same. The server will be running for weeks,
so allocate the memory and get on with it.
wunder
Walter Underwood
wunder@wunderwood.org
http://observer.wunderwood.org/ (my blog)
> On Oct 3, 2019, at 11:38 AM, ndra <pu...@gmail.com> wrote:
>
>> I don’t think having the initial heap larger than the max heap is a legal
> configuration.
>> I have no idea what that would do.
>
> Sorry my wording was poor. I meant if, instead of my initial HEAP of 512MB,
> it was closer to say 6 or 8GB or equal to my Max allowed of 10GB.
>
> Appreciate the info though.
>
> Thanks Watler
>
> Nick
>
> On Thu, Oct 3, 2019 at 10:57 AM Walter Underwood <wu...@wunderwood.org>
> wrote:
>
>> I don’t think having the initial heap larger than the max heap is a legal
>> configuration.
>> I have no idea what that would do.
>>
>> Modern GCs have a separate area for short-lived allocations. When that
>> fills up,
>> a minor GC happens. As allocations survive several minor GCs, they are
>> moved
>> to the long-lived space, which is managed by major GCs. This is called a
>> generational
>> collector.
>>
>> In Solr, nearly all allocations are for a single request, so those are
>> garbage after the
>> response is sent. Most of the action will be in the new allocation
>> (short-lived) space.
>> Cache allocations get moved to the long-lived space.
>>
>> wunder
>> Walter Underwood
>> wunder@wunderwood.org
>> http://observer.wunderwood.org/ (my blog)
>>
>>> On Oct 3, 2019, at 10:11 AM, ndra <pu...@gmail.com> wrote:
>>>
>>>> When the heap is out of free space that
>>>> can be recovered with minor GC, the JVM will increase the size if
>> possible.
>>>> Once it is at max, it will do a major GC.
>>>
>>> Thanks Walter,
>>>
>>> One more quick question about the above, so if the initial HEAP was
>> larger
>>> (or equal to the max as you suggested earlier) will the GCs minor GCs be
>>> less frequent because the HEAP still has available space?
>>>
>>> Unfortunately the system was rebooted by a infrastructure person prior to
>>> looking at `/admin/system/info` endpoint to look at the stats. Is there
>>> another way get those statistics (there is no JVM monitoring in place
>> from
>>> our INF team so I am starting this all from scratch right now.
>>>
>>> Nick
>>>
>>>
>>> On Thu, Oct 3, 2019 at 9:44 AM Walter Underwood <wu...@wunderwood.org>
>>> wrote:
>>>
>>>>> On Oct 3, 2019, at 9:31 AM, ndra <pu...@gmail.com> wrote:
>>>>>
>>>>> I was under the impression that by allocating a smaller initial HEAP I
>>>>> could avoid having a larger GCs but if I am understanding what you all
>>>> are
>>>>> suggesting, the smaller initial HEAP is requiring more full GCs to
>>>> maintian
>>>>> a HEAP closer to 512MB. Is that correct?
>>>>
>>>> I don’t think either of those are true. When the heap is out of free
>> space
>>>> that
>>>> can be recovered with minor GC, the JVM will increase the size if
>> possible.
>>>> Once it is at max, it will do a major GC.
>>>>
>>>> We use these settings in solr.in.sh:
>>>>
>>>> SOLR_HEAP=8g
>>>> # Use G1 GC -- wunder 2017-01-23
>>>> # Settings from https://wiki.apache.org/solr/ShawnHeisey
>>>> GC_TUNE=" \
>>>> -XX:+UseG1GC \
>>>> -XX:+ParallelRefProcEnabled \
>>>> -XX:G1HeapRegionSize=8m \
>>>> -XX:MaxGCPauseMillis=200 \
>>>> -XX:+UseLargePages \
>>>> -XX:+AggressiveOpts \
>>>> "
>>>> wunder
>>>> Walter Underwood
>>>> wunder@wunderwood.org
>>>> http://observer.wunderwood.org/ (my blog)
>>>>
>>>>
>>
>>
Re: Solr standalone timeouts after upgrading to SOLR 7
Posted by ndra <pu...@gmail.com>.
> I don’t think having the initial heap larger than the max heap is a legal
configuration.
> I have no idea what that would do.
Sorry my wording was poor. I meant if, instead of my initial HEAP of 512MB,
it was closer to say 6 or 8GB or equal to my Max allowed of 10GB.
Appreciate the info though.
Thanks Watler
Nick
On Thu, Oct 3, 2019 at 10:57 AM Walter Underwood <wu...@wunderwood.org>
wrote:
> I don’t think having the initial heap larger than the max heap is a legal
> configuration.
> I have no idea what that would do.
>
> Modern GCs have a separate area for short-lived allocations. When that
> fills up,
> a minor GC happens. As allocations survive several minor GCs, they are
> moved
> to the long-lived space, which is managed by major GCs. This is called a
> generational
> collector.
>
> In Solr, nearly all allocations are for a single request, so those are
> garbage after the
> response is sent. Most of the action will be in the new allocation
> (short-lived) space.
> Cache allocations get moved to the long-lived space.
>
> wunder
> Walter Underwood
> wunder@wunderwood.org
> http://observer.wunderwood.org/ (my blog)
>
> > On Oct 3, 2019, at 10:11 AM, ndra <pu...@gmail.com> wrote:
> >
> >> When the heap is out of free space that
> >> can be recovered with minor GC, the JVM will increase the size if
> possible.
> >> Once it is at max, it will do a major GC.
> >
> > Thanks Walter,
> >
> > One more quick question about the above, so if the initial HEAP was
> larger
> > (or equal to the max as you suggested earlier) will the GCs minor GCs be
> > less frequent because the HEAP still has available space?
> >
> > Unfortunately the system was rebooted by a infrastructure person prior to
> > looking at `/admin/system/info` endpoint to look at the stats. Is there
> > another way get those statistics (there is no JVM monitoring in place
> from
> > our INF team so I am starting this all from scratch right now.
> >
> > Nick
> >
> >
> > On Thu, Oct 3, 2019 at 9:44 AM Walter Underwood <wu...@wunderwood.org>
> > wrote:
> >
> >>> On Oct 3, 2019, at 9:31 AM, ndra <pu...@gmail.com> wrote:
> >>>
> >>> I was under the impression that by allocating a smaller initial HEAP I
> >>> could avoid having a larger GCs but if I am understanding what you all
> >> are
> >>> suggesting, the smaller initial HEAP is requiring more full GCs to
> >> maintian
> >>> a HEAP closer to 512MB. Is that correct?
> >>
> >> I don’t think either of those are true. When the heap is out of free
> space
> >> that
> >> can be recovered with minor GC, the JVM will increase the size if
> possible.
> >> Once it is at max, it will do a major GC.
> >>
> >> We use these settings in solr.in.sh:
> >>
> >> SOLR_HEAP=8g
> >> # Use G1 GC -- wunder 2017-01-23
> >> # Settings from https://wiki.apache.org/solr/ShawnHeisey
> >> GC_TUNE=" \
> >> -XX:+UseG1GC \
> >> -XX:+ParallelRefProcEnabled \
> >> -XX:G1HeapRegionSize=8m \
> >> -XX:MaxGCPauseMillis=200 \
> >> -XX:+UseLargePages \
> >> -XX:+AggressiveOpts \
> >> "
> >> wunder
> >> Walter Underwood
> >> wunder@wunderwood.org
> >> http://observer.wunderwood.org/ (my blog)
> >>
> >>
>
>
Re: Solr standalone timeouts after upgrading to SOLR 7
Posted by Walter Underwood <wu...@wunderwood.org>.
I don’t think having the initial heap larger than the max heap is a legal configuration.
I have no idea what that would do.
Modern GCs have a separate area for short-lived allocations. When that fills up,
a minor GC happens. As allocations survive several minor GCs, they are moved
to the long-lived space, which is managed by major GCs. This is called a generational
collector.
In Solr, nearly all allocations are for a single request, so those are garbage after the
response is sent. Most of the action will be in the new allocation (short-lived) space.
Cache allocations get moved to the long-lived space.
wunder
Walter Underwood
wunder@wunderwood.org
http://observer.wunderwood.org/ (my blog)
> On Oct 3, 2019, at 10:11 AM, ndra <pu...@gmail.com> wrote:
>
>> When the heap is out of free space that
>> can be recovered with minor GC, the JVM will increase the size if possible.
>> Once it is at max, it will do a major GC.
>
> Thanks Walter,
>
> One more quick question about the above, so if the initial HEAP was larger
> (or equal to the max as you suggested earlier) will the GCs minor GCs be
> less frequent because the HEAP still has available space?
>
> Unfortunately the system was rebooted by a infrastructure person prior to
> looking at `/admin/system/info` endpoint to look at the stats. Is there
> another way get those statistics (there is no JVM monitoring in place from
> our INF team so I am starting this all from scratch right now.
>
> Nick
>
>
> On Thu, Oct 3, 2019 at 9:44 AM Walter Underwood <wu...@wunderwood.org>
> wrote:
>
>>> On Oct 3, 2019, at 9:31 AM, ndra <pu...@gmail.com> wrote:
>>>
>>> I was under the impression that by allocating a smaller initial HEAP I
>>> could avoid having a larger GCs but if I am understanding what you all
>> are
>>> suggesting, the smaller initial HEAP is requiring more full GCs to
>> maintian
>>> a HEAP closer to 512MB. Is that correct?
>>
>> I don’t think either of those are true. When the heap is out of free space
>> that
>> can be recovered with minor GC, the JVM will increase the size if possible.
>> Once it is at max, it will do a major GC.
>>
>> We use these settings in solr.in.sh:
>>
>> SOLR_HEAP=8g
>> # Use G1 GC -- wunder 2017-01-23
>> # Settings from https://wiki.apache.org/solr/ShawnHeisey
>> GC_TUNE=" \
>> -XX:+UseG1GC \
>> -XX:+ParallelRefProcEnabled \
>> -XX:G1HeapRegionSize=8m \
>> -XX:MaxGCPauseMillis=200 \
>> -XX:+UseLargePages \
>> -XX:+AggressiveOpts \
>> "
>> wunder
>> Walter Underwood
>> wunder@wunderwood.org
>> http://observer.wunderwood.org/ (my blog)
>>
>>
Re: Solr standalone timeouts after upgrading to SOLR 7
Posted by ndra <pu...@gmail.com>.
> When the heap is out of free space that
>can be recovered with minor GC, the JVM will increase the size if possible.
>Once it is at max, it will do a major GC.
Thanks Walter,
One more quick question about the above, so if the initial HEAP was larger
(or equal to the max as you suggested earlier) will the GCs minor GCs be
less frequent because the HEAP still has available space?
Unfortunately the system was rebooted by a infrastructure person prior to
looking at `/admin/system/info` endpoint to look at the stats. Is there
another way get those statistics (there is no JVM monitoring in place from
our INF team so I am starting this all from scratch right now.
Nick
On Thu, Oct 3, 2019 at 9:44 AM Walter Underwood <wu...@wunderwood.org>
wrote:
> > On Oct 3, 2019, at 9:31 AM, ndra <pu...@gmail.com> wrote:
> >
> > I was under the impression that by allocating a smaller initial HEAP I
> > could avoid having a larger GCs but if I am understanding what you all
> are
> > suggesting, the smaller initial HEAP is requiring more full GCs to
> maintian
> > a HEAP closer to 512MB. Is that correct?
>
> I don’t think either of those are true. When the heap is out of free space
> that
> can be recovered with minor GC, the JVM will increase the size if possible.
> Once it is at max, it will do a major GC.
>
> We use these settings in solr.in.sh:
>
> SOLR_HEAP=8g
> # Use G1 GC -- wunder 2017-01-23
> # Settings from https://wiki.apache.org/solr/ShawnHeisey
> GC_TUNE=" \
> -XX:+UseG1GC \
> -XX:+ParallelRefProcEnabled \
> -XX:G1HeapRegionSize=8m \
> -XX:MaxGCPauseMillis=200 \
> -XX:+UseLargePages \
> -XX:+AggressiveOpts \
> "
> wunder
> Walter Underwood
> wunder@wunderwood.org
> http://observer.wunderwood.org/ (my blog)
>
>
Re: Solr standalone timeouts after upgrading to SOLR 7
Posted by Walter Underwood <wu...@wunderwood.org>.
> On Oct 3, 2019, at 9:31 AM, ndra <pu...@gmail.com> wrote:
>
> I was under the impression that by allocating a smaller initial HEAP I
> could avoid having a larger GCs but if I am understanding what you all are
> suggesting, the smaller initial HEAP is requiring more full GCs to maintian
> a HEAP closer to 512MB. Is that correct?
I don’t think either of those are true. When the heap is out of free space that
can be recovered with minor GC, the JVM will increase the size if possible.
Once it is at max, it will do a major GC.
We use these settings in solr.in.sh:
SOLR_HEAP=8g
# Use G1 GC -- wunder 2017-01-23
# Settings from https://wiki.apache.org/solr/ShawnHeisey
GC_TUNE=" \
-XX:+UseG1GC \
-XX:+ParallelRefProcEnabled \
-XX:G1HeapRegionSize=8m \
-XX:MaxGCPauseMillis=200 \
-XX:+UseLargePages \
-XX:+AggressiveOpts \
"
wunder
Walter Underwood
wunder@wunderwood.org
http://observer.wunderwood.org/ (my blog)
Re: Solr standalone timeouts after upgrading to SOLR 7
Posted by ndra <pu...@gmail.com>.
Thank you all for the responses. I do have a question about moving to G1.
Is there any plans for SOLR to make this the default JAVA_OPT for SOLR? We
have been running CMS without any issue prior to 7.
The primary change we made between 6->7 was to increase the max HEAP size
and increase the Xms as well (went from 1 and 8 to 2 and 10). We saw
similar issues with these new values so I reduced the Xms based on my
understanding of this (from
https://lucene.apache.org/solr/guide/7_7/jvm-settings.html)
> The larger the heap the longer it takes to do garbage collection. This
can mean minor, random pauses or, in extreme cases, "freeze the world"
pauses of a minute or more. As a practical matter, this >can become a
serious problem for heap sizes that exceed about two gigabytes, even if far
more physical memory is available. On robust hardware, you may get better
results running multiple JVMs, >rather than just one with a large memory
heap. Some specialized JVM implementations may have customized garbage
collection algorithms that do better with large heaps. Consult your JVM
vendor’s >documentation.
I was under the impression that by allocating a smaller initial HEAP I
could avoid having a larger GCs but if I am understanding what you all are
suggesting, the smaller initial HEAP is requiring more full GCs to maintian
a HEAP closer to 512MB. Is that correct?
Nick
On Thu, Oct 3, 2019 at 8:24 AM Jörn Franke <jo...@gmail.com> wrote:
> As the others said: move to the newer GC. I would also use this
> opportunity to work with the default Java options of Solr 7 and then tune
> again. If you change major versions you should always review the GC
> settings if they still make sense.
>
> > Am 02.10.2019 um 23:14 schrieb Solr User <pu...@gmail.com>:
> >
> > Hello all,
> >
> > We recently moved to SOLR 7 from SOLR 6 about 2 weeks ago. Once each week
> > (including today) we experienced query timeout issues with corresponding
> GC
> > events. There was a spike in CPU up to 66% which is not something we
> > previously saw w/ Solr 6. From the SOLR logs it looks like something
> inside
> > the JVM has happend, SOLR is reporting closed connections from Jetty. Our
> > data size is relatively small but we do run 5 cores within the one Jetty
> > instance. There index sizes are anywhere between 200Mb to 2GB
> >
> > Our memory consumption is relatively low:
> >
> > "free":"296.1 MB",
> >
> > "total":"569.6 MB",
> >
> > "max":"9.6 GB",
> >
> > "used":"273.5 MB (%2.8)",
> >
> >
> >
> > We had a spike in traffic about 5 minutes prior to some longer GC events
> > (similar situation last week).
> >
> > Any help would be appreciated. Below is my current system info along
> with a
> > GC log snippet and the corresponding SOLR log error.
> >
> > *System info:*
> > AMZ2 linux
> > 8 core 32 GB Mem
> > *Java:* 1.8.0_222-ea 25.222-b03
> > *Solr: *solr-spec-version":"7.7.2"
> > *Start options: *
> > "-Xms512m",
> > "-Xmx10g",
> > "-XX:NewRatio=3",
> > "-XX:SurvivorRatio=4",
> > "-XX:TargetSurvivorRatio=90",
> > "-XX:MaxTenuringThreshold=8",
> > "-XX:+UseConcMarkSweepGC",
> > "-XX:ConcGCThreads=4",
> > "-XX:ParallelGCThreads=4",
> > "-XX:+CMSScavengeBeforeRemark",
> > "-XX:PretenureSizeThreshold=64m",
> > "-XX:+UseCMSInitiatingOccupancyOnly",
> > "-XX:CMSInitiatingOccupancyFraction=50",
> > "-XX:CMSMaxAbortablePrecleanTime=6000",
> > "-XX:+CMSParallelRemarkEnabled",
> > "-XX:+ParallelRefProcEnabled",
> > "-XX:-OmitStackTraceInFastThrow",
> > "-verbose:gc",
> > "-XX:+PrintHeapAtGC",
> > "-XX:+PrintGCDetails",
> > "-XX:+PrintGCDateStamps",
> > "-XX:+PrintGCTimeStamps",
> > "-XX:+PrintTenuringDistribution",
> > "-XX:+PrintGCApplicationStoppedTime",
> > "-XX:+UseGCLogFileRotation",
> > "-XX:NumberOfGCLogFiles=9",
> > "-XX:GCLogFileSize=20M",
> > "-Xss256k",
> > "-Dsolr.log.muteconsole"
> >
> > Here is an example of from the GC log:
> >
> > 2019-10-02T16:03:15.888+0000: 265318.624: [Full GC (Allocation
> > Failure) 2019-10-02T16:03:15.888+0000: 265318.624:
> > [CMS2019-10-02T16:03:16.134+0000: 26
> > 5318.870: [CMS-concurrent-mark: 1.773/1.783 secs] [Times: user=13.14
> > sys=0.00, real=1.78 secs]
> > (concurrent mode failure): 7864319K->7864319K(7864320K), 9.5890129
> > secs] 10048895K->8863021K(10048896K), [Metaspace:
> > 53159K->53159K(1097728K)], 9.5892061 secs] [Times: user=10.31
> > sys=0.00, real=9.59 secs]
> > Heap after GC invocations=296656 (full 546):
> > par new generation total 2184576K, used 998701K
> > [0x0000000540000000, 0x00000005e0000000, 0x00000005e0000000)
> > eden space 1747712K, 57% used [0x0000000540000000,
> > 0x000000057cf4b4f0, 0x00000005aaac0000)
> > from space 436864K, 0% used [0x00000005aaac0000,
> > 0x00000005aaac0000, 0x00000005c5560000)
> > to space 436864K, 0% used [0x00000005c5560000,
> > 0x00000005c5560000, 0x00000005e0000000)
> > concurrent mark-sweep generation total 7864320K, used 7864319K
> > [0x00000005e0000000, 0x00000007c0000000, 0x00000007c0000000)
> > Metaspace used 53159K, capacity 54766K, committed 55148K,
> > reserved 1097728K
> > class space used 5589K, capacity 5950K, committed 6000K, reserved
> 1048576K
> > }
> > 2019-10-02T16:03:25.477+0000: 265328.214: Total time for which
> > application threads were stopped: 9.5906157 seconds, Stopping threads
> > took: 0.0001274 seconds
> > *With the following from the SOLR log: *
> >
> > [ x:core] o.a.s.s.HttpSolrCall Unable to write response, client
> > closed connection or we are s
> >
> > hutting down
> >
> > org.eclipse.jetty.io.EofException: Closed
> >
> > at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:665)
> > ~[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
> > ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c
> >
> > 1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
> >
> > at
> org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
> > ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fef
> >
> > c589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
> >
> > at java.io.OutputStream.write(OutputStream.java:116)
> ~[?:1.8.0_222-ea]
> >
> > at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> > ~[?:1.8.0_222-ea]
> >
> > at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> > ~[?:1.8.0_222-ea]
> >
> > at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> > ~[?:1.8.0_222-ea]
> >
> > at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> > ~[?:1.8.0_222-ea]
> >
> > at
> org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
> > ~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94
> > - j
> >
> > anhoy - 2019-05-28 23:37:52]
> >
> > at
> org.apache.solr.common.util.FastWriter.flushBuffer(FastWriter.java:154)
> > ~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
> >
> > 94 - janhoy - 2019-05-28 23:37:52]
> >
> > at
> org.apache.solr.response.TextResponseWriter.close(TextResponseWriter.java:82)
> > ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
> >
> > a415b94 - janhoy - 2019-05-28 23:37:48]
> >
> > at
> org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:68)
> > ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
> >
> > a415b94 - janhoy - 2019-05-28 23:37:48]
> >
> > at
> org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
> > ~[solr-core-7.7.2.jar:7.7.2 d4c30fc285
> >
> > 6154f2c1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
> >
> > at
> org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
> > [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
> >
> > 94 - janhoy - 2019-05-28 23:37:48]
> >
> > at
> org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
> > [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94 -
> > janh
> >
> > oy - 2019-05-28 23:37:48]
> >
> > at
> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
> > [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
> >
> > 70a415b94 - janhoy - 2019-05-28 23:37:48]
> >
> > at
> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
> > [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
> >
> > 70a415b94 - janhoy - 2019-05-28 23:37:48]
> >
> > at
> org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
> > [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v2018111
> >
> > 4]
> >
> > at
> org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
> > [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
> > [jetty-security-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
> > [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> > at
> org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220)
> > [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
> >
> >
> >
> > *Eventually we are receiving an actual ERROR *
> >
> >
> >
> > o.a.s.s.HttpSolrCall null:java.io.IOException:
> > java.util.concurrent.TimeoutExceptio
> > n: Idle timeout expired: 122014/120000 ms
> > at
> org.eclipse.jetty.util.SharedBlockingCallback$Blocker.block(SharedBlockingCallback.java:235)
> > at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:217)
> > at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:628)
> > at
> org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
> > at
> org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
> > at java.io.OutputStream.write(OutputStream.java:116)
> > at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> > at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> > at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> > at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> > at
> org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
> > at
> org.apache.solr.common.util.FastWriter.write(FastWriter.java:54)
> > at
> org.apache.solr.response.JSONWriter._writeChar(JSONWriter.java:173)
> > at
> org.apache.solr.common.util.JsonTextWriter.writeStr(JsonTextWriter.java:86)
> > at
> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:52)
> > at
> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> > at
> org.apache.solr.common.util.JsonTextWriter.writeJsonIter(JsonTextWriter.java:194)
> > at
> org.apache.solr.common.util.JsonTextWriter.writeArray(JsonTextWriter.java:270)
> > at
> org.apache.solr.common.util.TextWriter.writeArray(TextWriter.java:154)
> > at
> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:80)
> > at
> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> > at
> org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
> > at
> org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
> > at
> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
> > at
> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> > at
> org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
> > at
> org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
> > at
> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
> > at
> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> > at
> org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
> > at
> org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
> > at
> org.apache.solr.response.JSONWriter.writeResponse(JSONWriter.java:73)
> > at
> org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:66)
> > at
> org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
> > at
> org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
> > at
> org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
> > at
> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
> > at
> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
> > at
> org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
> > at
> org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
> > at
> org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
> > at
> org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
> > at
> org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
> > at
> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
> > at
> org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
> > at
> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
>
Re: Solr standalone timeouts after upgrading to SOLR 7
Posted by Jörn Franke <jo...@gmail.com>.
As the others said: move to the newer GC. I would also use this opportunity to work with the default Java options of Solr 7 and then tune again. If you change major versions you should always review the GC settings if they still make sense.
> Am 02.10.2019 um 23:14 schrieb Solr User <pu...@gmail.com>:
>
> Hello all,
>
> We recently moved to SOLR 7 from SOLR 6 about 2 weeks ago. Once each week
> (including today) we experienced query timeout issues with corresponding GC
> events. There was a spike in CPU up to 66% which is not something we
> previously saw w/ Solr 6. From the SOLR logs it looks like something inside
> the JVM has happend, SOLR is reporting closed connections from Jetty. Our
> data size is relatively small but we do run 5 cores within the one Jetty
> instance. There index sizes are anywhere between 200Mb to 2GB
>
> Our memory consumption is relatively low:
>
> "free":"296.1 MB",
>
> "total":"569.6 MB",
>
> "max":"9.6 GB",
>
> "used":"273.5 MB (%2.8)",
>
>
>
> We had a spike in traffic about 5 minutes prior to some longer GC events
> (similar situation last week).
>
> Any help would be appreciated. Below is my current system info along with a
> GC log snippet and the corresponding SOLR log error.
>
> *System info:*
> AMZ2 linux
> 8 core 32 GB Mem
> *Java:* 1.8.0_222-ea 25.222-b03
> *Solr: *solr-spec-version":"7.7.2"
> *Start options: *
> "-Xms512m",
> "-Xmx10g",
> "-XX:NewRatio=3",
> "-XX:SurvivorRatio=4",
> "-XX:TargetSurvivorRatio=90",
> "-XX:MaxTenuringThreshold=8",
> "-XX:+UseConcMarkSweepGC",
> "-XX:ConcGCThreads=4",
> "-XX:ParallelGCThreads=4",
> "-XX:+CMSScavengeBeforeRemark",
> "-XX:PretenureSizeThreshold=64m",
> "-XX:+UseCMSInitiatingOccupancyOnly",
> "-XX:CMSInitiatingOccupancyFraction=50",
> "-XX:CMSMaxAbortablePrecleanTime=6000",
> "-XX:+CMSParallelRemarkEnabled",
> "-XX:+ParallelRefProcEnabled",
> "-XX:-OmitStackTraceInFastThrow",
> "-verbose:gc",
> "-XX:+PrintHeapAtGC",
> "-XX:+PrintGCDetails",
> "-XX:+PrintGCDateStamps",
> "-XX:+PrintGCTimeStamps",
> "-XX:+PrintTenuringDistribution",
> "-XX:+PrintGCApplicationStoppedTime",
> "-XX:+UseGCLogFileRotation",
> "-XX:NumberOfGCLogFiles=9",
> "-XX:GCLogFileSize=20M",
> "-Xss256k",
> "-Dsolr.log.muteconsole"
>
> Here is an example of from the GC log:
>
> 2019-10-02T16:03:15.888+0000: 265318.624: [Full GC (Allocation
> Failure) 2019-10-02T16:03:15.888+0000: 265318.624:
> [CMS2019-10-02T16:03:16.134+0000: 26
> 5318.870: [CMS-concurrent-mark: 1.773/1.783 secs] [Times: user=13.14
> sys=0.00, real=1.78 secs]
> (concurrent mode failure): 7864319K->7864319K(7864320K), 9.5890129
> secs] 10048895K->8863021K(10048896K), [Metaspace:
> 53159K->53159K(1097728K)], 9.5892061 secs] [Times: user=10.31
> sys=0.00, real=9.59 secs]
> Heap after GC invocations=296656 (full 546):
> par new generation total 2184576K, used 998701K
> [0x0000000540000000, 0x00000005e0000000, 0x00000005e0000000)
> eden space 1747712K, 57% used [0x0000000540000000,
> 0x000000057cf4b4f0, 0x00000005aaac0000)
> from space 436864K, 0% used [0x00000005aaac0000,
> 0x00000005aaac0000, 0x00000005c5560000)
> to space 436864K, 0% used [0x00000005c5560000,
> 0x00000005c5560000, 0x00000005e0000000)
> concurrent mark-sweep generation total 7864320K, used 7864319K
> [0x00000005e0000000, 0x00000007c0000000, 0x00000007c0000000)
> Metaspace used 53159K, capacity 54766K, committed 55148K,
> reserved 1097728K
> class space used 5589K, capacity 5950K, committed 6000K, reserved 1048576K
> }
> 2019-10-02T16:03:25.477+0000: 265328.214: Total time for which
> application threads were stopped: 9.5906157 seconds, Stopping threads
> took: 0.0001274 seconds
> *With the following from the SOLR log: *
>
> [ x:core] o.a.s.s.HttpSolrCall Unable to write response, client
> closed connection or we are s
>
> hutting down
>
> org.eclipse.jetty.io.EofException: Closed
>
> at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:665)
> ~[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c
>
> 1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fef
>
> c589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at java.io.OutputStream.write(OutputStream.java:116) ~[?:1.8.0_222-ea]
>
> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> ~[?:1.8.0_222-ea]
>
> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> ~[?:1.8.0_222-ea]
>
> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> ~[?:1.8.0_222-ea]
>
> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> ~[?:1.8.0_222-ea]
>
> at org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
> ~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94
> - j
>
> anhoy - 2019-05-28 23:37:52]
>
> at org.apache.solr.common.util.FastWriter.flushBuffer(FastWriter.java:154)
> ~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
>
> 94 - janhoy - 2019-05-28 23:37:52]
>
> at org.apache.solr.response.TextResponseWriter.close(TextResponseWriter.java:82)
> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
>
> a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:68)
> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
>
> a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc285
>
> 6154f2c1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
>
> 94 - janhoy - 2019-05-28 23:37:48]
>
> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94 -
> janh
>
> oy - 2019-05-28 23:37:48]
>
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
>
> 70a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
>
> 70a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
> [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v2018111
>
> 4]
>
> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
> [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
> [jetty-security-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
> [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
>
>
> *Eventually we are receiving an actual ERROR *
>
>
>
> o.a.s.s.HttpSolrCall null:java.io.IOException:
> java.util.concurrent.TimeoutExceptio
> n: Idle timeout expired: 122014/120000 ms
> at org.eclipse.jetty.util.SharedBlockingCallback$Blocker.block(SharedBlockingCallback.java:235)
> at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:217)
> at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:628)
> at org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
> at org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
> at java.io.OutputStream.write(OutputStream.java:116)
> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> at org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
> at org.apache.solr.common.util.FastWriter.write(FastWriter.java:54)
> at org.apache.solr.response.JSONWriter._writeChar(JSONWriter.java:173)
> at org.apache.solr.common.util.JsonTextWriter.writeStr(JsonTextWriter.java:86)
> at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:52)
> at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> at org.apache.solr.common.util.JsonTextWriter.writeJsonIter(JsonTextWriter.java:194)
> at org.apache.solr.common.util.JsonTextWriter.writeArray(JsonTextWriter.java:270)
> at org.apache.solr.common.util.TextWriter.writeArray(TextWriter.java:154)
> at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:80)
> at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> at org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
> at org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
> at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
> at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> at org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
> at org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
> at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
> at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> at org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
> at org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
> at org.apache.solr.response.JSONWriter.writeResponse(JSONWriter.java:73)
> at org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:66)
> at org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
> at org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
> at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
Re: Solr standalone timeouts after upgrading to SOLR 7
Posted by Walter Underwood <wu...@wunderwood.org>.
Always make Xmx and Xms the same. The heap will increase to the max before a major GC, so avoid the pauses to grow it.
Use the G1 collector. CMS is really obsolete. We’ve had G1 in prod for at least three years.
wunder
Walter Underwood
wunder@wunderwood.org
http://observer.wunderwood.org/ (my blog)
> On Oct 2, 2019, at 11:07 PM, Paras Lehana <pa...@indiamart.com> wrote:
>
> Hi concerned (please use signature),
>
> The timeouts could be because of the "stop the world" kinda behaviour of
> longer GC pause. When we shifted our Auto-Suggest from Redis to Solr, I
> faced the similar GC pause issue while stress testing. This article
> <https://cwiki.apache.org/confluence/display/solr/ShawnHeisey#ShawnHeisey-GCTuningforSolr>
> by Shawn Heisey helped me a lot to experiment with different setups - I
> tried combinations of different collectors, heap and other configs.
>
> I think your -Xms and -Xmx values have too much of the relative difference.
> Your heap could be getting filled up to the max 10G during peak times and
> then the longer GC pauses would have made pending queries go timeout. By
> seeing your current memory usage, I recommend you to decrease the Xmx. Try
> with same values first or maybe 4,6G. If you think 10G is okay, then
> consider increasing your Xms to maybe 6-8G? Since this is a sort of
> experiment you have to perform and I can only recommend things as per my
> experience, I strongly recommend you to read Shawn's article.
>
> On Thu, 3 Oct 2019 at 02:44, Solr User <pu...@gmail.com> wrote:
>
>> Hello all,
>>
>> We recently moved to SOLR 7 from SOLR 6 about 2 weeks ago. Once each week
>> (including today) we experienced query timeout issues with corresponding GC
>> events. There was a spike in CPU up to 66% which is not something we
>> previously saw w/ Solr 6. From the SOLR logs it looks like something inside
>> the JVM has happend, SOLR is reporting closed connections from Jetty. Our
>> data size is relatively small but we do run 5 cores within the one Jetty
>> instance. There index sizes are anywhere between 200Mb to 2GB
>>
>> Our memory consumption is relatively low:
>>
>> "free":"296.1 MB",
>>
>> "total":"569.6 MB",
>>
>> "max":"9.6 GB",
>>
>> "used":"273.5 MB (%2.8)",
>>
>>
>>
>> We had a spike in traffic about 5 minutes prior to some longer GC events
>> (similar situation last week).
>>
>> Any help would be appreciated. Below is my current system info along with a
>> GC log snippet and the corresponding SOLR log error.
>>
>> *System info:*
>> AMZ2 linux
>> 8 core 32 GB Mem
>> *Java:* 1.8.0_222-ea 25.222-b03
>> *Solr: *solr-spec-version":"7.7.2"
>> *Start options: *
>> "-Xms512m",
>> "-Xmx10g",
>> "-XX:NewRatio=3",
>> "-XX:SurvivorRatio=4",
>> "-XX:TargetSurvivorRatio=90",
>> "-XX:MaxTenuringThreshold=8",
>> "-XX:+UseConcMarkSweepGC",
>> "-XX:ConcGCThreads=4",
>> "-XX:ParallelGCThreads=4",
>> "-XX:+CMSScavengeBeforeRemark",
>> "-XX:PretenureSizeThreshold=64m",
>> "-XX:+UseCMSInitiatingOccupancyOnly",
>> "-XX:CMSInitiatingOccupancyFraction=50",
>> "-XX:CMSMaxAbortablePrecleanTime=6000",
>> "-XX:+CMSParallelRemarkEnabled",
>> "-XX:+ParallelRefProcEnabled",
>> "-XX:-OmitStackTraceInFastThrow",
>> "-verbose:gc",
>> "-XX:+PrintHeapAtGC",
>> "-XX:+PrintGCDetails",
>> "-XX:+PrintGCDateStamps",
>> "-XX:+PrintGCTimeStamps",
>> "-XX:+PrintTenuringDistribution",
>> "-XX:+PrintGCApplicationStoppedTime",
>> "-XX:+UseGCLogFileRotation",
>> "-XX:NumberOfGCLogFiles=9",
>> "-XX:GCLogFileSize=20M",
>> "-Xss256k",
>> "-Dsolr.log.muteconsole"
>>
>> Here is an example of from the GC log:
>>
>> 2019-10-02T16:03:15.888+0000: 265318.624: [Full GC (Allocation
>> Failure) 2019-10-02T16:03:15.888+0000: 265318.624:
>> [CMS2019-10-02T16:03:16.134+0000: 26
>> 5318.870: [CMS-concurrent-mark: 1.773/1.783 secs] [Times: user=13.14
>> sys=0.00, real=1.78 secs]
>> (concurrent mode failure): 7864319K->7864319K(7864320K), 9.5890129
>> secs] 10048895K->8863021K(10048896K), [Metaspace:
>> 53159K->53159K(1097728K)], 9.5892061 secs] [Times: user=10.31
>> sys=0.00, real=9.59 secs]
>> Heap after GC invocations=296656 (full 546):
>> par new generation total 2184576K, used 998701K
>> [0x0000000540000000, 0x00000005e0000000, 0x00000005e0000000)
>> eden space 1747712K, 57% used [0x0000000540000000,
>> 0x000000057cf4b4f0, 0x00000005aaac0000)
>> from space 436864K, 0% used [0x00000005aaac0000,
>> 0x00000005aaac0000, 0x00000005c5560000)
>> to space 436864K, 0% used [0x00000005c5560000,
>> 0x00000005c5560000, 0x00000005e0000000)
>> concurrent mark-sweep generation total 7864320K, used 7864319K
>> [0x00000005e0000000, 0x00000007c0000000, 0x00000007c0000000)
>> Metaspace used 53159K, capacity 54766K, committed 55148K,
>> reserved 1097728K
>> class space used 5589K, capacity 5950K, committed 6000K, reserved
>> 1048576K
>> }
>> 2019-10-02T16:03:25.477+0000: 265328.214: Total time for which
>> application threads were stopped: 9.5906157 seconds, Stopping threads
>> took: 0.0001274 seconds
>> *With the following from the SOLR log: *
>>
>> [ x:core] o.a.s.s.HttpSolrCall Unable to write response, client
>> closed connection or we are s
>>
>> hutting down
>>
>> org.eclipse.jetty.io.EofException: Closed
>>
>> at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:665)
>> ~[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
>> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c
>>
>> 1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
>>
>> at
>> org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
>> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fef
>>
>> c589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
>>
>> at java.io.OutputStream.write(OutputStream.java:116)
>> ~[?:1.8.0_222-ea]
>>
>> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
>> ~[?:1.8.0_222-ea]
>>
>> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
>> ~[?:1.8.0_222-ea]
>>
>> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
>> ~[?:1.8.0_222-ea]
>>
>> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
>> ~[?:1.8.0_222-ea]
>>
>> at
>> org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
>> ~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94
>> - j
>>
>> anhoy - 2019-05-28 23:37:52]
>>
>> at
>> org.apache.solr.common.util.FastWriter.flushBuffer(FastWriter.java:154)
>> ~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
>>
>> 94 - janhoy - 2019-05-28 23:37:52]
>>
>> at
>> org.apache.solr.response.TextResponseWriter.close(TextResponseWriter.java:82)
>> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
>>
>> a415b94 - janhoy - 2019-05-28 23:37:48]
>>
>> at
>> org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:68)
>> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
>>
>> a415b94 - janhoy - 2019-05-28 23:37:48]
>>
>> at
>> org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
>> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc285
>>
>> 6154f2c1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
>>
>> at
>> org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
>> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
>>
>> 94 - janhoy - 2019-05-28 23:37:48]
>>
>> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
>> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94 -
>> janh
>>
>> oy - 2019-05-28 23:37:48]
>>
>> at
>> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
>> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
>>
>> 70a415b94 - janhoy - 2019-05-28 23:37:48]
>>
>> at
>> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
>> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
>>
>> 70a415b94 - janhoy - 2019-05-28 23:37:48]
>>
>> at
>> org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
>> [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v2018111
>>
>> 4]
>>
>> at
>> org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
>> [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
>> [jetty-security-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
>> [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>> at
>> org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220)
>> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>>
>>
>>
>> *Eventually we are receiving an actual ERROR *
>>
>>
>>
>> o.a.s.s.HttpSolrCall null:java.io.IOException:
>> java.util.concurrent.TimeoutExceptio
>> n: Idle timeout expired: 122014/120000 ms
>> at
>> org.eclipse.jetty.util.SharedBlockingCallback$Blocker.block(SharedBlockingCallback.java:235)
>> at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:217)
>> at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:628)
>> at
>> org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
>> at
>> org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
>> at java.io.OutputStream.write(OutputStream.java:116)
>> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
>> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
>> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
>> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
>> at
>> org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
>> at org.apache.solr.common.util.FastWriter.write(FastWriter.java:54)
>> at
>> org.apache.solr.response.JSONWriter._writeChar(JSONWriter.java:173)
>> at
>> org.apache.solr.common.util.JsonTextWriter.writeStr(JsonTextWriter.java:86)
>> at
>> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:52)
>> at
>> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
>> at
>> org.apache.solr.common.util.JsonTextWriter.writeJsonIter(JsonTextWriter.java:194)
>> at
>> org.apache.solr.common.util.JsonTextWriter.writeArray(JsonTextWriter.java:270)
>> at
>> org.apache.solr.common.util.TextWriter.writeArray(TextWriter.java:154)
>> at
>> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:80)
>> at
>> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
>> at
>> org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
>> at
>> org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
>> at
>> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
>> at
>> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
>> at
>> org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
>> at
>> org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
>> at
>> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
>> at
>> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
>> at
>> org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
>> at
>> org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
>> at
>> org.apache.solr.response.JSONWriter.writeResponse(JSONWriter.java:73)
>> at
>> org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:66)
>> at
>> org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
>> at
>> org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
>> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
>> at
>> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
>> at
>> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
>> at
>> org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
>> at
>> org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
>> at
>> org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
>> at
>> org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
>> at
>> org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
>> at
>> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
>> at
>> org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
>> at
>> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
>>
>
>
> --
> --
> Regards,
>
> *Paras Lehana* [65871]
> Software Programmer, Auto-Suggest,
> IndiaMART Intermesh Ltd.
>
> 8th Floor, Tower A, Advant-Navis Business Park, Sector 142,
> Noida, UP, IN - 201303
>
> Mob.: +91-9560911996
> Work: 01203916600 | Extn: *8173*
>
> --
> IMPORTANT:
> NEVER share your IndiaMART OTP/ Password with anyone.
Re: Solr standalone timeouts after upgrading to SOLR 7
Posted by Paras Lehana <pa...@indiamart.com>.
Hi concerned (please use signature),
The timeouts could be because of the "stop the world" kinda behaviour of
longer GC pause. When we shifted our Auto-Suggest from Redis to Solr, I
faced the similar GC pause issue while stress testing. This article
<https://cwiki.apache.org/confluence/display/solr/ShawnHeisey#ShawnHeisey-GCTuningforSolr>
by Shawn Heisey helped me a lot to experiment with different setups - I
tried combinations of different collectors, heap and other configs.
I think your -Xms and -Xmx values have too much of the relative difference.
Your heap could be getting filled up to the max 10G during peak times and
then the longer GC pauses would have made pending queries go timeout. By
seeing your current memory usage, I recommend you to decrease the Xmx. Try
with same values first or maybe 4,6G. If you think 10G is okay, then
consider increasing your Xms to maybe 6-8G? Since this is a sort of
experiment you have to perform and I can only recommend things as per my
experience, I strongly recommend you to read Shawn's article.
On Thu, 3 Oct 2019 at 02:44, Solr User <pu...@gmail.com> wrote:
> Hello all,
>
> We recently moved to SOLR 7 from SOLR 6 about 2 weeks ago. Once each week
> (including today) we experienced query timeout issues with corresponding GC
> events. There was a spike in CPU up to 66% which is not something we
> previously saw w/ Solr 6. From the SOLR logs it looks like something inside
> the JVM has happend, SOLR is reporting closed connections from Jetty. Our
> data size is relatively small but we do run 5 cores within the one Jetty
> instance. There index sizes are anywhere between 200Mb to 2GB
>
> Our memory consumption is relatively low:
>
> "free":"296.1 MB",
>
> "total":"569.6 MB",
>
> "max":"9.6 GB",
>
> "used":"273.5 MB (%2.8)",
>
>
>
> We had a spike in traffic about 5 minutes prior to some longer GC events
> (similar situation last week).
>
> Any help would be appreciated. Below is my current system info along with a
> GC log snippet and the corresponding SOLR log error.
>
> *System info:*
> AMZ2 linux
> 8 core 32 GB Mem
> *Java:* 1.8.0_222-ea 25.222-b03
> *Solr: *solr-spec-version":"7.7.2"
> *Start options: *
> "-Xms512m",
> "-Xmx10g",
> "-XX:NewRatio=3",
> "-XX:SurvivorRatio=4",
> "-XX:TargetSurvivorRatio=90",
> "-XX:MaxTenuringThreshold=8",
> "-XX:+UseConcMarkSweepGC",
> "-XX:ConcGCThreads=4",
> "-XX:ParallelGCThreads=4",
> "-XX:+CMSScavengeBeforeRemark",
> "-XX:PretenureSizeThreshold=64m",
> "-XX:+UseCMSInitiatingOccupancyOnly",
> "-XX:CMSInitiatingOccupancyFraction=50",
> "-XX:CMSMaxAbortablePrecleanTime=6000",
> "-XX:+CMSParallelRemarkEnabled",
> "-XX:+ParallelRefProcEnabled",
> "-XX:-OmitStackTraceInFastThrow",
> "-verbose:gc",
> "-XX:+PrintHeapAtGC",
> "-XX:+PrintGCDetails",
> "-XX:+PrintGCDateStamps",
> "-XX:+PrintGCTimeStamps",
> "-XX:+PrintTenuringDistribution",
> "-XX:+PrintGCApplicationStoppedTime",
> "-XX:+UseGCLogFileRotation",
> "-XX:NumberOfGCLogFiles=9",
> "-XX:GCLogFileSize=20M",
> "-Xss256k",
> "-Dsolr.log.muteconsole"
>
> Here is an example of from the GC log:
>
> 2019-10-02T16:03:15.888+0000: 265318.624: [Full GC (Allocation
> Failure) 2019-10-02T16:03:15.888+0000: 265318.624:
> [CMS2019-10-02T16:03:16.134+0000: 26
> 5318.870: [CMS-concurrent-mark: 1.773/1.783 secs] [Times: user=13.14
> sys=0.00, real=1.78 secs]
> (concurrent mode failure): 7864319K->7864319K(7864320K), 9.5890129
> secs] 10048895K->8863021K(10048896K), [Metaspace:
> 53159K->53159K(1097728K)], 9.5892061 secs] [Times: user=10.31
> sys=0.00, real=9.59 secs]
> Heap after GC invocations=296656 (full 546):
> par new generation total 2184576K, used 998701K
> [0x0000000540000000, 0x00000005e0000000, 0x00000005e0000000)
> eden space 1747712K, 57% used [0x0000000540000000,
> 0x000000057cf4b4f0, 0x00000005aaac0000)
> from space 436864K, 0% used [0x00000005aaac0000,
> 0x00000005aaac0000, 0x00000005c5560000)
> to space 436864K, 0% used [0x00000005c5560000,
> 0x00000005c5560000, 0x00000005e0000000)
> concurrent mark-sweep generation total 7864320K, used 7864319K
> [0x00000005e0000000, 0x00000007c0000000, 0x00000007c0000000)
> Metaspace used 53159K, capacity 54766K, committed 55148K,
> reserved 1097728K
> class space used 5589K, capacity 5950K, committed 6000K, reserved
> 1048576K
> }
> 2019-10-02T16:03:25.477+0000: 265328.214: Total time for which
> application threads were stopped: 9.5906157 seconds, Stopping threads
> took: 0.0001274 seconds
> *With the following from the SOLR log: *
>
> [ x:core] o.a.s.s.HttpSolrCall Unable to write response, client
> closed connection or we are s
>
> hutting down
>
> org.eclipse.jetty.io.EofException: Closed
>
> at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:665)
> ~[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c
>
> 1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at
> org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fef
>
> c589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at java.io.OutputStream.write(OutputStream.java:116)
> ~[?:1.8.0_222-ea]
>
> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> ~[?:1.8.0_222-ea]
>
> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> ~[?:1.8.0_222-ea]
>
> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> ~[?:1.8.0_222-ea]
>
> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> ~[?:1.8.0_222-ea]
>
> at
> org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
> ~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94
> - j
>
> anhoy - 2019-05-28 23:37:52]
>
> at
> org.apache.solr.common.util.FastWriter.flushBuffer(FastWriter.java:154)
> ~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
>
> 94 - janhoy - 2019-05-28 23:37:52]
>
> at
> org.apache.solr.response.TextResponseWriter.close(TextResponseWriter.java:82)
> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
>
> a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at
> org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:68)
> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
>
> a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at
> org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
> ~[solr-core-7.7.2.jar:7.7.2 d4c30fc285
>
> 6154f2c1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at
> org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
>
> 94 - janhoy - 2019-05-28 23:37:48]
>
> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94 -
> janh
>
> oy - 2019-05-28 23:37:48]
>
> at
> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
>
> 70a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at
> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
> [solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
>
> 70a415b94 - janhoy - 2019-05-28 23:37:48]
>
> at
> org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
> [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v2018111
>
> 4]
>
> at
> org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
> [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
> [jetty-security-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
> [jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
> at
> org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220)
> [jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
>
>
>
> *Eventually we are receiving an actual ERROR *
>
>
>
> o.a.s.s.HttpSolrCall null:java.io.IOException:
> java.util.concurrent.TimeoutExceptio
> n: Idle timeout expired: 122014/120000 ms
> at
> org.eclipse.jetty.util.SharedBlockingCallback$Blocker.block(SharedBlockingCallback.java:235)
> at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:217)
> at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:628)
> at
> org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
> at
> org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
> at java.io.OutputStream.write(OutputStream.java:116)
> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> at
> org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
> at org.apache.solr.common.util.FastWriter.write(FastWriter.java:54)
> at
> org.apache.solr.response.JSONWriter._writeChar(JSONWriter.java:173)
> at
> org.apache.solr.common.util.JsonTextWriter.writeStr(JsonTextWriter.java:86)
> at
> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:52)
> at
> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> at
> org.apache.solr.common.util.JsonTextWriter.writeJsonIter(JsonTextWriter.java:194)
> at
> org.apache.solr.common.util.JsonTextWriter.writeArray(JsonTextWriter.java:270)
> at
> org.apache.solr.common.util.TextWriter.writeArray(TextWriter.java:154)
> at
> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:80)
> at
> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> at
> org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
> at
> org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
> at
> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
> at
> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> at
> org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
> at
> org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
> at
> org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
> at
> org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
> at
> org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
> at
> org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
> at
> org.apache.solr.response.JSONWriter.writeResponse(JSONWriter.java:73)
> at
> org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:66)
> at
> org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
> at
> org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
> at
> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
> at
> org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
> at
> org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
> at
> org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
> at
> org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
> at
> org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
> at
> org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
> at
> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
> at
> org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
> at
> org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
>
--
--
Regards,
*Paras Lehana* [65871]
Software Programmer, Auto-Suggest,
IndiaMART Intermesh Ltd.
8th Floor, Tower A, Advant-Navis Business Park, Sector 142,
Noida, UP, IN - 201303
Mob.: +91-9560911996
Work: 01203916600 | Extn: *8173*
--
IMPORTANT:
NEVER share your IndiaMART OTP/ Password with anyone.
Fwd: Solr standalone timeouts after upgrading to SOLR 7
Posted by Solr User <pu...@gmail.com>.
Hello all,
We recently moved to SOLR 7 from SOLR 6 about 2 weeks ago. Once each week
(including today) we experienced query timeout issues with corresponding GC
events. There was a spike in CPU up to 66% which is not something we
previously saw w/ Solr 6. From the SOLR logs it looks like something inside
the JVM has happend, SOLR is reporting closed connections from Jetty. Our
data size is relatively small but we do run 5 cores within the one Jetty
instance. There index sizes are anywhere between 200Mb to 2GB
Our memory consumption is relatively low:
"free":"296.1 MB",
"total":"569.6 MB",
"max":"9.6 GB",
"used":"273.5 MB (%2.8)",
We had a spike in traffic about 5 minutes prior to some longer GC events
(similar situation last week).
Any help would be appreciated. Below is my current system info along with a
GC log snippet and the corresponding SOLR log error.
*System info:*
AMZ2 linux
8 core 32 GB Mem
*Java:* 1.8.0_222-ea 25.222-b03
*Solr: *solr-spec-version":"7.7.2"
*Start options: *
"-Xms512m",
"-Xmx10g",
"-XX:NewRatio=3",
"-XX:SurvivorRatio=4",
"-XX:TargetSurvivorRatio=90",
"-XX:MaxTenuringThreshold=8",
"-XX:+UseConcMarkSweepGC",
"-XX:ConcGCThreads=4",
"-XX:ParallelGCThreads=4",
"-XX:+CMSScavengeBeforeRemark",
"-XX:PretenureSizeThreshold=64m",
"-XX:+UseCMSInitiatingOccupancyOnly",
"-XX:CMSInitiatingOccupancyFraction=50",
"-XX:CMSMaxAbortablePrecleanTime=6000",
"-XX:+CMSParallelRemarkEnabled",
"-XX:+ParallelRefProcEnabled",
"-XX:-OmitStackTraceInFastThrow",
"-verbose:gc",
"-XX:+PrintHeapAtGC",
"-XX:+PrintGCDetails",
"-XX:+PrintGCDateStamps",
"-XX:+PrintGCTimeStamps",
"-XX:+PrintTenuringDistribution",
"-XX:+PrintGCApplicationStoppedTime",
"-XX:+UseGCLogFileRotation",
"-XX:NumberOfGCLogFiles=9",
"-XX:GCLogFileSize=20M",
"-Xss256k",
"-Dsolr.log.muteconsole"
Here is an example of from the GC log:
2019-10-02T16:03:15.888+0000: 265318.624: [Full GC (Allocation
Failure) 2019-10-02T16:03:15.888+0000: 265318.624:
[CMS2019-10-02T16:03:16.134+0000: 26
5318.870: [CMS-concurrent-mark: 1.773/1.783 secs] [Times: user=13.14
sys=0.00, real=1.78 secs]
(concurrent mode failure): 7864319K->7864319K(7864320K), 9.5890129
secs] 10048895K->8863021K(10048896K), [Metaspace:
53159K->53159K(1097728K)], 9.5892061 secs] [Times: user=10.31
sys=0.00, real=9.59 secs]
Heap after GC invocations=296656 (full 546):
par new generation total 2184576K, used 998701K
[0x0000000540000000, 0x00000005e0000000, 0x00000005e0000000)
eden space 1747712K, 57% used [0x0000000540000000,
0x000000057cf4b4f0, 0x00000005aaac0000)
from space 436864K, 0% used [0x00000005aaac0000,
0x00000005aaac0000, 0x00000005c5560000)
to space 436864K, 0% used [0x00000005c5560000,
0x00000005c5560000, 0x00000005e0000000)
concurrent mark-sweep generation total 7864320K, used 7864319K
[0x00000005e0000000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace used 53159K, capacity 54766K, committed 55148K,
reserved 1097728K
class space used 5589K, capacity 5950K, committed 6000K, reserved 1048576K
}
2019-10-02T16:03:25.477+0000: 265328.214: Total time for which
application threads were stopped: 9.5906157 seconds, Stopping threads
took: 0.0001274 seconds
*With the following from the SOLR log: *
[ x:core] o.a.s.s.HttpSolrCall Unable to write response, client
closed connection or we are s
hutting down
org.eclipse.jetty.io.EofException: Closed
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:665)
~[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c
1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fef
c589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
at java.io.OutputStream.write(OutputStream.java:116) ~[?:1.8.0_222-ea]
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
~[?:1.8.0_222-ea]
at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
~[?:1.8.0_222-ea]
at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
~[?:1.8.0_222-ea]
at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
~[?:1.8.0_222-ea]
at org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94
- j
anhoy - 2019-05-28 23:37:52]
at org.apache.solr.common.util.FastWriter.flushBuffer(FastWriter.java:154)
~[solr-solrj-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
94 - janhoy - 2019-05-28 23:37:52]
at org.apache.solr.response.TextResponseWriter.close(TextResponseWriter.java:82)
~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
a415b94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:68)
~[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070
a415b94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
~[solr-core-7.7.2.jar:7.7.2 d4c30fc285
6154f2c1fefc589eb7cd070a415b94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b
94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd070a415b94 -
janh
oy - 2019-05-28 23:37:48]
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
70a415b94 - janhoy - 2019-05-28 23:37:48]
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
[solr-core-7.7.2.jar:7.7.2 d4c30fc2856154f2c1fefc589eb7cd0
70a415b94 - janhoy - 2019-05-28 23:37:48]
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v2018111
4]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
[jetty-security-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220)
[jetty-server-9.4.14.v20181114.jar:9.4.14.v20181114]
*Eventually we are receiving an actual ERROR *
o.a.s.s.HttpSolrCall null:java.io.IOException:
java.util.concurrent.TimeoutExceptio
n: Idle timeout expired: 122014/120000 ms
at org.eclipse.jetty.util.SharedBlockingCallback$Blocker.block(SharedBlockingCallback.java:235)
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:217)
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:628)
at org.apache.solr.servlet.ServletOutputStreamWrapper.write(ServletOutputStreamWrapper.java:126)
at org.apache.solr.response.QueryResponseWriterUtil$1.write(QueryResponseWriterUtil.java:54)
at java.io.OutputStream.write(OutputStream.java:116)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
at org.apache.solr.common.util.FastWriter.flush(FastWriter.java:140)
at org.apache.solr.common.util.FastWriter.write(FastWriter.java:54)
at org.apache.solr.response.JSONWriter._writeChar(JSONWriter.java:173)
at org.apache.solr.common.util.JsonTextWriter.writeStr(JsonTextWriter.java:86)
at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:52)
at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
at org.apache.solr.common.util.JsonTextWriter.writeJsonIter(JsonTextWriter.java:194)
at org.apache.solr.common.util.JsonTextWriter.writeArray(JsonTextWriter.java:270)
at org.apache.solr.common.util.TextWriter.writeArray(TextWriter.java:154)
at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:80)
at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
at org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
at org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
at org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
at org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
at org.apache.solr.common.util.TextWriter.writeVal(TextWriter.java:63)
at org.apache.solr.response.TextResponseWriter.writeVal(TextResponseWriter.java:152)
at org.apache.solr.common.util.JsonTextWriter.writeNamedListAsMapWithDups(JsonTextWriter.java:386)
at org.apache.solr.common.util.JsonTextWriter.writeNamedList(JsonTextWriter.java:292)
at org.apache.solr.response.JSONWriter.writeResponse(JSONWriter.java:73)
at org.apache.solr.response.JSONResponseWriter.write(JSONResponseWriter.java:66)
at org.apache.solr.response.QueryResponseWriterUtil.writeQueryResponse(QueryResponseWriterUtil.java:65)
at org.apache.solr.servlet.HttpSolrCall.writeResponse(HttpSolrCall.java:789)
at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:525)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)