Solr logging just got better

Using a product like Solr over time makes you blind to certain things. Logging is one such area. For me it started with realizing that the default logging was way too verbose, and soon I found a two year old bug ticket with the title “Reduce logging during startup and shutdown” that I brought to life again.

Turned out that we could reduce the log from a bin/solr start -f from 31 to 9 lines, while bin/solr create -c foo was shrunk from 129 lines to 48 lines and bin/solr start -c -f was shrunk from 67 to 20 lines! Alan Woodward and Alexandre Rafalovitch joined the effort and soon SOLR-5563 was also committed.

logging-solr-start

Startup logging for bin/solr start -f in Solr 6.3

This was really encouraging, so I started searching JIRA for more logging issues our users were facing. And logging turned out to be a much bigger annoyance than I thought, so I decided to solve as many logging issues as possible for the 6.3 release!

Next target was Shawn Heisey’s SOLR-8186 Only log to console when running in foreground. For some reason Solr logged everything in two files: solr.log and solr-8983-console.log. And the problem, apart from polluting the console-log with redundant data, was that the console log is never rotated, just waiting to blow up your disk. Earlier you had to edit log4j.properties to change it. But the new ootb experience is to programmatically mute Log4j’s ConsoleAppender when Solr is started in the background, effectively only logging stdour/stderr to the console log file.

When on the topic of logs filling up your disk, I found another 1,5 years old issue SOLR-7506: Roll over GC logs by default which will now let the JVM rotate its verbose GC logs and delete the oldest, instead of creating one ever-increasing. But the start script would still create a time-stamped backup copy of solr.log as well as solr_gc.log on every startup which were never deleted! So I created SOLR-9570 Logs backed up on restart are kept forever, removing those time-stamped copies. I’ll let the CHANGES entry speak for itself:

* SOLR-9570: Various log tidying now happens at Solr startup:
Old solr_log_<date> and solr_gc_log_<date> files are removed, avoiding disks to fill up,
solr.log.X files are rotated, preserving solr.log from last run in solr.log.1, solr.log.1 => solr.log.2 etc
solr-*-console.log files are moved into $SOLR_LOGS_DIR/archived/ instead of being overwritten
Last JVM garbage collection log solr_gc.log is moved into $SOLR_LOGS_DIR/archived/ (janhoy)

Since the reason for backing up time stamped solr.log was that log4j would overwrite the same file on restart, the solution became instead to rotate the log before startup. Once we move to Log4j2 we can let the loggging framework do this task itself.

Next challenge was Tim Parker’s issue SOLR-9325 solr.log written to {solrRoot}/server/logs instead of location specified by SOLR_LOGS_DIR which made it overly complicated to do such a simple thing as the directory for Solr to put its log files. I added a new Java Property solr.log.dir which is passed on to Solr when started and substituted in log4j.properties. So now you simply define the logs directory in your solr.in config file!

Having made the standard logging less verbose, I wanted to make it a breeze starting Solr in debug logging mode, or in production-friendly quiet-mode. So with Solr 6.3, simply start Solr with bin/solr start -v for DEBUG logging or -q for WARN logging. Or set the new environment variable SOLR_LOG_LEVEL. What happens behind the scenes is that Java Property solr.log.level is set by the start script and picked up in SolrDispatchFilter and we change the root logging level of Log4j programatically. If you change log framework with SLF4j, this feature will not work, so you’ll need to configure your log framework of choice directly.

Finally I wanted key information like Solr version, start time, install-folder, and start mode (Cloud vs standalone) to be right at the beginning of the log. So why not throw in some eye-candy as well 🙂 and so the ASCII-logo was born, accompanied by the key info.

I hope you all enjoy the improved logging experience. Solr 6.3.0 was just released and should arrive at a mirror near you any moment!

 

Comments (1)

  1. Really enjoyed this post, great story! I love seeing so much great housekeeping work being done on Solr. This gives it legs for the next 5 years.

Leave a comment

Your email address will not be published. Required fields are marked *