Published 2020-12-28.
Time to read: about 3 minutes.

This article is categorized under Jekyll, Ruby

Debugging Jekyll plugins can be a challenge, but a configurable logging facility can be a big help. Writing puts statements to generate output does work, but they 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 STDERR, and control the output by setting the log level for the plugin’s logger.

Loggers are cheap – and easy to set up. Be sure to set the log level to warn or error when you are not debugging, so site generation goes full speed.

Use a new logger for each plugin that you write. At the end of this article I have provided the source code for logger_factory.rb, a Ruby library routine that I wrote which allows you to quickly make custom loggers for your plugins.

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 is configured with a colorizer, 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 "This green text is written to STDOUT".green

log.warn "This cyan text is written to STDERR because
that is how the logger is configured".cyan

This green text is written to STDOUT

This cyan text is written to STDERR because that is how the logger is configured

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 logger_factory.rb I provide later in this article.

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 your 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

Custom Ruby Logger To the Rescue!

Here is a working code example for a tag plugin that shows how to set up a custom logger in a plugin. While this code works, and is quite useful, I have packaged this code into a library routine that is more convenient to set up. You will read all about the library routine later in this article. But first, please read through this section so you understand how the library routine works.

• The logger, called log, is defined at the module scope. Output can be sent to STDOUT or STDERR.
• An accessor is defined called self.log, which is invoked as MyPlugin.log from within module classes.
• The logger output does not include a timestamp because that is generally not helpful.
• The program name that is passed to @@log.progname is also used to register the plugin with Jekyll. This ensures that the program name displayed in the log output corresponds to the registered name for the Jekyll plugin.

require 'logger'

module MyPlugin
  # See https://ruby-doc.org/stdlib-2.7.1/libdoc/logger/rdoc/Logger.html
  @@log = Logger.new(STDERR)  # Could send output to STDOUT
  @@log.level = Logger::WARN
  @@log.progname = 'my_tag_name'
  @@log.formatter = proc { |severity, datetime, progname, msg|
    "#{severity} #{progname}: #{msg}\n"
  }

  def self.log
    @@log
  end

  class MyClass < Liquid::Tag
    # Write output to the custom logger like this:
    MyPlugin.log.info "Hello, world"
    MyPlugin.log.warn "You can colorize the log output".yellow
  end
end

Liquid::Template.register_tag(MyPlugin.log.progname, MyPlugin::MyClass)

The above works fine, but it is tedious to apply to every plugin. We need a logger factory for creating loggers in a standard way.

logger_factory.rb

You have options for how you might download this F/OSS library plugin. Pick an option and save to a file in your Jekyll-powered site called _plugins/logger_factory.rb. Placing the file within the _plugins/ directory will make this library class available to all your Jekyll plugins by following the instructions I will provide in a moment. Your options are:

1. Download a zip file containing all the F/OSS Jekyll plugins I publish.
2. Copy the following code to your clipboard by clicking on the clipboard icon at the top right of the code container, then save the code to a file in your Jekyll-powered site called _plugins/logger_factory.rb.

logger_factory.rb

# frozen_string_literal: true

# @author Copyright 2020 Michael Slinn
# @license SPDX-License-Identifier: Apache-2.0

# Looks within _config.yml for a key corresponding to the plugin progname.
# For example, if the plugin's progname has value "abc" then an entry called logger_factory.abc 
# will be read from the config file, if present.
# If the entry exists, its value overrides the value specified when create_logger() was called.
# If no such entry is found then the log_level value specified when create_logger() was called is used.
#
# @example Create a new logger using this code like this:
#   LoggerFactory.new.create_logger('my_tag_name', site.config, Logger::WARN, $stderr)
#
# For more information about the logging feature in the Ruby standard library,
# @see https://ruby-doc.org/stdlib-2.7.1/libdoc/logger/rdoc/Logger.html
class LoggerFactory
  require 'logger'

  # @param log_level [String, Symbol, Integer] can be specified as $stderr or $stdout,
  #   or an integer from 0..3 (inclusive),
  #   or as a case-insensitive string
  #   (`debug`, `info`, `warn`, `error`, or `DEBUG`, `INFO`, `WARN`, `ERROR`),
  #   or as a symbol (`:debug`, `:info`, `:warn`, `:error` ).
  #
  # @param config [YAML] is normally created by reading a YAML file such as Jekyll's `_config.yml`.
  #   When invoking from a Jekyll plugin, provide `site.config`, 
  #   which is available from all types of Jekyll plugins as `Jekyll.configuration({})`.
  #
  # @example  If `progname` has value `abc`, then the YAML to override the programmatically set log_level to `debug` is:
  #   logger_factory:
  #     abc: debug
  def create_logger(progname, config, log_level, stream_name)
    config_log_level = check_config_log_level(config: config, progname: progname)

    logger = Logger.new(stream_name)
    logger.level = config_log_level || log_level
    logger.progname = progname
    logger.formatter = proc { |severity, _, prog_name, msg|
      "#{severity} #{prog_name}: #{msg}\n"
    }
    logger
  end

  private

  # @param config [YAML] Configuration data that might contain a entry for `logger_factory`
  # @param progname [String] The name of the `config` subentry to look for underneath the `logger_factory` entry
  # @return [String, FalseClass]
  def check_config_log_level(config:, progname:)
    log_config = config['logger_factory']
    return false if log_config.nil?

    progname_log_level = log_config[progname]
    return false if progname_log_level.nil?

    progname_log_level
  end
