Uploaded image for project: 'Solr'
  1. Solr
  2. SOLR-9548

solr.log should start with informative welcome message

    Details

    • Type: Improvement
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 6.3, master (7.0)
    • Component/s: Server
    • Security Level: Public (Default Security Level. Issues are Public)
    • Labels:

      Description

      When starting Solr, the first log line should be more informative, such as

      Welcome to Apache Solr™ version 7.0.0, running in standalone mode on port 8983 from folder /Users/janhoy/git/lucene-solr/solr
      
      1. SOLR-9548.patch
        2 kB
        Jan Høydahl
      2. SOLR-9548-detailversion.patch
        1 kB
        Jan Høydahl

        Issue Links

          Activity

          Hide
          janhoy Jan Høydahl added a comment -

          Simple patch. I'm assuming jetty.port and solr.install.dir are always set, and that the presence of either sysprop zkHost or zkRun is a certain way of detecting Cloud mode.

          After reducing more log noise this will be the 2nd line in a fresh solr.log file. Since this log line says almost exactly the same as the echo line from the start script when starting in foreground, this patch removes that echo.

          Startup will then look like

          % bin/solr start -f
          162  INFO  (main) [   ] o.e.j.s.Server jetty-9.3.8.v20160314
          500  INFO  (main) [   ] o.a.s.s.SolrDispatchFilter Welcome to Apache Solr™ version 7.0.0, starting in standalone mode on port 8983 from /Users/janhoy/git/lucene-solr/solr
          524  INFO  (main) [   ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /Users/janhoy/git/lucene-solr/solr/server/solr
          ...
          

          Any objections to this approach?

          Show
          janhoy Jan Høydahl added a comment - Simple patch. I'm assuming jetty.port and solr.install.dir are always set, and that the presence of either sysprop zkHost or zkRun is a certain way of detecting Cloud mode. After reducing more log noise this will be the 2nd line in a fresh solr.log file. Since this log line says almost exactly the same as the echo line from the start script when starting in foreground, this patch removes that echo. Startup will then look like % bin/solr start -f 162 INFO (main) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 500 INFO (main) [ ] o.a.s.s.SolrDispatchFilter Welcome to Apache Solr™ version 7.0.0, starting in standalone mode on port 8983 from /Users/janhoy/git/lucene-solr/solr 524 INFO (main) [ ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /Users/janhoy/git/lucene-solr/solr/server/solr ... Any objections to this approach?
          Hide
          elyograg Shawn Heisey added a comment -

          No objections. The line is fairly long, though. A thought for consideration: Would it make sense to output multiple lines that are each shorter, to reduce the risk of the lines wrapping on an 80-column text console?

          Show
          elyograg Shawn Heisey added a comment - No objections. The line is fairly long, though. A thought for consideration: Would it make sense to output multiple lines that are each shorter, to reduce the risk of the lines wrapping on an 80-column text console?
          Hide
          janhoy Jan Høydahl added a comment -

          How about this?

          163  INFO  (main) [   ] o.e.j.s.Server jetty-9.3.8.v20160314
          442  INFO  (main) [   ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 7.0.0
          442  INFO  (main) [   ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on port 8983
          442  INFO  (main) [   ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: /Users/janhoy/git/lucene-solr/solr
          493  INFO  (main) [   ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2016-09-22T07:30:46.085Z
          409  INFO  (main) [   ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /Users/janhoy/git/lucene-solr/solr/server/solr
          
          Show
          janhoy Jan Høydahl added a comment - How about this? 163 INFO (main) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 442 INFO (main) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0 442 INFO (main) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port 8983 442 INFO (main) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/janhoy/git/lucene-solr/solr 493 INFO (main) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-09-22T07:30:46.085Z 409 INFO (main) [ ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /Users/janhoy/git/lucene-solr/solr/server/solr
          Hide
          elyograg Shawn Heisey added a comment -

          That's really cool.

          Looks like an 80 column display is too narrow for that info even if we don't include the text logo. And in solr.log, with it's much larger timestamp, there's even less room. So trying to fit it into 80 columns is impossible anyway, unless each line is super short, but that would make it difficult to relay useful info. My idea won't work.

          Show
          elyograg Shawn Heisey added a comment - That's really cool. Looks like an 80 column display is too narrow for that info even if we don't include the text logo. And in solr.log, with it's much larger timestamp, there's even less room. So trying to fit it into 80 columns is impossible anyway, unless each line is super short, but that would make it difficult to relay useful info. My idea won't work.
          Hide
          janhoy Jan Høydahl added a comment -

          Yea. Btw we switched to logging full date-time also for console in another JIRA. I'm starting to doubt if that was wise, since it steals a lot of space. Adding the "Start time" to the top of the log will make it possible to convert the relative time into absolute time if one should need that. And those that need to run Solr in production with NSSM or similar which only can take STDOUT, can always edit log4j.properties. What do you say, shall we go back to relative time and shorter width? Could we also sacrifice (main), I guess that is thread name?

          Show
          janhoy Jan Høydahl added a comment - Yea. Btw we switched to logging full date-time also for console in another JIRA. I'm starting to doubt if that was wise, since it steals a lot of space. Adding the "Start time" to the top of the log will make it possible to convert the relative time into absolute time if one should need that. And those that need to run Solr in production with NSSM or similar which only can take STDOUT, can always edit log4j.properties. What do you say, shall we go back to relative time and shorter width? Could we also sacrifice (main) , I guess that is thread name?
          Hide
          elyograg Shawn Heisey added a comment -

          I much prefer a real timestamp to an ever-increasing measure of runtime. Without it, it's extremely difficult to compare an external timestamp to log information.

          I'm ambivalent when it comes to thread names in the log. I have not yet seen any situation where the thread names in Solr are useful, but perhaps that's a failure of imagination on my part. I haven't tried to connect different logging statements together by thread name. If they can be useful, we should leave them in, but if they aren't useful to most people, we should take them out, and explain in the docs how to adjust the config for situations where they can be useful.

          Show
          elyograg Shawn Heisey added a comment - I much prefer a real timestamp to an ever-increasing measure of runtime. Without it, it's extremely difficult to compare an external timestamp to log information. I'm ambivalent when it comes to thread names in the log. I have not yet seen any situation where the thread names in Solr are useful, but perhaps that's a failure of imagination on my part. I haven't tried to connect different logging statements together by thread name. If they can be useful, we should leave them in, but if they aren't useful to most people, we should take them out, and explain in the docs how to adjust the config for situations where they can be useful.
          Hide
          jira-bot ASF subversion and git services added a comment -

          Commit 4c7a8c4b813ff75aad4b05189e2903501d34fd33 in lucene-solr's branch refs/heads/master from Jan Høydahl
          [ https://git-wip-us.apache.org/repos/asf?p=lucene-solr.git;h=4c7a8c4 ]

          SOLR-9548: The beginning of solr.log now starts with a more informative welcome message

          Show
          jira-bot ASF subversion and git services added a comment - Commit 4c7a8c4b813ff75aad4b05189e2903501d34fd33 in lucene-solr's branch refs/heads/master from Jan Høydahl [ https://git-wip-us.apache.org/repos/asf?p=lucene-solr.git;h=4c7a8c4 ] SOLR-9548 : The beginning of solr.log now starts with a more informative welcome message
          Hide
          janhoy Jan Høydahl added a comment -

          I committed to master. But when testing further, I see that the version printout never contains -SNAPSHOT even from my own build. I'm using Version.LATEST. I think it would make sense to be able to distinguish from the log whether this is an official full release or a SNAPSHOT build. How can I do this in the best way? I see that the SystemInfoHandler uses SolrCore.class.getPackage().getImplementationVersion(), but is there a simpler way? I'd like it to simply print the spec-version if it is an official release, but perhaps the full impl-version if it is a snapshot release?

          Show
          janhoy Jan Høydahl added a comment - I committed to master. But when testing further, I see that the version printout never contains -SNAPSHOT even from my own build. I'm using Version.LATEST . I think it would make sense to be able to distinguish from the log whether this is an official full release or a SNAPSHOT build. How can I do this in the best way? I see that the SystemInfoHandler uses SolrCore.class.getPackage().getImplementationVersion() , but is there a simpler way? I'd like it to simply print the spec-version if it is an official release, but perhaps the full impl-version if it is a snapshot release?
          Hide
          janhoy Jan Høydahl added a comment -

          So the attached patch SOLR-9548-detailversion.patch is the best I could do for now. At least now it is evident from the log file by what exact version this log was generated.

          Show
          janhoy Jan Høydahl added a comment - So the attached patch SOLR-9548 -detailversion.patch is the best I could do for now. At least now it is evident from the log file by what exact version this log was generated.
          Hide
          jira-bot ASF subversion and git services added a comment -

          Commit c1553c20f0590cccaeb0571cb254efc7394f8275 in lucene-solr's branch refs/heads/master from Jan Høydahl
          [ https://git-wip-us.apache.org/repos/asf?p=lucene-solr.git;h=c1553c2 ]

          SOLR-9548: Print full solr-impl version for SNAPSHOT builds

          Show
          jira-bot ASF subversion and git services added a comment - Commit c1553c20f0590cccaeb0571cb254efc7394f8275 in lucene-solr's branch refs/heads/master from Jan Høydahl [ https://git-wip-us.apache.org/repos/asf?p=lucene-solr.git;h=c1553c2 ] SOLR-9548 : Print full solr-impl version for SNAPSHOT builds
          Hide
          jira-bot ASF subversion and git services added a comment -

          Commit 047b643d2baeb2e9011d0d1bdf40209c5f1ee2c2 in lucene-solr's branch refs/heads/branch_6x from Jan Høydahl
          [ https://git-wip-us.apache.org/repos/asf?p=lucene-solr.git;h=047b643 ]

          SOLR-9548: The beginning of solr.log now starts with a more informative welcome message

          (cherry picked from commit 4c7a8c4)

          Show
          jira-bot ASF subversion and git services added a comment - Commit 047b643d2baeb2e9011d0d1bdf40209c5f1ee2c2 in lucene-solr's branch refs/heads/branch_6x from Jan Høydahl [ https://git-wip-us.apache.org/repos/asf?p=lucene-solr.git;h=047b643 ] SOLR-9548 : The beginning of solr.log now starts with a more informative welcome message (cherry picked from commit 4c7a8c4)
          Hide
          jira-bot ASF subversion and git services added a comment -

          Commit 6e1c82336f2fba7ea15ec37037a1515f6ef4ecb5 in lucene-solr's branch refs/heads/branch_6x from Jan Høydahl
          [ https://git-wip-us.apache.org/repos/asf?p=lucene-solr.git;h=6e1c823 ]

          SOLR-9548: Print full solr-impl version for SNAPSHOT builds

          (cherry picked from commit c1553c2)

          Show
          jira-bot ASF subversion and git services added a comment - Commit 6e1c82336f2fba7ea15ec37037a1515f6ef4ecb5 in lucene-solr's branch refs/heads/branch_6x from Jan Høydahl [ https://git-wip-us.apache.org/repos/asf?p=lucene-solr.git;h=6e1c823 ] SOLR-9548 : Print full solr-impl version for SNAPSHOT builds (cherry picked from commit c1553c2)
          Hide
          elyograg Shawn Heisey added a comment -

          I think this probably needs to be in another issue, but I can't locate an open one, and I don't want to open a new one until I know that there's not an existing one we can do the work in:

          The startup logging, when in cloud mode, should log the precise information that will be used when registering with zookeeper – host, port, context path, http/https, etc. Have a user on IRC that has run into a problem starting a second node because it sees an existing ephemeral live node that matches the info it's trying to use to register. Setting the "-h hostname" option on bin/solr fixes the issue. If the logging had included the precise registration info, it would have been easier to track down. Ultimately we figured out that both hosts were trying to register as 127.0.1.1 – because /etc/hosts was incorrect.

          Show
          elyograg Shawn Heisey added a comment - I think this probably needs to be in another issue, but I can't locate an open one, and I don't want to open a new one until I know that there's not an existing one we can do the work in: The startup logging, when in cloud mode, should log the precise information that will be used when registering with zookeeper – host, port, context path, http/https, etc. Have a user on IRC that has run into a problem starting a second node because it sees an existing ephemeral live node that matches the info it's trying to use to register. Setting the "-h hostname" option on bin/solr fixes the issue. If the logging had included the precise registration info, it would have been easier to track down. Ultimately we figured out that both hosts were trying to register as 127.0.1.1 – because /etc/hosts was incorrect.
          Hide
          janhoy Jan Høydahl added a comment -

          Please open a new issue. I think you may want to add some logging in ZkContainer#initZookeeper(), by adding the extra info you need in this line which is already there:

          log.info("Zookeeper client=" + zookeeperHost);  
          
          Show
          janhoy Jan Høydahl added a comment - Please open a new issue. I think you may want to add some logging in ZkContainer#initZookeeper() , by adding the extra info you need in this line which is already there: log.info( "Zookeeper client=" + zookeeperHost);
          Hide
          shalinmangar Shalin Shekhar Mangar added a comment -

          Closing after 6.3.0 release.

          Show
          shalinmangar Shalin Shekhar Mangar added a comment - Closing after 6.3.0 release.

            People

            • Assignee:
              janhoy Jan Høydahl
              Reporter:
              janhoy Jan Høydahl
            • Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development