DSpace 5.10 SOLR error

169 views
Skip to first unread message

Alex Fletcher

unread,
Jan 5, 2021, 6:40:57 AM1/5/21
to DSpace Technical Support
Recently, we've started getting unusual SOLR errors on our DSpace 5.10 XMLUI installation.

It's reporting a Socket read failed. I did some googling and either my google-fu failed me... or there isn't much on this front at all.

Has anyone encountered this or have suggestions as to how to resolve this?

In the DSpace log, this reports as the dreaded "Expected mime type application/octet-stream but got text/html" error such as:

org.dspace.discovery.SearchServiceException: Expected mime type application/octet-stream but got text/html. <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>500 Internal Server Error</title>
</head><body>
<h1>Internal Server Error</h1>
<p>The server encountered an internal error or
misconfiguration and was unable to complete
your request.</p>
<p>Please contact the server administrator at
 root@localhost to inform them of the time this error occurred,
 and the actions you performed just before this error.</p>
<p>More information about this error may be available
in the server error log.</p>
</body></html>

    at org.dspace.discovery.SolrServiceImpl.search(SolrServiceImpl.java:1618)
    at org.dspace.discovery.SolrServiceImpl.search(SolrServiceImpl.java:1600)
    at org.dspace.discovery.SolrServiceImpl.search(SolrServiceImpl.java:1583)
    at org.dspace.app.xmlui.aspect.discovery.SidebarFacetsTransformer.getQueryArgs(SidebarFacetsTransformer.java:388)
    at org.dspace.app.xmlui.aspect.discovery.SidebarFacetsTransformer.performSearch(SidebarFacetsTransformer.java:156)
    at org.dspace.app.xmlui.aspect.discovery.SidebarFacetsTransformer.getValidity(SidebarFacetsTransformer.java:119)



The full SOLR error log is as follows.

2021-01-05 05:48:38,821 ERROR org.apache.solr.core.SolrCore @ org.apache.solr.common.SolrException: Socket read failed
    at org.apache.solr.handler.loader.XMLLoader.load(XMLLoader.java:176)
    at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:99)
    at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:74)
    at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
    at org.apache.solr.core.SolrCore.execute(SolrCore.java:1967)
    at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:777)
    at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:418)
    at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:207)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.dspace.solr.filters.LocalHostRestrictionFilter.doFilter(LocalHostRestrictionFilter.java:50)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:218)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:506)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:962)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
    at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:190)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)
Caused by: com.ctc.wstx.exc.WstxIOException: Socket read failed
    at com.ctc.wstx.stax.WstxInputFactory.doCreateSR(WstxInputFactory.java:548)
    at com.ctc.wstx.stax.WstxInputFactory.createSR(WstxInputFactory.java:604)
    at com.ctc.wstx.stax.WstxInputFactory.createSR(WstxInputFactory.java:629)
    at com.ctc.wstx.stax.WstxInputFactory.createXMLStreamReader(WstxInputFactory.java:324)
    at org.apache.solr.handler.loader.XMLLoader.load(XMLLoader.java:172)
    ... 27 more
Caused by: java.io.IOException: Socket read failed
    at org.apache.coyote.ajp.AjpProcessor.read(AjpProcessor.java:316)
    at org.apache.coyote.ajp.AjpProcessor.readMessage(AjpProcessor.java:367)
    at org.apache.coyote.ajp.AjpProcessor.receive(AjpProcessor.java:334)
    at org.apache.coyote.ajp.AbstractAjpProcessor.refillReadBuffer(AbstractAjpProcessor.java:735)
    at org.apache.coyote.ajp.AbstractAjpProcessor$SocketInputBuffer.doRead(AbstractAjpProcessor.java:1220)
    at org.apache.coyote.Request.doRead(Request.java:438)
    at org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:290)
    at org.apache.tomcat.util.buf.ByteChunk.substract(ByteChunk.java:449)
    at org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:315)
    at org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:167)
    at com.ctc.wstx.io.UTF8Reader.loadMore(UTF8Reader.java:365)
    at com.ctc.wstx.io.UTF8Reader.read(UTF8Reader.java:110)
    at com.ctc.wstx.io.ReaderBootstrapper.initialLoad(ReaderBootstrapper.java:245)
    at com.ctc.wstx.io.ReaderBootstrapper.bootstrapInput(ReaderBootstrapper.java:132)
    at com.ctc.wstx.stax.WstxInputFactory.doCreateSR(WstxInputFactory.java:543)
    ... 31 more

2021-01-05 05:48:38,822 INFO  org.apache.solr.core.SolrCore @ [statistics] webapp=/solr path=/update params={wt=javabin&version=2} status=400 QTime=2

Alex Fletcher

unread,
Jan 7, 2021, 11:55:02 AM1/7/21
to DSpace Technical Support
We're now finding that SOLR is going down on a regular basis and have no idea why.

This is starting to become a serious problem for us, as over the last 4-5 days, it's stayed up anywhere from 30m to 4+h.

We've see seen the error in the email below, plus other errors including:

2021-01-06 12:06:07,712 ERROR org.apache.solr.core.CoreContainer @ Error creating core [statistics-2014]: Error opening new searcher

2021-01-06 12:06:07,714 ERROR org.apache.solr.core.SolrCore @ org.apache.solr.common.SolrException: Error CREATEing SolrCore 'statistics-2014': Unable to create core [statistics-2014] Caused by: Lock obtain timed out: NativeFSLock@/data/solr/statistics-2014/data/index/write.lock

2021-01-06 12:06:12,514 ERROR org.apache.solr.update.SolrIndexWriter @ SolrIndexWriter was not closed prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!!

2021-01-06 12:06:12,526 ERROR org.apache.solr.update.SolrIndexWriter @ Error closing IndexWriter

  • no error at all, SOLR just stopping to respond such as this:
