Repository: kubernetes/minikube
Pull request #14711 (2022-08-02 20:54:01)

Fix audit tests
**Problem:**
The following would occasionally occur (flakey)
```
--- FAIL: TestAudit (0.00s)
    --- FAIL: TestAudit/LogCommandEnd (0.00s)
        audit_test.go:252: MaxAuditEntries did not work, expected 3 lines in the audit log found 5 /tmp/audit.json206795[22](https://github.com/kubernetes/minikube/runs/7639085179?check_suite_focus=true#step:6:23)61
E0802 19:42:18.446500   13569 logFile.go:49] failed to close the audit log: invalid argument
FAIL
```

**Cause:**
`LogCommandEnd` had hardcoded references to `localpath.AuditLog()` so setting `currentLogFile` to a test file still results in changes to `~/.minikube/logs/audit.json` instead of the desired test file.

**Fix:**
Created a variable `auditOverrideFilename` to override the audit log file to use when performing tests.

k8s-ci-robot: [APPROVALNOTIFIER] This PR is **APPROVED**

This pull-request has been approved by: *<a href="https://github.com/kubernetes/minikube/pull/14711#" title="Author self-approved">spowelljr</a>*

The full list of commands accepted by this bot can be found [here](https://go.k8s.io/bot-commands?repo=kubernetes%2Fminikube).

The pull request process is described [here](https://git.k8s.io/community/contributors/guide/owners.md#the-code-review-process)

<details >
Needs approval from an approver in each of these files:

- ~~[OWNERS](https://github.com/kubernetes/minikube/blob/master/OWNERS)~~ [spowelljr]

Approvers can indicate their approval by writing `/approve` in a comment
Approvers can cancel approval by writing `/approve cancel` in a comment
</details>
<!-- META={"approvers":[]} -->

Patch:
diff --git a/pkg/minikube/audit/audit.go b/pkg/minikube/audit/audit.go
index 8292bb227..6bbba3a85 100644
--- a/pkg/minikube/audit/audit.go
+++ b/pkg/minikube/audit/audit.go
@@ -30,7 +30,6 @@ import (
 	"github.com/spf13/viper"
 	"k8s.io/minikube/pkg/minikube/config"
 	"k8s.io/minikube/pkg/minikube/constants"
-	"k8s.io/minikube/pkg/minikube/localpath"
 	"k8s.io/minikube/pkg/version"
 )
 
@@ -91,7 +90,7 @@ func LogCommandEnd(id string) error {
 		return fmt.Errorf("failed to convert logs to rows: %v", err)
 	}
 	// have to truncate the audit log while closed as Windows can't truncate an open file
-	if err := os.Truncate(localpath.AuditLog(), 0); err != nil {
+	if err := truncateAuditLog(); err != nil {
 		return fmt.Errorf("failed to truncate audit log: %v", err)
 	}
 	if err := openAuditLog(); err != nil {
diff --git a/pkg/minikube/audit/logFile.go b/pkg/minikube/audit/logFile.go
index 6f2fd8e2e..fb5de7de3 100644
--- a/pkg/minikube/audit/logFile.go
+++ b/pkg/minikube/audit/logFile.go
@@ -25,8 +25,13 @@ import (
 	"k8s.io/minikube/pkg/minikube/out/register"
 )
 
-// currentLogFile the file that's used to store audit logs
-var currentLogFile *os.File
+var (
+	// currentLogFile the file that's used to store audit logs
+	currentLogFile *os.File
+
+	// auditOverrideFilename overrides the default audit log filename, used for testing purposes
+	auditOverrideFilename string
+)
 
 // openAuditLog opens the audit log file or creates it if it doesn't exist.
 func openAuditLog() error {
@@ -34,8 +39,7 @@ func openAuditLog() error {
 	if currentLogFile != nil {
 		return nil
 	}
-	lp := localpath.AuditLog()
-	f, err := os.OpenFile(lp, os.O_APPEND|os.O_CREATE|os.O_RDWR, 0644)
+	f, err := os.OpenFile(auditPath(), os.O_APPEND|os.O_CREATE|os.O_RDWR, 0644)
 	if err != nil {
 		return fmt.Errorf("failed to open the audit log: %v", err)
 	}
@@ -67,3 +71,18 @@ func appendToLog(row *row) error {
 	}
 	return nil
 }
+
+// truncateAuditLog truncates the audit log file
+func truncateAuditLog() error {
+	if err := os.Truncate(auditPath(), 0); err != nil {
+		return fmt.Errorf("failed to truncate audit log: %v", err)
+	}
+	return nil
+}
+
+func auditPath() string {
+	if auditOverrideFilename != "" {
+		return auditOverrideFilename
+	}
+	return localpath.AuditLog()
+}


Test patch:
diff --git a/pkg/minikube/audit/audit_test.go b/pkg/minikube/audit/audit_test.go
index 3397850bf..b5d1773e1 100644
--- a/pkg/minikube/audit/audit_test.go
+++ b/pkg/minikube/audit/audit_test.go
@@ -17,7 +17,6 @@ limitations under the License.
 package audit
 
 import (
-	"io"
 	"os"
 	"os/exec"
 	"os/user"
@@ -30,33 +29,30 @@ import (
 )
 
 func TestAudit(t *testing.T) {
-	var auditFilename string
+	defer func() { auditOverrideFilename = "" }()
 
 	t.Run("setup", func(t *testing.T) {
 		f, err := os.CreateTemp("", "audit.json")
 		if err != nil {
 			t.Fatalf("failed creating temporary file: %v", err)
 		}
-		auditFilename = f.Name()
+		defer f.Close()
+		auditOverrideFilename = f.Name()
 
-		s := `{"data":{"args":"-p mini1","command":"start","endTime":"Wed, 03 Feb 2021 15:33:05 MST","profile":"mini1","startTime":"Wed, 03 Feb 2021 15:30:33 MST","user":"user1"},"datacontenttype":"application/json","id":"9b7593cb-fbec-49e5-a3ce-bdc2d0bfb208","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.si  gs.minikube.audit"}
-{"data":{"args":"-p mini1","command":"start","endTime":"Wed, 03 Feb 2021 15:33:05 MST","profile":"mini1","startTime":"Wed, 03 Feb 2021 15:30:33 MST","user":"user1"},"datacontenttype":"application/json","id":"9b7593cb-fbec-49e5-a3ce-bdc2d0bfb208","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.si  gs.minikube.audit"}
+		s := `{"data":{"args":"-p mini1","command":"start","endTime":"Wed, 03 Feb 2021 15:33:05 MST","profile":"mini1","startTime":"Wed, 03 Feb 2021 15:30:33 MST","user":"user1"},"datacontenttype":"application/json","id":"9b7593cb-fbec-49e5-a3ce-bdc2d0bfb208","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.sigs.minikube.audit"}
+{"data":{"args":"-p mini1","command":"start","endTime":"Wed, 03 Feb 2021 15:33:05 MST","profile":"mini1","startTime":"Wed, 03 Feb 2021 15:30:33 MST","user":"user1"},"datacontenttype":"application/json","id":"9b7593cb-fbec-49e5-a3ce-bdc2d0bfb208","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.sigs.minikube.audit"}
 {"data":{"args":"--user user2","command":"logs","endTime":"Tue, 02 Feb 2021 16:46:20 MST","profile":"minikube","startTime":"Tue, 02 Feb 2021 16:46:00 MST","user":"user2"},"datacontenttype":"application/json","id":"fec03227-2484-48b6-880a-88fd010b5efd","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.sigs.minikube.audit"}
-{"data":{"args":"-p mini1","command":"start","endTime":"Wed, 03 Feb 2021 15:33:05 MST","profile":"mini1","startTime":"Wed, 03 Feb 2021 15:30:33 MST","user":"user1"},"datacontenttype":"application/json","id":"9b7593cb-fbec-49e5-a3ce-bdc2d0bfb208","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.si  gs.minikube.audit"}
+{"data":{"args":"-p mini1","command":"start","endTime":"Wed, 03 Feb 2021 15:33:05 MST","profile":"mini1","startTime":"Wed, 03 Feb 2021 15:30:33 MST","user":"user1"},"datacontenttype":"application/json","id":"9b7593cb-fbec-49e5-a3ce-bdc2d0bfb208","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.sigs.minikube.audit"}
 {"data":{"args":"--user user2","command":"logs","endTime":"Tue, 02 Feb 2021 16:46:20 MST","profile":"minikube","startTime":"Tue, 02 Feb 2021 16:46:00 MST","user":"user2"},"datacontenttype":"application/json","id":"fec03227-2484-48b6-880a-88fd010b5efd","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.sigs.minikube.audit"}
 `
 
 		if _, err := f.WriteString(s); err != nil {
 			t.Fatalf("failed writing to file: %v", err)
 		}
-		if _, err := f.Seek(0, io.SeekStart); err != nil {
-			t.Fatalf("failed seeking to start of file: %v", err)
-		}
-
-		currentLogFile = f
-		viper.Set(config.MaxAuditEntries, 3)
 	})
 
+	defer os.Remove(auditOverrideFilename)
+
 	t.Run("username", func(t *testing.T) {
 		u, err := user.Current()
 		if err != nil {
@@ -217,18 +213,19 @@ func TestAudit(t *testing.T) {
 		}()
 		mockArgs(t, os.Args)
 		auditID, err := LogCommandStart()
-		if auditID == "" {
-			t.Fatal("audit ID should not be empty")
-		}
 		if err != nil {
 			t.Fatal(err)
 		}
+		if auditID == "" {
+			t.Fatal("audit ID should not be empty")
+		}
 	})
 
 	t.Run("LogCommandEnd", func(t *testing.T) {
 		oldArgs := os.Args
 		defer func() { os.Args = oldArgs }()
-		os.Args = []string{"minikube"}
+		os.Args = []string{"minikube", "start"}
+		viper.Set(config.MaxAuditEntries, 3)
 
 		oldCommandLine := pflag.CommandLine
 		defer func() {
@@ -238,13 +235,13 @@ func TestAudit(t *testing.T) {
 		mockArgs(t, os.Args)
 		auditID, err := LogCommandStart()
 		if err != nil {
-			t.Fatal("start failed")
+			t.Fatalf("start failed: %v", err)
 		}
 		if err := LogCommandEnd(auditID); err != nil {
 			t.Fatal(err)
 		}
 
-		b, err := exec.Command("wc", "-l", auditFilename).Output()
+		b, err := exec.Command("wc", "-l", auditOverrideFilename).Output()
 		if err != nil {
 			t.Fatal(err)
 		}
@@ -257,7 +254,7 @@ func TestAudit(t *testing.T) {
 	t.Run("LogCommandEndNonExistingID", func(t *testing.T) {
 		oldArgs := os.Args
 		defer func() { os.Args = oldArgs }()
-		os.Args = []string{"minikube"}
+		os.Args = []string{"minikube", "start"}
 
 		oldCommandLine := pflag.CommandLine
 		defer func() {
@@ -265,8 +262,7 @@ func TestAudit(t *testing.T) {
 			pflag.Parse()
 		}()
 		mockArgs(t, os.Args)
-		err := LogCommandEnd("non-existing-id")
-		if err == nil {
+		if err := LogCommandEnd("non-existing-id"); err == nil {
 			t.Fatal("function LogCommandEnd should return an error when a non-existing id is passed in it as an argument")
 		}
 	})
diff --git a/pkg/minikube/audit/report_test.go b/pkg/minikube/audit/report_test.go
index 0f00725b4..308e6a61f 100644
--- a/pkg/minikube/audit/report_test.go
+++ b/pkg/minikube/audit/report_test.go
@@ -29,8 +29,8 @@ func TestReport(t *testing.T) {
 	}
 	defer os.Remove(f.Name())
 
-	s := `{"data":{"args":"-p mini1","command":"start","endTime":"Wed, 03 Feb 2021 15:33:05 MST","profile":"mini1","startTime":"Wed, 03 Feb 2021 15:30:33 MST","user":"user1"},"datacontenttype":"application/json","id":"9b7593cb-fbec-49e5-a3ce-bdc2d0bfb208","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.si  gs.minikube.audit"}
-{"data":{"args":"-p mini1","command":"start","endTime":"Wed, 03 Feb 2021 15:33:05 MST","profile":"mini1","startTime":"Wed, 03 Feb 2021 15:30:33 MST","user":"user1"},"datacontenttype":"application/json","id":"9b7593cb-fbec-49e5-a3ce-bdc2d0bfb208","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.si  gs.minikube.audit"}
+	s := `{"data":{"args":"-p mini1","command":"start","endTime":"Wed, 03 Feb 2021 15:33:05 MST","profile":"mini1","startTime":"Wed, 03 Feb 2021 15:30:33 MST","user":"user1"},"datacontenttype":"application/json","id":"9b7593cb-fbec-49e5-a3ce-bdc2d0bfb208","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.sigs.minikube.audit"}
+{"data":{"args":"-p mini1","command":"start","endTime":"Wed, 03 Feb 2021 15:33:05 MST","profile":"mini1","startTime":"Wed, 03 Feb 2021 15:30:33 MST","user":"user1"},"datacontenttype":"application/json","id":"9b7593cb-fbec-49e5-a3ce-bdc2d0bfb208","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.sigs.minikube.audit"}
 {"data":{"args":"--user user2","command":"logs","endTime":"Tue, 02 Feb 2021 16:46:20 MST","profile":"minikube","startTime":"Tue, 02 Feb 2021 16:46:00 MST","user":"user2"},"datacontenttype":"application/json","id":"fec03227-2484-48b6-880a-88fd010b5efd","source":"https://minikube.sigs.k8s.io/","specversion":"1.0","type":"io.k8s.sigs.minikube.audit"}
 `