Skip to content

Instantly share code, notes, and snippets.

@thinkerbot

thinkerbot/README.md

Created September 27, 2011 21:54
Show Gist options
  • Save thinkerbot/1246359 to your computer and use it in GitHub Desktop.
Save thinkerbot/1246359 to your computer and use it in GitHub Desktop.
Download ZIP

Revisions

  1. @pinnacol-schiang pinnacol-schiang revised this gist Oct 24, 2011. 1 changed file with 11 additions and 7 deletions.
    18 changes: 11 additions & 7 deletions README.md
    View file
    Original file line number Diff line number Diff line change
    @@ -38,16 +38,20 @@ Then restart syslogd:
    Recommendations
    ----------------

    It's a good idea to intentionally use string formatting (ie %), 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 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.
    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](http://www.faqs.org/rfcs/rfc5426.html) RFC:
    From the [Transmission of Syslog Messages over
    UDP](http://www.faqs.org/rfcs/rfc5426.html) RFC:

    IPv4 syslog receivers MUST be able to receive datagrams with message
    sizes up to and including 480 octets. IPv6 syslog receivers MUST be
  2. @pinnacol-schiang pinnacol-schiang revised this gist Oct 24, 2011. 1 changed file with 21 additions and 20 deletions.
    41 changes: 21 additions & 20 deletions README.md
    View file
    Original file line number Diff line number Diff line change
    @@ -1,30 +1,32 @@
    Setup
    ===================================================================

    To test syslog, you have to setup syslog. Setting up syslog is system-specific
    and potentially quite variable because they frequently run syslogd
    replacements like rsyslogd (Ubuntu) or syslogd-ng. OSX has it's own internal
    system logger (the apple system logger) that supports the syslog API, but then
    adds additional stuff (like the 'syslog' command line application).
    This gist tests various aspects of syslog from Ruby. In order to do so you
    have to setup syslog first.

    The idea is to add syslog configs to write to '/var/log/local2.log' for the
    local2 facility. In all cases, test with this:
    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

    Should print the 'hello world' log. These tests allow an alternate log file
    and/or facility via the SYSLOG\_TEST\_LOG\_FILE and SYSLOG\_TEST\_FACILITY
    environment variables.
    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 config, for a fairly standard syslogd (although it
    does not have the bells of something like the [syslogd on
    OS X has a fairly standard syslog config (side note - it does not have the
    bells of the [syslogd on
    FreeBSD](http://www.freebsd.org/doc/handbook/configtuning-configfiles.html)).

    Add to /etc/syslog.conf
    Add this to /etc/syslog.conf:

    local2.* /var/log/local2.log

    @@ -36,16 +38,15 @@ Then restart syslogd:
    Recommendations
    ----------------

    Given the actual behavior of what successfully transmits over UDP and writes
    to a log file, it's a bad idea to rely on messages longer than 1k. There's a
    break point somewhere between 1k and 2k.

    It's a good idea to intentionally use string formatting, to prevent the chance
    of extra arguments getting passed in and busting Syslog. Lastly, null
    It's a good idea to intentionally use string formatting (ie %), 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 best practice is
    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](http://www.faqs.org/rfcs/rfc5426.html) RFC:

    IPv4 syslog receivers MUST be able to receive datagrams with message
  3. @pinnacol-schiang pinnacol-schiang revised this gist Oct 24, 2011. 2 changed files with 0 additions and 140 deletions.
    103 changes: 0 additions & 103 deletions testsyslog_test.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -1,103 +0,0 @@
    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
    37 changes: 0 additions & 37 deletions testtest_helper.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -1,37 +0,0 @@
    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
  4. thinkerbot revised this gist Sep 30, 2011. 1 changed file with 8 additions and 9 deletions.
    17 changes: 8 additions & 9 deletions README.md
    View file
    Original file line number Diff line number Diff line change
    @@ -46,14 +46,13 @@ characters need to be escaped to prevent truncation, and there is some strange
    escaping with carriage returns and line feeds. Basically the best practice is
    to scrub for anything but alphanumeric and punctuation characters.

    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.
    From the [Transmission of Syslog Messages over UDP](http://www.faqs.org/rfcs/rfc5426.html) RFC:

    See:
    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.

    * [The Syslog Protocol](http://tools.ietf.org/html/rfc5424)
    * [Transmission of Syslog Messages over UDP](http://www.faqs.org/rfcs/rfc5426.html)
    See also [the Syslog Protocol](http://tools.ietf.org/html/rfc5424) RFC.
  5. thinkerbot revised this gist Sep 30, 2011. 1 changed file with 2 additions and 1 deletion.
    3 changes: 2 additions & 1 deletion README.md
    View file
    Original file line number Diff line number Diff line change
    @@ -33,7 +33,8 @@ Then restart syslogd:
    sudo launchctl unload /System/Library/LaunchDaemons/com.apple.syslogd.plist
    sudo launchctl load /System/Library/LaunchDaemons/com.apple.syslogd.plist

    == Recommendations
    Recommendations
    ----------------

    Given the actual behavior of what successfully transmits over UDP and writes
    to a log file, it's a bad idea to rely on messages longer than 1k. There's a
  6. thinkerbot revised this gist Sep 30, 2011. 3 changed files with 143 additions and 3 deletions.
    6 changes: 3 additions & 3 deletions README.md
    View file
    Original file line number Diff line number Diff line change
    @@ -22,7 +22,7 @@ OS X

    OS X has a fairly standard config, for a fairly standard syslogd (although it
    does not have the bells of something like the [syslogd on
    FreeBSD][http://www.freebsd.org/doc/handbook/configtuning-configfiles.html]).
    FreeBSD](http://www.freebsd.org/doc/handbook/configtuning-configfiles.html)).

    Add to /etc/syslog.conf

    @@ -54,5 +54,5 @@ to scrub for anything but alphanumeric and punctuation characters.

    See:

    * [The Syslog Protocol][http://tools.ietf.org/html/rfc5424]
    * [Transmission of Syslog Messages over UDP][http://www.faqs.org/rfcs/rfc5426.html]
    * [The Syslog Protocol](http://tools.ietf.org/html/rfc5424)
    * [Transmission of Syslog Messages over UDP](http://www.faqs.org/rfcs/rfc5426.html)
    103 changes: 103 additions & 0 deletions testsyslog_test.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,103 @@
    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
    37 changes: 37 additions & 0 deletions testtest_helper.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,37 @@
    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
  7. @pinnacol-schiang pinnacol-schiang revised this gist Sep 29, 2011. 2 changed files with 28 additions and 7 deletions.
    33 changes: 27 additions & 6 deletions test/syslog_test.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -19,18 +19,39 @@ def test_syslog_from_ruby
    assert_log "informing", "warning"
    end

    def test_syslog_with_newline_is_treated_as_a_literal_sequence
    def test_syslog_preserves_whitespace
    syslog do |log|
    log.info "abc\nxyz"
    log.info " abc "
    end
    assert_log 'abc\nxyz'
    assert_log " abc "
    end

    def test_syslog_with_carraige_return_is_converted_to_unicode_presentation
    def test_syslog_strips_trailing_newlines
    syslog do |log|
    log.info "abc\rxyz"
    log.info "abc\n\n\n"
    end
    assert_log 'abc^Mxyz'
    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
    2 changes: 1 addition & 1 deletion test/test_helper.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -28,7 +28,7 @@ def assert_log(*expected)
    pairs = lines.zip(expected)

    pairs.each_with_index do |(line, message), n|
    unless line && line.include?(message)
    unless line && line[-message.length..-1] == message
    flunk "[#{n}] != #{message.inspect}\n#{line.inspect}"
    end
    assert true
  8. @pinnacol-schiang pinnacol-schiang revised this gist Sep 29, 2011. 1 changed file with 1 addition and 1 deletion.
    2 changes: 1 addition & 1 deletion test/syslog_test.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -26,7 +26,7 @@ def test_syslog_with_newline_is_treated_as_a_literal_sequence
    assert_log 'abc\nxyz'
    end

    def test_syslog_with_carraige_return_is_converted_to_something
    def test_syslog_with_carraige_return_is_converted_to_unicode_presentation
    syslog do |log|
    log.info "abc\rxyz"
    end
  9. @pinnacol-schiang pinnacol-schiang revised this gist Sep 29, 2011. 1 changed file with 24 additions and 0 deletions.
    24 changes: 24 additions & 0 deletions README.md
    View file
    Original file line number Diff line number Diff line change
    @@ -32,3 +32,27 @@ Then restart syslogd:

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

    == Recommendations

    Given the actual behavior of what successfully transmits over UDP and writes
    to a log file, it's a bad idea to rely on messages longer than 1k. There's a
    break point somewhere between 1k and 2k.

    It's a good idea to intentionally use string formatting, 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 best practice is
    to scrub for anything but alphanumeric and punctuation characters.

    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:

    * [The Syslog Protocol][http://tools.ietf.org/html/rfc5424]
    * [Transmission of Syslog Messages over UDP][http://www.faqs.org/rfcs/rfc5426.html]
  10. @pinnacol-schiang pinnacol-schiang revised this gist Sep 29, 2011. 1 changed file with 21 additions and 0 deletions.
    21 changes: 21 additions & 0 deletions test/syslog_test.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -26,13 +26,34 @@ def test_syslog_with_newline_is_treated_as_a_literal_sequence
    assert_log 'abc\nxyz'
    end

    def test_syslog_with_carraige_return_is_converted_to_something
    syslog do |log|
    log.info "abc\rxyz"
    end
    assert_log 'abc^Mxyz'
    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|
  11. @pinnacol-schiang pinnacol-schiang revised this gist Sep 28, 2011. 2 changed files with 9 additions and 35 deletions.
    39 changes: 8 additions & 31 deletions test/syslog_test.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -6,6 +6,7 @@ class SyslogTest < Test::Unit::TestCase

    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

    @@ -47,38 +48,14 @@ def test_syslog_with_null_truncates_message
    assert_log 'ab'
    end

    def test_syslog_with_1k_messages
    def test_syslog_up_to_10k_message
    s1k = '.' * 1024
    syslog do |log|
    log.info s1k
    end
    assert_log s1k
    end

    # Apparently fails at: ~1860 (usually 1857)
    # def test_where_syslog_length_fails
    # counts = []
    # 10.times do
    # reset
    # 1024.upto(2048) do |i|
    # syslog do |log|
    # log.info "%0#{i}d", i
    # end
    # end
    # sleep 1
    # last = newlines.last
    # last =~ /([1-9]\d*)$/
    # counts << [$1, last.length].join("\t")
    # end
    # puts
    # puts counts.join("\n")
    # end

    def test_syslog_with_2k_message
    s2k = '.' * 1024 * 2
    syslog do |log|
    log.info s2k
    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
    assert_log s2k
    end
    end
    5 changes: 1 addition & 4 deletions test/test_helper.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -1,13 +1,10 @@
    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 setup
    super
    end

    def tail(n)
    `tail -n #{n} '#{SYSLOG_TEST_LOG_FILE}'`
    end
  12. @pinnacol-schiang pinnacol-schiang revised this gist Sep 28, 2011. 3 changed files with 30 additions and 47 deletions.
    7 changes: 6 additions & 1 deletion README.md
    View file
    Original file line number Diff line number Diff line change
    @@ -24,6 +24,11 @@ OS X has a fairly standard config, for a fairly standard syslogd (although it
    does not have the bells of something like the [syslogd on
    FreeBSD][http://www.freebsd.org/doc/handbook/configtuning-configfiles.html]).

    echo 'local2.* /var/log/local2.log' > /etc/syslog.config
    Add 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
    35 changes: 11 additions & 24 deletions test/syslog_test.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -5,11 +5,8 @@ class SyslogTest < Test::Unit::TestCase
    include TestHelper

    def test_new_content_for_syslog
    assert newlines.empty?
    reset

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

    def test_syslog_from_ruby
    @@ -18,52 +15,44 @@ def test_syslog_from_ruby
    log.info "informing"
    log.warning "warning"
    end
    sleep 0.1
    assert_log 0, "informing"
    assert_log 1, "warning"
    assert_log "informing", "warning"
    end

    def test_syslog_with_newline_is_treated_as_a_literal_sequence
    syslog do |log|
    log.info "abc\nxyz"
    end
    sleep 0.1
    assert_log 0, 'abc\nxyz'
    assert_log 'abc\nxyz'
    end

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

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

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

    def test_syslog_with_1k_messages
    s1k = '.' * 1024

    syslog do |log|
    log.info s1k
    end
    sleep 0.1
    assert_log(0, s1k)
    assert_log s1k
    end

    # Apparently fails at: ~1860 (usually 1857)
    @@ -85,13 +74,11 @@ def test_syslog_with_1k_messages
    # puts counts.join("\n")
    # end

    def test_syslog_with_2k_messages_fails
    def test_syslog_with_2k_message
    s2k = '.' * 1024 * 2

    syslog do |log|
    log.info s2k
    end
    sleep 0.1
    assert newlines.empty?
    assert_log s2k
    end
    end
    35 changes: 13 additions & 22 deletions test/test_helper.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -6,44 +6,35 @@ module TestHelper

    def setup
    super
    reset
    end

    def reset
    @start_pos = File.exists?(SYSLOG_TEST_LOG_FILE) ? File.stat(SYSLOG_TEST_LOG_FILE).size : 0
    @newlines = nil
    end

    def newlines
    @newlines ||= begin
    if File.exists?(SYSLOG_TEST_LOG_FILE)
    File.open(SYSLOG_TEST_LOG_FILE) do |io|
    io.pos = @start_pos
    io.readlines
    end
    else
    []
    end
    end
    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, facilty)
    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(index, message)
    unless newlines[index].include?(message)
    flunk "[#{index}] != #{message.inspect}\n#{newlines.inspect}"
    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.include?(message)
    flunk "[#{n}] != #{message.inspect}\n#{line.inspect}"
    end
    assert true
    end
    assert true
    end
    end
  13. @pinnacol-schiang pinnacol-schiang revised this gist Sep 28, 2011. 1 changed file with 39 additions and 0 deletions.
    39 changes: 39 additions & 0 deletions test/syslog_test.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -55,4 +55,43 @@ def test_syslog_with_null_truncates_message
    sleep 0.1
    assert_log 0, 'ab'
    end

    def test_syslog_with_1k_messages
    s1k = '.' * 1024

    syslog do |log|
    log.info s1k
    end
    sleep 0.1
    assert_log(0, s1k)
    end

    # Apparently fails at: ~1860 (usually 1857)
    # def test_where_syslog_length_fails
    # counts = []
    # 10.times do
    # reset
    # 1024.upto(2048) do |i|
    # syslog do |log|
    # log.info "%0#{i}d", i
    # end
    # end
    # sleep 1
    # last = newlines.last
    # last =~ /([1-9]\d*)$/
    # counts << [$1, last.length].join("\t")
    # end
    # puts
    # puts counts.join("\n")
    # end

    def test_syslog_with_2k_messages_fails
    s2k = '.' * 1024 * 2

    syslog do |log|
    log.info s2k
    end
    sleep 0.1
    assert newlines.empty?
    end
    end
  14. @pinnacol-schiang pinnacol-schiang revised this gist Sep 28, 2011. 1 changed file with 33 additions and 0 deletions.
    33 changes: 33 additions & 0 deletions test/syslog_test.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -22,4 +22,37 @@ def test_syslog_from_ruby
    assert_log 0, "informing"
    assert_log 1, "warning"
    end

    def test_syslog_with_newline_is_treated_as_a_literal_sequence
    syslog do |log|
    log.info "abc\nxyz"
    end
    sleep 0.1
    assert_log 0, 'abc\nxyz'
    end

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

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

    def test_syslog_with_null_truncates_message
    syslog do |log|
    log.info "ab\0c"
    end
    sleep 0.1
    assert_log 0, 'ab'
    end
    end
  15. @pinnacol-schiang pinnacol-schiang revised this gist Sep 28, 2011. 1 changed file with 1 addition and 1 deletion.
    2 changes: 1 addition & 1 deletion test/test_helper.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -41,7 +41,7 @@ def syslog(tag=method_name, mask='info')
    end

    def assert_log(index, message)
    unless newlines[index] =~ /\[\d+\]: #{message}/
    unless newlines[index].include?(message)
    flunk "[#{index}] != #{message.inspect}\n#{newlines.inspect}"
    end
    assert true
  16. @pinnacol-schiang pinnacol-schiang revised this gist Sep 28, 2011. 1 changed file with 8 additions and 4 deletions.
    12 changes: 8 additions & 4 deletions test/test_helper.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -10,15 +10,19 @@ def setup
    end

    def reset
    @start_pos = File.stat(SYSLOG_TEST_LOG_FILE).size
    @start_pos = File.exists?(SYSLOG_TEST_LOG_FILE) ? File.stat(SYSLOG_TEST_LOG_FILE).size : 0
    @newlines = nil
    end

    def newlines
    @newlines ||= begin
    File.open(SYSLOG_TEST_LOG_FILE) do |io|
    io.pos = @start_pos
    io.readlines
    if File.exists?(SYSLOG_TEST_LOG_FILE)
    File.open(SYSLOG_TEST_LOG_FILE) do |io|
    io.pos = @start_pos
    io.readlines
    end
    else
    []
    end
    end
    end
  17. @pinnacol-schiang pinnacol-schiang revised this gist Sep 28, 2011. 1 changed file with 0 additions and 15 deletions.
    15 changes: 0 additions & 15 deletions Rakefile
    View file
    Original file line number Diff line number Diff line change
    @@ -1,15 +0,0 @@

    #
    # Test tasks
    #

    def current_ruby
    `ruby -v`.split[0,2].join('-')
    end

    desc 'Run the tests'
    task :test do
    puts "Using #{current_ruby}"
    tests = Dir.glob('test/**/*_test.rb')
    sh('ruby', '-w', '-e', 'ARGV.dup.each {|test| load test}', *tests)
    end
  18. @pinnacol-schiang pinnacol-schiang revised this gist Sep 27, 2011. 2 changed files with 44 additions and 3 deletions.
    14 changes: 14 additions & 0 deletions test/syslog_test.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -1,11 +1,25 @@
    require File.expand_path('../test_helper', __FILE__)
    require 'syslog'

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

    def test_new_content_for_syslog
    assert newlines.empty?
    reset

    system "logger -p local2.info -t example hello world"
    assert newlines[0] =~ /example\[\d+\]: hello world/
    end

    def test_syslog_from_ruby
    syslog do |log|
    log.debug "debugging"
    log.info "informing"
    log.warning "warning"
    end
    sleep 0.1
    assert_log 0, "informing"
    assert_log 1, "warning"
    end
    end
    33 changes: 30 additions & 3 deletions test/test_helper.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -6,13 +6,40 @@ module TestHelper

    def setup
    super
    reset
    end

    def reset
    @start_pos = File.stat(SYSLOG_TEST_LOG_FILE).size
    @newlines = nil
    end

    def newlines
    File.open(SYSLOG_TEST_LOG_FILE) do |io|
    io.pos = @start_pos
    io.readlines
    @newlines ||= begin
    File.open(SYSLOG_TEST_LOG_FILE) do |io|
    io.pos = @start_pos
    io.readlines
    end
    end
    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, facilty)
    Syslog.mask = Syslog::LOG_UPTO(level)
    yield Syslog
    ensure
    Syslog.close
    end
    end

    def assert_log(index, message)
    unless newlines[index] =~ /\[\d+\]: #{message}/
    flunk "[#{index}] != #{message.inspect}\n#{newlines.inspect}"
    end
    assert true
    end
    end
  19. @pinnacol-schiang pinnacol-schiang revised this gist Sep 27, 2011. 3 changed files with 44 additions and 0 deletions.
    15 changes: 15 additions & 0 deletions Rakefile
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,15 @@

    #
    # Test tasks
    #

    def current_ruby
    `ruby -v`.split[0,2].join('-')
    end

    desc 'Run the tests'
    task :test do
    puts "Using #{current_ruby}"
    tests = Dir.glob('test/**/*_test.rb')
    sh('ruby', '-w', '-e', 'ARGV.dup.each {|test| load test}', *tests)
    end
    11 changes: 11 additions & 0 deletions test/syslog_test.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,11 @@
    require File.expand_path('../test_helper', __FILE__)

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

    def test_new_content_for_syslog
    assert newlines.empty?
    system "logger -p local2.info -t example hello world"
    assert newlines[0] =~ /example\[\d+\]: hello world/
    end
    end
    18 changes: 18 additions & 0 deletions test/test_helper.rb
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,18 @@
    require 'test/unit'

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

    def setup
    super
    @start_pos = File.stat(SYSLOG_TEST_LOG_FILE).size
    end

    def newlines
    File.open(SYSLOG_TEST_LOG_FILE) do |io|
    io.pos = @start_pos
    io.readlines
    end
    end
    end
  20. @pinnacol-schiang pinnacol-schiang created this gist Sep 27, 2011.
    29 changes: 29 additions & 0 deletions README.md
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,29 @@
    Setup
    ===================================================================

    To test syslog, you have to setup syslog. Setting up syslog is system-specific
    and potentially quite variable because they frequently run syslogd
    replacements like rsyslogd (Ubuntu) or syslogd-ng. OSX has it's own internal
    system logger (the apple system logger) that supports the syslog API, but then
    adds additional stuff (like the 'syslog' command line application).

    The idea is to add syslog configs to write to '/var/log/local2.log' for the
    local2 facility. In all cases, test with this:

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

    Should print the 'hello world' log. These tests allow 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 config, for a fairly standard syslogd (although it
    does not have the bells of something like the [syslogd on
    FreeBSD][http://www.freebsd.org/doc/handbook/configtuning-configfiles.html]).

    echo 'local2.* /var/log/local2.log' > /etc/syslog.config
    sudo launchctl unload /System/Library/LaunchDaemons/com.apple.syslogd.plist
    sudo launchctl load /System/Library/LaunchDaemons/com.apple.syslogd.plist