Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

authz: End2End test for AuditLogger #6304

Merged
merged 23 commits into from Jun 1, 2023
Merged

authz: End2End test for AuditLogger #6304

merged 23 commits into from Jun 1, 2023

Conversation

erm-g
Copy link
Contributor

@erm-g erm-g commented May 22, 2023

End to end tests covering

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

RELEASE NOTES: none

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

@rockspore rockspore left a comment

Choose a reason for hiding this comment

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

Left some initial comments. Please fix the tests.

authz/grpc_audit_end2end_test.go Outdated Show resolved Hide resolved
authz/grpc_audit_end2end_test.go Outdated Show resolved Hide resolved
Copy link
Contributor

@gtcooke94 gtcooke94 left a comment

Choose a reason for hiding this comment

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

A few small comments

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
@erm-g erm-g requested review from rockspore and gtcooke94 May 23, 2023 03:27
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
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
} else {
s.AuthzDescisionStat[false]++
}
s.SpiffeIds = append(s.SpiffeIds, event.Principal)
Copy link
Contributor

Choose a reason for hiding this comment

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

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

Copy link
Contributor Author

Choose a reason for hiding this comment

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

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

Copy link
Contributor

Choose a reason for hiding this comment

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

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 Outdated Show resolved Hide resolved
authz/grpc_audit_end2end_test.go Outdated Show resolved Hide resolved
@erm-g erm-g requested a review from rockspore May 23, 2023 21:06
Copy link
Contributor

@rockspore rockspore left a comment

Choose a reason for hiding this comment

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

Please fix the vet testing failure.

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

Choose a reason for hiding this comment

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

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 Outdated Show resolved Hide resolved
@erm-g erm-g requested a review from rockspore May 24, 2023 16:16
Copy link
Contributor

@rockspore rockspore left a comment

Choose a reason for hiding this comment

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

LGTM. Thanks!

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

Choose a reason for hiding this comment

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

micronit: 2023

@erm-g erm-g requested a review from easwars May 24, 2023 16:20
@dfawley dfawley self-assigned this May 24, 2023
@dfawley
Copy link
Contributor

dfawley commented May 24, 2023

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
Copy link
Contributor

dfawley commented May 24, 2023

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 Outdated Show resolved Hide resolved
Comment on lines 58 to 62
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)
Copy link
Contributor

Choose a reason for hiding this comment

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

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

Copy link
Contributor Author

Choose a reason for hiding this comment

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

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?

Copy link
Contributor

Choose a reason for hiding this comment

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

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:

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

Copy link
Contributor

Choose a reason for hiding this comment

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

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.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

No worries!

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
ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
defer cancel()

// Make 2 unary calls and 1 streaming call.
Copy link
Contributor

Choose a reason for hiding this comment

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

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.

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

Choose a reason for hiding this comment

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

This needs to check the error.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

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

Comment on lines 318 to 323
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])
}
Copy link
Contributor

Choose a reason for hiding this comment

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

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.

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 {
Copy link
Contributor

Choose a reason for hiding this comment

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

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

Copy link
Contributor Author

Choose a reason for hiding this comment

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

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 Show resolved Hide resolved
@dfawley dfawley removed their assignment May 24, 2023
_ "google.golang.org/grpc/authz/audit/stdout"
)

func TestAudit(t *testing.T) {
Copy link
Contributor

Choose a reason for hiding this comment

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

Please just Test, which is our convention.

Comment on lines 58 to 62
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)
Copy link
Contributor

Choose a reason for hiding this comment

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

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:

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

// 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),
Copy link
Contributor

Choose a reason for hiding this comment

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

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

Comment on lines 105 to 106
"request":
{
Copy link
Contributor

Choose a reason for hiding this comment

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

Missed one

Comment on lines 144 to 145
"paths":
[
Copy link
Contributor

Choose a reason for hiding this comment

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

Missed one

Comment on lines 182 to 183
"request":
{
Copy link
Contributor

Choose a reason for hiding this comment

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

Missed one

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

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
Copy link
Contributor

Choose a reason for hiding this comment

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

This is not a map anymore.

Comment on lines 304 to 306
if err != nil {
t.Fatalf("failed StreamingInputCall err: %v", err)
}
Copy link
Contributor

Choose a reason for hiding this comment

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

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.

Copy link
Contributor

@dfawley dfawley left a comment

Choose a reason for hiding this comment

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

Missed a couple recent changes

@@ -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
Copy link
Contributor

Choose a reason for hiding this comment

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

Space after // please.


// 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 {
Copy link
Contributor

Choose a reason for hiding this comment

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

Nit: CA not Ca

@erm-g erm-g requested a review from dfawley May 30, 2023 22:06
client.UnaryCall(ctx, &testpb.SimpleRequest{})
client.UnaryCall(ctx, &testpb.SimpleRequest{})
_, err = client.UnaryCall(ctx, &testpb.SimpleRequest{})
validateCallResult(t, err)
Copy link
Contributor

Choose a reason for hiding this comment

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

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)
}

Copy link
Contributor Author

Choose a reason for hiding this comment

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

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?

Copy link
Contributor

Choose a reason for hiding this comment

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

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.

Copy link
Contributor Author

@erm-g erm-g May 31, 2023

Choose a reason for hiding this comment

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

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.

Copy link
Contributor

Choose a reason for hiding this comment

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

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?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

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

}
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)
Copy link
Contributor

Choose a reason for hiding this comment

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

Please check the error.

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

Choose a reason for hiding this comment

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

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

Copy link
Contributor Author

Choose a reason for hiding this comment

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

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?

Copy link
Contributor

Choose a reason for hiding this comment

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

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.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

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

  • cmp.Diff cases
  • errors which status.Code is not expected

@erm-g erm-g merged commit 8edfa1a into grpc:master Jun 1, 2023
11 checks passed
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Nov 29, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants