Re: Getting SocketTimeoutException after a very short amount of time

2015-10-13 Thread Shawn Heisey
On 9/4/2015 3:18 PM, Shawn Heisey wrote:
> On 9/4/2015 12:36 PM, Oleg Kalnichevski wrote:
>> There is nothing wrong with your code. Feel free to run it outside
>> Solr without any extra dependencies to make sure it works as intended.
>> I _strongly_ suspect there is an older version of HttpClient /
>> HttpCore on your classpath.
> 
> I'm willing to believe almost anything the evidence supports at this
> point, but I haven't seen anything to support that theory.

Closing out this discussion:

The problem turned out, unsurprisingly, to be a bug in my own code.  As
much as I hate to learn that I've done something wrong, I'm glad to see
that the problem is not in HttpClient, and therefore cannot affect other
people.

Part of my code creates a few threads to do indexing on multiple Solr
shards in parallel, then uses join() to wait for those threads.  The
code that uses join() was incorrect, and not waiting long enough.  The
main loop of my program continued on its merry way, unaware of the
problem, while one of those threads was running in the background,
eventually reaching socket timeout and sending an alarm email.

Now that I know where the problem is, I can come up with a solution.

Thanks,
Shawn


-
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org



Re: Getting SocketTimeoutException after a very short amount of time

2015-09-04 Thread Shawn Heisey
On 9/4/2015 12:36 PM, Oleg Kalnichevski wrote:
> There is nothing wrong with your code. Feel free to run it outside
> Solr without any extra dependencies to make sure it works as intended.
> I _strongly_ suspect there is an older version of HttpClient /
> HttpCore on your classpath.

I'm willing to believe almost anything the evidence supports at this
point, but I haven't seen anything to support that theory.

I will try to come up with a test program using HttpClient only that
calls one of our optimize URLs to see whether I get the same timeout. 
If it works as expected, I will take this problem to the Solr list.

The classpath calculation is simple.  Here's the "env.sh" that my start
script sources to set the classpath:

root@bigindy5:/opt/sparkbuild# cat env.sh
#!/bin/sh


for i in \
 -Xms4M \
 -Xmx1024M \
 -XX:+UseG1GC \
 -XX:+ParallelRefProcEnabled \
 -XX:G1HeapRegionSize=8m \
 -XX:MaxGCPauseMillis=200 \
 -XX:+UseLargePages \
 -XX:+AggressiveOpts \
# -Dcom.sun.management.jmxremote \
# -Dcom.sun.management.jmxremote.port=3001 \
# -Dcom.sun.management.jmxremote.ssl=false \
# -Dcom.sun.management.jmxremote.authenticate=false \

do
  OPTS="${OPTS} $i"
done
export OPTS

