Solr
  1. Solr
  2. SOLR-3362

FacetComponent throws NPE when doing distributed query

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 4.0-ALPHA
    • Fix Version/s: None
    • Component/s: SolrCloud
    • Labels:
      None
    • Environment:

      RHEL
      lucene svn revision 1308309

      Description

      When executing a query against a field in my index I am getting the following exception

      The query I am executing is as follows:

      http://host:port/solr/collection1/select?q=bob&facet=true&facet.field=organization

      debugging the FacetComponent line 489 sfc is null

      SEVERE: java.lang.NullPointerException
      at org.apache.solr.handler.component.FacetComponent.refineFacets(FacetComponent.java:489)
      at org.apache.solr.handler.component.FacetComponent.handleResponses(FacetComponent.java:278)
      at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:307)
      at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:129)
      at org.apache.solr.core.SolrCore.execute(SolrCore.java:1550)
      at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:442)
      at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:263)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1337)
      at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:484)
      at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
      at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:524)
      at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:233)
      at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1065)
      at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:413)
      at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192)
      at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:999)
      at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
      at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250)
      at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)
      at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111)
      at org.eclipse.jetty.server.Server.handle(Server.java:351)
      at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:454)
      at org.eclipse.jetty.server.BlockingHttpConnection.handleRequest(BlockingHttpConnection.java:47)
      at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:890)
      at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:944)
      at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:634)
      at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:230)
      at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:66)
      at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:254)
      at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:599)
      at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:534)
      at java.lang.Thread.run(Thread.java:662)

        Issue Links

          Activity

          Jamie Johnson created issue -
          Jamie Johnson made changes -
          Field Original Value New Value
          Environment MacOSX RHEL
          lucene svn revision 1308309
          Hide
          Yonik Seeley added a comment -

          So it seems like we're getting back a term we didn't ask for.
          One way this could happen is if the encoding is messed up - StrUtils.join and splitSmart are used for this, and I don't see an obvious error there.

          At this point perhaps we should add a check at line 489 and log terms that come back that we don't ask for.

          Show
          Yonik Seeley added a comment - So it seems like we're getting back a term we didn't ask for. One way this could happen is if the encoding is messed up - StrUtils.join and splitSmart are used for this, and I don't see an obvious error there. At this point perhaps we should add a check at line 489 and log terms that come back that we don't ask for.
          Hide
          Jamie Johnson added a comment -

          Essentially doing something like this?

          if(sfc == null){
            //log message
            continue;
          }
          
          Show
          Jamie Johnson added a comment - Essentially doing something like this? if (sfc == null ){ //log message continue ; }
          Hide
          Yonik Seeley added a comment -

          Right. I just checked something in for FacetComponent to log the term and other info.

          Show
          Yonik Seeley added a comment - Right. I just checked something in for FacetComponent to log the term and other info.
          Hide
          Jamie Johnson added a comment -

          This certainly made the error I was having go away, should I be worried about a lower level issue that this change masks?

          Show
          Jamie Johnson added a comment - This certainly made the error I was having go away, should I be worried about a lower level issue that this change masks?
          Hide
          Yonik Seeley added a comment -

          This certainly made the error I was having go away, should I be worried about a lower level issue that this change masks?

          Yes, I'd be worried. Do you see any "Unexpected term returned" errors in the logs?

          Show
          Yonik Seeley added a comment - This certainly made the error I was having go away, should I be worried about a lower level issue that this change masks? Yes, I'd be worried. Do you see any "Unexpected term returned" errors in the logs?
          Hide
          Jamie Johnson added a comment -

          I'm trying to avoid pasting the entire response.....I do see the errors in the log though. I see

          Unexpected term returned for facet refining. key=se_organizationname_umvs term='Test 
          
          
          
          ? 
          
          
          
          Daily News'
          

          in the request I see the following

          Test+%0A%0A%0A%0A%C2%A0+%0A%0A%0A%Daily+News
          

          Debugging the key doing (int)name.charAt says the is ASCII character 63 instead of ASCII character 160. It looks like the encoding on the name is wrong.

          I am really pretty lost as to where this could be happening but this looks like it could be the issue. Any thoughts where this could be happening?

          Show
          Jamie Johnson added a comment - I'm trying to avoid pasting the entire response.....I do see the errors in the log though. I see Unexpected term returned for facet refining. key=se_organizationname_umvs term='Test ? Daily News' in the request I see the following Test+%0A%0A%0A%0A%C2%A0+%0A%0A%0A%Daily+News Debugging the key doing (int)name.charAt says the is ASCII character 63 instead of ASCII character 160. It looks like the encoding on the name is wrong. I am really pretty lost as to where this could be happening but this looks like it could be the issue. Any thoughts where this could be happening?
          Hide
          Yonik Seeley added a comment -

          I assume you're not using the jetty bundled with Solr?
          If not, let's check that first by running exampledocs/test_utf8.sh

          Show
          Yonik Seeley added a comment - I assume you're not using the jetty bundled with Solr? If not, let's check that first by running exampledocs/test_utf8.sh
          Hide
          Jamie Johnson added a comment -

          I am using the jetty bundled with Solr, absolutely no changes at all in that regard.

          What I am having difficulty doing is duplicating this issue on a very small set of data, I can only duplicate with the actual data right now. If I run a very simple test and add some of the extended ASCII characters it appears in the facets properly, but with the actual data I am having issues, not sure why.

          Show
          Jamie Johnson added a comment - I am using the jetty bundled with Solr, absolutely no changes at all in that regard. What I am having difficulty doing is duplicating this issue on a very small set of data, I can only duplicate with the actual data right now. If I run a very simple test and add some of the extended ASCII characters it appears in the facets properly, but with the actual data I am having issues, not sure why.
          Hide
          Yonik Seeley added a comment -

          OK, then the next most likely possibility would seem to be the client sending the sub-request.
          I just managed to reproduce this problem with this URL:
          http://localhost:8983/solr/select?wt=python&indent=true&q=*:*&facet=true&facet.query=

          {!term%20f=id}

          wx%C2%A0yz&shards=localhost:8983/solr

          Show
          Yonik Seeley added a comment - OK, then the next most likely possibility would seem to be the client sending the sub-request. I just managed to reproduce this problem with this URL: http://localhost:8983/solr/select?wt=python&indent=true&q=*:*&facet=true&facet.query= {!term%20f=id} wx%C2%A0yz&shards=localhost:8983/solr
          Hide
          Yonik Seeley added a comment -

          Oh yuck... I just used netcat to listen on port 8985 and changed the shards parameter to that to see just what was being sent.
          What a waste of space! And that is where the charset is getting hacked...

          /opt/code/lusolr/solr/example/exampledocs$ nc -l 8985
          POST /solr/select HTTP/1.1
          User-Agent: Solr[org.apache.solr.client.solrj.impl.HttpSolrServer] 1.0
          Content-Charset: UTF-8
          Accept-Charset: UTF-8
          Content-Length: 1217
          Content-Type: multipart/form-data; boundary=eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Host: localhost:8985
          Connection: Keep-Alive
          
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="rows"
          
          10
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="facet"
          
          true
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="facet.query"
          
          {!term f=id}wx?yz
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="q"
          
          *:*
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="start"
          
          0
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="fsv"
          
          true
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="fl"
          
          id,score
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="distrib"
          
          false
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="isShard"
          
          true
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="shard.url"
          
          localhost:8985/solr
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="NOW"
          
          1334757315277
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="wt"
          
          javabin
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="version"
          
          2
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3--
          
          Show
          Yonik Seeley added a comment - Oh yuck... I just used netcat to listen on port 8985 and changed the shards parameter to that to see just what was being sent. What a waste of space! And that is where the charset is getting hacked... /opt/code/lusolr/solr/example/exampledocs$ nc -l 8985 POST /solr/select HTTP/1.1 User-Agent: Solr[org.apache.solr.client.solrj.impl.HttpSolrServer] 1.0 Content-Charset: UTF-8 Accept-Charset: UTF-8 Content-Length: 1217 Content-Type: multipart/form-data; boundary=eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Host: localhost:8985 Connection: Keep-Alive --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "rows" 10 --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "facet" true --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "facet.query" {!term f=id}wx?yz --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "q" *:* --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "start" 0 --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "fsv" true --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "fl" id,score --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "distrib" false --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "isShard" true --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "shard.url" localhost:8985/solr --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "NOW" 1334757315277 --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "wt" javabin --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "version" 2 --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3--
          Hide
          Yonik Seeley added a comment -

          Oh yuck... I just used netcat to listen on port 8985 and changed the shards parameter to that to see just what was being sent.
          What a waste of space! And that is where the charset is getting hacked...

          /opt/code/lusolr/solr/example/exampledocs$ nc -l 8985
          POST /solr/select HTTP/1.1
          User-Agent: Solr[org.apache.solr.client.solrj.impl.HttpSolrServer] 1.0
          Content-Charset: UTF-8
          Accept-Charset: UTF-8
          Content-Length: 1217
          Content-Type: multipart/form-data; boundary=eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Host: localhost:8985
          Connection: Keep-Alive
          
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="rows"
          
          10
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="facet"
          
          true
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="facet.query"
          
          {!term f=id}wx?yz
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="q"
          
          *:*
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="start"
          
          0
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="fsv"
          
          true
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="fl"
          
          id,score
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="distrib"
          
          false
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="isShard"
          
          true
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="shard.url"
          
          localhost:8985/solr
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="NOW"
          
          1334757315277
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="wt"
          
          javabin
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3
          Content-Disposition: form-data; name="version"
          
          2
          --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3--
          
          Show
          Yonik Seeley added a comment - Oh yuck... I just used netcat to listen on port 8985 and changed the shards parameter to that to see just what was being sent. What a waste of space! And that is where the charset is getting hacked... /opt/code/lusolr/solr/example/exampledocs$ nc -l 8985 POST /solr/select HTTP/1.1 User-Agent: Solr[org.apache.solr.client.solrj.impl.HttpSolrServer] 1.0 Content-Charset: UTF-8 Accept-Charset: UTF-8 Content-Length: 1217 Content-Type: multipart/form-data; boundary=eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Host: localhost:8985 Connection: Keep-Alive --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "rows" 10 --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "facet" true --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "facet.query" {!term f=id}wx?yz --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "q" *:* --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "start" 0 --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "fsv" true --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "fl" id,score --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "distrib" false --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "isShard" true --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "shard.url" localhost:8985/solr --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "NOW" 1334757315277 --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "wt" javabin --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3 Content-Disposition: form-data; name= "version" 2 --eADQ-PDh-HqmlsJi5PyvlmPclUWpz3--
          Hide
          Yonik Seeley added a comment -

          OK, I just verified that this is not a problem with older trunk builds, so this was an issue introduced by the new http client 4 (upgraded on 3/29).
          Before that, we get a normal looking single-part post with correct encoding.

          Show
          Yonik Seeley added a comment - OK, I just verified that this is not a problem with older trunk builds, so this was an issue introduced by the new http client 4 (upgraded on 3/29). Before that, we get a normal looking single-part post with correct encoding.
          Hide
          Jamie Johnson added a comment -

          I don't claim to understand what specifically the issue is but I am glad that we were able to duplicate it.

          We had never seen this issue on previous builds so it makes sense that this issue was introduced as part of that switch. Again I really appreciate you digging into this.

          Show
          Jamie Johnson added a comment - I don't claim to understand what specifically the issue is but I am glad that we were able to duplicate it. We had never seen this issue on previous builds so it makes sense that this issue was introduced as part of that switch. Again I really appreciate you digging into this.
          Erick Erickson made changes -
          Link This issue relates to SOLR-2020 [ SOLR-2020 ]
          Hide
          Erick Erickson added a comment -

          Just linking since both may be closed at once.

          Show
          Erick Erickson added a comment - Just linking since both may be closed at once.
          Hide
          Sami Siren added a comment -

          OK, I just verified that this is not a problem with older trunk builds, so this was an issue introduced by the new http client 4 (upgraded on 3/29). Before that, we get a normal looking single-part post with correct encoding.

          What is the action the solrj client is doing here?

          Show
          Sami Siren added a comment - OK, I just verified that this is not a problem with older trunk builds, so this was an issue introduced by the new http client 4 (upgraded on 3/29). Before that, we get a normal looking single-part post with correct encoding. What is the action the solrj client is doing here?
          Hide
          Yonik Seeley added a comment -

          Sami checked in a fix today... things should be fixed, but please reopen if not.

          Show
          Yonik Seeley added a comment - Sami checked in a fix today... things should be fixed, but please reopen if not.
          Yonik Seeley made changes -
          Status Open [ 1 ] Resolved [ 5 ]
          Resolution Fixed [ 1 ]
          Hide
          Jamie Johnson added a comment -

          Was this fix in commit 1327635? I just want to make sure i am looking at the appropriate place.

          Show
          Jamie Johnson added a comment - Was this fix in commit 1327635? I just want to make sure i am looking at the appropriate place.
          Hide
          Jamie Johnson added a comment -

          I ran the code from trunk and the issue is resolved. Again thanks!

          Show
          Jamie Johnson added a comment - I ran the code from trunk and the issue is resolved. Again thanks!

            People

            • Assignee:
              Unassigned
              Reporter:
              Jamie Johnson
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development