Published 2020-12-28.
Last modified 2022-04-05.
Time to read: 4 minutes.
Debugging Jekyll plugins can be a challenge, but a configurable logging facility can be a big help.
Writing puts
statements to generate output works,
but puts
statements are tedious to control
because you must comment and uncomment lines that generate output as you work through issues.
It is better to set up another standard Ruby logger,
perhaps outputting to STDOUT
, STDERR
, or a file,
and control the output by setting the log level for the plugin’s logger.
when used correctly
Loggers are cheap – and easy to set up.
Be sure to set the log level to warn
or error
when you are not debugging,
and place the expression to be evaluated within a block (more on this later),
so site generation goes full speed.
Use a new logger for each plugin that you write.
This article describes jekyll_plugin_logger
,
a Ruby gem that I created that allows you to quickly make custom loggers for your plugins.
This plugin was originally called logger_factory
, but it was renamed for version 2
because it was completely rewritten and became incompatible with previous versions.
Colored Log Output
It can be difficult to find what you are looking for as you watch miles and miles of log output spew onto your console,
hour after hour, while you work on a problem.
Colored output can be a big help.
Jekyll relies on the colorizer gem,
so you can use colors on any terminal output written by puts
,
or sent to a log that writes to STDERR
or STDOUT
.
It is easy to do this, just append a suffix to a string that indicates the color you want that string to be displayed with.
For example:
puts "Green text and ham!".green log.warn "Red text at night, sailor's delight".red
Green text and ham!
Red text at night, sailor's delight.
Supported colors are:
red
black
green
yellow
magenta
white
blue
cyan
bold
First, the Obvious But Wrong Way
You can send a message to Jekyll.logger
from a plugin like this:
Jekyll.logger.debug "Hello, world" Jekyll.logger.info "Hello, world" Jekyll.logger.warn "Hello, world" Jekyll.logger.error "Hello, world"
However, the default Jekyll.logger.log_level
is :info
.
This is a global setting that affects all of Jekyll because only one Logger
is used throughout Jekyll.
It outputs to STDERR
.
If you want to control the output by adjusting log levels,
you will quickly realize that attempting to adjust the
log_level
for Jekyll’s logger singleton is problematic.
This is because when you need to see verbose output from your plugin,
verbose output from the rest of Jekyll will spew all over your terminal.
Adjusting Jekyll.logger.log_level
Jekyll.logger
is under-documented.
This section is just provided to round out your understanding of how logging works in Jekyll.
Please do not attempt to use Jekyll’s logger in your plugins – instead,
use the jekyll_plugin_logger
, described below, which is packaged as a Ruby gem for convenience.
To set Jekyll.logger.log_level
(globally), specify the
--verbose
/ -V
or --quiet
/ -q
options when starting Jekyll:
$ bundle exec jekyll build --verbose # Sets log_level to :debug $ bundle exec jekyll build --quiet # Sets log_level to :error $ JEKYLL_ENV=development bundle exec jekyll serve --verbose $ JEKYLL_ENV=development bundle exec jekyll serve --quiet
You can also reset the Jekyll log level from within a Jekyll plugin like this:
Jekyll.logger.adjust_verbosity(:verbose => true)
I found that _config.yml
has no effect on Jekyll.logger.log_level
;
the following entry does nothing:
quiet: true
Jekyll_plugin_logger To the Rescue!
Jekyll_plugin_logger
provides 2 classes:
PluginMetaLogger
–PluginLogger
factory and top-level logger.PluginLogger
– Logger dedicated to a specific Jekyll plugin.
PluginMetaLogger
provides each Jekyll plugin its own PluginLogger
instance.
This allows each plugin's log level to be individually controlled.
debug
level output is colored magenta.info
level output is colored cyan.warn
level output is colored yellow.error
level output is colored red.
The current version does not allow the colors for each log level to be customized. Please create an issue if that feature would be useful to you.
Background
As you may know, Jekyll sets site.config
by parsing _config.yml
as YAML.
When Jekyll_plugin_logger
is asked to create a logger,
it looks within site.config
for a key corresponding to the plugin progname
,
which is by default the name of the enclosing scope (a module or class) that the plugin is created for.
For example, if the plugin's class is called MyPlugin1
,
then an entry called plugin_loggers.MyPlugin1
would be read from the site configuration, if present.
If no such entry is found,
then the log_level
for that logger is set to info
.
plugin_loggers: PluginMetaLogger: info MyPlugin1: warn MyPlugin2: error MyPlugin3: debug
When the plugin is loaded, a Jekyll site
hook is invoked that instantiates the PluginMetaLogger
singleton.
At this time, the plugin_loggers
key values are retrieved from the Jekyll site configuration.
PluginMetaLogger
will construct a PluginLogger
instance for each value found,
with the log level specified in _config.yml
.
PluginMetaLogger.instance.config
holds the site.config
read from _config.yml
.
In the above _config.yml
the PluginMetaLogger
is constructed with log level info
.
Example Usage
Below is a high-level example of how to create and use this plugin.
The site.config
is retrieved from PluginMetaLogger.instance.config
; for some plugins, that information is provided as a site
parameter.
In that circumstance, site.config
is a less verbose method of obtaining the same information.
module MyPlugin1 @logger = PluginMetaLogger.instance.new_logger(self, PluginMetaLogger.instance.config) def my_plugin_method(text, query) @logger.debug { "text='#{text}' query='#{query}'" } # TODO write the rest of the method end # TODO write the rest of the plugin end PluginMetaLogger.instance.info { "Loaded my_plugin_1 v0.1.0 plugin." } # Register MyPlugin1 here
By default, the above causes output to appear on the console like this:
INFO PluginMetaLogger: Loaded my_plugin_1 v0.1.0 plugin. DEBUG MyPlugin1: text='Hello world' query='Bogus query'
Take a look at
my begin_end
plugin
for a complete example.
Do Not Use Simple Strings
These log messages are always computed, needed or not:
@logger.info "Information message" @logger.warn("Warning message") @logger.error "Error message"
Use Blocks Instead
The following blocks are not evaluated unless log_level
for that requires them to be.
This means your Jekyll site will regenerate quickly when log_level
is set high enough to suppress most output.
@logger.info { "Information message" } @logger.warn { "Warning message" } @logger.error { "Error message" }
Proof That Blocks Are Lazily Evaluated
Below is a simple example that demonstrates Ruby blocks are lazily evaluated.
Output from the block passed to the test
method results each time the block is evaluated.
As you can see, it is never evaluated.
This is because blocks in Ruby are only evaluated when invoked,
they are somewhat similar to call by reference,
and are definitely not call by value.
$ irb irb(main):001:0> def test; yield if false; end => :test irb(main):002:0> test { puts "hi" } => nil
For More Information
More information is available about this plugin from its GitHub project at
github.com/mslinn/jekyll_plugin_logger
.
This plugin is provided as a Ruby gem at rubygems.org/gems/jekyll_plugin_logger
.
Acknowledgements
Thanks to Ashwin Maroli (@ashmaroli) for his kind assistance.