Solr
  1. Solr
  2. SOLR-6673

MDC based logging of collection, shard etc.

    Details

    • Type: Improvement Improvement
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 5.1, 6.0
    • Component/s: None
    • Labels:

      Description

      In cloud mode, the many log items don't contain the collection name, shard name, core name etc. Debugging becomes specially difficult when many collections/shards are hosted on the same node.

      The proposed solution adds MDC based stamping of collection, shard, core to the thread.

      See also: SOLR-5969, SOLR-5277

      1. log4j.properties
        2 kB
        Ishan Chattopadhyaya
      2. log4j.properties
        1 kB
        Ishan Chattopadhyaya
      3. SOLR-6673_NPE_fix.patch
        0.6 kB
        Ishan Chattopadhyaya
      4. SOLR-6673.patch
        91 kB
        Ishan Chattopadhyaya
      5. SOLR-6673.patch
        93 kB
        Ishan Chattopadhyaya
      6. SOLR-6673.patch
        94 kB
        Ishan Chattopadhyaya
      7. SOLR-6673.patch
        39 kB
        Ishan Chattopadhyaya
      8. SOLR-6673.patch
        14 kB
        Ishan Chattopadhyaya
      9. SOLR-6673.patch
        15 kB
        Ishan Chattopadhyaya
      10. SOLR-6673.patch
        13 kB
        Ishan Chattopadhyaya
      11. SOLR-6673.patch
        15 kB
        Ishan Chattopadhyaya
      12. SOLR-6673-log-more.patch
        4 kB
        Shalin Shekhar Mangar

        Issue Links

          Activity

          Hide
          Ishan Chattopadhyaya added a comment -

          Here's a patch for this. The stamping is done from wherever the collection, shard, core names become available first. There are many more places from where this MDC based stamping could be done, this is just for a start and should cover the important places.

          Attached log4j.properties is from the location: solr/core/src/test-files/log4j.properties

          Show
          Ishan Chattopadhyaya added a comment - Here's a patch for this. The stamping is done from wherever the collection, shard, core names become available first. There are many more places from where this MDC based stamping could be done, this is just for a start and should cover the important places. Attached log4j.properties is from the location: solr/core/src/test-files/log4j.properties
          Hide
          Erik Hatcher added a comment -

          +11 on MDC!!!

          does MDC.clear() need to be called up-front somewhere?

          Show
          Erik Hatcher added a comment - +11 on MDC!!! does MDC.clear() need to be called up-front somewhere?
          Hide
          Ishan Chattopadhyaya added a comment -

          @Erik, Thanks for your review.
          Added MDC.clear() everywhere before starting out. Although, this might be a bit conservative, but seemed safer. In many places, only a collection name is stamped to MDC, but a stale shard name stamped to the MDC, remnants of some previous stamping in the same thread, should be cleared.

          Also, added collection, shard stamping to the constructor of the ShardLeaderElectionContextBase.

          Show
          Ishan Chattopadhyaya added a comment - @Erik, Thanks for your review. Added MDC.clear() everywhere before starting out. Although, this might be a bit conservative, but seemed safer. In many places, only a collection name is stamped to MDC, but a stale shard name stamped to the MDC, remnants of some previous stamping in the same thread, should be cleared. Also, added collection, shard stamping to the constructor of the ShardLeaderElectionContextBase.
          Hide
          Yonik Seeley added a comment -

          Hmmm, we currently use RequestInfo for this... (it was the only way to debug solr cloud tests...).
          It's used by the tests, but not by the normal logger.
          But we've already done some work adding RequestInfo to places that didn't need it, just for the sake of logging:
          See RecoveryStrategy.run and SyncStrategy.sync:

              SolrRequestInfo.setRequestInfo(new SolrRequestInfo(req, rsp));
              [...]
              SolrRequestInfo.clear();
          

          Also see SolrLogLayout / SolrLogFormatter.

          Show
          Yonik Seeley added a comment - Hmmm, we currently use RequestInfo for this... (it was the only way to debug solr cloud tests...). It's used by the tests, but not by the normal logger. But we've already done some work adding RequestInfo to places that didn't need it, just for the sake of logging: See RecoveryStrategy.run and SyncStrategy.sync: SolrRequestInfo.setRequestInfo( new SolrRequestInfo(req, rsp)); [...] SolrRequestInfo.clear(); Also see SolrLogLayout / SolrLogFormatter.
          Hide
          Ishan Chattopadhyaya added a comment -

          Yonik Seeley Thanks for the pointer, I had a look at it in some places. There were some places where I thought having a RequestInfo would be difficult, and MDC would be easier to populate in such cases. Do you think for a start it would be okay for both MDC and RequestInfo based logging to coexist, and later we phase out one or the other as we go along?

          Show
          Ishan Chattopadhyaya added a comment - Yonik Seeley Thanks for the pointer, I had a look at it in some places. There were some places where I thought having a RequestInfo would be difficult, and MDC would be easier to populate in such cases. Do you think for a start it would be okay for both MDC and RequestInfo based logging to coexist, and later we phase out one or the other as we go along?
          Hide
          Mike Drob added a comment -

          Bump.

          Is there anything still holding this patch up? I can take the time to bring it up to date, if necessary.

          Show
          Mike Drob added a comment - Bump. Is there anything still holding this patch up? I can take the time to bring it up to date, if necessary.
          Hide
          Noble Paul added a comment -

          Please do

          Show
          Noble Paul added a comment - Please do
          Hide
          Ishan Chattopadhyaya added a comment -

          Updated the patch for current trunk.
          Also attached a sample log4j.properties file (I used the LeaderElectionTest and a few other tests as a starting point for testing).

          Show
          Ishan Chattopadhyaya added a comment - Updated the patch for current trunk. Also attached a sample log4j.properties file (I used the LeaderElectionTest and a few other tests as a starting point for testing).
          Hide
          Ishan Chattopadhyaya added a comment -

          Mike Drob, Noble Paul Can you please review and find more places of where we could log into MDC from?

          Show
          Ishan Chattopadhyaya added a comment - Mike Drob , Noble Paul Can you please review and find more places of where we could log into MDC from?
          Hide
          Noble Paul added a comment -

          The changes to log4j.properties should be a part of the patch as well

          Show
          Noble Paul added a comment - The changes to log4j.properties should be a part of the patch as well
          Hide
          Mark Miller added a comment -

          Wow, I hadn't see this yet. We so desperately need it. My SolrLogReader will be very happy, as well as anyone that has to do any multi core debugging.

          Show
          Mark Miller added a comment - Wow, I hadn't see this yet. We so desperately need it. My SolrLogReader will be very happy, as well as anyone that has to do any multi core debugging.
          Hide
          Mark Miller added a comment -

          I hate to be the code policeman, but let's please clean up the formatting - there is lot's of my pet peeve formatting:

          if(collection!=null)

          It's a shared code base, we have a code style, we have produced for all 3 major IDE's, we should follow it unless the rule break improves readability in some corner cases.

          Show
          Mark Miller added a comment - I hate to be the code policeman, but let's please clean up the formatting - there is lot's of my pet peeve formatting: if(collection!=null) It's a shared code base, we have a code style, we have produced for all 3 major IDE's, we should follow it unless the rule break improves readability in some corner cases.
          Hide
          Ishan Chattopadhyaya added a comment - - edited

          Apologies for the inconsistent formatting; I'll keep this in mind Thanks for calling it out!

          Updated the patch with changes going to SolrLogLayout, adding the MDC values in this format:

          [core] [collection] [shard] [replica]

          Show
          Ishan Chattopadhyaya added a comment - - edited Apologies for the inconsistent formatting; I'll keep this in mind Thanks for calling it out! Updated the patch with changes going to SolrLogLayout, adding the MDC values in this format: [core] [collection] [shard] [replica]
          Hide
          Ishan Chattopadhyaya added a comment -

          Updating the patch to trunk.

          Show
          Ishan Chattopadhyaya added a comment - Updating the patch to trunk.
          Hide
          Noble Paul added a comment -

          I think doing an MDC.clear() is not a good idea. You should only clear what you set .Most likely there will be other entries in MDC which should not be cleared

          Show
          Noble Paul added a comment - I think doing an MDC.clear() is not a good idea. You should only clear what you set .Most likely there will be other entries in MDC which should not be cleared
          Hide
          Ishan Chattopadhyaya added a comment -

          Noble Paul That's a good point. I've updated the patch to unset/clean up the MDC values changed in each method that uses MDC.

          Show
          Ishan Chattopadhyaya added a comment - Noble Paul That's a good point. I've updated the patch to unset/clean up the MDC values changed in each method that uses MDC.
          Hide
          Noble Paul added a comment -

          Instead of doing MDC unset in multiple places in one method , it should be one block

          try {
          // all operations
          }finally{
          } 
          
          Show
          Noble Paul added a comment - Instead of doing MDC unset in multiple places in one method , it should be one block try { // all operations }finally{ }
          Hide
          Ishan Chattopadhyaya added a comment -

          Thanks Noble. I've updated the patch to change the "try/finally"s to improve code readability.

          Show
          Ishan Chattopadhyaya added a comment - Thanks Noble. I've updated the patch to change the "try/finally"s to improve code readability.
          Hide
          ASF subversion and git services added a comment -

          Commit 1668992 from Noble Paul in branch 'dev/trunk'
          [ https://svn.apache.org/r1668992 ]

          SOLR-6673: MDC based logging of collection, shard, replica, core

          Show
          ASF subversion and git services added a comment - Commit 1668992 from Noble Paul in branch 'dev/trunk' [ https://svn.apache.org/r1668992 ] SOLR-6673 : MDC based logging of collection, shard, replica, core
          Hide
          ASF subversion and git services added a comment -

          Commit 1668994 from Noble Paul in branch 'dev/branches/branch_5x'
          [ https://svn.apache.org/r1668994 ]

          SOLR-6673: MDC based logging of collection, shard, replica, core

          Show
          ASF subversion and git services added a comment - Commit 1668994 from Noble Paul in branch 'dev/branches/branch_5x' [ https://svn.apache.org/r1668994 ] SOLR-6673 : MDC based logging of collection, shard, replica, core
          Hide
          Shalin Shekhar Mangar added a comment - - edited

          Thanks a lot Ishan and Noble for taking this up. This was very much needed for debugging SolrCloud tests.

          There are some additional logging that can be handled here. For example, simple queries and updates don't log anything other than core name currently. The SolrDispatchFilter has the core object so it should have all the information (via CloudDescriptor) to log collection, shard, coreNodeName etc.

          I'm re-opening this issue to handle the other stuff instead of creating a new issue to change un-released functionality.

          Show
          Shalin Shekhar Mangar added a comment - - edited Thanks a lot Ishan and Noble for taking this up. This was very much needed for debugging SolrCloud tests. There are some additional logging that can be handled here. For example, simple queries and updates don't log anything other than core name currently. The SolrDispatchFilter has the core object so it should have all the information (via CloudDescriptor) to log collection, shard, coreNodeName etc. I'm re-opening this issue to handle the other stuff instead of creating a new issue to change un-released functionality.
          Hide
          Noble Paul added a comment -

          Shalin Shekhar Mangar While you are at it , also add "node" also(only for tests )

          Show
          Noble Paul added a comment - Shalin Shekhar Mangar While you are at it , also add "node" also(only for tests )
          Hide
          Shalin Shekhar Mangar added a comment -

          While you are at it , also add "node" also(only for tests )

          That's a good idea. I can put up a patch unless Ishan gets to it first.

          Show
          Shalin Shekhar Mangar added a comment - While you are at it , also add "node" also(only for tests ) That's a good idea. I can put up a patch unless Ishan gets to it first.
          Hide
          Ramkumar Aiyengar added a comment - - edited

          A bit late here, but a minor note looking at the default log4j.properties there.. Won't it come up with empty []'s for each property with no value? Might be a little less weird looking if it was just [%X{a} %X{b}...]? (Ideally conditionals in the pattern would be great if I am not aware of a way to do with the standard PatternLayout)

          Show
          Ramkumar Aiyengar added a comment - - edited A bit late here, but a minor note looking at the default log4j.properties there.. Won't it come up with empty []'s for each property with no value? Might be a little less weird looking if it was just [%X{a} %X{b}...]? (Ideally conditionals in the pattern would be great if I am not aware of a way to do with the standard PatternLayout)
          Hide
          Mike Drob added a comment -

          I was running tests on trunk after this change and did see a lot of lines like

            2> 1363 T13 [] [] [] []  oasc.CoreContainer.<init> New CoreContainer 493421698
          

          IMO, these make the output much harder to read, and it would be nice to clean this up.

          Show
          Mike Drob added a comment - I was running tests on trunk after this change and did see a lot of lines like 2> 1363 T13 [] [] [] [] oasc.CoreContainer.<init> New CoreContainer 493421698 IMO, these make the output much harder to read, and it would be nice to clean this up.
          Hide
          Yonik Seeley added a comment -

          IMO, these make the output much harder to read, and it would be nice to clean this up.

          +1

          Show
          Yonik Seeley added a comment - IMO, these make the output much harder to read, and it would be nice to clean this up. +1
          Hide
          Shalin Shekhar Mangar added a comment -

          How does this look?

          34093 T174 C:collection1 S:shard1 R:core_node6 c:collection1 C17 P62757 oasup.LogUpdateProcessor.finish [collection1] webapp=/ar path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:62746/ar/collection1/&wt=javabin&version=2} {add=[100000478 (1496644420418666496), 100000479 (1496644420419715072)]} 0 1
          

          This patch logs collection, shard, coreNodeName and core name in tests.

          Show
          Shalin Shekhar Mangar added a comment - How does this look? 34093 T174 C:collection1 S:shard1 R:core_node6 c:collection1 C17 P62757 oasup.LogUpdateProcessor.finish [collection1] webapp=/ar path=/update params={update.distrib=FROMLEADER&distrib.from=http: //127.0.0.1:62746/ar/collection1/&wt=javabin&version=2} {add=[100000478 (1496644420418666496), 100000479 (1496644420419715072)]} 0 1 This patch logs collection, shard, coreNodeName and core name in tests.
          Hide
          Mike Drob added a comment -

          The duplication between "c:collection1" and "[collection1]" bothers me a little bit, but not enough to think that we should change it. Especially because I can imagine somebody's ops tooling already relying on the name of the collection in brackets. Overall, +1.

          Show
          Mike Drob added a comment - The duplication between "c:collection1" and "[collection1]" bothers me a little bit, but not enough to think that we should change it. Especially because I can imagine somebody's ops tooling already relying on the name of the collection in brackets. Overall, +1.
          Hide
          ASF subversion and git services added a comment -

          Commit 1669236 from shalin@apache.org in branch 'dev/trunk'
          [ https://svn.apache.org/r1669236 ]

          SOLR-6673: Log collection, shard, replica, core name for update and search requests

          Show
          ASF subversion and git services added a comment - Commit 1669236 from shalin@apache.org in branch 'dev/trunk' [ https://svn.apache.org/r1669236 ] SOLR-6673 : Log collection, shard, replica, core name for update and search requests
          Hide
          ASF subversion and git services added a comment -

          Commit 1669237 from shalin@apache.org in branch 'dev/branches/branch_5x'
          [ https://svn.apache.org/r1669237 ]

          SOLR-6673: Log collection, shard, replica, core name for update and search requests

          Show
          ASF subversion and git services added a comment - Commit 1669237 from shalin@apache.org in branch 'dev/branches/branch_5x' [ https://svn.apache.org/r1669237 ] SOLR-6673 : Log collection, shard, replica, core name for update and search requests
          Hide
          Shalin Shekhar Mangar added a comment -

          Won't it come up with empty []'s for each property with no value? Might be a little less weird looking if it was just [%X{a} %X{b}...]? (Ideally conditionals in the pattern would be great if I am not aware of a way to do with the standard PatternLayout)

          Yeah, it will. I don't know of a way to add conditionals in log4j configuration either. I'm open to suggestions.

          Show
          Shalin Shekhar Mangar added a comment - Won't it come up with empty []'s for each property with no value? Might be a little less weird looking if it was just [%X{a} %X{b}...] ? (Ideally conditionals in the pattern would be great if I am not aware of a way to do with the standard PatternLayout) Yeah, it will. I don't know of a way to add conditionals in log4j configuration either. I'm open to suggestions.
          Hide
          Ramkumar Aiyengar added a comment -

          I think reducing it to one set of [] than four will at least reduce the weirdness..

          Show
          Ramkumar Aiyengar added a comment - I think reducing it to one set of [] than four will at least reduce the weirdness..
          Hide
          Joel Bernstein added a comment - - edited

          I did a fresh 5x checkout this morning and ran the cloud-dev/solrcloud-start.sh script and got the error below when I accessed /solr from the servers. Not sure if this reflects an error in how solrcloud-start.sh is doing things or a bug in Solr.

          trace=java.lang.NullPointerException
          at org.apache.solr.servlet.SolrDispatchFilter.addMDCValues(SolrDispatchFilter.java:497)
          at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:366)
          at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:220)
          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419)
          at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455)
          at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
          at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:557)
          at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231)
          at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1075)
          at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:384)
          at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
          at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1009)
          at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
          at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:255)
          at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:154)
          at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
          at org.eclipse.jetty.server.Server.handle(Server.java:368)
          at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:489)
          at org.eclipse.jetty.server.BlockingHttpConnection.handleRequest(BlockingHttpConnection.java:53)
          at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:942)
          at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:1004)
          at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:640)
          at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
          at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:72)
          at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:264)
          at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
          at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
          at java.lang.Thread.run(Thread.java:745)
          ,code=500

          Show
          Joel Bernstein added a comment - - edited I did a fresh 5x checkout this morning and ran the cloud-dev/solrcloud-start.sh script and got the error below when I accessed /solr from the servers. Not sure if this reflects an error in how solrcloud-start.sh is doing things or a bug in Solr. trace=java.lang.NullPointerException at org.apache.solr.servlet.SolrDispatchFilter.addMDCValues(SolrDispatchFilter.java:497) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:366) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:220) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:557) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1075) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:384) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1009) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135) at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:255) at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:154) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116) at org.eclipse.jetty.server.Server.handle(Server.java:368) at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:489) at org.eclipse.jetty.server.BlockingHttpConnection.handleRequest(BlockingHttpConnection.java:53) at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:942) at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:1004) at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:640) at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235) at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:72) at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:264) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) at java.lang.Thread.run(Thread.java:745) ,code=500
          Hide
          Varun Thacker added a comment -

          34093 T174 C:collection1 S:shard1 R:core_node6 c:collection1 C17 P62757 oasup.LogUpdateProcessor.finish [collection1] webapp=/ar path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:62746/ar/collection1/&wt=javabin&version=2} {add=[100000478 (1496644420418666496), 100000479 (1496644420419715072)]} 0 1

          Can we be more verbose about it? Call 'C' 'Collection' and 'c' 'core'?

          981970 T4850 C:collection1 c:collection1 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
          Lines like this could confuse someone.

          Don't have a strong opinion about it though.

          Show
          Varun Thacker added a comment - 34093 T174 C:collection1 S:shard1 R:core_node6 c:collection1 C17 P62757 oasup.LogUpdateProcessor.finish [collection1] webapp=/ar path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:62746/ar/collection1/&wt=javabin&version=2} {add=[100000478 (1496644420418666496), 100000479 (1496644420419715072)]} 0 1 Can we be more verbose about it? Call 'C' 'Collection' and 'c' 'core'? 981970 T4850 C:collection1 c:collection1 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1 Lines like this could confuse someone. Don't have a strong opinion about it though.
          Hide
          Yonik Seeley added a comment -

          Can we be more verbose about it? Call 'C' 'Collection' and 'c' 'core'?

          If this stuff will be repeated in every log line, I like the fact that it's short, and that should actually enhance readability once you get used to it.

          There is some other redundant info now though: C17 P62757
          That's the core number and the port number. Both where important in the past (along with the thread number) to figuring out chaos monkey test fails. But they don't seem important for production? The port number should be different for diff log files in production, and the collection name we already have.

          Show
          Yonik Seeley added a comment - Can we be more verbose about it? Call 'C' 'Collection' and 'c' 'core'? If this stuff will be repeated in every log line, I like the fact that it's short, and that should actually enhance readability once you get used to it. There is some other redundant info now though: C17 P62757 That's the core number and the port number. Both where important in the past (along with the thread number) to figuring out chaos monkey test fails. But they don't seem important for production? The port number should be different for diff log files in production, and the collection name we already have.
          Hide
          Mark Miller added a comment -

          I don't really like using caps for the label distinction. Seems nicer to have like c:collection n:core1 or something. Looks a lot nicer, doesn't overload the c char. I don't really know that it screams "small c, must be core" anyway. We just need a consistent clean format that is easy script parsable. Or c:collection s:core1 for the more proper SolrCore?

          Show
          Mark Miller added a comment - I don't really like using caps for the label distinction. Seems nicer to have like c:collection n:core1 or something. Looks a lot nicer, doesn't overload the c char. I don't really know that it screams "small c, must be core" anyway. We just need a consistent clean format that is easy script parsable. Or c:collection s:core1 for the more proper SolrCore?
          Hide
          Yonik Seeley added a comment -

          Or c:collection s:core1 for the more proper SolrCore?

          +1

          Show
          Yonik Seeley added a comment - Or c:collection s:core1 for the more proper SolrCore? +1
          Hide
          Joel Bernstein added a comment -

          Just ran through a manual SolrCloud setup on the 5x branch and I still am getting the null pointer related to MDC when going to the admin screen.

          trace=java.lang.NullPointerException
          at org.apache.solr.servlet.SolrDispatchFilter.addMDCValues(SolrDispatchFilter.java:497)

          Show
          Joel Bernstein added a comment - Just ran through a manual SolrCloud setup on the 5x branch and I still am getting the null pointer related to MDC when going to the admin screen. trace=java.lang.NullPointerException at org.apache.solr.servlet.SolrDispatchFilter.addMDCValues(SolrDispatchFilter.java:497)
          Hide
          Ishan Chattopadhyaya added a comment -

          Added a patch for the NPE fix at SolrDispatchFilter (trunk).

          Show
          Ishan Chattopadhyaya added a comment - Added a patch for the NPE fix at SolrDispatchFilter (trunk).
          Hide
          ASF subversion and git services added a comment -

          Commit 1669374 from shalin@apache.org in branch 'dev/trunk'
          [ https://svn.apache.org/r1669374 ]

          SOLR-6673: Fix NPE

          Show
          ASF subversion and git services added a comment - Commit 1669374 from shalin@apache.org in branch 'dev/trunk' [ https://svn.apache.org/r1669374 ] SOLR-6673 : Fix NPE
          Hide
          ASF subversion and git services added a comment -

          Commit 1669375 from shalin@apache.org in branch 'dev/branches/branch_5x'
          [ https://svn.apache.org/r1669375 ]

          SOLR-6673: Fix NPE

          Show
          ASF subversion and git services added a comment - Commit 1669375 from shalin@apache.org in branch 'dev/branches/branch_5x' [ https://svn.apache.org/r1669375 ] SOLR-6673 : Fix NPE
          Hide
          Ishan Chattopadhyaya added a comment -

          The log4j.properties in solr/server/resources/log4j.properties still has [] [] [] [] like stamping, which would get used in production logs for users. Based on discussion above, I'm marking this as a blocker for 5.1, until we have a fix for that.

          Show
          Ishan Chattopadhyaya added a comment - The log4j.properties in solr/server/resources/log4j.properties still has [] [] [] [] like stamping, which would get used in production logs for users. Based on discussion above, I'm marking this as a blocker for 5.1, until we have a fix for that.
          Hide
          Shalin Shekhar Mangar added a comment -

          Sorry, this ain't a blocker. We can still change it though because a new RC is in order.

          Show
          Shalin Shekhar Mangar added a comment - Sorry, this ain't a blocker. We can still change it though because a new RC is in order.
          Hide
          ASF subversion and git services added a comment -

          Commit 1672331 from shalin@apache.org in branch 'dev/trunk'
          [ https://svn.apache.org/r1672331 ]

          SOLR-6673: Change default pattern for both console and file appenders

          Show
          ASF subversion and git services added a comment - Commit 1672331 from shalin@apache.org in branch 'dev/trunk' [ https://svn.apache.org/r1672331 ] SOLR-6673 : Change default pattern for both console and file appenders
          Hide
          ASF subversion and git services added a comment -

          Commit 1672337 from shalin@apache.org in branch 'dev/branches/branch_5x'
          [ https://svn.apache.org/r1672337 ]

          SOLR-6673: Change default pattern for both console and file appenders

          Show
          ASF subversion and git services added a comment - Commit 1672337 from shalin@apache.org in branch 'dev/branches/branch_5x' [ https://svn.apache.org/r1672337 ] SOLR-6673 : Change default pattern for both console and file appenders
          Hide
          ASF subversion and git services added a comment -

          Commit 1672340 from shalin@apache.org in branch 'dev/branches/lucene_solr_5_1'
          [ https://svn.apache.org/r1672340 ]

          SOLR-6673: Change default pattern for both console and file appenders

          Show
          ASF subversion and git services added a comment - Commit 1672340 from shalin@apache.org in branch 'dev/branches/lucene_solr_5_1' [ https://svn.apache.org/r1672340 ] SOLR-6673 : Change default pattern for both console and file appenders
          Hide
          Shalin Shekhar Mangar added a comment -

          I committed a change to the default pattern for both console and file appenders. I find it strange that we have two identical log4j.properties in server/resources and example/resources. Does anyone know why? We should nuke one of them.

          This is what solr.log looks like in cloud mode:

          INFO  - 2015-04-09 13:11:02.583; [xyz shard1 core_node1 xyz_shard1_replica1] org.apache.solr.core.SolrCore; [xyz_shard1_replica1] webapp=/solr path=/select params={q=*:*&indent=true&wt=json&_=1428585062554} hits=0 status=0 QTime=19
          

          And the following is the solr-8983-console.log

          402422 [qtp2065530879-15] INFO  org.apache.solr.core.SolrCore.Request  [xyz shard1 core_node1 xyz_shard1_replica1] – [xyz_shard1_replica1] webapp=/solr path=/select params={q=*:*&indent=true&wt=json&_=1428585062554} hits=0 status=0 QTime=19
          
          Show
          Shalin Shekhar Mangar added a comment - I committed a change to the default pattern for both console and file appenders. I find it strange that we have two identical log4j.properties in server/resources and example/resources. Does anyone know why? We should nuke one of them. This is what solr.log looks like in cloud mode: INFO - 2015-04-09 13:11:02.583; [xyz shard1 core_node1 xyz_shard1_replica1] org.apache.solr.core.SolrCore; [xyz_shard1_replica1] webapp=/solr path=/select params={q=*:*&indent= true &wt=json&_=1428585062554} hits=0 status=0 QTime=19 And the following is the solr-8983-console.log 402422 [qtp2065530879-15] INFO org.apache.solr.core.SolrCore.Request [xyz shard1 core_node1 xyz_shard1_replica1] – [xyz_shard1_replica1] webapp=/solr path=/select params={q=*:*&indent= true &wt=json&_=1428585062554} hits=0 status=0 QTime=19
          Hide
          Shalin Shekhar Mangar added a comment -

          Let's close this one for 5.1. I'll open a few improvement issues for 5.2

          Show
          Shalin Shekhar Mangar added a comment - Let's close this one for 5.1. I'll open a few improvement issues for 5.2
          Hide
          Timothy Potter added a comment -

          Bulk close after 5.1 release

          Show
          Timothy Potter added a comment - Bulk close after 5.1 release
          Hide
          Mark Miller added a comment -

          I don't really like using caps for the label distinction.

          I still see this in the tests, hadn't looked to see what production is yet - looks really ugly in my opinion.

          22369 T48 N:127.0.0.1:49464__ c:collection1 C12 oasup.DocExpirationUpdateProcessorFactory$DeleteExpiredDocsRunnable.run 
          22685 T34 N:127.0.0.1:49464__ C:control_collection S:shard1 R:core_node1 c:collection1 
          

          Really ugly stuff we should change IMO.

          Show
          Mark Miller added a comment - I don't really like using caps for the label distinction. I still see this in the tests, hadn't looked to see what production is yet - looks really ugly in my opinion. 22369 T48 N:127.0.0.1:49464__ c:collection1 C12 oasup.DocExpirationUpdateProcessorFactory$DeleteExpiredDocsRunnable.run 22685 T34 N:127.0.0.1:49464__ C:control_collection S:shard1 R:core_node1 c:collection1 Really ugly stuff we should change IMO.
          Hide
          Mark Miller added a comment -

          Upon review, I found a lot of problems with this issue - I've tried to address them all in SOLR-7590.

          Show
          Mark Miller added a comment - Upon review, I found a lot of problems with this issue - I've tried to address them all in SOLR-7590 .
          Hide
          Mike Drob added a comment -

          Did this ever make it into the wiki or ref guide?

          Show
          Mike Drob added a comment - Did this ever make it into the wiki or ref guide?
          Hide
          Ishan Chattopadhyaya added a comment -

          Good catch, we should document it.
          Maybe https://cwiki.apache.org/confluence/display/solr/Logging or https://cwiki.apache.org/confluence/display/solr/Configuring+Logging. I can take a look in ~2 days, unless someone else wants to take it up and/or beats me to it.

          Show
          Ishan Chattopadhyaya added a comment - Good catch, we should document it. Maybe https://cwiki.apache.org/confluence/display/solr/Logging or https://cwiki.apache.org/confluence/display/solr/Configuring+Logging . I can take a look in ~2 days, unless someone else wants to take it up and/or beats me to it.

            People

            • Assignee:
              Noble Paul
              Reporter:
              Ishan Chattopadhyaya
            • Votes:
              0 Vote for this issue
              Watchers:
              12 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development