0 Recipes:Logging from Puppet

rarruda edited this page 2014-05-28 11:33:34 -07:00

Table of Contents

• JSON logging from puppet

JSON logging from puppet

Its possible for puppet (versions >= 3.4) to output logstash valid json by configuring the logging output to logstash_event as in the example below:

puppet agent --logdest logstash_event

However it does just write json to STDOUT. Its possible to pipe its output to a log file, but then one would miss the ability to follow the progress of the puppet run in real time in the terminal. Additionally looking at json fly by the terminal is not a very appealing proposition to most people...

So in order to both:

• write to a log file for further processing by logstash
• see what puppet is doing, while it runs

We can use tee together a small ruby script so one can have both functionalities:

puppet agent --logdest logstash_event | tee -a /var/log/puppet/puppet.json.log | ~/bin/logstash_event2console.rb

And here is the logstash_event2console.rb script to convert from puppet's json output to regular output.

And for bonus points you also get with it:

• you can pick if you want to see the output with ansi colors or not.
• you get to see how long did each operation in puppet took (similar to https://github.com/rodjek/puppet-profiler)

#!/usr/bin/env ruby
require 'json'
require 'optparse'

#
# Read from STDIN logstash_event json string from puppet, and output what the puppet console logdest does.
#
# Sample use:
# $ puppet (agent|apply) --noop --logdest logstash_event | tee /tmp/logstash_event.log | ~/logstash_event2console.rb
#

$options = { }
$options[:color] = 'ansi'
$options[:time]  = false
opt_parser = OptionParser.new do |opt|
  opt.separator  ""
  opt.separator  "Options"
  opt.on("-c","--color=(ansi|false)", "should the output include or not colors.", String) do |color|
    $options[:color] = color
  end
  opt.on("-t","--time", "output timestamps as well.", String) do |color|
    $options[:time] = true
  end

  opt.on("-h","--help","help") do
    puts opt_parser
    exit 0
  end
end
opt_parser.parse!

ANSI_COLOR = {
  :hred  => "\e[31m",
  :reset => "\e[0m",
  :green => "\e[32m",
  :cyan  => "\e[36m",
  :yellow=> "\e[33m",
  :white => "\e[37m",
  :blue  => "\e[30m",
  :magenta => "\e[35m",
}

# warnings are red, but written to stdout, to not trigger failure in bamboo.
LEVELS = {
  'emerg'   => { :name => 'Emergency', :color => :hred,  :stream => $stderr },
  'alert'   => { :name => 'Alert',     :color => :hred,  :stream => $stderr },
  'crit'    => { :name => 'Critical',  :color => :hred,  :stream => $stderr },
  'err'     => { :name => 'Error',     :color => :hred,  :stream => $stderr },
  'warning' => { :name => 'Warning',   :color => :hred,  :stream => $stdout },

  'notice'  => { :name => 'Notice',    :color => :reset, :stream => $stdout },
  'info'    => { :name => 'Info',      :color => :green, :stream => $stdout },
  'debug'   => { :name => 'Debug',     :color => :cyan,  :stream => $stdout },
}


def colorize( color, message )
  if $options[:color] == 'ansi'
    return "#{ANSI_COLOR[color]}#{message}#{ANSI_COLOR[:reset]}"
  else
    return message
  end
end


event = { }
str_pre = ''
ARGF.each do |line|
  begin
    event = JSON.parse(line)
    str = event['message']
    str = event['source'] == "Puppet" ? str : "#{event['source']}: #{str}"
  rescue => e
    # level: notice unless stated otherwise:
    event['level'] = 'notice'
    cllevel = line.gsub(/: .*/,'').strip

    # in case the output is really broken, we escalate it to warning (maybe should be error?)
    if cllevel.length > 20
      cllevel = 'Warning'
    end

    LEVELS.each{|k,h| if h[:name] == cllevel ; event['level'] = k; end }
    str = 'non-json: '+line.rstrip
  end

  if $options[:time]
    str_pre = event['@timestamp']+' '
  end
  level = LEVELS[event['level']]
  level[:stream].puts colorize(level[:color], "#{str_pre}#{level[:name]}: #{str}")

  #puts JSON.pretty_generate(event)
end

Hello! I'm your friendly footer. If you're actually reading this, I'm impressed. :)