authz: End2End test for AuditLogger #6304

erm-g · 2023-05-22T15:43:02Z

End to end tests covering

AuditLogging invocation testing
Audit on Allow, Audit on Deny, Audit All, No Auditing
SPIFFE Ids from new cert

RELEASE NOTES: none

rockspore

Left some initial comments. Please fix the tests.

authz/grpc_audit_end2end_test.go

gtcooke94

A few small comments

authz/grpc_audit_end2end_test.go

rockspore · 2023-05-23T16:16:39Z

authz/grpc_audit_end2end_test.go

+	} else {
+		s.AuthzDescisionStat[false]++
+	}
+	s.SpiffeIds = append(s.SpiffeIds, event.Principal)


Now that we have EventContent, do we still need this field singled out?

I'm checking EventContent only once but I'd still prefer to check SPIFFE every time

Is there any specific reason behind that? I thought if Spiffe ID is populated in one case, we can safely assume it's already there.

authz/grpc_audit_end2end_test.go

rockspore

Please fix the vet testing failure.

rockspore · 2023-05-23T21:50:36Z

authz/grpc_audit_end2end_test.go

+	} else {
+		s.AuthzDescisionStat[false]++
+	}
+	s.SpiffeIds = append(s.SpiffeIds, event.Principal)


Is there any specific reason behind that? I thought if Spiffe ID is populated in one case, we can safely assume it's already there.

authz/grpc_audit_end2end_test.go

rockspore

LGTM. Thanks!

rockspore · 2023-05-24T16:17:29Z

authz/grpc_audit_end2end_test.go

