You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by "Jan Høydahl (JIRA)" <ji...@apache.org> on 2019/04/12 09:38:00 UTC
[jira] [Resolved] (SOLR-13218) MetricsHistoryHandler failes to
collect metrics in BasicAuthPlugin enabled setup
[ https://issues.apache.org/jira/browse/SOLR-13218?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jan Høydahl resolved SOLR-13218.
--------------------------------
Resolution: Duplicate
> MetricsHistoryHandler failes to collect metrics in BasicAuthPlugin enabled setup
> --------------------------------------------------------------------------------
>
> Key: SOLR-13218
> URL: https://issues.apache.org/jira/browse/SOLR-13218
> Project: Solr
> Issue Type: Bug
> Security Level: Public(Default Security Level. Issues are Public)
> Components: Authentication, metrics
> Affects Versions: 7.6
> Environment: Rhel6 Servers
> Windows 10
> Reporter: Daniel Hofer
> Priority: Major
> Labels: BasicAuth, SolrCloud, metrics
> Attachments: image-2019-02-05-11-29-22-569.png, image-2019-02-05-11-30-33-948.png, security.json, solr.xml, zoo.cfg.txt
>
>
> After Updating solr to version 7.6.0 (from 6.6.5) running the setup
> * SolrCloud with 3 Zookeepers and 2 Solr Servers
> * HTTPS enabled
> * BasicAuthentication Enabled
> {code:java}
> {
> "authorization": {
> "user-role": {"Solr": "admin"},
> "permissions": [{
> "role": "admin",
> "name": "security-edit"
> }],
> "class": "solr.RuleBasedAuthorizationPlugin"
> },
> "authentication": {
> "credentials": {"Solr": "1XkpuFRODp3WJJeMqvyGXcu8QSeo0juRvR2g4B1pCvQ= RETXcj9xeYDQ9V+kuDSV3hF2gEUEj79e7Uo+HehPfAE="},
> "blockUnknown": true,
> "class": "solr.BasicAuthPlugin"
> }
> }{code}
> the following errors started showing up in the logs at regular intervals
> {code:java}
> 11:22:35 [MetricsHistoryHandler-12-thread-1] WARN o.a.s.c.s.i.SolrClientNodeStateProvider - could not get tags from node localhost:8011_solr
> org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://localhost:8011/solr: Expected mime type application/octet-stream but got text/html. <html>
> <head>
> <meta http-equiv="Content-Type" content="text/html;charset=utf-8"/>
> <title>Error 401 require authentication</title>
> </head>
> <body><h2>HTTP ERROR 401</h2>
> <p>Problem accessing /solr/admin/metrics. Reason:
> <pre> require authentication</pre></p>
> </body>
> </html>
> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:607)
> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
> at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1260)
> at org.apache.solr.client.solrj.impl.SolrClientNodeStateProvider$ClientSnitchCtx.invoke(SolrClientNodeStateProvider.java:349)
> at org.apache.solr.client.solrj.impl.SolrClientNodeStateProvider.fetchReplicaMetrics(SolrClientNodeStateProvider.java:195)
> at org.apache.solr.client.solrj.impl.SolrClientNodeStateProvider$AutoScalingSnitch.getRemoteInfo(SolrClientNodeStateProvider.java:242)
> at org.apache.solr.common.cloud.rule.ImplicitSnitch.getTags(ImplicitSnitch.java:76)
> at org.apache.solr.client.solrj.impl.SolrClientNodeStateProvider.fetchTagValues(SolrClientNodeStateProvider.java:138)
> at org.apache.solr.client.solrj.impl.SolrClientNodeStateProvider.getNodeValues(SolrClientNodeStateProvider.java:127)
> at org.apache.solr.handler.admin.MetricsHistoryHandler.collectGlobalMetrics(MetricsHistoryHandler.java:498)
> at org.apache.solr.handler.admin.MetricsHistoryHandler.collectMetrics(MetricsHistoryHandler.java:371)
> at org.apache.solr.handler.admin.MetricsHistoryHandler.lambda$new$0(MetricsHistoryHandler.java:231)
> {code}
> After some debugging it showed that the error only shows up during the (seemingly) periodic metrics collection on the leader node. The following stack is seen in this cases
> !image-2019-02-05-11-29-22-569.png!
> While trying to debug it a bit if this can be resolved by some additional settings - for which no solution was found - this method was also called from another location during collection creation where the authentication seems to work just fine
> !image-2019-02-05-11-30-33-948.png!
> So something in this chain must enable the correct authentication settings it seems.
> Appart from periodic error logs generally functionality seems to work but most likely something related to the cluster metrics is not fully working.
> Disabling basic authentication or setting ""blockUnknown": false" makes the issue disappear as expected.
>
> Edit how to reproduce:
>
> Hi, already thanks for the fast response. Just tested and yes I can reproduce it even with a completely fresh download and 2 simple commands, using the following steps and files (this test was done on windows 10 with an embedded zookeeper but we observed the same for the rhel6 server installations with an external zookeeper ensemble)
> * Download solr-7.6.0.zip from [http://archive.apache.org/dist/lucene/solr/7.6.0/]
> * Unpack it somewhere
> * Create a "solr" directory in the unpacked directory and insert the attached [^solr.xml] and [^zoo.cfg.txt] files - need to remove the .txt from the zoo.cfg file wouldn't let me upload otherwise (not 100% sure this even needed but I'm used to it so I decided to stick close to the original case)
> * Finally copy the attached [^security.json] file into the unpacked directory
> * Now open a cmd in the unpacked directory and run
> {noformat}
> bin\solr.cmd start -p 8010 -f -c -s solr -a "-Dhost=localhost -Xdebug -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=1044"{noformat}
> * Open a second cmd and run
> {noformat}
> bin\solr.cmd zk cp file:security.json zk:/security.json -z localhost:9010{noformat}
> Soon afterwards the errors happened the first time even without any collection being created. It would also appear right away again after solr server restarts. Here's the full log
> {noformat}
> Listening for transport dt_socket at address: 1044
> 2019-02-05 14:01:25.203 INFO (main) [ ] o.e.j.u.log Logging initialized @677ms to org.eclipse.jetty.util.log.Slf4jLog
> 2019-02-05 14:01:25.329 INFO (main) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_191-b12
> 2019-02-05 14:01:25.354 INFO (main) [ ] o.e.j.d.p.ScanningAppProvider Deployment monitor [file:///C:/Users/xhd/Downloads/solr-7.6.0/server/contexts/] at interval 0
> 2019-02-05 14:01:25.727 INFO (main) [ ] o.e.j.w.StandardDescriptorProcessor NO JSP Support for /solr, did not find org.apache.jasper.servlet.JspServlet
> 2019-02-05 14:01:25.735 INFO (main) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
> 2019-02-05 14:01:25.735 INFO (main) [ ] o.e.j.s.session No SessionScavenger set, using defaults
> 2019-02-05 14:01:25.737 INFO (main) [ ] o.e.j.s.session node0 Scavenging every 660000ms
> 2019-02-05 14:01:25.769 INFO (main) [ ] o.a.s.u.c.SSLCredentialProviderFactory Processing SSL Credential Provider chain: env;sysprop
> 2019-02-05 14:01:25.804 INFO (main) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
> 2019-02-05 14:01:25.808 INFO (main) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache SolrÖ version 7.6.0
> 2019-02-05 14:01:25.808 INFO (main) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port 8010
> 2019-02-05 14:01:25.808 INFO (main) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\xhd\Downloads\solr-7.6.0
> 2019-02-05 14:01:25.809 INFO (main) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-02-05T14:01:25.809Z
> 2019-02-05 14:01:25.826 INFO (main) [ ] o.a.s.c.SolrResourceLoader Using system property solr.solr.home: C:\Users\xhd\Downloads\solr-7.6.0\solr
> 2019-02-05 14:01:25.831 INFO (main) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\xhd\Downloads\solr-7.6.0\solr\solr.xml
> 2019-02-05 14:01:25.872 INFO (main) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@72bc6553, but no JMX reporters were configured - adding default JMX reporter.
> 2019-02-05 14:01:26.533 INFO (main) [ ] o.a.s.c.SolrZkServerProps Reading configuration from: C:\Users\xhd\Downloads\solr-7.6.0\solr\zoo.cfg
> 2019-02-05 14:01:26.534 INFO (main) [ ] o.a.s.c.SolrZkServer STARTING EMBEDDED STANDALONE ZOOKEEPER SERVER at port 9010
> 2019-02-05 14:01:27.036 INFO (main) [ ] o.a.s.c.ZkContainer Zookeeper client=localhost:9010
> 2019-02-05 14:01:27.121 INFO (zkConnectionManagerCallback-4-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> 2019-02-05 14:01:27.187 INFO (main) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> 2019-02-05 14:01:42.061 INFO (zkCallback-3-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
> 2019-02-05 14:01:42.077 INFO (main) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader localhost:8010_solr
> 2019-02-05 14:01:42.083 INFO (main) [ ] o.a.s.c.Overseer Overseer (id=72119892333101056-localhost:8010_solr-n_0000000001) starting
> 2019-02-05 14:01:42.136 INFO (zkConnectionManagerCallback-11-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> 2019-02-05 14:01:42.142 INFO (main) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at localhost:9010 ready
> 2019-02-05 14:01:42.179 INFO (main) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/localhost:8010_solr
> 2019-02-05 14:01:42.185 INFO (OverseerStateUpdate-72119892333101056-localhost:8010_solr-n_0000000001) [ ] o.a.s.c.Overseer Starting to work on the main queue : localhost:8010_solr
> 2019-02-05 14:01:42.194 INFO (zkCallback-10-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> 2019-02-05 14:01:42.193 INFO (OverseerStateUpdate-72119892333101056-localhost:8010_solr-n_0000000001) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> 2019-02-05 14:01:42.199 INFO (main) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin
> 2019-02-05 14:01:42.213 INFO (main) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin
> 2019-02-05 14:01:42.222 INFO (main) [ ] o.a.s.c.CoreContainer PKIAuthenticationPlugin is managing internode requests
> 2019-02-05 14:01:42.312 INFO (main) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
> 2019-02-05 14:01:42.362 INFO (main) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72bc6553
> 2019-02-05 14:01:42.363 INFO (main) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72bc6553
> 2019-02-05 14:01:42.369 INFO (main) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@72bc6553
> 2019-02-05 14:01:42.393 INFO (main) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\xhd\Downloads\solr-7.6.0\solr
> 2019-02-05 14:01:42.946 INFO (main) [ ] o.e.j.s.h.ContextHandler Started o.e.j.w.WebAppContext@46268f08{/solr,file:///C:/Users/xhd/Downloads/solr-7.6.0/server/solr-webapp/webapp/,AVAILABLE}{C:\Users\xhd\Downloads\solr-7.6.0\server/solr-webapp/webapp}
> 2019-02-05 14:01:42.956 INFO (main) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4beabeec{HTTP/1.1,[http/1.1]}{0.0.0.0:8010}
> 2019-02-05 14:01:42.956 INFO (main) [ ] o.e.j.s.Server Started @18432ms
> 2019-02-05 14:02:48.667 WARN (MetricsHistoryHandler-12-thread-1) [ ] o.a.s.c.s.i.SolrClientNodeStateProvider could not get tags from node localhost:8010_solr
> org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://localhost:8010/solr: Expected mime type application/octet-stream but got text/html. <html>
> <head>
> <meta http-equiv="Content-Type" content="text/html;charset=utf-8"/>
> <title>Error 401 require authentication</title>
> </head>
> <body><h2>HTTP ERROR 401</h2>
> <p>Problem accessing /solr/admin/metrics. Reason:
> <pre> require authentication</pre></p>
> </body>
> </html>
> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:607) ~[solr-solrj-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:53]
> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255) ~[solr-solrj-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:53]
> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244) ~[solr-solrj-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:53]
> at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1260) ~[solr-solrj-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:53]
> at org.apache.solr.client.solrj.impl.SolrClientNodeStateProvider$ClientSnitchCtx.invoke(SolrClientNodeStateProvider.java:349) ~[solr-solrj-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:53]
> at org.apache.solr.client.solrj.impl.SolrClientNodeStateProvider.fetchReplicaMetrics(SolrClientNodeStateProvider.java:195) ~[solr-solrj-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:53]
> at org.apache.solr.client.solrj.impl.SolrClientNodeStateProvider$AutoScalingSnitch.getRemoteInfo(SolrClientNodeStateProvider.java:242) ~[solr-solrj-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:53]
> at org.apache.solr.common.cloud.rule.ImplicitSnitch.getTags(ImplicitSnitch.java:76) ~[solr-solrj-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:53]
> at org.apache.solr.client.solrj.impl.SolrClientNodeStateProvider.fetchTagValues(SolrClientNodeStateProvider.java:138) ~[solr-solrj-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:53]
> at org.apache.solr.client.solrj.impl.SolrClientNodeStateProvider.getNodeValues(SolrClientNodeStateProvider.java:127) ~[solr-solrj-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:53]
> at org.apache.solr.handler.admin.MetricsHistoryHandler.collectGlobalMetrics(MetricsHistoryHandler.java:498) ~[solr-core-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:52]
> at org.apache.solr.handler.admin.MetricsHistoryHandler.collectMetrics(MetricsHistoryHandler.java:371) ~[solr-core-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:52]
> at org.apache.solr.handler.admin.MetricsHistoryHandler.lambda$new$0(MetricsHistoryHandler.java:231) ~[solr-core-7.6.0.jar:7.6.0 719cde97f84640faa1e3525690d262946571245f - nknize - 2018-12-07 14:47:52]
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_191]
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_191]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_191]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_191]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_191]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_191]
> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]{noformat}
> Hope this helps!
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org