klog_test.go

Documentation: k8s.io/klog/v2/integration_tests

     1  package integration_tests_test
     2  
     3  import (
     4  	"bytes"
     5  	"fmt"
     6  	"io"
     7  	"io/ioutil"
     8  	"os"
     9  	"os/exec"
    10  	"path/filepath"
    11  	"regexp"
    12  	"runtime"
    13  	"strings"
    14  	"testing"
    15  )
    16  
    17  const (
    18  	infoLog    = "this is a info log line"
    19  	warningLog = "this is a warning log line"
    20  	errorLog   = "this is a error log line"
    21  	fatalLog   = "this is a fatal log line"
    22  )
    23  
    24  // res is a type alias to a slice of pointers to regular expressions.
    25  type res = []*regexp.Regexp
    26  
    27  var (
    28  	infoLogRE    = regexp.MustCompile(regexp.QuoteMeta(infoLog))
    29  	warningLogRE = regexp.MustCompile(regexp.QuoteMeta(warningLog))
    30  	errorLogRE   = regexp.MustCompile(regexp.QuoteMeta(errorLog))
    31  	fatalLogRE   = regexp.MustCompile(regexp.QuoteMeta(fatalLog))
    32  
    33  	stackTraceRE = regexp.MustCompile(`\ngoroutine \d+ \[[^]]+\]:\n`)
    34  
    35  	allLogREs = res{infoLogRE, warningLogRE, errorLogRE, fatalLogRE, stackTraceRE}
    36  
    37  	defaultExpectedInDirREs = map[int]res{
    38  		0: {stackTraceRE, fatalLogRE, errorLogRE, warningLogRE, infoLogRE},
    39  		1: {stackTraceRE, fatalLogRE, errorLogRE, warningLogRE},
    40  		2: {stackTraceRE, fatalLogRE, errorLogRE},
    41  		3: {stackTraceRE, fatalLogRE},
    42  	}
    43  	expectedOneOutputInDirREs = map[int]res{
    44  		0: {infoLogRE},
    45  		1: {warningLogRE},
    46  		2: {errorLogRE},
    47  		3: {fatalLogRE},
    48  	}
    49  
    50  	defaultNotExpectedInDirREs = map[int]res{
    51  		0: {},
    52  		1: {infoLogRE},
    53  		2: {infoLogRE, warningLogRE},
    54  		3: {infoLogRE, warningLogRE, errorLogRE},
    55  	}
    56  )
    57  
    58  func TestDestinationsWithDifferentFlags(t *testing.T) {
    59  	tests := map[string]struct {
    60  		// logfile states if the flag -log_file should be set
    61  		logfile bool
    62  		// logdir states if the flag -log_dir should be set
    63  		logdir bool
    64  		// flags is for additional flags to pass to the klog'ed executable
    65  		flags []string
    66  
    67  		// expectedLogFile states if we generally expect the log file to exist.
    68  		// If this is not set, we expect the file not to exist and will error if it
    69  		// does.
    70  		expectedLogFile bool
    71  		// expectedLogDir states if we generally expect the log files in the log
    72  		// dir to exist.
    73  		// If this is not set, we expect the log files in the log dir not to exist and
    74  		// will error if they do.
    75  		expectedLogDir bool
    76  
    77  		// expectedOnStderr is a list of REs we expect to find on stderr
    78  		expectedOnStderr res
    79  		// notExpectedOnStderr is a list of REs that we must not find on stderr
    80  		notExpectedOnStderr res
    81  		// expectedInFile is a list of REs we expect to find in the log file
    82  		expectedInFile res
    83  		// notExpectedInFile is a list of REs we must not find in the log file
    84  		notExpectedInFile res
    85  
    86  		// expectedInDir is a list of REs we expect to find in the log files in the
    87  		// log dir, specified by log severity (0 = warning, 1 = info, ...)
    88  		expectedInDir map[int]res
    89  		// notExpectedInDir is a list of REs we must not find in the log files in
    90  		// the log dir, specified by log severity (0 = warning, 1 = info, ...)
    91  		notExpectedInDir map[int]res
    92  	}{
    93  		"default flags": {
    94  			// Everything, EXCEPT the trace on fatal, goes to stderr
    95  
    96  			expectedOnStderr:    res{infoLogRE, warningLogRE, errorLogRE, fatalLogRE},
    97  			notExpectedOnStderr: res{stackTraceRE},
    98  		},
    99  		"everything disabled": {
   100  			// Nothing, including the trace on fatal, is showing anywhere
   101  
   102  			flags: []string{"-logtostderr=false", "-alsologtostderr=false", "-stderrthreshold=1000"},
   103  
   104  			notExpectedOnStderr: allLogREs,
   105  		},
   106  		"everything disabled but low stderrthreshold": {
   107  			// Everything above -stderrthreshold, including the trace on fatal, will
   108  			// be logged to stderr, even if we set -logtostderr to false.
   109  
   110  			flags: []string{"-logtostderr=false", "-alsologtostderr=false", "-stderrthreshold=1"},
   111  
   112  			expectedOnStderr:    res{warningLogRE, errorLogRE, stackTraceRE},
   113  			notExpectedOnStderr: res{infoLogRE},
   114  		},
   115  		"with logtostderr only": {
   116  			// Everything, EXCEPT the trace on fatal, goes to stderr
   117  
   118  			flags: []string{"-logtostderr=true", "-alsologtostderr=false", "-stderrthreshold=1000"},
   119  
   120  			expectedOnStderr:    res{infoLogRE, warningLogRE, errorLogRE, fatalLogRE},
   121  			notExpectedOnStderr: res{stackTraceRE},
   122  		},
   123  		"with log file only": {
   124  			// Everything, including the trace on fatal, goes to the single log file
   125  
   126  			logfile: true,
   127  			flags:   []string{"-logtostderr=false", "-alsologtostderr=false", "-stderrthreshold=1000"},
   128  
   129  			expectedLogFile: true,
   130  
   131  			notExpectedOnStderr: allLogREs,
   132  			expectedInFile:      allLogREs,
   133  		},
   134  		"with log dir only": {
   135  			// Everything, including the trace on fatal, goes to the log files in the log dir
   136  
   137  			logdir: true,
   138  			flags:  []string{"-logtostderr=false", "-alsologtostderr=false", "-stderrthreshold=1000"},
   139  
   140  			expectedLogDir: true,
   141  
   142  			notExpectedOnStderr: allLogREs,
   143  			expectedInDir:       defaultExpectedInDirREs,
   144  			notExpectedInDir:    defaultNotExpectedInDirREs,
   145  		},
   146  		"with log dir only and one_output": {
   147  			// Everything, including the trace on fatal, goes to the log files in the log dir
   148  
   149  			logdir: true,
   150  			flags:  []string{"-logtostderr=false", "-alsologtostderr=false", "-stderrthreshold=1000", "-one_output=true"},
   151  
   152  			expectedLogDir: true,
   153  
   154  			notExpectedOnStderr: allLogREs,
   155  			expectedInDir:       expectedOneOutputInDirREs,
   156  			notExpectedInDir:    defaultNotExpectedInDirREs,
   157  		},
   158  		"with log dir and logtostderr": {
   159  			// Everything, EXCEPT the trace on fatal, goes to stderr. The -log_dir is
   160  			// ignored, nothing goes to the log files in the log dir.
   161  
   162  			logdir: true,
   163  			flags:  []string{"-logtostderr=true", "-alsologtostderr=false", "-stderrthreshold=1000"},
   164  
   165  			expectedOnStderr:    res{infoLogRE, warningLogRE, errorLogRE, fatalLogRE},
   166  			notExpectedOnStderr: res{stackTraceRE},
   167  		},
   168  		"with log file and log dir": {
   169  			// Everything, including the trace on fatal, goes to the single log file.
   170  			// The -log_dir is ignored, nothing goes to the log file in the log dir.
   171  
   172  			logdir:  true,
   173  			logfile: true,
   174  			flags:   []string{"-logtostderr=false", "-alsologtostderr=false", "-stderrthreshold=1000"},
   175  
   176  			expectedLogFile: true,
   177  
   178  			notExpectedOnStderr: allLogREs,
   179  			expectedInFile:      allLogREs,
   180  		},
   181  		"with log file and alsologtostderr": {
   182  			// Everything, including the trace on fatal, goes to the single log file
   183  			// AND to stderr.
   184  
   185  			flags:   []string{"-alsologtostderr=true", "-logtostderr=false", "-stderrthreshold=1000"},
   186  			logfile: true,
   187  
   188  			expectedLogFile: true,
   189  
   190  			expectedOnStderr: allLogREs,
   191  			expectedInFile:   allLogREs,
   192  		},
   193  		"with log dir and alsologtostderr": {
   194  			// Everything, including the trace on fatal, goes to the log file in the
   195  			// log dir AND to stderr.
   196  
   197  			logdir: true,
   198  			flags:  []string{"-alsologtostderr=true", "-logtostderr=false", "-stderrthreshold=1000"},
   199  
   200  			expectedLogDir: true,
   201  
   202  			expectedOnStderr: allLogREs,
   203  			expectedInDir:    defaultExpectedInDirREs,
   204  			notExpectedInDir: defaultNotExpectedInDirREs,
   205  		},
   206  		"with log dir, alsologtostderr and one_output": {
   207  			// Everything, including the trace on fatal, goes to the log file in the
   208  			// log dir AND to stderr.
   209  
   210  			logdir: true,
   211  			flags:  []string{"-alsologtostderr=true", "-logtostderr=false", "-stderrthreshold=1000", "-one_output=true"},
   212  
   213  			expectedLogDir: true,
   214  
   215  			expectedOnStderr: allLogREs,
   216  			expectedInDir:    expectedOneOutputInDirREs,
   217  			notExpectedInDir: defaultNotExpectedInDirREs,
   218  		},
   219  	}
   220  
   221  	binaryFileExtention := ""
   222  	if runtime.GOOS == "windows" {
   223  		binaryFileExtention = ".exe"
   224  	}
   225  
   226  	for tcName, tc := range tests {
   227  		tc := tc
   228  		t.Run(tcName, func(t *testing.T) {
   229  			t.Parallel()
   230  			withTmpDir(t, func(logdir string) {
   231  				// :: Setup
   232  				flags := tc.flags
   233  				stderr := &bytes.Buffer{}
   234  				logfile := filepath.Join(logdir, "the_single_log_file") // /some/tmp/dir/the_single_log_file
   235  
   236  				if tc.logfile {
   237  					flags = append(flags, "-log_file="+logfile)
   238  				}
   239  				if tc.logdir {
   240  					flags = append(flags, "-log_dir="+logdir)
   241  				}
   242  
   243  				// :: Execute
   244  				klogRun(t, flags, stderr)
   245  
   246  				// :: Assert
   247  				// check stderr
   248  				checkForLogs(t, tc.expectedOnStderr, tc.notExpectedOnStderr, stderr.String(), "stderr")
   249  
   250  				// check log_file
   251  				if tc.expectedLogFile {
   252  					content := getFileContent(t, logfile)
   253  					checkForLogs(t, tc.expectedInFile, tc.notExpectedInFile, content, "logfile")
   254  				} else {
   255  					assertFileIsAbsent(t, logfile)
   256  				}
   257  
   258  				// check files in log_dir
   259  				for level, levelName := range logFileLevels {
   260  					binaryName := "main" + binaryFileExtention
   261  					logfile, err := getLogFilePath(logdir, binaryName, levelName)
   262  					if tc.expectedLogDir {
   263  						if err != nil {
   264  							t.Errorf("Unable to find log file: %v", err)
   265  						}
   266  						content := getFileContent(t, logfile)
   267  						checkForLogs(t, tc.expectedInDir[level], tc.notExpectedInDir[level], content, "logfile["+logfile+"]")
   268  					} else {
   269  						if err == nil {
   270  							t.Errorf("Unexpectedly found log file %s", logfile)
   271  						}
   272  					}
   273  				}
   274  			})
   275  		})
   276  	}
   277  }
   278  
   279  const klogExampleGoFile = "./internal/main.go"
   280  
   281  // klogRun spawns a simple executable that uses klog, to later inspect its
   282  // stderr and potentially created log files
   283  func klogRun(t *testing.T, flags []string, stderr io.Writer) {
   284  	callFlags := []string{"run", klogExampleGoFile}
   285  	callFlags = append(callFlags, flags...)
   286  
   287  	cmd := exec.Command("go", callFlags...)
   288  	cmd.Stderr = stderr
   289  	cmd.Env = append(os.Environ(),
   290  		"KLOG_INFO_LOG="+infoLog,
   291  		"KLOG_WARNING_LOG="+warningLog,
   292  		"KLOG_ERROR_LOG="+errorLog,
   293  		"KLOG_FATAL_LOG="+fatalLog,
   294  	)
   295  
   296  	err := cmd.Run()
   297  
   298  	if _, ok := err.(*exec.ExitError); !ok {
   299  		t.Fatalf("Run failed: %v", err)
   300  	}
   301  }
   302  
   303  var logFileLevels = map[int]string{
   304  	0: "INFO",
   305  	1: "WARNING",
   306  	2: "ERROR",
   307  	3: "FATAL",
   308  }
   309  
   310  func getFileContent(t *testing.T, filePath string) string {
   311  	content, err := ioutil.ReadFile(filePath)
   312  	if err != nil {
   313  		t.Errorf("Could not read file '%s': %v", filePath, err)
   314  	}
   315  	return string(content)
   316  }
   317  
   318  func assertFileIsAbsent(t *testing.T, filePath string) {
   319  	if _, err := os.Stat(filePath); !os.IsNotExist(err) {
   320  		t.Errorf("Expected file '%s' not to exist", filePath)
   321  	}
   322  }
   323  
   324  func checkForLogs(t *testing.T, expected, disallowed res, content, name string) {
   325  	for _, re := range expected {
   326  		checkExpected(t, true, name, content, re)
   327  	}
   328  	for _, re := range disallowed {
   329  		checkExpected(t, false, name, content, re)
   330  	}
   331  }
   332  
   333  func checkExpected(t *testing.T, expected bool, where string, haystack string, needle *regexp.Regexp) {
   334  	found := needle.MatchString(haystack)
   335  
   336  	if expected && !found {
   337  		t.Errorf("Expected to find '%s' in %s", needle, where)
   338  	}
   339  	if !expected && found {
   340  		t.Errorf("Expected not to find '%s' in %s", needle, where)
   341  	}
   342  }
   343  
   344  func withTmpDir(t *testing.T, f func(string)) {
   345  	tmpDir, err := ioutil.TempDir("", "klog_e2e_")
   346  	if err != nil {
   347  		t.Fatalf("Could not create temp directory: %v", err)
   348  	}
   349  	defer func() {
   350  		if err := os.RemoveAll(tmpDir); err != nil {
   351  			t.Fatalf("Could not remove temp directory '%s': %v", tmpDir, err)
   352  		}
   353  	}()
   354  
   355  	f(tmpDir)
   356  }
   357  
   358  // getLogFileFromDir returns the path of either the symbolic link to the logfile, or the the logfile itself. This must
   359  // be done as the creation of a symlink is not guaranteed on any platform. On Windows, only users with administration
   360  // privileges can create a symlink.
   361  func getLogFilePath(dir, binaryName, levelName string) (string, error) {
   362  	symlink := filepath.Join(dir, binaryName+"."+levelName)
   363  	if _, err := os.Stat(symlink); err == nil {
   364  		return symlink, nil
   365  	}
   366  	files, err := ioutil.ReadDir(dir)
   367  	if err != nil {
   368  		return "", fmt.Errorf("could not read directory %s: %v", dir, err)
   369  	}
   370  	var foundFile string
   371  	for _, file := range files {
   372  		if strings.HasPrefix(file.Name(), binaryName) && strings.Contains(file.Name(), levelName) {
   373  			if foundFile != "" {
   374  				return "", fmt.Errorf("found multiple matching files")
   375  			}
   376  			foundFile = file.Name()
   377  		}
   378  	}
   379  	if foundFile != "" {
   380  		return filepath.Join(dir, foundFile), nil
   381  	}
   382  	return "", fmt.Errorf("file missing from directory")
   383  }
   384
View as plain text