Source file src/log/syslog/syslog_test.go

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

View as plain text