README.md

Setup

This gist tests various aspects of syslog from Ruby. In order to do so you have to setup syslog first.

Setting up syslog is system-specific and quite variable because of variations like rsyslogd or syslogd-ng. OSX, for example, uses a custom system logger (the apple system logger) that supports the syslog API, but also adds additional stuff like the 'syslog' command line application.

The basic requirement is to make syslog to write to '/var/log/local2.log' using the local2 facility. If this prints a 'hello world' log message then these tests should run properly.

logger -s -p local2.info -t example hello world
grep example /var/log/local2.log

The tests can be configured to use an alternate log file and/or facility via the SYSLOG_TEST_LOG_FILE and SYSLOG_TEST_FACILITY environment variables.

OS X

OS X has a fairly standard syslog config (side note - it does not have the bells of the syslogd on FreeBSD).

Add this to /etc/syslog.conf:

local2.* /var/log/local2.log

Then restart syslogd:

sudo launchctl unload  /System/Library/LaunchDaemons/com.apple.syslogd.plist
sudo launchctl load  /System/Library/LaunchDaemons/com.apple.syslogd.plist

Recommendations

It's a good idea to intentionally use string formatting (ie '%s'), to prevent the chance of extra arguments getting passed in and busting Syslog. Lastly, null characters need to be escaped to prevent truncation, and there is some strange escaping with carriage returns and line feeds. Basically the safe practice is to scrub for anything but alphanumeric and punctuation characters.

It's a bad idea to rely on messages longer than 1k. There's a break point somewhere between 1k and 2k when logging to a file on many systems (although some systems allow for much larger messages). There are additional constraints when when logging across UDP, due to the protocol itself. I haven't seen problems below 1k but it gets complicated for larger messages.

From the Transmission of Syslog Messages over UDP RFC:

IPv4 syslog receivers MUST be able to receive datagrams with message
sizes up to and including 480 octets.  IPv6 syslog receivers MUST be
able to receive datagrams with message sizes up to and including 1180
octets.  All syslog receivers SHOULD be able to receive datagrams
with message sizes of up to and including 2048 octets.  The ability
to receive larger messages is encouraged.

See also the Syslog Protocol RFC.

syslog_test.rb

require File.expand_path('../test_helper', __FILE__)
require 'syslog'

class SyslogTest < Test::Unit::TestCase
  include TestHelper

  def test_new_content_for_syslog
    system "logger -p local2.info -t #{method_name} hello world"
    sleep 0.2
    assert tail(1) =~ /#{method_name}\[\d+\]: hello world/
  end

  def test_syslog_from_ruby
    syslog do |log|
      log.debug "debugging"
      log.info  "informing"
      log.warning "warning"
    end
    assert_log "informing", "warning"
  end

  def test_syslog_preserves_whitespace
    syslog do |log|
      log.info  "   abc   "
    end
    assert_log "   abc   "
  end

  def test_syslog_strips_trailing_newlines
    syslog do |log|
      log.info  "abc\n\n\n"
    end
    assert_log 'abc'
  end

  def test_syslog_with_internal_newline_is_escaped_to_a_literal_sequence
    syslog do |log|
      log.info  "abc\n\cJ\C-Jxyz"
    end
    assert_log 'abc\n\n\nxyz'
  end

  def test_syslog_with_tab_is_treated_as_a_tab
    syslog do |log|
      log.info  "\t\cI\C-I"
    end
    assert_log "\t\t\t"
  end

  def test_syslog_with_other_control_chars_are_converted_to_unicode_presentation
    syslog do |log|
      log.info "\a\b\e\f\r\v\cG\cH\c[\cL\cM\c?"
    end
    assert_log "^G^H^[^L^M^K^G^H^[^L^M^?"
  end

  def test_syslog_with_percent_substitution_and_variables
    syslog do |log|
      log.info  "a%sc", "b"
    end
    assert_log 'abc'
  end

  def test_syslog_with_percent_substitution_and_punctuation
    syslog do |log|
      log.info "%s", %q{`~!@#{$%^&*()_-+={[}}|;:<,>.?/"'}
    end
    assert_log %q{`~!@#{$%^&*()_-+={[}}|;:<,>.?/"'}
  end

  def test_syslog_with_percent_substitution_and_crlf
    syslog do |log|
      log.info "%s", %{abc\r\nxyz}
    end
    assert_log %{abc^M\\nxyz}
  end

  def test_syslog_with_percent_substitution_uses_ruby_sprintf
    obj = Object.new
    syslog do |log|
      log.info "%p", obj
    end
    assert_log obj.inspect
  end

  def test_syslog_with_null_truncates_message
    syslog do |log|
      log.info  "ab\0c"
    end
    assert_log 'ab'
  end

  def test_syslog_up_to_10k_message
    s1k = '.' * 1024
    1.upto(10) do |i|
      syslog do |log|
        log.info s1k * i
      end
      sleep 0.2
      assert tail(1).include?(s1k * i), "failed at #{i}k"
    end
  end
end

test_helper.rb

require 'test/unit'
require 'fileutils'

module TestHelper
  SYSLOG_TEST_FACILITY = ENV['SYSLOG_TEST_FACILITY'] || 'local2'
  SYSLOG_TEST_LOG_FILE = ENV['SYSLOG_TEST_LOG_FILE'] || '/var/log/local2.log'

  def tail(n)
    `tail -n #{n} '#{SYSLOG_TEST_LOG_FILE}'`
  end

  def syslog(tag=method_name, mask='info')
    facilty = Syslog.const_get("LOG_#{SYSLOG_TEST_FACILITY}".upcase)
    level   = Syslog.const_get("LOG_#{mask}".upcase)

    begin
      Syslog.open(method_name, Syslog::LOG_ODELAY | Syslog::LOG_CONS, facilty)
      Syslog.mask = Syslog::LOG_UPTO(level)
      yield Syslog
    ensure
      Syslog.close
    end
  end

  def assert_log(*expected)
    sleep 0.2
    lines = tail(expected.length).split("\n")
    pairs = lines.zip(expected)

    pairs.each_with_index do |(line, message), n|
      unless line && line[-message.length..-1] == message
        flunk "[#{n}] != #{message.inspect}\n#{line.inspect}"
      end
      assert true
    end
  end
end