Solr standalone timeouts after upgrading to SOLR 7

classic Classic list List threaded Threaded
11 messages Options
Reply | Threaded
Open this post in threaded view
|

Solr standalone timeouts after upgrading to SOLR 7

ndra
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)
Reply | Threaded
Open this post in threaded view
|

Fwd: Solr standalone timeouts after upgrading to SOLR 7

ndra
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)
Reply | Threaded
Open this post in threaded view
|

Re: Solr standalone timeouts after upgrading to SOLR 7

Paras Lehana
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 <[hidden email]> 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.
Reply | Threaded
Open this post in threaded view
|

Re: Solr standalone timeouts after upgrading to SOLR 7

Walter Underwood
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
[hidden email]
http://observer.wunderwood.org/  (my blog)

> On Oct 2, 2019, at 11:07 PM, Paras Lehana <[hidden email]> 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 <[hidden email]> 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.

Reply | Threaded
Open this post in threaded view
|

Re: Solr standalone timeouts after upgrading to SOLR 7

Jörn Franke
In reply to this post by ndra
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 <[hidden email]>:
>
> 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)
Reply | Threaded
Open this post in threaded view
|

Re: Solr standalone timeouts after upgrading to SOLR 7

ndra
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 <[hidden email]> 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 <[hidden email]>:
> >
> > 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)
>
Reply | Threaded
Open this post in threaded view
|

Re: Solr standalone timeouts after upgrading to SOLR 7

Walter Underwood
> On Oct 3, 2019, at 9:31 AM, ndra <[hidden email]> 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
[hidden email]
http://observer.wunderwood.org/  (my blog)

Reply | Threaded
Open this post in threaded view
|

Re: Solr standalone timeouts after upgrading to SOLR 7

ndra
> 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 <[hidden email]>
wrote:

> > On Oct 3, 2019, at 9:31 AM, ndra <[hidden email]> 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
> [hidden email]
> http://observer.wunderwood.org/  (my blog)
>
>
Reply | Threaded
Open this post in threaded view
|

Re: Solr standalone timeouts after upgrading to SOLR 7

Walter Underwood
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
[hidden email]
http://observer.wunderwood.org/  (my blog)

> On Oct 3, 2019, at 10:11 AM, ndra <[hidden email]> 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 <[hidden email]>
> wrote:
>
>>> On Oct 3, 2019, at 9:31 AM, ndra <[hidden email]> 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
>> [hidden email]
>> http://observer.wunderwood.org/  (my blog)
>>
>>

Reply | Threaded
Open this post in threaded view
|

Re: Solr standalone timeouts after upgrading to SOLR 7

ndra
> 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 <[hidden email]>
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
> [hidden email]
> http://observer.wunderwood.org/  (my blog)
>
> > On Oct 3, 2019, at 10:11 AM, ndra <[hidden email]> 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 <[hidden email]>
> > wrote:
> >
> >>> On Oct 3, 2019, at 9:31 AM, ndra <[hidden email]> 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
> >> [hidden email]
> >> http://observer.wunderwood.org/  (my blog)
> >>
> >>
>
>
Reply | Threaded
Open this post in threaded view
|

Re: Solr standalone timeouts after upgrading to SOLR 7

Walter Underwood
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
[hidden email]
http://observer.wunderwood.org/  (my blog)

> On Oct 3, 2019, at 11:38 AM, ndra <[hidden email]> 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 <[hidden email]>
> 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
>> [hidden email]
>> http://observer.wunderwood.org/  (my blog)
>>
>>> On Oct 3, 2019, at 10:11 AM, ndra <[hidden email]> 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 <[hidden email]>
>>> wrote:
>>>
>>>>> On Oct 3, 2019, at 9:31 AM, ndra <[hidden email]> 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
>>>> [hidden email]
>>>> http://observer.wunderwood.org/  (my blog)
>>>>
>>>>
>>
>>