stacktrace_ext_test.go

Documentation: go.uber.org/zap

     1  // Copyright (c) 2016, 2017 Uber Technologies, Inc.
     2  //
     3  // Permission is hereby granted, free of charge, to any person obtaining a copy
     4  // of this software and associated documentation files (the "Software"), to deal
     5  // in the Software without restriction, including without limitation the rights
     6  // to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
     7  // copies of the Software, and to permit persons to whom the Software is
     8  // furnished to do so, subject to the following conditions:
     9  //
    10  // The above copyright notice and this permission notice shall be included in
    11  // all copies or substantial portions of the Software.
    12  //
    13  // THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
    14  // IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
    15  // FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
    16  // AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
    17  // LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
    18  // OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
    19  // THE SOFTWARE.
    20  
    21  package zap_test
    22  
    23  import (
    24  	"bytes"
    25  	"encoding/json"
    26  	"os"
    27  	"os/exec"
    28  	"path/filepath"
    29  	"runtime"
    30  	"strings"
    31  	"testing"
    32  
    33  	"go.uber.org/zap"
    34  	"go.uber.org/zap/zapcore"
    35  
    36  	"github.com/stretchr/testify/assert"
    37  	"github.com/stretchr/testify/require"
    38  )
    39  
    40  // _zapPackages are packages that we search for in the logging output to match a
    41  // zap stack frame. It is different from _zapStacktracePrefixes which  is only
    42  // intended to match on the function name, while this is on the full output
    43  // which includes filenames.
    44  var _zapPackages = []string{
    45  	"go.uber.org/zap.",
    46  	"go.uber.org/zap/zapcore.",
    47  }
    48  
    49  func TestStacktraceFiltersZapLog(t *testing.T) {
    50  	withLogger(t, func(logger *zap.Logger, out *bytes.Buffer) {
    51  		logger.Error("test log")
    52  		logger.Sugar().Error("sugar test log")
    53  
    54  		require.Contains(t, out.String(), "TestStacktraceFiltersZapLog", "Should not strip out non-zap import")
    55  		verifyNoZap(t, out.String())
    56  	})
    57  }
    58  
    59  func TestStacktraceFiltersZapMarshal(t *testing.T) {
    60  	withLogger(t, func(logger *zap.Logger, out *bytes.Buffer) {
    61  		marshal := func(enc zapcore.ObjectEncoder) error {
    62  			logger.Warn("marshal caused warn")
    63  			enc.AddString("f", "v")
    64  			return nil
    65  		}
    66  		logger.Error("test log", zap.Object("obj", zapcore.ObjectMarshalerFunc(marshal)))
    67  
    68  		logs := out.String()
    69  
    70  		// The marshal function (which will be under the test function) should not be stripped.
    71  		const marshalFnPrefix = "TestStacktraceFiltersZapMarshal."
    72  		require.Contains(t, logs, marshalFnPrefix, "Should not strip out marshal call")
    73  
    74  		// There should be no zap stack traces before that point.
    75  		marshalIndex := strings.Index(logs, marshalFnPrefix)
    76  		verifyNoZap(t, logs[:marshalIndex])
    77  
    78  		// After that point, there should be zap stack traces - we don't want to strip out
    79  		// the Marshal caller information.
    80  		for _, fnPrefix := range _zapPackages {
    81  			require.Contains(t, logs[marshalIndex:], fnPrefix, "Missing zap caller stack for Marshal")
    82  		}
    83  	})
    84  }
    85  
    86  func TestStacktraceFiltersVendorZap(t *testing.T) {
    87  	// We already have the dependencies downloaded so this should be
    88  	// instant.
    89  	deps := downloadDependencies(t)
    90  
    91  	// We need to simulate a zap as a vendor library, so we're going to
    92  	// create a fake GOPATH and run the above test which will contain zap
    93  	// in the vendor directory.
    94  	withGoPath(t, func(goPath string) {
    95  		zapDir, err := os.Getwd()
    96  		require.NoError(t, err, "Failed to get current directory")
    97  
    98  		testDir := filepath.Join(goPath, "src/go.uber.org/zap_test/")
    99  		vendorDir := filepath.Join(testDir, "vendor")
   100  		require.NoError(t, os.MkdirAll(testDir, 0o777), "Failed to create source director")
   101  
   102  		curFile := getSelfFilename(t)
   103  		setupSymlink(t, curFile, filepath.Join(testDir, curFile))
   104  
   105  		// Set up symlinks for zap, and for any test dependencies.
   106  		setupSymlink(t, zapDir, filepath.Join(vendorDir, "go.uber.org/zap"))
   107  		for _, dep := range deps {
   108  			setupSymlink(t, dep.Dir, filepath.Join(vendorDir, dep.ImportPath))
   109  		}
   110  
   111  		// Now run the above test which ensures we filter out zap
   112  		// stacktraces, but this time zap is in a vendor
   113  		cmd := exec.Command("go", "test", "-v", "-run", "TestStacktraceFiltersZap")
   114  		cmd.Dir = testDir
   115  		cmd.Env = append(os.Environ(), "GO111MODULE=off")
   116  		out, err := cmd.CombinedOutput()
   117  		require.NoError(t, err, "Failed to run test in vendor directory, output: %s", out)
   118  		assert.Contains(t, string(out), "PASS")
   119  	})
   120  }
   121  
   122  func TestStacktraceWithoutCallerSkip(t *testing.T) {
   123  	withLogger(t, func(logger *zap.Logger, out *bytes.Buffer) {
   124  		func() {
   125  			logger.Error("test log")
   126  		}()
   127  
   128  		require.Contains(t, out.String(), "TestStacktraceWithoutCallerSkip.", "Should not skip too much")
   129  		verifyNoZap(t, out.String())
   130  	})
   131  }
   132  
   133  func TestStacktraceWithCallerSkip(t *testing.T) {
   134  	withLogger(t, func(logger *zap.Logger, out *bytes.Buffer) {
   135  		logger = logger.WithOptions(zap.AddCallerSkip(2))
   136  		func() {
   137  			logger.Error("test log")
   138  		}()
   139  
   140  		require.NotContains(t, out.String(), "TestStacktraceWithCallerSkip.", "Should skip as requested by caller skip")
   141  		require.Contains(t, out.String(), "TestStacktraceWithCallerSkip", "Should not skip too much")
   142  		verifyNoZap(t, out.String())
   143  	})
   144  }
   145  
   146  // withLogger sets up a logger with a real encoder set up, so that any marshal functions are called.
   147  // The inbuilt observer does not call Marshal for objects/arrays, which we need for some tests.
   148  func withLogger(t *testing.T, fn func(logger *zap.Logger, out *bytes.Buffer)) {
   149  	buf := &bytes.Buffer{}
   150  	encoder := zapcore.NewConsoleEncoder(zap.NewDevelopmentEncoderConfig())
   151  	core := zapcore.NewCore(encoder, zapcore.AddSync(buf), zapcore.DebugLevel)
   152  	logger := zap.New(core, zap.AddStacktrace(zap.DebugLevel))
   153  	fn(logger, buf)
   154  }
   155  
   156  func verifyNoZap(t *testing.T, logs string) {
   157  	for _, fnPrefix := range _zapPackages {
   158  		require.NotContains(t, logs, fnPrefix, "Should not strip out marshal call")
   159  	}
   160  }
   161  
   162  func withGoPath(t *testing.T, f func(goPath string)) {
   163  	goPath := filepath.Join(t.TempDir(), "gopath")
   164  	t.Setenv("GOPATH", goPath)
   165  
   166  	f(goPath)
   167  }
   168  
   169  func getSelfFilename(t *testing.T) string {
   170  	_, file, _, ok := runtime.Caller(0)
   171  	require.True(t, ok, "Failed to get caller information to identify local file")
   172  
   173  	return filepath.Base(file)
   174  }
   175  
   176  func setupSymlink(t *testing.T, src, dst string) {
   177  	// Make sure the destination directory exists.
   178  	require.NoError(t, os.MkdirAll(filepath.Dir(dst), 0o777))
   179  
   180  	// Get absolute path of the source for the symlink, otherwise we can create a symlink
   181  	// that uses relative paths.
   182  	srcAbs, err := filepath.Abs(src)
   183  	require.NoError(t, err, "Failed to get absolute path")
   184  
   185  	require.NoError(t, os.Symlink(srcAbs, dst), "Failed to set up symlink")
   186  }
   187  
   188  type dependency struct {
   189  	ImportPath string `json:"Path"` // import path of the dependency
   190  	Dir        string `json:"Dir"`  // location on disk
   191  }
   192  
   193  // Downloads all dependencies for the current Go module and reports their
   194  // module paths and locations on disk.
   195  func downloadDependencies(t *testing.T) []dependency {
   196  	cmd := exec.Command("go", "mod", "download", "-json")
   197  
   198  	stdout, err := cmd.Output()
   199  	require.NoError(t, err, "Failed to run 'go mod download'")
   200  
   201  	var deps []dependency
   202  	dec := json.NewDecoder(bytes.NewBuffer(stdout))
   203  	for dec.More() {
   204  		var d dependency
   205  		require.NoError(t, dec.Decode(&d), "Failed to decode dependency")
   206  		deps = append(deps, d)
   207  	}
   208  
   209  	return deps
   210  }
   211
View as plain text