diff options
Diffstat (limited to 'src/pkg/log')
-rw-r--r-- | src/pkg/log/syslog/syslog.go | 239 | ||||
-rw-r--r-- | src/pkg/log/syslog/syslog_plan9.go | 8 | ||||
-rw-r--r-- | src/pkg/log/syslog/syslog_test.go | 339 | ||||
-rw-r--r-- | src/pkg/log/syslog/syslog_unix.go | 8 |
4 files changed, 469 insertions, 125 deletions
diff --git a/src/pkg/log/syslog/syslog.go b/src/pkg/log/syslog/syslog.go index f53310cb0..8bdd9825e 100644 --- a/src/pkg/log/syslog/syslog.go +++ b/src/pkg/log/syslog/syslog.go @@ -4,9 +4,13 @@ // +build !windows,!plan9 -// Package syslog provides a simple interface to the system log service. It -// can send messages to the syslog daemon using UNIX domain sockets, UDP, or -// TCP connections. +// Package syslog provides a simple interface to the system log +// service. It can send messages to the syslog daemon using UNIX +// domain sockets, UDP or TCP. +// +// Only one call to Dial is necessary. On write failures, +// the syslog client will attempt to reconnect to the server +// and write again. package syslog import ( @@ -15,11 +19,23 @@ import ( "log" "net" "os" + "strings" + "sync" + "time" ) +// The Priority is a combination of the syslog facility and +// severity. For example, LOG_ALERT | LOG_FTP sends an alert severity +// message from the FTP facility. The default severity is LOG_EMERG; +// the default facility is LOG_KERN. type Priority int +const severityMask = 0x07 +const facilityMask = 0xf8 + const ( + // Severity. + // From /usr/include/sys/syslog.h. // These are the same on Linux, BSD, and OS X. LOG_EMERG Priority = iota @@ -32,129 +48,220 @@ const ( LOG_DEBUG ) +const ( + // Facility. + + // From /usr/include/sys/syslog.h. + // These are the same up to LOG_FTP on Linux, BSD, and OS X. + LOG_KERN Priority = iota << 3 + LOG_USER + LOG_MAIL + LOG_DAEMON + LOG_AUTH + LOG_SYSLOG + LOG_LPR + LOG_NEWS + LOG_UUCP + LOG_CRON + LOG_AUTHPRIV + LOG_FTP + _ // unused + _ // unused + _ // unused + _ // unused + LOG_LOCAL0 + LOG_LOCAL1 + LOG_LOCAL2 + LOG_LOCAL3 + LOG_LOCAL4 + LOG_LOCAL5 + LOG_LOCAL6 + LOG_LOCAL7 +) + // A Writer is a connection to a syslog server. type Writer struct { priority Priority - prefix string - conn serverConn -} + tag string + hostname string + network string + raddr string -type serverConn interface { - writeBytes(p Priority, prefix string, b []byte) (int, error) - writeString(p Priority, prefix string, s string) (int, error) - close() error + mu sync.Mutex // guards conn + conn net.Conn } -type netConn struct { - conn net.Conn +// New establishes a new connection to the system log daemon. Each +// write to the returned writer sends a log message with the given +// priority and prefix. +func New(priority Priority, tag string) (w *Writer, err error) { + return Dial("", "", priority, tag) } -// New establishes a new connection to the system log daemon. -// Each write to the returned writer sends a log message with -// the given priority and prefix. -func New(priority Priority, prefix string) (w *Writer, err error) { - return Dial("", "", priority, prefix) +// Dial establishes a connection to a log daemon by connecting to +// address raddr on the network net. Each write to the returned +// writer sends a log message with the given facility, severity and +// tag. +func Dial(network, raddr string, priority Priority, tag string) (*Writer, error) { + if priority < 0 || priority > LOG_LOCAL7|LOG_DEBUG { + return nil, errors.New("log/syslog: invalid priority") + } + + if tag == "" { + tag = os.Args[0] + } + hostname, _ := os.Hostname() + + w := &Writer{ + priority: priority, + tag: tag, + hostname: hostname, + network: network, + raddr: raddr, + } + + w.mu.Lock() + defer w.mu.Unlock() + + err := w.connect() + if err != nil { + return nil, err + } + return w, err } -// Dial establishes a connection to a log daemon by connecting -// to address raddr on the network net. -// Each write to the returned writer sends a log message with -// the given priority and prefix. -func Dial(network, raddr string, priority Priority, prefix string) (w *Writer, err error) { - if prefix == "" { - prefix = os.Args[0] +// connect makes a connection to the syslog server. +// It must be called with w.mu held. +func (w *Writer) connect() (err error) { + if w.conn != nil { + // ignore err from close, it makes sense to continue anyway + w.conn.Close() + w.conn = nil } - var conn serverConn - if network == "" { - conn, err = unixSyslog() + + if w.network == "" { + w.conn, err = unixSyslog() + if w.hostname == "" { + w.hostname = "localhost" + } } else { var c net.Conn - c, err = net.Dial(network, raddr) - conn = netConn{c} + c, err = net.Dial(w.network, w.raddr) + if err == nil { + w.conn = c + if w.hostname == "" { + w.hostname = c.LocalAddr().String() + } + } } - return &Writer{priority, prefix, conn}, err + return } // Write sends a log message to the syslog daemon. func (w *Writer) Write(b []byte) (int, error) { - if w.priority > LOG_DEBUG || w.priority < LOG_EMERG { - return 0, errors.New("log/syslog: invalid priority") - } - return w.conn.writeBytes(w.priority, w.prefix, b) + return w.writeAndRetry(w.priority, string(b)) } -func (w *Writer) writeString(p Priority, s string) (int, error) { - return w.conn.writeString(p, w.prefix, s) -} +// Close closes a connection to the syslog daemon. +func (w *Writer) Close() error { + w.mu.Lock() + defer w.mu.Unlock() -func (w *Writer) Close() error { return w.conn.close() } + if w.conn != nil { + err := w.conn.Close() + w.conn = nil + return err + } + return nil +} -// Emerg logs a message using the LOG_EMERG priority. +// Emerg logs a message with severity LOG_EMERG, ignoring the severity +// passed to New. func (w *Writer) Emerg(m string) (err error) { - _, err = w.writeString(LOG_EMERG, m) + _, err = w.writeAndRetry(LOG_EMERG, m) return err } -// Alert logs a message using the LOG_ALERT priority. +// Alert logs a message with severity LOG_ALERT, ignoring the severity +// passed to New. func (w *Writer) Alert(m string) (err error) { - _, err = w.writeString(LOG_ALERT, m) + _, err = w.writeAndRetry(LOG_ALERT, m) return err } -// Crit logs a message using the LOG_CRIT priority. +// Crit logs a message with severity LOG_CRIT, ignoring the severity +// passed to New. func (w *Writer) Crit(m string) (err error) { - _, err = w.writeString(LOG_CRIT, m) + _, err = w.writeAndRetry(LOG_CRIT, m) return err } -// Err logs a message using the LOG_ERR priority. +// Err logs a message with severity LOG_ERR, ignoring the severity +// passed to New. func (w *Writer) Err(m string) (err error) { - _, err = w.writeString(LOG_ERR, m) + _, err = w.writeAndRetry(LOG_ERR, m) return err } -// Warning logs a message using the LOG_WARNING priority. +// Wanring logs a message with severity LOG_WARNING, ignoring the +// severity passed to New. func (w *Writer) Warning(m string) (err error) { - _, err = w.writeString(LOG_WARNING, m) + _, err = w.writeAndRetry(LOG_WARNING, m) return err } -// Notice logs a message using the LOG_NOTICE priority. +// Notice logs a message with severity LOG_NOTICE, ignoring the +// severity passed to New. func (w *Writer) Notice(m string) (err error) { - _, err = w.writeString(LOG_NOTICE, m) + _, err = w.writeAndRetry(LOG_NOTICE, m) return err } -// Info logs a message using the LOG_INFO priority. +// Info logs a message with severity LOG_INFO, ignoring the severity +// passed to New. func (w *Writer) Info(m string) (err error) { - _, err = w.writeString(LOG_INFO, m) + _, err = w.writeAndRetry(LOG_INFO, m) return err } -// Debug logs a message using the LOG_DEBUG priority. +// Debug logs a message with severity LOG_DEBUG, ignoring the severity +// passed to New. func (w *Writer) Debug(m string) (err error) { - _, err = w.writeString(LOG_DEBUG, m) + _, err = w.writeAndRetry(LOG_DEBUG, m) return err } -func (n netConn) writeBytes(p Priority, prefix string, b []byte) (int, error) { - _, err := fmt.Fprintf(n.conn, "<%d>%s: %s\n", p, prefix, b) - if err != nil { +func (w *Writer) writeAndRetry(p Priority, s string) (int, error) { + pr := (w.priority & facilityMask) | (p & severityMask) + + w.mu.Lock() + defer w.mu.Unlock() + + if w.conn != nil { + if n, err := w.write(pr, s); err == nil { + return n, err + } + } + if err := w.connect(); err != nil { return 0, err } - return len(b), nil + return w.write(pr, s) } -func (n netConn) writeString(p Priority, prefix string, s string) (int, error) { - _, err := fmt.Fprintf(n.conn, "<%d>%s: %s\n", p, prefix, s) - if err != nil { - return 0, err +// write generates and writes a syslog formatted string. The +// format is as follows: <PRI>TIMESTAMP HOSTNAME TAG[PID]: MSG +func (w *Writer) write(p Priority, msg string) (int, error) { + // ensure it ends in a \n + nl := "" + if !strings.HasSuffix(msg, "\n") { + nl = "\n" } - return len(s), nil -} -func (n netConn) close() error { - return n.conn.Close() + timestamp := time.Now().Format(time.RFC3339) + fmt.Fprintf(w.conn, "<%d>%s %s %s[%d]: %s%s", + p, timestamp, w.hostname, + w.tag, os.Getpid(), msg, nl) + return len(msg), nil } // NewLogger creates a log.Logger whose output is written to diff --git a/src/pkg/log/syslog/syslog_plan9.go b/src/pkg/log/syslog/syslog_plan9.go new file mode 100644 index 000000000..0c05f6f83 --- /dev/null +++ b/src/pkg/log/syslog/syslog_plan9.go @@ -0,0 +1,8 @@ +// Copyright 2012 The Go Authors. All rights reserved. +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +// Package syslog provides a simple interface to the system log service. +package syslog + +// BUG(akumar): This package is not implemented on Plan 9 yet. diff --git a/src/pkg/log/syslog/syslog_test.go b/src/pkg/log/syslog/syslog_test.go index 0fd623905..ec4525190 100644 --- a/src/pkg/log/syslog/syslog_test.go +++ b/src/pkg/log/syslog/syslog_test.go @@ -7,52 +7,181 @@ package syslog import ( + "bufio" + "fmt" "io" + "io/ioutil" "log" "net" + "os" + "sync" "testing" "time" ) -var serverAddr string - -func runSyslog(c net.PacketConn, done chan<- string) { +func runPktSyslog(c net.PacketConn, done chan<- string) { var buf [4096]byte - var rcvd string = "" + var rcvd string + ct := 0 for { - n, _, err := c.ReadFrom(buf[0:]) - if err != nil || n == 0 { + var n int + var err error + + c.SetReadDeadline(time.Now().Add(100 * time.Millisecond)) + n, _, err = c.ReadFrom(buf[:]) + rcvd += string(buf[:n]) + if err != nil { + if oe, ok := err.(*net.OpError); ok { + if ct < 3 && oe.Temporary() { + ct++ + continue + } + } break } - rcvd += string(buf[0:n]) } + c.Close() done <- rcvd } -func startServer(done chan<- string) { - c, e := net.ListenPacket("udp", "127.0.0.1:0") - if e != nil { - log.Fatalf("net.ListenPacket failed udp :0 %v", e) +var crashy = false + +func runStreamSyslog(l net.Listener, done chan<- string, wg *sync.WaitGroup) { + for { + var c net.Conn + var err error + if c, err = l.Accept(); err != nil { + return + } + wg.Add(1) + go func(c net.Conn) { + defer wg.Done() + c.SetReadDeadline(time.Now().Add(5 * time.Second)) + b := bufio.NewReader(c) + for ct := 1; !crashy || ct&7 != 0; ct++ { + s, err := b.ReadString('\n') + if err != nil { + break + } + done <- s + } + c.Close() + }(c) } - serverAddr = c.LocalAddr().String() - c.SetReadDeadline(time.Now().Add(100 * time.Millisecond)) - go runSyslog(c, done) } -func skipNetTest(t *testing.T) bool { - if testing.Short() { - // Depends on syslog daemon running, and sometimes it's not. - t.Logf("skipping syslog test during -short") - return true +func startServer(n, la string, done chan<- string) (addr string, sock io.Closer, wg *sync.WaitGroup) { + if n == "udp" || n == "tcp" { + la = "127.0.0.1:0" + } else { + // unix and unixgram: choose an address if none given + if la == "" { + // use ioutil.TempFile to get a name that is unique + f, err := ioutil.TempFile("", "syslogtest") + if err != nil { + log.Fatal("TempFile: ", err) + } + f.Close() + la = f.Name() + } + os.Remove(la) + } + + wg = new(sync.WaitGroup) + if n == "udp" || n == "unixgram" { + l, e := net.ListenPacket(n, la) + if e != nil { + log.Fatalf("startServer failed: %v", e) + } + addr = l.LocalAddr().String() + sock = l + wg.Add(1) + go func() { + defer wg.Done() + runPktSyslog(l, done) + }() + } else { + l, e := net.Listen(n, la) + if e != nil { + log.Fatalf("startServer failed: %v", e) + } + addr = l.Addr().String() + sock = l + wg.Add(1) + go func() { + defer wg.Done() + runStreamSyslog(l, done, wg) + }() + } + return +} + +func TestWithSimulated(t *testing.T) { + msg := "Test 123" + transport := []string{"unix", "unixgram", "udp", "tcp"} + + for _, tr := range transport { + done := make(chan string) + addr, _, _ := startServer(tr, "", done) + if tr == "unix" || tr == "unixgram" { + defer os.Remove(addr) + } + s, err := Dial(tr, addr, LOG_INFO|LOG_USER, "syslog_test") + if err != nil { + t.Fatalf("Dial() failed: %v", err) + } + err = s.Info(msg) + if err != nil { + t.Fatalf("log failed: %v", err) + } + check(t, msg, <-done) + s.Close() + } +} + +func TestFlap(t *testing.T) { + net := "unix" + done := make(chan string) + addr, sock, _ := startServer(net, "", done) + defer os.Remove(addr) + defer sock.Close() + + s, err := Dial(net, addr, LOG_INFO|LOG_USER, "syslog_test") + if err != nil { + t.Fatalf("Dial() failed: %v", err) + } + msg := "Moo 2" + err = s.Info(msg) + if err != nil { + t.Fatalf("log failed: %v", err) + } + check(t, msg, <-done) + + // restart the server + _, sock2, _ := startServer(net, addr, done) + defer sock2.Close() + + // and try retransmitting + msg = "Moo 3" + err = s.Info(msg) + if err != nil { + t.Fatalf("log failed: %v", err) } - return false + check(t, msg, <-done) + + s.Close() } func TestNew(t *testing.T) { - if skipNetTest(t) { - return + if LOG_LOCAL7 != 23<<3 { + t.Fatalf("LOG_LOCAL7 has wrong value") + } + if testing.Short() { + // Depends on syslog daemon running, and sometimes it's not. + t.Skip("skipping syslog test during -short") } - s, err := New(LOG_INFO, "") + + s, err := New(LOG_INFO|LOG_USER, "the_tag") if err != nil { t.Fatalf("New() failed: %s", err) } @@ -61,57 +190,159 @@ func TestNew(t *testing.T) { } func TestNewLogger(t *testing.T) { - if skipNetTest(t) { - return + if testing.Short() { + t.Skip("skipping syslog test during -short") } - f, err := NewLogger(LOG_INFO, 0) + f, err := NewLogger(LOG_USER|LOG_INFO, 0) if f == nil { t.Error(err) } } func TestDial(t *testing.T) { - if skipNetTest(t) { - return + if testing.Short() { + t.Skip("skipping syslog test during -short") } - l, err := Dial("", "", LOG_ERR, "syslog_test") + f, err := Dial("", "", (LOG_LOCAL7|LOG_DEBUG)+1, "syslog_test") + if f != nil { + t.Fatalf("Should have trapped bad priority") + } + f, err = Dial("", "", -1, "syslog_test") + if f != nil { + t.Fatalf("Should have trapped bad priority") + } + l, err := Dial("", "", LOG_USER|LOG_ERR, "syslog_test") if err != nil { t.Fatalf("Dial() failed: %s", err) } l.Close() } -func TestUDPDial(t *testing.T) { - done := make(chan string) - startServer(done) - l, err := Dial("udp", serverAddr, LOG_INFO, "syslog_test") - if err != nil { - t.Fatalf("syslog.Dial() failed: %s", err) - } - msg := "udp test" - l.Info(msg) - expected := "<6>syslog_test: udp test\n" - rcvd := <-done - if rcvd != expected { - t.Fatalf("s.Info() = '%q', but wanted '%q'", rcvd, expected) +func check(t *testing.T, in, out string) { + tmpl := fmt.Sprintf("<%d>%%s %%s syslog_test[%%d]: %s\n", LOG_USER+LOG_INFO, in) + if hostname, err := os.Hostname(); err != nil { + t.Error("Error retrieving hostname") + } else { + var parsedHostname, timestamp string + var pid int + if n, err := fmt.Sscanf(out, tmpl, ×tamp, &parsedHostname, &pid); n != 3 || err != nil || hostname != parsedHostname { + t.Errorf("Got %q, does not match template %q (%d %s)", out, tmpl, n, err) + } } } func TestWrite(t *testing.T) { - done := make(chan string) - startServer(done) - l, err := Dial("udp", serverAddr, LOG_ERR, "syslog_test") - if err != nil { - t.Fatalf("syslog.Dial() failed: %s", err) + tests := []struct { + pri Priority + pre string + msg string + exp string + }{ + {LOG_USER | LOG_ERR, "syslog_test", "", "%s %s syslog_test[%d]: \n"}, + {LOG_USER | LOG_ERR, "syslog_test", "write test", "%s %s syslog_test[%d]: write test\n"}, + // Write should not add \n if there already is one + {LOG_USER | LOG_ERR, "syslog_test", "write test 2\n", "%s %s syslog_test[%d]: write test 2\n"}, } - msg := "write test" - _, err = io.WriteString(l, msg) + + if hostname, err := os.Hostname(); err != nil { + t.Fatalf("Error retrieving hostname") + } else { + for _, test := range tests { + done := make(chan string) + addr, sock, _ := startServer("udp", "", done) + defer sock.Close() + l, err := Dial("udp", addr, test.pri, test.pre) + if err != nil { + t.Fatalf("syslog.Dial() failed: %v", err) + } + _, err = io.WriteString(l, test.msg) + if err != nil { + t.Fatalf("WriteString() failed: %v", err) + } + rcvd := <-done + test.exp = fmt.Sprintf("<%d>", test.pri) + test.exp + var parsedHostname, timestamp string + var pid int + if n, err := fmt.Sscanf(rcvd, test.exp, ×tamp, &parsedHostname, &pid); n != 3 || err != nil || hostname != parsedHostname { + t.Errorf("s.Info() = '%q', didn't match '%q' (%d %s)", rcvd, test.exp, n, err) + } + } + } +} + +func TestConcurrentWrite(t *testing.T) { + addr, sock, _ := startServer("udp", "", make(chan string)) + defer sock.Close() + w, err := Dial("udp", addr, LOG_USER|LOG_ERR, "how's it going?") if err != nil { - t.Fatalf("WriteString() failed: %s", err) + t.Fatalf("syslog.Dial() failed: %v", err) + } + var wg sync.WaitGroup + for i := 0; i < 10; i++ { + wg.Add(1) + go func() { + err := w.Info("test") + if err != nil { + t.Errorf("Info() failed: %v", err) + return + } + wg.Done() + }() } - expected := "<3>syslog_test: write test\n" - rcvd := <-done - if rcvd != expected { - t.Fatalf("s.Info() = '%q', but wanted '%q'", rcvd, expected) + wg.Wait() +} + +func TestConcurrentReconnect(t *testing.T) { + crashy = true + defer func() { crashy = false }() + + net := "unix" + done := make(chan string) + addr, sock, srvWG := startServer(net, "", done) + defer os.Remove(addr) + + // count all the messages arriving + count := make(chan int) + go func() { + ct := 0 + for _ = range done { + ct++ + // we are looking for 500 out of 1000 events + // here because lots of log messages are lost + // in buffers (kernel and/or bufio) + if ct > 500 { + break + } + } + count <- ct + }() + + var wg sync.WaitGroup + for i := 0; i < 10; i++ { + wg.Add(1) + go func() { + w, err := Dial(net, addr, LOG_USER|LOG_ERR, "tag") + if err != nil { + t.Fatalf("syslog.Dial() failed: %v", err) + } + for i := 0; i < 100; i++ { + err := w.Info("test") + if err != nil { + t.Errorf("Info() failed: %v", err) + return + } + } + wg.Done() + }() + } + wg.Wait() + sock.Close() + srvWG.Wait() + close(done) + + select { + case <-count: + case <-time.After(100 * time.Millisecond): + t.Error("timeout in concurrent reconnect") } } diff --git a/src/pkg/log/syslog/syslog_unix.go b/src/pkg/log/syslog/syslog_unix.go index 46a164dd5..a0001ccae 100644 --- a/src/pkg/log/syslog/syslog_unix.go +++ b/src/pkg/log/syslog/syslog_unix.go @@ -14,18 +14,16 @@ import ( // unixSyslog opens a connection to the syslog daemon running on the // local machine using a Unix domain socket. -func unixSyslog() (conn serverConn, err error) { +func unixSyslog() (conn net.Conn, err error) { logTypes := []string{"unixgram", "unix"} logPaths := []string{"/dev/log", "/var/run/syslog"} - var raddr string for _, network := range logTypes { for _, path := range logPaths { - raddr = path - conn, err := net.Dial(network, raddr) + conn, err := net.Dial(network, path) if err != nil { continue } else { - return netConn{conn}, nil + return conn, nil } } } |