2021-01-06 11:34:32,618 INFO org.apache.solr.update.UpdateHandler @ start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
2021-01-06 11:34:33,170 INFO org.apache.solr.core.SolrCore @ SolrDeletionPolicy.onCommit: commits: num=2
commit{dir=NRTCachingDirectory(MMapDirectory@/data/solr/statistics/data/index lockFactory=NativeFSLockFactory@/data/solr/statistics/data/index; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2z3o,generation=138804}
commit{dir=NRTCachingDirectory(MMapDirectory@/data/solr/statistics/data/index lockFactory=NativeFSLockFactory@/data/solr/statistics/data/index; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2z3p,generation=138805}
2021-01-06 11:34:33,170 INFO org.apache.solr.core.SolrCore @ newest commit generation = 138805
2021-01-06 11:34:33,173 INFO org.apache.solr.search.SolrIndexSearcher @ Opening Searcher@632863a0[statistics] main
2021-01-06 11:34:33,173 INFO org.apache.solr.update.UpdateHandler @ end_commit_flush
2021-01-06 11:34:33,173 INFO org.apache.solr.core.SolrCore @ QuerySenderListener sending requests to Searcher@632863a0[statistics] main{StandardDirectoryReader(segments_2z3m:666863:nrt _730g(4.10.2):C12580009/77:delGen=1 _736b(4.10.2):C22600 _736c(4.10.2):C91 _736d(4.10.2):C1 _736e(4.10.2):C1 _736f(4.10.2):C1 _736g(4.10.2):C424 _736h(4.10.2):C1 _736i(4.10.2):C131 _736k(4.10.2):C108 _736j(4.10.2):C92)}
2021-01-06 11:34:33,173 INFO org.apache.solr.core.SolrCore @ QuerySenderListener done.
2021-01-06 11:34:33,175 INFO org.apache.solr.core.SolrCore @ [statistics] Registered new searcher Searcher@632863a0[statistics] main{StandardDirectoryReader(segments_2z3m:666863:nrt _730g(4.10.2):C12580009/77:delGen=1 _736b(4.10.2):C22600 _736c(4.10.2):C91 _736d(4.10.2):C1 _736e(4.10.2):C1 _736f(4.10.2):C1 _736g(4.10.2):C424 _736h(4.10.2):C1 _736i(4.10.2):C131 _736k(4.10.2):C108 _736j(4.10.2):C92)}

  • and now a brand new one like this:
2021-01-07 11:34:51,211 ERROR org.apache.solr.core.SolrCore @ org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Expected mime type application/octet-stream but got text/html. <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">

<html><head>
<title>500 Internal Server Error</title>
</head><body>
<h1>Internal Server Error</h1>
<p>The server encountered an internal error or
misconfiguration and was unable to complete
your request.</p>
<p>Please contact the server administrator at
 root@localhost to inform them of the time this error occurred,
 and the actions you performed just before this error.</p>
<p>More information about this error may be available
in the server error log.</p>
</body></html>
    at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:512)
    at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
    at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
    at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:157)
    at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:119)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:473)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)
    at java.lang.Thread.run(Thread.java:748)
2021-01-07 11:34:51,211 INFO  org.apache.solr.core.SolrCore @ [statistics] webapp=/solr path=/select params={facet=true&shards=localhost/solr/statistics-2014,localhost/solr/statistics-2015,localhost/solr/statistics-2013,localhost/solr/statistics-2016,localhost/solr/statistics-2017,localhost/solr/statistics-2018,localhost/solr/statistics-2019,localhost/solr/statistics-2020,localhost/solr/statistics&facet.mincount=1&q=type:+2+AND++id:31406&facet.limit=10&facet.field=id&wt=javabin&fq=-isBot:true&fq=-(bundleName:[*+TO+*]-bundleName:ORIGINAL)&fq=(time:[2020-07-01T00:00:00.000Z+TO+2021-02-01T00:00:00.000Z])+AND+-(statistics_type:[*+TO+*]+AND+-statistics_type:view)&version=2&rows=0} status=500 QTime=600912
2021-01-07 11:34:51,211 ERROR org.apache.solr.servlet.SolrDispatchFilter @ null:org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Expected mime type application/octet-stream but got text/html. <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">

<html><head>
<title>500 Internal Server Error</title>
</head><body>
<h1>Internal Server Error</h1>
<p>The server encountered an internal error or
misconfiguration and was unable to complete
your request.</p>
<p>Please contact the server administrator at
 root@localhost to inform them of the time this error occurred,
 and the actions you performed just before this error.</p>
<p>More information about this error may be available
in the server error log.</p>
</body></html>
    at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:512)
    at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
    at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
    at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:157)
    at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:119)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:473)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)
    at java.lang.Thread.run(Thread.java:748)

Paul Kobasa

unread,
Jan 8, 2021, 11:47:27 AM1/8/21
to DSpace Technical Support
Purely guessing, I'd suspect Solr is failing over a character it doesn't have exceptions for. Are there any foreign language characters in your records?
Of course, nothing beats properly inspecting the logs to know for sure, but Dspace is "Someone elses' programming" so it's difficult to know where to look.
Good luck.

Alex Fletcher

unread,
Jan 25, 2021, 9:38:39 AM1/25/21
to DSpace Technical Support
Update:

On advice from UWaterloo, we disabled the Google Analytics bean in the XMLUI and lo and behold... no SOLR errors for a week now.

That was done in this file:

dspace-xmlui/src/main/webapp/WEB-INF/spring/applicationContext.xml

I simply commented out this particular bean:  org.dspace.google.GoogleRecorderEventListener

Alex
Reply all
Reply to author
Forward
0 new messages