syslog_test.go

Documentation: log/syslog

     1  // Copyright 2009 The Go Authors. All rights reserved.
     2  // Use of this source code is governed by a BSD-style
     3  // license that can be found in the LICENSE file.
     4  
     5  //go:build !windows && !plan9 && !js
     6  // +build !windows,!plan9,!js
     7  
     8  package syslog
     9  
    10  import (
    11  	"bufio"
    12  	"fmt"
    13  	"io"
    14  	"log"
    15  	"net"
    16  	"os"
    17  	"runtime"
    18  	"sync"
    19  	"testing"
    20  	"time"
    21  )
    22  
    23  func runPktSyslog(c net.PacketConn, done chan<- string) {
    24  	var buf [4096]byte
    25  	var rcvd string
    26  	ct := 0
    27  	for {
    28  		var n int
    29  		var err error
    30  
    31  		c.SetReadDeadline(time.Now().Add(100 * time.Millisecond))
    32  		n, _, err = c.ReadFrom(buf[:])
    33  		rcvd += string(buf[:n])
    34  		if err != nil {
    35  			if oe, ok := err.(*net.OpError); ok {
    36  				if ct < 3 && oe.Temporary() {
    37  					ct++
    38  					continue
    39  				}
    40  			}
    41  			break
    42  		}
    43  	}
    44  	c.Close()
    45  	done <- rcvd
    46  }
    47  
    48  var crashy = false
    49  
    50  func testableNetwork(network string) bool {
    51  	switch network {
    52  	case "unix", "unixgram":
    53  		switch runtime.GOOS {
    54  		case "ios", "android":
    55  			return false
    56  		}
    57  	}
    58  	return true
    59  }
    60  
    61  func runStreamSyslog(l net.Listener, done chan<- string, wg *sync.WaitGroup) {
    62  	for {
    63  		var c net.Conn
    64  		var err error
    65  		if c, err = l.Accept(); err != nil {
    66  			return
    67  		}
    68  		wg.Add(1)
    69  		go func(c net.Conn) {
    70  			defer wg.Done()
    71  			c.SetReadDeadline(time.Now().Add(5 * time.Second))
    72  			b := bufio.NewReader(c)
    73  			for ct := 1; !crashy || ct&7 != 0; ct++ {
    74  				s, err := b.ReadString('\n')
    75  				if err != nil {
    76  					break
    77  				}
    78  				done <- s
    79  			}
    80  			c.Close()
    81  		}(c)
    82  	}
    83  }
    84  
    85  func startServer(n, la string, done chan<- string) (addr string, sock io.Closer, wg *sync.WaitGroup) {
    86  	if n == "udp" || n == "tcp" {
    87  		la = "127.0.0.1:0"
    88  	} else {
    89  		// unix and unixgram: choose an address if none given
    90  		if la == "" {
    91  			// use os.CreateTemp to get a name that is unique
    92  			f, err := os.CreateTemp("", "syslogtest")
    93  			if err != nil {
    94  				log.Fatal("TempFile: ", err)
    95  			}
    96  			f.Close()
    97  			la = f.Name()
    98  		}
    99  		os.Remove(la)
   100  	}
   101  
   102  	wg = new(sync.WaitGroup)
   103  	if n == "udp" || n == "unixgram" {
   104  		l, e := net.ListenPacket(n, la)
   105  		if e != nil {
   106  			log.Fatalf("startServer failed: %v", e)
   107  		}
   108  		addr = l.LocalAddr().String()
   109  		sock = l
   110  		wg.Add(1)
   111  		go func() {
   112  			defer wg.Done()
   113  			runPktSyslog(l, done)
   114  		}()
   115  	} else {
   116  		l, e := net.Listen(n, la)
   117  		if e != nil {
   118  			log.Fatalf("startServer failed: %v", e)
   119  		}
   120  		addr = l.Addr().String()
   121  		sock = l
   122  		wg.Add(1)
   123  		go func() {
   124  			defer wg.Done()
   125  			runStreamSyslog(l, done, wg)
   126  		}()
   127  	}
   128  	return
   129  }
   130  
   131  func TestWithSimulated(t *testing.T) {
   132  	t.Parallel()
   133  	msg := "Test 123"
   134  	var transport []string
   135  	for _, n := range []string{"unix", "unixgram", "udp", "tcp"} {
   136  		if testableNetwork(n) {
   137  			transport = append(transport, n)
   138  		}
   139  	}
   140  
   141  	for _, tr := range transport {
   142  		done := make(chan string)
   143  		addr, sock, srvWG := startServer(tr, "", done)
   144  		defer srvWG.Wait()
   145  		defer sock.Close()
   146  		if tr == "unix" || tr == "unixgram" {
   147  			defer os.Remove(addr)
   148  		}
   149  		s, err := Dial(tr, addr, LOG_INFO|LOG_USER, "syslog_test")
   150  		if err != nil {
   151  			t.Fatalf("Dial() failed: %v", err)
   152  		}
   153  		err = s.Info(msg)
   154  		if err != nil {
   155  			t.Fatalf("log failed: %v", err)
   156  		}
   157  		check(t, msg, <-done, tr)
   158  		s.Close()
   159  	}
   160  }
   161  
   162  func TestFlap(t *testing.T) {
   163  	net := "unix"
   164  	if !testableNetwork(net) {
   165  		t.Skipf("skipping on %s/%s; 'unix' is not supported", runtime.GOOS, runtime.GOARCH)
   166  	}
   167  
   168  	done := make(chan string)
   169  	addr, sock, srvWG := startServer(net, "", done)
   170  	defer srvWG.Wait()
   171  	defer os.Remove(addr)
   172  	defer sock.Close()
   173  
   174  	s, err := Dial(net, addr, LOG_INFO|LOG_USER, "syslog_test")
   175  	if err != nil {
   176  		t.Fatalf("Dial() failed: %v", err)
   177  	}
   178  	msg := "Moo 2"
   179  	err = s.Info(msg)
   180  	if err != nil {
   181  		t.Fatalf("log failed: %v", err)
   182  	}
   183  	check(t, msg, <-done, net)
   184  
   185  	// restart the server
   186  	_, sock2, srvWG2 := startServer(net, addr, done)
   187  	defer srvWG2.Wait()
   188  	defer sock2.Close()
   189  
   190  	// and try retransmitting
   191  	msg = "Moo 3"
   192  	err = s.Info(msg)
   193  	if err != nil {
   194  		t.Fatalf("log failed: %v", err)
   195  	}
   196  	check(t, msg, <-done, net)
   197  
   198  	s.Close()
   199  }
   200  
   201  func TestNew(t *testing.T) {
   202  	if LOG_LOCAL7 != 23<<3 {
   203  		t.Fatalf("LOG_LOCAL7 has wrong value")
   204  	}
   205  	if testing.Short() {
   206  		// Depends on syslog daemon running, and sometimes it's not.
   207  		t.Skip("skipping syslog test during -short")
   208  	}
   209  
   210  	s, err := New(LOG_INFO|LOG_USER, "the_tag")
   211  	if err != nil {
   212  		if err.Error() == "Unix syslog delivery error" {
   213  			t.Skip("skipping: syslogd not running")
   214  		}
   215  		t.Fatalf("New() failed: %s", err)
   216  	}
   217  	// Don't send any messages.
   218  	s.Close()
   219  }
   220  
   221  func TestNewLogger(t *testing.T) {
   222  	if testing.Short() {
   223  		t.Skip("skipping syslog test during -short")
   224  	}
   225  	f, err := NewLogger(LOG_USER|LOG_INFO, 0)
   226  	if f == nil {
   227  		if err.Error() == "Unix syslog delivery error" {
   228  			t.Skip("skipping: syslogd not running")
   229  		}
   230  		t.Error(err)
   231  	}
   232  }
   233  
   234  func TestDial(t *testing.T) {
   235  	if testing.Short() {
   236  		t.Skip("skipping syslog test during -short")
   237  	}
   238  	f, err := Dial("", "", (LOG_LOCAL7|LOG_DEBUG)+1, "syslog_test")
   239  	if f != nil {
   240  		t.Fatalf("Should have trapped bad priority")
   241  	}
   242  	f, err = Dial("", "", -1, "syslog_test")
   243  	if f != nil {
   244  		t.Fatalf("Should have trapped bad priority")
   245  	}
   246  	l, err := Dial("", "", LOG_USER|LOG_ERR, "syslog_test")
   247  	if err != nil {
   248  		if err.Error() == "Unix syslog delivery error" {
   249  			t.Skip("skipping: syslogd not running")
   250  		}
   251  		t.Fatalf("Dial() failed: %s", err)
   252  	}
   253  	l.Close()
   254  }
   255  
   256  func check(t *testing.T, in, out, transport string) {
   257  	hostname, err := os.Hostname()
   258  	if err != nil {
   259  		t.Error("Error retrieving hostname")
   260  		return
   261  	}
   262  
   263  	if transport == "unixgram" || transport == "unix" {
   264  		var month, date, ts string
   265  		var pid int
   266  		tmpl := fmt.Sprintf("<%d>%%s %%s %%s syslog_test[%%d]: %s\n", LOG_USER+LOG_INFO, in)
   267  		n, err := fmt.Sscanf(out, tmpl, &month, &date, &ts, &pid)
   268  		if n != 4 || err != nil {
   269  			t.Errorf("Got %q, does not match template %q (%d %s)", out, tmpl, n, err)
   270  		}
   271  		return
   272  	}
   273  
   274  	// Non-UNIX domain transports.
   275  	var parsedHostname, timestamp string
   276  	var pid int
   277  	tmpl := fmt.Sprintf("<%d>%%s %%s syslog_test[%%d]: %s\n", LOG_USER+LOG_INFO, in)
   278  	n, err := fmt.Sscanf(out, tmpl, &timestamp, &parsedHostname, &pid)
   279  	if n != 3 || err != nil || hostname != parsedHostname {
   280  		t.Errorf("Got %q, does not match template %q (%d %s)", out, tmpl, n, err)
   281  	}
   282  }
   283  
   284  func TestWrite(t *testing.T) {
   285  	t.Parallel()
   286  	tests := []struct {
   287  		pri Priority
   288  		pre string
   289  		msg string
   290  		exp string
   291  	}{
   292  		{LOG_USER | LOG_ERR, "syslog_test", "", "%s %s syslog_test[%d]: \n"},
   293  		{LOG_USER | LOG_ERR, "syslog_test", "write test", "%s %s syslog_test[%d]: write test\n"},
   294  		// Write should not add \n if there already is one
   295  		{LOG_USER | LOG_ERR, "syslog_test", "write test 2\n", "%s %s syslog_test[%d]: write test 2\n"},
   296  	}
   297  
   298  	if hostname, err := os.Hostname(); err != nil {
   299  		t.Fatalf("Error retrieving hostname")
   300  	} else {
   301  		for _, test := range tests {
   302  			done := make(chan string)
   303  			addr, sock, srvWG := startServer("udp", "", done)
   304  			defer srvWG.Wait()
   305  			defer sock.Close()
   306  			l, err := Dial("udp", addr, test.pri, test.pre)
   307  			if err != nil {
   308  				t.Fatalf("syslog.Dial() failed: %v", err)
   309  			}
   310  			defer l.Close()
   311  			_, err = io.WriteString(l, test.msg)
   312  			if err != nil {
   313  				t.Fatalf("WriteString() failed: %v", err)
   314  			}
   315  			rcvd := <-done
   316  			test.exp = fmt.Sprintf("<%d>", test.pri) + test.exp
   317  			var parsedHostname, timestamp string
   318  			var pid int
   319  			if n, err := fmt.Sscanf(rcvd, test.exp, &timestamp, &parsedHostname, &pid); n != 3 || err != nil || hostname != parsedHostname {
   320  				t.Errorf("s.Info() = '%q', didn't match '%q' (%d %s)", rcvd, test.exp, n, err)
   321  			}
   322  		}
   323  	}
   324  }
   325  
   326  func TestConcurrentWrite(t *testing.T) {
   327  	addr, sock, srvWG := startServer("udp", "", make(chan string, 1))
   328  	defer srvWG.Wait()
   329  	defer sock.Close()
   330  	w, err := Dial("udp", addr, LOG_USER|LOG_ERR, "how's it going?")
   331  	if err != nil {
   332  		t.Fatalf("syslog.Dial() failed: %v", err)
   333  	}
   334  	var wg sync.WaitGroup
   335  	for i := 0; i < 10; i++ {
   336  		wg.Add(1)
   337  		go func() {
   338  			defer wg.Done()
   339  			err := w.Info("test")
   340  			if err != nil {
   341  				t.Errorf("Info() failed: %v", err)
   342  				return
   343  			}
   344  		}()
   345  	}
   346  	wg.Wait()
   347  }
   348  
   349  func TestConcurrentReconnect(t *testing.T) {
   350  	crashy = true
   351  	defer func() { crashy = false }()
   352  
   353  	const N = 10
   354  	const M = 100
   355  	net := "unix"
   356  	if !testableNetwork(net) {
   357  		net = "tcp"
   358  		if !testableNetwork(net) {
   359  			t.Skipf("skipping on %s/%s; neither 'unix' or 'tcp' is supported", runtime.GOOS, runtime.GOARCH)
   360  		}
   361  	}
   362  	done := make(chan string, N*M)
   363  	addr, sock, srvWG := startServer(net, "", done)
   364  	if net == "unix" {
   365  		defer os.Remove(addr)
   366  	}
   367  
   368  	// count all the messages arriving
   369  	count := make(chan int, 1)
   370  	go func() {
   371  		ct := 0
   372  		for range done {
   373  			ct++
   374  			// we are looking for 500 out of 1000 events
   375  			// here because lots of log messages are lost
   376  			// in buffers (kernel and/or bufio)
   377  			if ct > N*M/2 {
   378  				break
   379  			}
   380  		}
   381  		count <- ct
   382  	}()
   383  
   384  	var wg sync.WaitGroup
   385  	wg.Add(N)
   386  	for i := 0; i < N; i++ {
   387  		go func() {
   388  			defer wg.Done()
   389  			w, err := Dial(net, addr, LOG_USER|LOG_ERR, "tag")
   390  			if err != nil {
   391  				t.Errorf("syslog.Dial() failed: %v", err)
   392  				return
   393  			}
   394  			defer w.Close()
   395  			for i := 0; i < M; i++ {
   396  				err := w.Info("test")
   397  				if err != nil {
   398  					t.Errorf("Info() failed: %v", err)
   399  					return
   400  				}
   401  			}
   402  		}()
   403  	}
   404  	wg.Wait()
   405  	sock.Close()
   406  	srvWG.Wait()
   407  	close(done)
   408  
   409  	select {
   410  	case <-count:
   411  	case <-time.After(100 * time.Millisecond):
   412  		t.Error("timeout in concurrent reconnect")
   413  	}
   414  }
   415
View as plain text