Search code examples
solrapache-zookeeper

Solr / Zookeeper : "An exception was thrown while closing send thread"


I am trying Solr for the first time on RHEL 8 with Openjdk version "17.0.2". I am following the tutorial https://solr.apache.org/guide/8_11/solr-tutorial.html. I get the warning:

WARN  - 2022-04-20 12:07:20.762; org.apache.zookeeper.ClientCnxn; An exception was thrown while closing send thread for session 0x10003e1057e0003. => EndOfStreamException: Unable to read additional data from server sessionid 0x10003e1057e0003, likely server has closed socket
        at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:77)
org.apache.zookeeper.ClientCnxn$EndOfStreamException: Unable to read additional data from server sessionid 0x10003e1057e0003, likely server has closed socket
        at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:77) ~[zookeeper-3.6.2.jar:3.6.2]
        at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350) ~[zookeeper-3.6.2.jar:3.6.2]
        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1275) ~[zookeeper-3.6.2.jar:3.6.2]

This should be a straight forward tutorial. Do you know what I am missing?

Here is tutorial from the start:

[solr@abc294837 ~]$ ./bin/solr start -e cloud

Welcome to the SolrCloud example!

This interactive session will help you launch a SolrCloud cluster on your local workstation.
To begin, how many Solr nodes would you like to run in your local cluster? (specify 1-4 nodes) [2]:

Ok, let's start up 2 Solr nodes for your example SolrCloud cluster.
Please enter the port for node1 [8983]:

Please enter the port for node2 [7574]:

Solr home directory /opt/solr/example/cloud/node1/solr already exists.
/opt/solr/example/cloud/node2 already exists.

Starting up Solr on port 8983 using command:
"/opt/solr/bin/solr" start -cloud -p 8983 -s "/opt/solr/example/cloud/node1/solr"

Waiting up to 180 seconds to see Solr running on port 8983 [\]
Started Solr server on port 8983 (pid=50226). Happy searching!

Starting up Solr on port 7574 using command:
"/opt/solr/bin/solr" start -cloud -p 7574 -s "/opt/solr/example/cloud/node2/solr" -z localhost:2181

Waiting up to 180 seconds to see Solr running on port 7574 [-]
Started Solr server on port 7574 (pid=50417). Happy searching!
                                                                                                                          INFO  - 2022-04-20 12:07:20.502; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
INFO  - 2022-04-20 12:07:20.553; org.apache.solr.common.cloud.ConnectionManager; zkClient has connected
INFO  - 2022-04-20 12:07:20.556; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
INFO  - 2022-04-20 12:07:20.631; org.apache.solr.common.cloud.ZkStateReader; Updated live nodes from ZooKeeper... (0) -> (2)
INFO  - 2022-04-20 12:07:20.737; org.apache.solr.client.solrj.impl.ZkClientClusterStateProvider; Cluster at localhost:2181 ready
WARN  - 2022-04-20 12:07:20.762; org.apache.zookeeper.ClientCnxn; An exception was thrown while closing send thread for session 0x10003e1057e0003. => EndOfStreamException: Unable to read additional data from server sessionid 0x10003e1057e0003, likely server has closed socket
        at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:77)
org.apache.zookeeper.ClientCnxn$EndOfStreamException: Unable to read additional data from server sessionid 0x10003e1057e0003, likely server has closed socket
        at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:77) ~[zookeeper-3.6.2.jar:3.6.2]
        at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350) ~[zookeeper-3.6.2.jar:3.6.2]
        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1275) ~[zookeeper-3.6.2.jar:3.6.2]

Now let's create a new collection for indexing documents in your 2-node cluster.
Please provide a name for your new collection: [gettingstarted]
´´´

Solution

  • You are not missing anything, this is Zookeeper falsely warning about a socket connection being closed.

    [EDIT] : This has been fixed in Solr versions 8.11.2, and 9.0.0 (Zookeeper versions 3.6.4, 3.7.1, 3.8.1, 3.9.0).


    We can see in this commit that the exception is caught and expected (comment says closing so this is expected), yet it is now reported as a warning and a stack trace is logged, although this is not an error per se. So you can consider this message a debug message (as it was before that commit).

    See for reference this issue, caused by this issue, and this pull request for the fix.

    We can still make Zookeeper quiet from Solr/log4j config, by changing the level of its logger from "warn" to "error" :

    solr/solr/server/resources/log4j2-console.xml

    <AsyncLogger name="org.apache.zookeeper" level="ERROR"/>