pprof_test.go

     1  // Copyright 2018 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 pprof
     6  
     7  import (
     8  	"bytes"
     9  	"fmt"
    10  	"internal/profile"
    11  	"internal/testenv"
    12  	"io"
    13  	"net/http"
    14  	"net/http/httptest"
    15  	"runtime"
    16  	"runtime/pprof"
    17  	"strings"
    18  	"sync"
    19  	"sync/atomic"
    20  	"testing"
    21  	"time"
    22  )
    23  
    24  // TestDescriptions checks that the profile names under runtime/pprof package
    25  // have a key in the description map.
    26  func TestDescriptions(t *testing.T) {
    27  	for _, p := range pprof.Profiles() {
    28  		_, ok := profileDescriptions[p.Name()]
    29  		if ok != true {
    30  			t.Errorf("%s does not exist in profileDescriptions map\n", p.Name())
    31  		}
    32  	}
    33  }
    34  
    35  func TestHandlers(t *testing.T) {
    36  	testCases := []struct {
    37  		path               string
    38  		handler            http.HandlerFunc
    39  		statusCode         int
    40  		contentType        string
    41  		contentDisposition string
    42  		resp               []byte
    43  	}{
    44  		{"/debug/pprof/<script>scripty<script>", Index, http.StatusNotFound, "text/plain; charset=utf-8", "", []byte("Unknown profile\n")},
    45  		{"/debug/pprof/heap", Index, http.StatusOK, "application/octet-stream", `attachment; filename="heap"`, nil},
    46  		{"/debug/pprof/heap?debug=1", Index, http.StatusOK, "text/plain; charset=utf-8", "", nil},
    47  		{"/debug/pprof/cmdline", Cmdline, http.StatusOK, "text/plain; charset=utf-8", "", nil},
    48  		{"/debug/pprof/profile?seconds=1", Profile, http.StatusOK, "application/octet-stream", `attachment; filename="profile"`, nil},
    49  		{"/debug/pprof/symbol", Symbol, http.StatusOK, "text/plain; charset=utf-8", "", nil},
    50  		{"/debug/pprof/trace", Trace, http.StatusOK, "application/octet-stream", `attachment; filename="trace"`, nil},
    51  		{"/debug/pprof/mutex", Index, http.StatusOK, "application/octet-stream", `attachment; filename="mutex"`, nil},
    52  		{"/debug/pprof/block?seconds=1", Index, http.StatusOK, "application/octet-stream", `attachment; filename="block-delta"`, nil},
    53  		{"/debug/pprof/goroutine?seconds=1", Index, http.StatusOK, "application/octet-stream", `attachment; filename="goroutine-delta"`, nil},
    54  		{"/debug/pprof/", Index, http.StatusOK, "text/html; charset=utf-8", "", []byte("Types of profiles available:")},
    55  	}
    56  	for _, tc := range testCases {
    57  		t.Run(tc.path, func(t *testing.T) {
    58  			req := httptest.NewRequest("GET", "http://example.com"+tc.path, nil)
    59  			w := httptest.NewRecorder()
    60  			tc.handler(w, req)
    61  
    62  			resp := w.Result()
    63  			if got, want := resp.StatusCode, tc.statusCode; got != want {
    64  				t.Errorf("status code: got %d; want %d", got, want)
    65  			}
    66  
    67  			body, err := io.ReadAll(resp.Body)
    68  			if err != nil {
    69  				t.Errorf("when reading response body, expected non-nil err; got %v", err)
    70  			}
    71  			if got, want := resp.Header.Get("X-Content-Type-Options"), "nosniff"; got != want {
    72  				t.Errorf("X-Content-Type-Options: got %q; want %q", got, want)
    73  			}
    74  			if got, want := resp.Header.Get("Content-Type"), tc.contentType; got != want {
    75  				t.Errorf("Content-Type: got %q; want %q", got, want)
    76  			}
    77  			if got, want := resp.Header.Get("Content-Disposition"), tc.contentDisposition; got != want {
    78  				t.Errorf("Content-Disposition: got %q; want %q", got, want)
    79  			}
    80  
    81  			if resp.StatusCode == http.StatusOK {
    82  				return
    83  			}
    84  			if got, want := resp.Header.Get("X-Go-Pprof"), "1"; got != want {
    85  				t.Errorf("X-Go-Pprof: got %q; want %q", got, want)
    86  			}
    87  			if !bytes.Equal(body, tc.resp) {
    88  				t.Errorf("response: got %q; want %q", body, tc.resp)
    89  			}
    90  		})
    91  	}
    92  }
    93  
    94  var Sink uint32
    95  
    96  func mutexHog1(mu1, mu2 *sync.Mutex, start time.Time, dt time.Duration) {
    97  	atomic.AddUint32(&Sink, 1)
    98  	for time.Since(start) < dt {
    99  		// When using gccgo the loop of mutex operations is
   100  		// not preemptible. This can cause the loop to block a GC,
   101  		// causing the time limits in TestDeltaContentionz to fail.
   102  		// Since this loop is not very realistic, when using
   103  		// gccgo add preemption points 100 times a second.
   104  		t1 := time.Now()
   105  		for time.Since(start) < dt && time.Since(t1) < 10*time.Millisecond {
   106  			mu1.Lock()
   107  			mu2.Lock()
   108  			mu1.Unlock()
   109  			mu2.Unlock()
   110  		}
   111  		if runtime.Compiler == "gccgo" {
   112  			runtime.Gosched()
   113  		}
   114  	}
   115  }
   116  
   117  // mutexHog2 is almost identical to mutexHog but we keep them separate
   118  // in order to distinguish them with function names in the stack trace.
   119  // We make them slightly different, using Sink, because otherwise
   120  // gccgo -c opt will merge them.
   121  func mutexHog2(mu1, mu2 *sync.Mutex, start time.Time, dt time.Duration) {
   122  	atomic.AddUint32(&Sink, 2)
   123  	for time.Since(start) < dt {
   124  		// See comment in mutexHog.
   125  		t1 := time.Now()
   126  		for time.Since(start) < dt && time.Since(t1) < 10*time.Millisecond {
   127  			mu1.Lock()
   128  			mu2.Lock()
   129  			mu1.Unlock()
   130  			mu2.Unlock()
   131  		}
   132  		if runtime.Compiler == "gccgo" {
   133  			runtime.Gosched()
   134  		}
   135  	}
   136  }
   137  
   138  // mutexHog starts multiple goroutines that runs the given hogger function for the specified duration.
   139  // The hogger function will be given two mutexes to lock & unlock.
   140  func mutexHog(duration time.Duration, hogger func(mu1, mu2 *sync.Mutex, start time.Time, dt time.Duration)) {
   141  	start := time.Now()
   142  	mu1 := new(sync.Mutex)
   143  	mu2 := new(sync.Mutex)
   144  	var wg sync.WaitGroup
   145  	wg.Add(10)
   146  	for i := 0; i < 10; i++ {
   147  		go func() {
   148  			defer wg.Done()
   149  			hogger(mu1, mu2, start, duration)
   150  		}()
   151  	}
   152  	wg.Wait()
   153  }
   154  
   155  func TestDeltaProfile(t *testing.T) {
   156  	if runtime.GOOS == "openbsd" && runtime.GOARCH == "arm" {
   157  		testenv.SkipFlaky(t, 50218)
   158  	}
   159  
   160  	rate := runtime.SetMutexProfileFraction(1)
   161  	defer func() {
   162  		runtime.SetMutexProfileFraction(rate)
   163  	}()
   164  
   165  	// mutexHog1 will appear in non-delta mutex profile
   166  	// if the mutex profile works.
   167  	mutexHog(20*time.Millisecond, mutexHog1)
   168  
   169  	// If mutexHog1 does not appear in the mutex profile,
   170  	// skip this test. Mutex profile is likely not working,
   171  	// so is the delta profile.
   172  
   173  	p, err := query("/debug/pprof/mutex")
   174  	if err != nil {
   175  		t.Skipf("mutex profile is unsupported: %v", err)
   176  	}
   177  
   178  	if !seen(p, "mutexHog1") {
   179  		t.Skipf("mutex profile is not working: %v", p)
   180  	}
   181  
   182  	// causes mutexHog2 call stacks to appear in the mutex profile.
   183  	done := make(chan bool)
   184  	go func() {
   185  		for {
   186  			mutexHog(20*time.Millisecond, mutexHog2)
   187  			select {
   188  			case <-done:
   189  				done <- true
   190  				return
   191  			default:
   192  				time.Sleep(10 * time.Millisecond)
   193  			}
   194  		}
   195  	}()
   196  	defer func() { // cleanup the above goroutine.
   197  		done <- true
   198  		<-done // wait for the goroutine to exit.
   199  	}()
   200  
   201  	for _, d := range []int{1, 4, 16, 32} {
   202  		endpoint := fmt.Sprintf("/debug/pprof/mutex?seconds=%d", d)
   203  		p, err := query(endpoint)
   204  		if err != nil {
   205  			t.Fatalf("failed to query %q: %v", endpoint, err)
   206  		}
   207  		if !seen(p, "mutexHog1") && seen(p, "mutexHog2") && p.DurationNanos > 0 {
   208  			break // pass
   209  		}
   210  		if d == 32 {
   211  			t.Errorf("want mutexHog2 but no mutexHog1 in the profile, and non-zero p.DurationNanos, got %v", p)
   212  		}
   213  	}
   214  	p, err = query("/debug/pprof/mutex")
   215  	if err != nil {
   216  		t.Fatalf("failed to query mutex profile: %v", err)
   217  	}
   218  	if !seen(p, "mutexHog1") || !seen(p, "mutexHog2") {
   219  		t.Errorf("want both mutexHog1 and mutexHog2 in the profile, got %v", p)
   220  	}
   221  }
   222  
   223  var srv = httptest.NewServer(nil)
   224  
   225  func query(endpoint string) (*profile.Profile, error) {
   226  	url := srv.URL + endpoint
   227  	r, err := http.Get(url)
   228  	if err != nil {
   229  		return nil, fmt.Errorf("failed to fetch %q: %v", url, err)
   230  	}
   231  	if r.StatusCode != http.StatusOK {
   232  		return nil, fmt.Errorf("failed to fetch %q: %v", url, r.Status)
   233  	}
   234  
   235  	b, err := io.ReadAll(r.Body)
   236  	r.Body.Close()
   237  	if err != nil {
   238  		return nil, fmt.Errorf("failed to read and parse the result from %q: %v", url, err)
   239  	}
   240  	return profile.Parse(bytes.NewBuffer(b))
   241  }
   242  
   243  // seen returns true if the profile includes samples whose stacks include
   244  // the specified function name (fname).
   245  func seen(p *profile.Profile, fname string) bool {
   246  	locIDs := map[*profile.Location]bool{}
   247  	for _, loc := range p.Location {
   248  		for _, l := range loc.Line {
   249  			if strings.Contains(l.Function.Name, fname) {
   250  				locIDs[loc] = true
   251  				break
   252  			}
   253  		}
   254  	}
   255  	for _, sample := range p.Sample {
   256  		for _, loc := range sample.Location {
   257  			if locIDs[loc] {
   258  				return true
   259  			}
   260  		}
   261  	}
   262  	return false
   263  }
   264
View as plain text