@@ -0,0 +1,332 @@
+/*
+ *
+ * Copyright 2021 gRPC authors.


micronit: 2023

dfawley · 2023-05-24T23:09:28Z

RELEASE NOTES:

TBD

Please fill in release notes when creating the PR (or asap after noticing they're missing due to failing checker). This should be part of what is reviewed as part of the PR review. In this case, it's just for testing, so we use RELEASE NOTES: none (or n/a) since our users don't really care much about our tests (they just assume we do a good enough job with them).

dfawley · 2023-05-24T23:10:45Z

Also: only one Type label should be applied (pick the best one). In this case, Testing makes the most sense since you aren't addressing a security-related issue, but it's not actually all that important if there are no release notes.

authz/grpc_audit_end2end_test.go

dfawley · 2023-05-24T23:16:15Z

authz/grpc_audit_end2end_test.go

+	s.EventContent["rpc_method"] = event.FullMethodName
+	s.EventContent["principal"] = event.Principal
+	s.EventContent["policy_name"] = event.PolicyName
+	s.EventContent["matched_rule"] = event.MatchedRule
+	s.EventContent["authorized"] = strconv.FormatBool(event.Authorized)


Why not s.EventContent = event and make this field type *audit.Event? (Also consider a rename to lastEvent?)

Here EventContent is a map created at loggerBuilder but manipulated by statAuditLogger. At the end I'm using loggerBuilder to access it's content. I'm not sure how to achieve the same using *audit.Event - maybe only if I use a slice or map wrapping it?

I DON"T UNDERSTAND THIS> Why can't you just change the type of this field (now lastEventContent) to *audit.Event and rename the field to lastEvent? Are you saying the tricky bit is communicating between the test and the constructed logger? If so, 2 options:

Use *audit.Event and *s.lastEvent = *event

Use **audit.Event and *s.lastEvent = event

Wow what happened with my last comment here?? Sometimes the shift key sticks on my keyboard, but I can't believe I didn't see it. Sorry if that came off as rude, I didn't mean to type in all-caps.

No worries!

authz/grpc_audit_end2end_test.go

dfawley · 2023-05-24T23:42:05Z

authz/grpc_audit_end2end_test.go

+			ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
+			defer cancel()
+
+			// Make 2 unary calls and 1 streaming call.


By the time I got here reading the code, it's pretty obvious what is happening. 😄 IMO: delete this comment but put something like this up at the top of the function.

dfawley · 2023-05-24T23:42:48Z

authz/grpc_audit_end2end_test.go

+			if err := stream.Send(req); err != nil && err != io.EOF {
+				t.Fatalf("failed stream.Send err: %v", err)
+			}
+			stream.CloseAndRecv()


This needs to check the error.

I'm leaning towards ignoring the errors here - #6304 (comment)

dfawley · 2023-05-24T23:44:01Z

authz/grpc_audit_end2end_test.go

+			if lb.AuthDecisionStat[true] != test.wantAllows {
+				t.Errorf("Allow case failed, want %v got %v", test.wantAllows, lb.AuthDecisionStat[true])
+			}
+			if lb.AuthDecisionStat[false] != test.wantDenies {
+				t.Errorf("Deny case failed, want %v got %v", test.wantDenies, lb.AuthDecisionStat[false])
+			}


Maybe define map[bool]int as a want in the testcase struct instead? Or replace the map in the logger with 2 bools so it's clearer that this is comparing equivalent things.

dfawley · 2023-05-24T23:46:24Z

authz/grpc_audit_end2end_test.go

+				t.Errorf("Deny case failed, want %v got %v", test.wantDenies, lb.AuthDecisionStat[false])
+			}
+			// Compare event fields with expected values from authz policy.
+			if test.eventContent != nil {


Only one test case actually covers this. And it only captures the most recent event. Is that sufficient?

The idea is that we already tested event content propagation in unit tests. Here it's an extra check because of end to end scenario including certificate with a SPIFFE ID. That's why I'm doing it just once

testdata/x509/create.sh

dfawley · 2023-05-26T16:25:01Z

authz/audit_logging_test.go

+	_ "google.golang.org/grpc/authz/audit/stdout"
+)
+
+func TestAudit(t *testing.T) {


Please just Test, which is our convention.

dfawley · 2023-05-26T16:28:57Z

authz/grpc_audit_end2end_test.go

+	s.EventContent["rpc_method"] = event.FullMethodName
+	s.EventContent["principal"] = event.Principal
+	s.EventContent["policy_name"] = event.PolicyName
+	s.EventContent["matched_rule"] = event.MatchedRule
+	s.EventContent["authorized"] = strconv.FormatBool(event.Authorized)


I DON"T UNDERSTAND THIS> Why can't you just change the type of this field (now lastEventContent) to *audit.Event and rename the field to lastEvent? Are you saying the tricky bit is communicating between the test and the constructed logger? If so, 2 options:

Use *audit.Event and *s.lastEvent = *event

Use **audit.Event and *s.lastEvent = event

dfawley · 2023-05-26T16:29:44Z

authz/audit_logging_test.go

+// Additionally, it checks if SPIFFE ID from a certificate is propagated correctly.
+func (s) TestAuditLogger(t *testing.T) {
+	// Each test data entry contains an authz policy for a grpc server,
+	// how many 'allow' and 'deny' outcomes we expect (each test case makes 2 unary calls and one client-streaming call),


Please wrap all comments at 80 columns (every file and always). Thanks!

dfawley · 2023-05-26T16:31:17Z

authz/audit_logging_test.go

+						"request":
+						{


dfawley · 2023-05-26T16:31:24Z

authz/audit_logging_test.go

+							"paths":
+							[


dfawley · 2023-05-26T16:31:37Z

authz/audit_logging_test.go

+						"request":
+						{


dfawley · 2023-05-26T23:48:38Z

authz/audit/audit_logging_test.go

+
+type statAuditLogger struct {
+	authzDecisionStat map[bool]int // Map to hold the counts of authorization decisions
+	lastEvent         *audit.Event // Map to hold event fields in key:value fashion


This is not a map anymore.

dfawley · 2023-05-30T16:23:22Z

authz/grpc_audit_end2end_test.go

+			if err != nil {
+				t.Fatalf("failed StreamingInputCall err: %v", err)
+			}


I don't think ignoring errors is a good idea. Check them so we can more easily debug what went wrong instead of trying to figure out why the numbers didn't match up at the end.

dfawley

Missed a couple recent changes

dfawley · 2023-05-30T16:25:33Z

authz/audit/audit_logging_test.go

@@ -229,31 +227,46 @@ func (s) TestAuditLogger(t *testing.T) {
 			wantAuthzOutcomes: map[bool]int{true: 0, false: 3},
 		},
 	}
-
+	//Construct the credentials for the tests and the stub server


Space after // please.

dfawley · 2023-05-30T16:26:20Z

authz/audit/audit_logging_test.go

+
+// loadCaCerts loads CA certificates and constructs x509.CertPool
+// It is used for loading both client and server CAs for the test
+func loadCaCerts(t *testing.T, certPath string) *x509.CertPool {


Nit: CA not Ca

dfawley · 2023-05-30T22:12:47Z

authz/audit/audit_logging_test.go

-			client.UnaryCall(ctx, &testpb.SimpleRequest{})
-			client.UnaryCall(ctx, &testpb.SimpleRequest{})
+			_, err = client.UnaryCall(ctx, &testpb.SimpleRequest{})
+			validateCallResult(t, err)


Inline this please, since it's so simple:

if _, err := client.UnaryCall(ctx, &testpb.SimpleRequest{}); err != nil { t.Fatalf("Unexpected error from UnaryCall: %v", err) }

I also need to check if the err is a permission denied one - it's a valid scenario for the test (we count deny as well).
I think I can rely on code only but still it'll be 2 LOCs

_, err = client.UnaryCall(ctx, &testpb.SimpleRequest{}) if errCode := status.Code(err); errCode != permissionDeniedStatus.Code() && errCode != codes.OK { t.Errorf("Call failed:%v", err) }

Or I can create a helper function which takes SimpleResponse, error and returns back error code - smth like

if errCode := errorCodeExtractor(client.UnaryCall(ctx, &testpb.SimpleRequest{})); errCode != permissionDeniedStatus.Code() && errCode != codes.OK { t.Errorf("Call failed:%v", err) }

WDYT?

So this is more of a problem of your test design.. You're using a table driven test but things are sufficiently different between iterations that it leads to these sorts of problems.

If you want to not care which one should happen:

if _, err := UnaryCall(); err != nil && status.Code(err) != codes.PermissionDenied { t.Fatalf() }

Or if you want to require no error when unary should not be denied and vice-versa:

_, err := UnaryCall() if test.wantAuthzOutcomes[false] > 1 /* LOL */ && status.Code(err) != codes.PermissionDenied { t.Fatalf() } else if test.wantAuthzOutcomes[false] < 2 /* also LOL */ && err != nil { t.Fatalf() }