end

The contents of logger_factory.rb defines a class called LoggerFactory. This class could be used to easily create custom loggers in any Ruby program. Following is a complete example of how you could use LoggerFactory in your Jekyll tag plugin.

jekyll_tag_template.rb

# frozen_string_literal: true

# @author Copyright 2020 {https://www.mslinn.com Michael Slinn}
# @license SPDX-License-Identifier: Apache-2.0
#
# Module-level description goes here.
#
# @example Heading for this example
#   Describe what this example does
#   {% my_tag_template "parameter" %}
#
# @example Heading for this example
#   Describe what this example does
#   {% my_tag_template "parameter" %}
module MyTagTemplate
  # Start of custom logger definition
  require_relative 'logger_factory' # include the source of logger_factory.rb into this program

  @log = LoggerFactory.new.create_logger('my_tag_template', Jekyll.configuration({}), :warn, $stderr)

  # This accessor allows classes in this module to use the logger.
  def self.log
    @log
  end

  # End of custom logger definition

  # This class implements the Jekyll tag functionality
  class MyTag < Liquid::Tag
    # Constructor.
    # @param tag_name [String] is the name of the tag, which we already know.
    # @param arguments [Hash, String, Liquid::Tag::Parser] the arguments from the tag.
    # @param tokens [Liquid::ParseContext] tokenized command line
    # @return [void]
    def initialize(tag_name, arguments, tokens)
      super(tag_name, arguments, tokens)
      MyTagTemplate.log.info "tag_name [#{tag_name.class}] = '#{tag_name}' [#{tag_name.class}]".green
      MyTagTemplate.log.info "arguments [#{arguments.class}] = '#{arguments}'".green

      # @site = context.registers[:site] # This variable is handy but not required
      # @config = @site.config # This variable is handy but not required
      # @mode = @config['env']['JEKYLL_ENV'] # This variable is handy but not required
      # MyTagTemplate.log.info "mode=#{@mode}".green

      @arguments = arguments
      @arguments = '' if @arguments.nil? || @arguments.empty?
    end

    # Method prescribed by the Jekyll plugin lifecycle.
    # @return [String]
    def render(context)
      @site = context.registers[:site]
      @config = @site.config
      @mode = @config['env']['JEKYLL_ENV']
      MyTagTemplate.log.info "mode='#{@mode}'".green

      @page = context.registers[:page]
      MyTagTemplate.log.info "page.path='#{@page.path}'".green
      MyTagTemplate.log.info "page.url='#{@page.url}'".green


      <<~HEREDOC
        <p style="color: green; background-color: yellow; padding: 1em; border: solid thin grey;">
          #{@arguments}
        </p>
      HEREDOC
    end
  end

  private

  # Describe the function's purpose
  # This is a link {https://domain.com with some text}.
  # @param parameter [String] Describe this parameter's purpose
  # @return [String, nil] Describe the return value
  def my_private_function(parameter)
    log.info "my_private_function.parameter=#{parameter}"
  end

  # parse, or return the args
  # @note you can pass in parsed args
  # @return [Liquid::Tag::Parser]
  def parse_args(args)
    return args if args.is_a?(Liquid::Tag::Parser) || args.is_a?(Hash)
    Liquid::Tag::Parser.new(
      @args
    )
  end
end

Liquid::Template.register_tag(MyTagTemplate.log.progname, MyTagTemplate::MyTag)

Acknowledgements

Thanks to Ashwin Maroli (@ashmaroli) for his kind assistance.

---

• Blog by category
• Blog by date
  • Previous post: Propagating Git Template Changes Downstream
  • Next post: Jekyll Plugin Template Collection