CLASSPATH="bin:resources"
for i in lib/*.jar
do
  CLASSPATH=${CLASSPATH}:${i}
done
export CLASSPATH

At the following URL is the entire "lsof" output for the running copy of
my program.  I only see one location for the HC jars.  They do show up
twice, but it's the same location each time.  The only change I made in
this output was to redact our domain name from the TCP entries.  Solr is
listening on 8982, which explains the connections to that port in
CLOSE_WAIT.

http://apaste.info/38Z

Separate from my apparent inability to get a socket timeout set, but
possibly related, I'm somewhat mystified by the fact that I get a socket
timeout exception after 30 seconds when typical Java and Linux defaults
are no socket timeout and the DEBUG entries from httpclient are saying
that the connection can be kept alive indefinitely.  I haven't changed
any timeout settings in the Ubuntu OS, so unless Ubuntu sets a default
socket timeout, I don't know where this is coming from.  The same thing
happens on the production servers running CentOS 6, and I have not set
any OS-level timeouts there either.

Thanks,
Shawn


-
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org



Re: Getting SocketTimeoutException after a very short amount of time

2015-09-04 Thread Oleg Kalnichevski
On Fri, 2015-09-04 at 11:39 -0600, Shawn Heisey wrote:
> On 9/4/2015 7:53 AM, Oleg Kalnichevski wrote:
> > I added socket timeout logging to the 4.5.x branch and trunk
> >
> > http://svn.apache.org/r1701258
> >
> > I clearly those values logged when executing HttpClient examples. 
> 
> I abandoned my custom httpcore jar built from the 4.4.1 tag with the one
> line addition, pulled down the 4.5.x branch of httpclient, and built
> it.  I replaced httpclient-4.5.jar with httpclient-4.5.1-SNAPSHOT.jar,
> and verified that the commit you made was included in the source code
> that I checked out.
> 
> Because I am using slf4j which ultimately logs to log4j1, I do have the
> jcl-over-slf4j jar in my classpath, which should capture the commons
> logging that httpclient uses.  I put the following in my
> log4j.properties file:
> 
> log4j.logger.org.apache.http=DEBUG, file
> 
> During program startup (when I build the HttpClient objects), I do not
> see any logs from httpclient at all, but when it actually connects to
> Solr, I do see DEBUG logs.  Those debug logs do not include the "set
> socket timeout" log entry that you added.  One of the logs says this:
> 
> DEBUG - 2015-09-04 11:38:01.551;   262; 3; Connection [id: 1][route:
> {}->http://bigindy5.REDACTED.com:8982] can be kept alive indefinitely
> 
> I must be creating the client objects incorrectlyfor the "set socket
> timeout" message to never be logged.  So you don't have to go looking
> back through the thread, here is the code I'm using:
> 

There is nothing wrong with your code. Feel free to run it outside Solr
without any extra dependencies to make sure it works as intended.

I _strongly_ suspect there is an older version of HttpClient / HttpCore
on your classpath.

Oleg 


> /* Trying out a new way of creating clients */
> RequestConfig requestConfig = RequestConfig.custom()
>   .setSocketTimeout(90)
>   .setConnectTimeout(15000)
>   .build();
> httpClient = HttpClients.custom()
>   .setDefaultRequestConfig(requestConfig)
>   .setMaxConnPerRoute(300)
>   .setMaxConnTotal(5000)
>   .build();
> RequestConfig optimizeRequestConfig = RequestConfig.custom()
>   .setSocketTimeout(720)
>   .setConnectTimeout(15000)
>   .build();
> optimizeHttpClient = HttpClients.custom()
>   .setDefaultRequestConfig(optimizeRequestConfig)
>   .build();
> 
> Thanks,
> Shawn
> 
> 
> -
> To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
> For additional commands, e-mail: httpclient-users-h...@hc.apache.org
> 



-
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org



Re: Getting SocketTimeoutException after a very short amount of time

2015-09-04 Thread Stefan Magnus Landrø
Could you use SocketConfig?

Sendt fra min iPhone

> Den 4. sep. 2015 kl. 19.52 skrev Shawn Heisey :
> 
>> On 9/4/2015 11:39 AM, Shawn Heisey wrote:
>> I must be creating the client objects incorrectly for the "set socket
>> timeout" message to never be logged.
> 
> I checked the ClientConfiguration.java example, and found that it sets
> the socket timeout when it is building the HttpGet object, not the
> HttpClient object.
> 
> In my program, I have absolutely no control over the GET/POST requests,
> that is deep in the bowels of SolrJ.
> 
> As a committer on Lucene/Solr, I *do* have the ability to change SolrJ,
> and perhaps these parameters should be configured in our SolrClient
> object and actually set when the request objects are created, but I
> think it should be possible to set them on the HttpClient object and
> have all requests utilize those defaults.
> 
> Thanks,
> Shawn
> 
> 
> -
> To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
> For additional commands, e-mail: httpclient-users-h...@hc.apache.org
> 

-
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org



Re: Getting SocketTimeoutException after a very short amount of time

2015-09-04 Thread Shawn Heisey
On 9/4/2015 11:39 AM, Shawn Heisey wrote:
> I must be creating the client objects incorrectly for the "set socket
> timeout" message to never be logged.

I checked the ClientConfiguration.java example, and found that it sets
the socket timeout when it is building the HttpGet object, not the
HttpClient object.

In my program, I have absolutely no control over the GET/POST requests,
that is deep in the bowels of SolrJ.

As a committer on Lucene/Solr, I *do* have the ability to change SolrJ,
and perhaps these parameters should be configured in our SolrClient
object and actually set when the request objects are created, but I
think it should be possible to set them on the HttpClient object and
have all requests utilize those defaults.

