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