github.com/aloncn/graphics-go@v0.0.1/src/runtime/trace/trace_test.go (about)

     1  // Copyright 2014 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  package trace_test
     6  
     7  import (
     8  	"bytes"
     9  	"internal/trace"
    10  	"io"
    11  	"net"
    12  	"os"
    13  	"runtime"
    14  	. "runtime/trace"
    15  	"sync"
    16  	"testing"
    17  	"time"
    18  )
    19  
    20  func TestTraceStartStop(t *testing.T) {
    21  	buf := new(bytes.Buffer)
    22  	if err := Start(buf); err != nil {
    23  		t.Fatalf("failed to start tracing: %v", err)
    24  	}
    25  	Stop()
    26  	size := buf.Len()
    27  	if size == 0 {
    28  		t.Fatalf("trace is empty")
    29  	}
    30  	time.Sleep(100 * time.Millisecond)
    31  	if size != buf.Len() {
    32  		t.Fatalf("trace writes after stop: %v -> %v", size, buf.Len())
    33  	}
    34  }
    35  
    36  func TestTraceDoubleStart(t *testing.T) {
    37  	Stop()
    38  	buf := new(bytes.Buffer)
    39  	if err := Start(buf); err != nil {
    40  		t.Fatalf("failed to start tracing: %v", err)
    41  	}
    42  	if err := Start(buf); err == nil {
    43  		t.Fatalf("succeed to start tracing second time")
    44  	}
    45  	Stop()
    46  	Stop()
    47  }
    48  
    49  func TestTrace(t *testing.T) {
    50  	buf := new(bytes.Buffer)
    51  	if err := Start(buf); err != nil {
    52  		t.Fatalf("failed to start tracing: %v", err)
    53  	}
    54  	Stop()
    55  	_, err := trace.Parse(buf)
    56  	if err == trace.ErrTimeOrder {
    57  		t.Skipf("skipping trace: %v", err)
    58  	}
    59  	if err != nil {
    60  		t.Fatalf("failed to parse trace: %v", err)
    61  	}
    62  }
    63  
    64  func parseTrace(t *testing.T, r io.Reader) ([]*trace.Event, map[uint64]*trace.GDesc, error) {
    65  	events, err := trace.Parse(r)
    66  	if err == trace.ErrTimeOrder {
    67  		t.Skipf("skipping trace: %v", err)
    68  	}
    69  	if err != nil {
    70  		return nil, nil, err
    71  	}
    72  	gs := trace.GoroutineStats(events)
    73  	for goid := range gs {
    74  		// We don't do any particular checks on the result at the moment.
    75  		// But still check that RelatedGoroutines does not crash, hang, etc.
    76  		_ = trace.RelatedGoroutines(events, goid)
    77  	}
    78  	return events, gs, nil
    79  }
    80  
    81  func TestTraceStress(t *testing.T) {
    82  	var wg sync.WaitGroup
    83  	done := make(chan bool)
    84  
    85  	// Create a goroutine blocked before tracing.
    86  	wg.Add(1)
    87  	go func() {
    88  		<-done
    89  		wg.Done()
    90  	}()
    91  
    92  	// Create a goroutine blocked in syscall before tracing.
    93  	rp, wp, err := os.Pipe()
    94  	if err != nil {
    95  		t.Fatalf("failed to create pipe: %v", err)
    96  	}
    97  	defer func() {
    98  		rp.Close()
    99  		wp.Close()
   100  	}()
   101  	wg.Add(1)
   102  	go func() {
   103  		var tmp [1]byte
   104  		rp.Read(tmp[:])
   105  		<-done
   106  		wg.Done()
   107  	}()
   108  	time.Sleep(time.Millisecond) // give the goroutine above time to block
   109  
   110  	buf := new(bytes.Buffer)
   111  	if err := Start(buf); err != nil {
   112  		t.Fatalf("failed to start tracing: %v", err)
   113  	}
   114  
   115  	procs := runtime.GOMAXPROCS(10)
   116  	time.Sleep(50 * time.Millisecond) // test proc stop/start events
   117  
   118  	go func() {
   119  		runtime.LockOSThread()
   120  		for {
   121  			select {
   122  			case <-done:
   123  				return
   124  			default:
   125  				runtime.Gosched()
   126  			}
   127  		}
   128  	}()
   129  
   130  	runtime.GC()
   131  	// Trigger GC from malloc.
   132  	n := int(1e3)
   133  	if runtime.GOOS == "openbsd" && runtime.GOARCH == "arm" {
   134  		// Reduce allocation to avoid running out of
   135  		// memory on the builder - see issue/12032.
   136  		n = 512
   137  	}
   138  	for i := 0; i < n; i++ {
   139  		_ = make([]byte, 1<<20)
   140  	}
   141  
   142  	// Create a bunch of busy goroutines to load all Ps.
   143  	for p := 0; p < 10; p++ {
   144  		wg.Add(1)
   145  		go func() {
   146  			// Do something useful.
   147  			tmp := make([]byte, 1<<16)
   148  			for i := range tmp {
   149  				tmp[i]++
   150  			}
   151  			_ = tmp
   152  			<-done
   153  			wg.Done()
   154  		}()
   155  	}
   156  
   157  	// Block in syscall.
   158  	wg.Add(1)
   159  	go func() {
   160  		var tmp [1]byte
   161  		rp.Read(tmp[:])
   162  		<-done
   163  		wg.Done()
   164  	}()
   165  
   166  	// Test timers.
   167  	timerDone := make(chan bool)
   168  	go func() {
   169  		time.Sleep(time.Millisecond)
   170  		timerDone <- true
   171  	}()
   172  	<-timerDone
   173  
   174  	// A bit of network.
   175  	ln, err := net.Listen("tcp", "127.0.0.1:0")
   176  	if err != nil {
   177  		t.Fatalf("listen failed: %v", err)
   178  	}
   179  	defer ln.Close()
   180  	go func() {
   181  		c, err := ln.Accept()
   182  		if err != nil {
   183  			return
   184  		}
   185  		time.Sleep(time.Millisecond)
   186  		var buf [1]byte
   187  		c.Write(buf[:])
   188  		c.Close()
   189  	}()
   190  	c, err := net.Dial("tcp", ln.Addr().String())
   191  	if err != nil {
   192  		t.Fatalf("dial failed: %v", err)
   193  	}
   194  	var tmp [1]byte
   195  	c.Read(tmp[:])
   196  	c.Close()
   197  
   198  	go func() {
   199  		runtime.Gosched()
   200  		select {}
   201  	}()
   202  
   203  	// Unblock helper goroutines and wait them to finish.
   204  	wp.Write(tmp[:])
   205  	wp.Write(tmp[:])
   206  	close(done)
   207  	wg.Wait()
   208  
   209  	runtime.GOMAXPROCS(procs)
   210  
   211  	Stop()
   212  	_, _, err = parseTrace(t, buf)
   213  	if err != nil {
   214  		t.Fatalf("failed to parse trace: %v", err)
   215  	}
   216  }
   217  
   218  // Do a bunch of various stuff (timers, GC, network, etc) in a separate goroutine.
   219  // And concurrently with all that start/stop trace 3 times.
   220  func TestTraceStressStartStop(t *testing.T) {
   221  	defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(8))
   222  	outerDone := make(chan bool)
   223  
   224  	go func() {
   225  		defer func() {
   226  			outerDone <- true
   227  		}()
   228  
   229  		var wg sync.WaitGroup
   230  		done := make(chan bool)
   231  
   232  		wg.Add(1)
   233  		go func() {
   234  			<-done
   235  			wg.Done()
   236  		}()
   237  
   238  		rp, wp, err := os.Pipe()
   239  		if err != nil {
   240  			t.Fatalf("failed to create pipe: %v", err)
   241  		}
   242  		defer func() {
   243  			rp.Close()
   244  			wp.Close()
   245  		}()
   246  		wg.Add(1)
   247  		go func() {
   248  			var tmp [1]byte
   249  			rp.Read(tmp[:])
   250  			<-done
   251  			wg.Done()
   252  		}()
   253  		time.Sleep(time.Millisecond)
   254  
   255  		go func() {
   256  			runtime.LockOSThread()
   257  			for {
   258  				select {
   259  				case <-done:
   260  					return
   261  				default:
   262  					runtime.Gosched()
   263  				}
   264  			}
   265  		}()
   266  
   267  		runtime.GC()
   268  		// Trigger GC from malloc.
   269  		n := int(1e3)
   270  		if runtime.GOOS == "openbsd" && runtime.GOARCH == "arm" {
   271  			// Reduce allocation to avoid running out of
   272  			// memory on the builder - see issue/12032.
   273  			n = 512
   274  		}
   275  		for i := 0; i < n; i++ {
   276  			_ = make([]byte, 1<<20)
   277  		}
   278  
   279  		// Create a bunch of busy goroutines to load all Ps.
   280  		for p := 0; p < 10; p++ {
   281  			wg.Add(1)
   282  			go func() {
   283  				// Do something useful.
   284  				tmp := make([]byte, 1<<16)
   285  				for i := range tmp {
   286  					tmp[i]++
   287  				}
   288  				_ = tmp
   289  				<-done
   290  				wg.Done()
   291  			}()
   292  		}
   293  
   294  		// Block in syscall.
   295  		wg.Add(1)
   296  		go func() {
   297  			var tmp [1]byte
   298  			rp.Read(tmp[:])
   299  			<-done
   300  			wg.Done()
   301  		}()
   302  
   303  		runtime.GOMAXPROCS(runtime.GOMAXPROCS(1))
   304  
   305  		// Test timers.
   306  		timerDone := make(chan bool)
   307  		go func() {
   308  			time.Sleep(time.Millisecond)
   309  			timerDone <- true
   310  		}()
   311  		<-timerDone
   312  
   313  		// A bit of network.
   314  		ln, err := net.Listen("tcp", "127.0.0.1:0")
   315  		if err != nil {
   316  			t.Fatalf("listen failed: %v", err)
   317  		}
   318  		defer ln.Close()
   319  		go func() {
   320  			c, err := ln.Accept()
   321  			if err != nil {
   322  				return
   323  			}
   324  			time.Sleep(time.Millisecond)
   325  			var buf [1]byte
   326  			c.Write(buf[:])
   327  			c.Close()
   328  		}()
   329  		c, err := net.Dial("tcp", ln.Addr().String())
   330  		if err != nil {
   331  			t.Fatalf("dial failed: %v", err)
   332  		}
   333  		var tmp [1]byte
   334  		c.Read(tmp[:])
   335  		c.Close()
   336  
   337  		go func() {
   338  			runtime.Gosched()
   339  			select {}
   340  		}()
   341  
   342  		// Unblock helper goroutines and wait them to finish.
   343  		wp.Write(tmp[:])
   344  		wp.Write(tmp[:])
   345  		close(done)
   346  		wg.Wait()
   347  	}()
   348  
   349  	for i := 0; i < 3; i++ {
   350  		buf := new(bytes.Buffer)
   351  		if err := Start(buf); err != nil {
   352  			t.Fatalf("failed to start tracing: %v", err)
   353  		}
   354  		time.Sleep(time.Millisecond)
   355  		Stop()
   356  		if _, _, err := parseTrace(t, buf); err != nil {
   357  			t.Fatalf("failed to parse trace: %v", err)
   358  		}
   359  	}
   360  	<-outerDone
   361  }
   362  
   363  func TestTraceFutileWakeup(t *testing.T) {
   364  	buf := new(bytes.Buffer)
   365  	if err := Start(buf); err != nil {
   366  		t.Fatalf("failed to start tracing: %v", err)
   367  	}
   368  
   369  	defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(8))
   370  	c0 := make(chan int, 1)
   371  	c1 := make(chan int, 1)
   372  	c2 := make(chan int, 1)
   373  	const procs = 2
   374  	var done sync.WaitGroup
   375  	done.Add(4 * procs)
   376  	for p := 0; p < procs; p++ {
   377  		const iters = 1e3
   378  		go func() {
   379  			for i := 0; i < iters; i++ {
   380  				runtime.Gosched()
   381  				c0 <- 0
   382  			}
   383  			done.Done()
   384  		}()
   385  		go func() {
   386  			for i := 0; i < iters; i++ {
   387  				runtime.Gosched()
   388  				<-c0
   389  			}
   390  			done.Done()
   391  		}()
   392  		go func() {
   393  			for i := 0; i < iters; i++ {
   394  				runtime.Gosched()
   395  				select {
   396  				case c1 <- 0:
   397  				case c2 <- 0:
   398  				}
   399  			}
   400  			done.Done()
   401  		}()
   402  		go func() {
   403  			for i := 0; i < iters; i++ {
   404  				runtime.Gosched()
   405  				select {
   406  				case <-c1:
   407  				case <-c2:
   408  				}
   409  			}
   410  			done.Done()
   411  		}()
   412  	}
   413  	done.Wait()
   414  
   415  	Stop()
   416  	events, _, err := parseTrace(t, buf)
   417  	if err != nil {
   418  		t.Fatalf("failed to parse trace: %v", err)
   419  	}
   420  	// Check that (1) trace does not contain EvFutileWakeup events and
   421  	// (2) there are no consecutive EvGoBlock/EvGCStart/EvGoBlock events
   422  	// (we call runtime.Gosched between all operations, so these would be futile wakeups).
   423  	gs := make(map[uint64]int)
   424  	for _, ev := range events {
   425  		switch ev.Type {
   426  		case trace.EvFutileWakeup:
   427  			t.Fatalf("found EvFutileWakeup event")
   428  		case trace.EvGoBlockSend, trace.EvGoBlockRecv, trace.EvGoBlockSelect:
   429  			if gs[ev.G] == 2 {
   430  				t.Fatalf("goroutine %v blocked on %v at %v right after start",
   431  					ev.G, trace.EventDescriptions[ev.Type].Name, ev.Ts)
   432  			}
   433  			if gs[ev.G] == 1 {
   434  				t.Fatalf("goroutine %v blocked on %v at %v while blocked",
   435  					ev.G, trace.EventDescriptions[ev.Type].Name, ev.Ts)
   436  			}
   437  			gs[ev.G] = 1
   438  		case trace.EvGoStart:
   439  			if gs[ev.G] == 1 {
   440  				gs[ev.G] = 2
   441  			}
   442  		default:
   443  			delete(gs, ev.G)
   444  		}
   445  	}
   446  }