Thanks,
Shawn


-
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org



Re: Getting SocketTimeoutException after a very short amount of time

2015-09-04 Thread Shawn Heisey
On 9/4/2015 7:53 AM, Oleg Kalnichevski wrote:
> I added socket timeout logging to the 4.5.x branch and trunk
>
> http://svn.apache.org/r1701258
>
> I clearly those values logged when executing HttpClient examples. 

I abandoned my custom httpcore jar built from the 4.4.1 tag with the one
line addition, pulled down the 4.5.x branch of httpclient, and built
it.  I replaced httpclient-4.5.jar with httpclient-4.5.1-SNAPSHOT.jar,
and verified that the commit you made was included in the source code
that I checked out.

Because I am using slf4j which ultimately logs to log4j1, I do have the
jcl-over-slf4j jar in my classpath, which should capture the commons
logging that httpclient uses.  I put the following in my
log4j.properties file:

log4j.logger.org.apache.http=DEBUG, file

During program startup (when I build the HttpClient objects), I do not
see any logs from httpclient at all, but when it actually connects to
Solr, I do see DEBUG logs.  Those debug logs do not include the "set
socket timeout" log entry that you added.  One of the logs says this:

DEBUG - 2015-09-04 11:38:01.551;   262; 3; Connection [id: 1][route:
{}->http://bigindy5.REDACTED.com:8982] can be kept alive indefinitely

I must be creating the client objects incorrectlyfor the "set socket
timeout" message to never be logged.  So you don't have to go looking
back through the thread, here is the code I'm using:

/* Trying out a new way of creating clients */
RequestConfig requestConfig = RequestConfig.custom()
  .setSocketTimeout(90)
  .setConnectTimeout(15000)
  .build();
httpClient = HttpClients.custom()
  .setDefaultRequestConfig(requestConfig)
  .setMaxConnPerRoute(300)
  .setMaxConnTotal(5000)
  .build();
RequestConfig optimizeRequestConfig = RequestConfig.custom()
  .setSocketTimeout(720)
  .setConnectTimeout(15000)
  .build();
optimizeHttpClient = HttpClients.custom()
  .setDefaultRequestConfig(optimizeRequestConfig)
  .build();

Thanks,
Shawn


-
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org



Re: Getting SocketTimeoutException after a very short amount of time

2015-09-04 Thread Oleg Kalnichevski
On Thu, 2015-09-03 at 13:13 -0600, Shawn Heisey wrote:
> On 9/3/2015 10:57 AM, Shawn Heisey wrote:
> > I don't see anything in the file my start script creates by
> > redirecting stdout, though. If everything were working right,
> > shouldn't I see output from setting the timeout in my own code?
> 
> I replaced the client construction using Solr's HttpClientUtil with the
> following, which I came up with after reading the
> ClientConfiguration.java example on the HC website:
> 
>   /* Trying out a new way of creating clients */
>   RequestConfig requestConfig = RequestConfig.custom()
>   .setSocketTimeout(90)
>   .setConnectTimeout(15000)
>   .build();
>   httpClient = HttpClients.custom()
>   .setDefaultRequestConfig(requestConfig)
>   .setMaxConnPerRoute(300)
>   .setMaxConnTotal(5000)
>   .build();
>   RequestConfig optimizeRequestConfig = RequestConfig.custom()
>   .setSocketTimeout(720)
>   .setConnectTimeout(15000)
>   .build();
>   optimizeHttpClient = HttpClients.custom()
>   .setDefaultRequestConfig(optimizeRequestConfig)
>   .build();
> 
> The httpClient and optimizeHttpClient instances are defined like this:
> 
>   /**
>* A static http client to use on Solr client objects.
>*/
>   private static HttpClient httpClient = null;
> 
>   /**
>* A static http client to use on Solr client objects. This one is for
> doing
>* optimizes, will use a much longer socket timeout.
>*/
>   private static HttpClient optimizeHttpClient = null;
> 
> I am still seeing nothing in stdout, even though there's an added
> System.out.println in BHttpResponseBase.java at the recommended location.
> 
> Am I doing something wrong in my attempts to debug this problem?
> 

Shawn

I added socket timeout logging to the 4.5.x branch and trunk

http://svn.apache.org/r1701258

I clearly those values logged when executing HttpClient examples. 

---
[DEBUG] RequestAddCookies - CookieSpec selected: default
[DEBUG] RequestAuthCache - Auth cache not set in the context
[DEBUG] PoolingHttpClientConnectionManager - Connection request: [route: 
{}->http://httpbin.org:80][total kept alive: 0; route allocated: 0 of 10; total 
allocated: 0 of 100]
[DEBUG] PoolingHttpClientConnectionManager - Connection leased: [id: 0][route: 
{}->http://httpbin.org:80][total kept alive: 0; route allocated: 1 of 10; total 
allocated: 1 of 100]
[DEBUG] MainClientExec - Opening connection {}->http://httpbin.org:80
[DEBUG] DefaultHttpClientConnectionOperator - Connecting to 
httpbin.org/54.175.219.8:80
[DEBUG] DefaultHttpClientConnectionOperator - Connection established 
10.0.0.8:55361<->54.175.219.8:80
[DEBUG] DefaultManagedHttpClientConnection - http-outgoing-0: set socket 
timeout to 5000
[DEBUG] MainClientExec - Executing request GET /get HTTP/1.1
---

Oleg


-
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org



Re: Getting SocketTimeoutException after a very short amount of time

2015-09-03 Thread Shawn Heisey
On 9/3/2015 10:57 AM, Shawn Heisey wrote:
> I don't see anything in the file my start script creates by
> redirecting stdout, though. If everything were working right,
> shouldn't I see output from setting the timeout in my own code?

I replaced the client construction using Solr's HttpClientUtil with the
following, which I came up with after reading the
ClientConfiguration.java example on the HC website:

  /* Trying out a new way of creating clients */
  RequestConfig requestConfig = RequestConfig.custom()
  .setSocketTimeout(90)
  .setConnectTimeout(15000)
  .build();
  httpClient = HttpClients.custom()
  .setDefaultRequestConfig(requestConfig)
  .setMaxConnPerRoute(300)
  .setMaxConnTotal(5000)
  .build();
  RequestConfig optimizeRequestConfig = RequestConfig.custom()
  .setSocketTimeout(720)
  .setConnectTimeout(15000)
  .build();
  optimizeHttpClient = HttpClients.custom()
  .setDefaultRequestConfig(optimizeRequestConfig)
  .build();

The httpClient and optimizeHttpClient instances are defined like this:

  /**
   * A static http client to use on Solr client objects.
   */
  private static HttpClient httpClient = null;

  /**
   * A static http client to use on Solr client objects. This one is for
doing
   * optimizes, will use a much longer socket timeout.
   */
  private static HttpClient optimizeHttpClient = null;

I am still seeing nothing in stdout, even though there's an added
System.out.println in BHttpResponseBase.java at the recommended location.

Am I doing something wrong in my attempts to debug this problem?

Thanks,
Shawn


-
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org



Re: Getting SocketTimeoutException after a very short amount of time

2015-09-03 Thread Shawn Heisey
On 8/31/2015 3:02 AM, Oleg Kalnichevski wrote:
> There likely to be something that sets SO_TIMEOUT to a lower value. You
> should be able to trace it by placing a breakpoint or good ol'
> System.out.println at this line:
> http://hc.apache.org/httpcomponents-core-4.4.x/httpcore/xref/org/apache/http/impl/BHttpConnectionBase.html#277

I added a line just before the existing line 277:

System.out.println("timeout debug: " + timeout);

I never did figure out how to pull httpcore into eclipse, so I initially
had a problem with tabs in the source from my editing escapade in
Notepad++.  After I fixed that, I got a new jar, which I put into my
project and installed on the server.  With lsof on the server, I can see
that the new jar (named httpcore-4.4.1-custom-with-println.jar) has been
used by Java, and the original file is NOT in use by that process.

I don't see anything in the file my start script creates by redirecting
stdout, though.  If everything were working right, shouldn't I see
output from setting the timeout in my own code?  I thought HttpClient
defaulted to zero (no timeout) if it wasn't specified ... was I wrong
about that?  Is BHttpConnectionBase used by the deprecated
classes/methods as well as the suggested ones?

Right now it is looking like there's a problem with SolrJ setting the
socket timeout.  I see code in our HttpClientUtil that does set the
timeout, so if this problem I'm suspecting is correct, either SolrJ is
doing it wrong or the deprecated classes aren't working right.

What thoughts do you have?  Perhaps I should be creating the HttpClient
objects using HC methods directly instead of the SolrJ helper class.

Thanks,
Shawn


-
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org



Re: Getting SocketTimeoutException after a very short amount of time

2015-08-31 Thread Shawn Heisey
On 8/31/2015 3:02 AM, Oleg Kalnichevski wrote:
> The socket timeout in blocking i/o is handled by the JRE. We have no
> control over it. 
> --- 
> Caused by: java.net.SocketTimeoutException: Read timed out
> at java.net.SocketInputStream.socketRead0(Native Method)
> ---
> There likely to be something that sets SO_TIMEOUT to a lower value. You
> should be able to trace it by placing a breakpoint or good ol'
> System.out.println at this line:
> http://hc.apache.org/httpcomponents-core-4.4.x/httpcore/xref/org/apache/http/impl/BHttpConnectionBase.html#277
> 
> Naturally it would make things easier if Solr used no deprecated
> methods.

I once tried to work out a patch for Solr to remove deprecated classes
implementing HttpClient.  I quickly got myself bogged down in issues I
didn't know how to fix.  I wasn't even attempting to fix the deeper-down
usage using deprecated methods, just the HttpClient objects themselves.

I'm not sure how to set up a debugging environment with breakpoints, so
I think println is going to be my friend.  Now I need to figure out how
to pull the project into eclipse for editing, and then how to build
httpcore.

Thanks,
Shawn


-
To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org
For additional commands, e-mail: httpclient-users-h...@hc.apache.org



Re: Getting SocketTimeoutException after a very short amount of time

2015-08-31 Thread Oleg Kalnichevski
On Sun, 2015-08-30 at 20:39 -0600, Shawn Heisey wrote:
> I am seeing SocketTimeoutException in the log for my SolrJ program. 
> SolrJ uses HttpClient.
> 
> I'm starting with the HC list for this problem because that seems like
> the most likely place for a problem, but I know that it could be in
> SolrJ or my own code.
> 
> The index cycle that timed out began at 06:13:30.003.  This starts out
> talking to a MySQL database to work out any index changes that need to
> be made, and if any are found, proceeds to make them.  The loop failed
> with a socket timeout error at 2015-08-30 06:14:00.232, so it looks like
> it only waited 30 seconds ... but the SO_TIMEOUT on the httpclient
> should have been set to 15 minutes.
> 
> Here is the full exception, slightly redacted to obscure my company name:
> 
> ERROR - 2015-08-30 06:14:00.232;   977; 2; chain.b: error committing shard 2
> com.REDACTED.idxbuild.util.BuildException: shard.b.2.spark2live commit
> failed
> at com.REDACTED.idxbuild.solr.Core.commit(Core.java:496)
> at com.REDACTED.idxbuild.index.Shard.commit(Shard.java:454)
> at com.REDACTED.idxbuild.index.Chain$2.run(Chain.java:969)
> Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout
> occured while waiting response from server at:
> http://idxb3.REDACTED.com:8981/solr
> at
> org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:570)
> at
> org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235)
> at
> org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227)
> at
> org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:135)
> at
> org.apache.solr.client.solrj.SolrClient.commit(SolrClient.java:523)
> at com.REDACTED.idxbuild.solr.Core.commit(Core.java:484)
> ... 2 more
> Caused by: java.net.SocketTimeoutException: Read timed out
> at java.net.SocketInputStream.socketRead0(Native Method)
> at java.net.SocketInputStream.read(SocketInputStream.java:152)
> at java.net.SocketInputStream.read(SocketInputStream.java:122)
> at
> org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
> at
> org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
> at
> org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
> at
> org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
> at
> org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
> at
> org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
> at
> org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
> at
> org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
> at
> org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
> at
> org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
> at
> org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
> at
> org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)
> at
> org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)
> at
> org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
> at
> org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
> at
> org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)
> at
> org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
> at
> org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:466)
> ... 7 more
> 
> Here's my code that creates the two HttpClient objects which are shared
> among multiple HttpSolrClient instances.  I create a client with a 15
> minute socket timeout for general use, and a client with a two hour
> timeout for doing index optimizes:
> 
>   synchronized (firstInstance)
>   {
>   if (firstInstance)
>   {
>   ModifiableSolrParams params = new ModifiableSolrParams();
>   params.add(HttpClientUtil.PROP_MAX_CONNECTIONS_PER_HOST, "300");
>   params.add(HttpClientUtil.PROP_MAX_CONNECTIONS, "5000");
>   params.add(HttpClientUtil.PROP_CONNECTION_TIMEOUT, "15000");
>   params.add(HttpClientUtil.PROP_SO_TIMEOUT, "90");
>   httpClient = HttpClientUtil.createClient(params);
>   params.clear();
>   params.add(HttpClientUtil.PROP_CONNECTION_TIMEOUT, "15000");
>   para

Getting SocketTimeoutException after a very short amount of time

2015-08-30 Thread Shawn Heisey
I am seeing SocketTimeoutException in the log for my SolrJ program. 
SolrJ uses HttpClient.

I'm starting with the HC list for this problem because that seems like
the most likely place for a problem, but I know that it could be in
SolrJ or my own code.

The index cycle that timed out began at 06:13:30.003.  This starts out
talking to a MySQL database to work out any index changes that need to
be made, and if any are found, proceeds to make them.  The loop failed
with a socket timeout error at 2015-08-30 06:14:00.232, so it looks like
it only waited 30 seconds ... but the SO_TIMEOUT on the httpclient
should have been set to 15 minutes.

Here is the full exception, slightly redacted to obscure my company name:

ERROR - 2015-08-30 06:14:00.232;   977; 2; chain.b: error committing shard 2
com.REDACTED.idxbuild.util.BuildException: shard.b.2.spark2live commit
failed
at com.REDACTED.idxbuild.solr.Core.commit(Core.java:496)
at com.REDACTED.idxbuild.index.Shard.commit(Shard.java:454)
at com.REDACTED.idxbuild.index.Chain$2.run(Chain.java:969)
Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout
occured while waiting response from server at:
http://idxb3.REDACTED.com:8981/solr
at
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:570)
at
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235)
at
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227)
at
org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:135)
at
org.apache.solr.client.solrj.SolrClient.commit(SolrClient.java:523)
at com.REDACTED.idxbuild.solr.Core.commit(Core.java:484)
... 2 more
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:152)
at java.net.SocketInputStream.read(SocketInputStream.java:122)
at
org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
at
org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
at
org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
at
org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
at
org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
at
org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
at
org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
at
org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
at
org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
at
org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
at
org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
at
org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)
at
org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)
at
org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
at
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
at
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)
at
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
at
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:466)
... 7 more

Here's my code that creates the two HttpClient objects which are shared
among multiple HttpSolrClient instances.  I create a client with a 15
minute socket timeout for general use, and a client with a two hour
timeout for doing index optimizes:

  synchronized (firstInstance)
  {
  if (firstInstance)
  {
  ModifiableSolrParams params = new ModifiableSolrParams();
  params.add(HttpClientUtil.PROP_MAX_CONNECTIONS_PER_HOST, "300");
  params.add(HttpClientUtil.PROP_MAX_CONNECTIONS, "5000");
  params.add(HttpClientUtil.PROP_CONNECTION_TIMEOUT, "15000");
  params.add(HttpClientUtil.PROP_SO_TIMEOUT, "90");
  httpClient = HttpClientUtil.createClient(params);
  params.clear();
  params.add(HttpClientUtil.PROP_CONNECTION_TIMEOUT, "15000");
  params.add(HttpClientUtil.PROP_SO_TIMEOUT, "720");
  optimizeHttpClient = HttpClientUtil.createClient(params);
  firstInstance = false;
  }
  }

httpClient and optimizeHttpClient are static instances of HttpClient.

The code for