RFC3164 parsing fails after the first message

[abligh]

See the enclosed test program (copied almost verbatim from your examples directory). When running the test program and the enclosed perl to generate syslog compliant with RFC3164, the output for the first run of the perl is correct, i.e.:

map[severity:6 timestamp:2015-06-30 20:17:25 +0000 UTC hostname:logger: tag:This content:is a test from me priority:6 facility:0]

but the output for the second and subsequent runs of the perl is:

map[hostname: tag: content: priority:0 facility:0 severity:0 timestamp:0001-01-01 00:00:00 +0000 UTC]

i.e. parsing is failing. Restarting the golang code fixes it.

Introducing an (unnecessary) \n into the perl log does not fix it.

Test code as follows.

package main

/* Perl test program logger.pl

#!/usr/bin/perl

use strict;
use warnings;
use Sys::Syslog qw(:standard :macros setlogsock);

setlogsock({type=>"udp", port=>10514});
openlog("logger", "ndelay", LOG_LOCAL0);    # don't forget this
syslog(LOG_INFO, "This is a test from %s", "me");
closelog();

*/

import (
    "fmt"
    "gopkg.in/mcuadros/go-syslog.v2"
)

func main() {
    // something here
    channel := make(syslog.LogPartsChannel)
    handler := syslog.NewChannelHandler(channel)

    server := syslog.NewServer()
    server.SetFormat(syslog.RFC3164)
    server.SetHandler(handler)
    server.ListenUDP("0.0.0.0:10514")
    server.Boot()

    go func(channel syslog.LogPartsChannel) {
        for logParts := range channel {
            fmt.Println(logParts)
        }
    }(channel)

    server.Wait()
}

[abligh]

Having run tcpdump the issue is that perl's Syslog routine (like many I believe) does not strictly conform to the standard.

Here's what a packet looks like:

17:17:35.646330 AF IPv4 (2), length 83: (tos 0x0, ttl 64, id 4594, offset 0, flags [none], proto UDP (17), length 79, bad cksum 0 (->6aaa)!)
    127.0.0.1.59804 > 127.0.0.1.10514: [bad udp cksum 0xfe4e -> 0x933c!] UDP, length 51
    0x0000:  4500 004f 11f2 0000 4011 0000 7f00 0001  E..O....@.......
    0x0010:  7f00 0001 e99c 2912 003b fe4e 3c36 3e4a  ......)..;.N<6>J
    0x0020:  756c 2020 3120 3137 3a31 373a 3335 206c  ul..1.17:17:35.l
    0x0030:  6f67 6765 723a 2054 6869 7320 6973 2061  ogger:.This.is.a
    0x0040:  2074 6573 7420 6672 6f6d 206d 650a 00    .test.from.me..

As you can see, the packet ends in an unwanted \n and a NUL. Neither of those should be present per RFC3164. I strongly suspect however that perl is not the only offender here.

What appears to be happen is that the go-syslog uses a bufio scanner which splits on \n. This is also wrong - see #10 - as the \n is not guaranteed to be there (indeed should not be there per RFC3164 which states all characters should be printable). However, it does split on that, and then the NUL is left in the buffer and prepended to the next (unrelated) UDP packet which happens to arrive.

I'm not sure of the right way to fix this. One could presumably supply a splitfunc which took \n(\0)+ as a delimiter, but that's only papering over the issue. The real issue it seems to me is that at least on UDP, there is no delimiter. The delimiter is the end of the UDP packet. Non printable trailing characters should just be ignored. This would also fix #10 .

[abligh]

This pull request should fix it: https://github.com/abligh/go-syslog/commit/df573444e870c589591445efd55b4c953580a83f