Black Lives Matter. Support the Equal Justice Initiative.

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

View as plain text