Realistically, the latter is how your code should behave, but it's ugly. Maybe the test should be reworked a bit or split into multiple tests, as this seems wrong.

So this is more of a problem of your test design.. You're using a table driven test but things are sufficiently different between iterations that it leads to these sorts of problems.

My idea is to have a set of authz policies with various audit_condition values. In order to test each audit_condition I need to make a few calls and then check if audit logger was invoked as expected. That's why I think that iterations are common enough to use a table driven approach. From my perspective

if _, err := UnaryCall(); err != nil && status.Code(err) != codes.PermissionDenied { t.Fatalf() }

covers all the cases (we want to error test if a call returns an err but it's not a permission denied one).

Maybe the test should be reworked a bit or split into multiple tests, as this seems wrong.

What'd be your suggestion for refactoring? I think that splitting it will result in very similar tests with different err handling for permission denied cases.

My idea is to have a set of authz policies with various audit_condition values. In order to test each audit_condition I need to make a few calls and then check if audit logger was invoked as expected. That's why I think that iterations are common enough to use a table driven approach. From my perspective

Maybe add a codes.Code for the expected result from the Unary and Streaming RPC calls to the table?

Agreed, I think it makes the test more readable. PTAL

dfawley · 2023-06-01T14:55:24Z

authz/audit/audit_logging_test.go

+			}
+			if _, err := client.UnaryCall(ctx, &testpb.SimpleRequest{}); status.Code(err) != test.wantUnaryCallCode {
+				t.Fatalf("Unexpected UnaryCall fail: got %v want %v", err, test.wantUnaryCallCode)
+			}
 			stream, _ := client.StreamingInputCall(ctx)


Please check the error.

dfawley · 2023-06-01T15:54:26Z

authz/audit/audit_logging_test.go

+			}
+			stream, err := client.StreamingInputCall(ctx)
+			if err != nil {
+				t.Errorf("StreamingInputCall failed:%v", err)


This one needs to be Fatal because using the stream is illegal.

I need some help here - go/go-style/decisions.md?cl=head#keep-going suggests to prefer Error over Fatal

to print out all of the failed checks in a single run

So for this test even if stream is not usable I can still proceed with unary calls to get the test results for it.
However the same doc suggests

Calling t.Fatal is primarily useful for reporting an unexpected error condition

and unusable stream is definitely something we don't expect.
WDYT?

True, Error is nicer, generally, but this is a precondition for (some of) the rest of the test. The "ideal" would be to skip just the streaming calls and the checks that depend on them happening, but that really clutters the code and isn't worth it at all. Just Fatal since a precondition failed and keep things simple.

Ok, sounds good - I changed Errorf to be used for

cmp.Diff cases

errors which status.Code is not expected

erm-g added 6 commits May 18, 2023 15:46

Draft of e2e test

5778913

No Audit, Audit on Allow and Deny

cebf932

Audit on Allow, Audit on Deny

d405ab2

fix typo

0baf0e6

SPIFFE related testing

b569c67

SPIFFE Id validation and certs creation script

135565a

erm-g requested review from rockspore and gtcooke94 May 22, 2023 15:43

rockspore requested changes May 22, 2023

View reviewed changes

authz/grpc_audit_end2end_test.go Outdated Show resolved Hide resolved

authz/grpc_audit_end2end_test.go Outdated Show resolved Hide resolved

gtcooke94 reviewed May 22, 2023

View reviewed changes

authz/grpc_audit_end2end_test.go Outdated Show resolved Hide resolved

authz/grpc_audit_end2end_test.go Outdated Show resolved Hide resolved

authz/grpc_audit_end2end_test.go Outdated Show resolved Hide resolved

Address PR comments

c19e304

erm-g added Type: Testing Type: Security labels May 23, 2023

erm-g added this to the 1.56 Release milestone May 23, 2023

Wrap tests using grpctest.Tester

1e7fcc4

erm-g requested review from rockspore and gtcooke94 May 23, 2023 03:27

gtcooke94 reviewed May 23, 2023

View reviewed changes

authz/grpc_audit_end2end_test.go Outdated Show resolved Hide resolved

authz/grpc_audit_end2end_test.go Outdated Show resolved Hide resolved

authz/grpc_audit_end2end_test.go Outdated Show resolved Hide resolved

rockspore reviewed May 23, 2023

View reviewed changes

arvindbr8 added the Status: Requires Reporter Clarification label May 23, 2023

arvindbr8 assigned erm-g May 23, 2023

erm-g added 2 commits May 23, 2023 20:36

Address PR comments

e5991f2

Change package name to authz_test to fit other end2end tests

620d990

erm-g requested a review from rockspore May 23, 2023 21:06

rockspore reviewed May 23, 2023

View reviewed changes

Add licence header, remove SPIFFE slice

cba398c

erm-g requested a review from rockspore May 24, 2023 16:16

rockspore approved these changes May 24, 2023

View reviewed changes

authz/grpc_audit_end2end_test.go Outdated

@@ -0,0 +1,332 @@

/*

*

* Copyright 2021 gRPC authors.

Copy link

Contributor

rockspore May 24, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

micronit: 2023

Licence year change

de59ce5

erm-g requested a review from easwars May 24, 2023 16:20

dfawley self-assigned this May 24, 2023

dfawley removed the Type: Security label May 24, 2023

dfawley reviewed May 24, 2023

View reviewed changes

dfawley removed their assignment May 24, 2023

erm-g added 2 commits May 26, 2023 04:03

Address PR comments part 1

9a8ee49

Address PR comments part 2

36bc552

dfawley reviewed May 26, 2023

View reviewed changes

erm-g added 3 commits May 26, 2023 22:13

Address PR comments part 3

b255385

Address PR comments final part

7777c5b

Drop newline for a brace

191fdf6

erm-g requested a review from dfawley May 29, 2023 04:16

dfawley reviewed May 30, 2023

View reviewed changes

Address PR comments, fix outdated function comment

80d38b4

erm-g requested a review from dfawley May 30, 2023 22:06

dfawley reviewed May 30, 2023

View reviewed changes

erm-g added 3 commits May 31, 2023 19:37

Address PR comments

46fda00

Fix typo

a02960d

Remove unused var

56eba6e

dfawley approved these changes Jun 1, 2023

View reviewed changes

Address PR comment, change most test error handling to Errorf

cb01a30

dfawley reviewed Jun 1, 2023

View reviewed changes

Address PR comments

4f30f15

dfawley approved these changes Jun 1, 2023

View reviewed changes

erm-g merged commit 8edfa1a into grpc:master Jun 1, 2023
11 checks passed

gtcooke94 mentioned this pull request Jun 15, 2023

xds: E2E Test for Audit Logging #6377

Merged

erm-g mentioned this pull request Oct 20, 2023

crl provider: Static and FileWatcher provider implementations #6670

Merged

github-actions bot locked as resolved and limited conversation to collaborators Nov 29, 2023

authz: End2End test for AuditLogger #6304

authz: End2End test for AuditLogger #6304

Conversation

erm-g commented May 22, 2023 • edited

rockspore left a comment

Choose a reason for hiding this comment

gtcooke94 left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

rockspore left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

rockspore left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dfawley commented May 24, 2023

dfawley commented May 24, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dfawley left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

erm-g May 31, 2023 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

erm-g commented May 22, 2023 •

edited

erm-g May 31, 2023 •

edited