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.

Sign up for GitHub

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

Jump to bottom

authz: End2End test for AuditLogger #6304

Merged
merged 23 commits into from
Jun 1, 2023
Merged

authz: End2End test for AuditLogger #6304

Show file tree
Hide file tree
Changes from 8 commits
Commits
Show all changes
23 commits
Select commit Hold shift + click to select a range
5778913
Draft of e2e test
erm-g May 18, 2023
cebf932
No Audit, Audit on Allow and Deny
erm-g May 18, 2023
d405ab2
Audit on Allow, Audit on Deny
erm-g May 19, 2023
0baf0e6
fix typo
erm-g May 19, 2023
b569c67
SPIFFE related testing
erm-g May 22, 2023
135565a
SPIFFE Id validation and certs creation script
erm-g May 22, 2023
c19e304
Address PR comments
erm-g May 23, 2023
1e7fcc4
Wrap tests using grpctest.Tester
erm-g May 23, 2023
e5991f2
Address PR comments
erm-g May 23, 2023
620d990
Change package name to authz_test to fit other end2end tests
erm-g May 23, 2023
cba398c
Add licence header, remove SPIFFE slice
erm-g May 24, 2023
de59ce5
Licence year change
erm-g May 24, 2023
9a8ee49
Address PR comments part 1
erm-g May 26, 2023
36bc552
Address PR comments part 2
erm-g May 26, 2023
b255385
Address PR comments part 3
erm-g May 26, 2023
7777c5b
Address PR comments final part
erm-g May 29, 2023
191fdf6
Drop newline for a brace
erm-g May 29, 2023
80d38b4
Address PR comments, fix outdated function comment
erm-g May 30, 2023
46fda00
Address PR comments
erm-g May 31, 2023
a02960d
Fix typo
erm-g May 31, 2023
56eba6e
Remove unused var
erm-g May 31, 2023
cb01a30
Address PR comment, change most test error handling to Errorf
erm-g Jun 1, 2023
4f30f15
Address PR comments
erm-g Jun 1, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
344 changes: 344 additions & 0 deletions authz/grpc_audit_end2end_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,344 @@
package authz

import (
"context"
"crypto/tls"
"crypto/x509"
"encoding/json"
"io"
"net"
"os"
"strconv"
"testing"
"time"

"github.com/google/go-cmp/cmp"
"google.golang.org/grpc"
"google.golang.org/grpc/authz/audit"
"google.golang.org/grpc/credentials"
"google.golang.org/grpc/internal/grpctest"
testgrpc "google.golang.org/grpc/interop/grpc_testing"
testpb "google.golang.org/grpc/interop/grpc_testing"
"google.golang.org/grpc/testdata"

_ "google.golang.org/grpc/authz/audit/stdout"
)

type s struct {
rockspore marked this conversation as resolved.
Show resolved Hide resolved
grpctest.Tester
}

func Test(t *testing.T) {
grpctest.RunSubTests(t, s{})
}

type testServer struct {
testgrpc.UnimplementedTestServiceServer
}

func (s *testServer) UnaryCall(ctx context.Context, req *testpb.SimpleRequest) (*testpb.SimpleResponse, error) {
return &testpb.SimpleResponse{}, nil
}

type statAuditLogger struct {
AuthzDescisionStat map[bool]int //Map to hold the counts of authorization decisions
dfawley marked this conversation as resolved.
Show resolved Hide resolved
EventContent map[string]string //Map to hold event fields in key:value fashion
SpiffeIds []string //Slice to hold collected SPIFFE IDs
}

func (s *statAuditLogger) Log(event *audit.Event) {
if event.Authorized {
s.AuthzDescisionStat[true]++
rockspore marked this conversation as resolved.
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.

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
Member

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
Member

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
Member

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!

}

type loggerBuilder struct {
AuthzDescisionStat map[bool]int
EventContent map[string]string
SpiffeIds []string
}

func (loggerBuilder) Name() string {
return "stat_logger"
}
func (lb *loggerBuilder) Build(audit.LoggerConfig) audit.Logger {
dfawley marked this conversation as resolved.
Show resolved Hide resolved
return &statAuditLogger{
AuthzDescisionStat: lb.AuthzDescisionStat,
EventContent: lb.EventContent,
}
}

func (*loggerBuilder) ParseLoggerConfig(config json.RawMessage) (audit.LoggerConfig, error) {
return nil, nil
}

const spiffeId = "spiffe://foo.bar.com/client/workload/1"

func (s) TestAuditLogger(t *testing.T) {
gtcooke94 marked this conversation as resolved.
Show resolved Hide resolved
dfawley marked this conversation as resolved.
Show resolved Hide resolved
tests := map[string]struct {
dfawley marked this conversation as resolved.
Show resolved Hide resolved
authzPolicy string
wantAllows int
wantDenies int
}{
"No audit": {
authzPolicy: `{
"name": "authz",
"allow_rules":
[
dfawley marked this conversation as resolved.
Show resolved Hide resolved
{
"name": "allow_UnaryCall",
"request":
{
"paths":
[
"/grpc.testing.TestService/UnaryCall"
]
}
}
],
"audit_logging_options": {
"audit_condition": "NONE",
"audit_loggers": [
{
"name": "stat_logger",
"config": {},
"is_optional": false
}
]
}
}`,
wantAllows: 0,
wantDenies: 0,
dfawley marked this conversation as resolved.
Show resolved Hide resolved
},
"Allow All Deny Streaming - Audit All": {
authzPolicy: `{
"name": "authz",
"allow_rules":
[
{
"name": "allow_all",
"request": {
"paths":
[
"*"
]
}
}
],
"deny_rules":
[
{
"name": "deny_all",
"request": {
"paths":
[
"/grpc.testing.TestService/StreamingInputCall"
]
}
}
],
"audit_logging_options": {
"audit_condition": "ON_DENY_AND_ALLOW",
"audit_loggers": [
{
"name": "stat_logger",
"config": {},
"is_optional": false
},
{
"name": "stdout_logger",
"is_optional": false
}
]
}
}`,
wantAllows: 2,
wantDenies: 1,
},
"Allow Unary - Audit Allow": {
authzPolicy: `{
"name": "authz",
"allow_rules":
[
{
"name": "allow_UnaryCall",
"request":
{
"paths":
[
"/grpc.testing.TestService/UnaryCall"
]
}
}
],
"audit_logging_options": {
"audit_condition": "ON_ALLOW",
"audit_loggers": [
{
"name": "stat_logger",
"config": {},
"is_optional": false
}
]
}
}`,
wantAllows: 2,
wantDenies: 0,
},
"Allow Typo - Audit Deny": {
authzPolicy: `{
"name": "authz",
"allow_rules":
[
{
"name": "allow_UnaryCall",
"request":
{
"paths":
[
"/grpc.testing.TestService/UnaryCall_Z"
]
}
}
],
"audit_logging_options": {
"audit_condition": "ON_DENY",
"audit_loggers": [
{
"name": "stat_logger",
"config": {},
"is_optional": false
}
]
}
}`,
wantAllows: 0,
wantDenies: 3,
},
}

for name, test := range tests {
t.Run(name, func(t *testing.T) {
// Setup test statAuditLogger, gRPC test server with authzPolicy, unary and stream interceptors
lb := &loggerBuilder{
AuthzDescisionStat: make(map[bool]int),
EventContent: make(map[string]string),
}
audit.RegisterLoggerBuilder(lb)
i, _ := NewStatic(test.authzPolicy)
cert, err := tls.LoadX509KeyPair(testdata.Path("x509/server1_cert.pem"), testdata.Path("x509/server1_key.pem"))
if err != nil {
t.Fatalf("tls.LoadX509KeyPair(x509/server1_cert.pem, x509/server1_key.pem) failed: %v", err)
}
ca, err := os.ReadFile(testdata.Path("x509/client_ca_cert.pem"))
if err != nil {
t.Fatalf("os.ReadFile(x509/client_ca_cert.pem) failed: %v", err)
}
certPool := x509.NewCertPool()
if !certPool.AppendCertsFromPEM(ca) {
t.Fatal("failed to append certificates")
}
creds := credentials.NewTLS(&tls.Config{
ClientAuth: tls.RequireAndVerifyClientCert,
Certificates: []tls.Certificate{cert},
ClientCAs: certPool,
})
Copy link
Member

Choose a reason for hiding this comment

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

This seems to be the same in every test case... I would move it outside the loop. Optionally: same thing with the logger builder, unless you're concerned about state leaking.

s := grpc.NewServer(
grpc.Creds(creds),
grpc.ChainUnaryInterceptor(i.UnaryInterceptor),
grpc.ChainStreamInterceptor(i.StreamInterceptor))
defer s.Stop()
testgrpc.RegisterTestServiceServer(s, &testServer{})
Copy link
Member

Choose a reason for hiding this comment

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

Does testServer have some magic behavior you need?

I would greatly prefer the use of grpc/internal/stubserver instead. See grpc/test/* for example usages. It should be really easy to use and not couple the behavior of this test and the service's implementation which is in another location.

lis, err := net.Listen("tcp", "localhost:0")
gtcooke94 marked this conversation as resolved.
Show resolved Hide resolved
if err != nil {
t.Fatalf("error listening: %v", err)
}
go s.Serve(lis)

// Setup gRPC test client with certificates containing a SPIFFE Id
cert, err = tls.LoadX509KeyPair(testdata.Path("x509/client_with_spiffe_cert.pem"), testdata.Path("x509/client_with_spiffe_key.pem"))
if err != nil {
t.Fatalf("tls.LoadX509KeyPair(x509/client1_cert.pem, x509/client1_key.pem) failed: %v", err)
Copy link
Member

Choose a reason for hiding this comment

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

This error message doesn't match the code.

Two options: 1. fix it, or 2. use a helper to fix this and everything else forever and always:

func loadKeys(t *testing.T, cert, key string) tls.WhateverTypeThisIs {
  t.Helper()
  cert, err := tls.LoadX509KeyPair(testdata.Path(cert), testdata.Path(key))
  if err != nil {
    t.Fatalf("tls.LoadX509KeyPair(%q, %q) failed: %v", cert, key, err)
  }
  return cert
}

}
ca, err = os.ReadFile(testdata.Path("x509/server_ca_cert.pem"))
if err != nil {
t.Fatalf("os.ReadFile(x509/server_ca_cert.pem) failed: %v", err)
}
roots := x509.NewCertPool()
if !roots.AppendCertsFromPEM(ca) {
t.Fatal("failed to append certificates")
}
creds = credentials.NewTLS(&tls.Config{
Certificates: []tls.Certificate{cert},
RootCAs: roots,
ServerName: "x.test.example.com",
})
clientConn, err := grpc.Dial(lis.Addr().String(), grpc.WithTransportCredentials(creds))
if err != nil {
t.Fatalf("grpc.Dial(%v) failed: %v", lis.Addr().String(), err)
}
defer clientConn.Close()
client := testgrpc.NewTestServiceClient(clientConn)
ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
defer cancel()

//Make 2 unary calls and 1 streaming call
client.UnaryCall(ctx, &testpb.SimpleRequest{})
client.UnaryCall(ctx, &testpb.SimpleRequest{})
stream, err := client.StreamingInputCall(ctx)
if err != nil {
t.Fatalf("failed StreamingInputCall err: %v", err)
}
Copy link
Member

Choose a reason for hiding this comment

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

Why do you check this error but not any error that could be returned by UnaryCall?

Also, starting a stream almost never fails. The way to get that error is to capture it from CloseAndRecv.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

That's a good point - I think the nature of the test is literally testing audit part of authz policy so I think just making calls and ignoring errors is fine.

Copy link
Member

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.

req := &testpb.StreamingInputCallRequest{
Payload: &testpb.Payload{
Body: []byte("hi"),
},
}
if err := stream.Send(req); err != nil && err != io.EOF {
t.Fatalf("failed stream.Send err: %v", err)
}
stream.CloseAndRecv()
Copy link
Member

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)


//Compare expected number of allows/denies with content of internal map of statAuditLogger
rockspore marked this conversation as resolved.
Show resolved Hide resolved
if lb.AuthzDescisionStat[true] != test.wantAllows {
t.Errorf("Allow case failed, want %v got %v", test.wantAllows, lb.AuthzDescisionStat[true])
}
if lb.AuthzDescisionStat[false] != test.wantDenies {
t.Errorf("Deny case failed, want %v got %v", test.wantDenies, lb.AuthzDescisionStat[false])
}
//Compare recorded SPIFFE Ids with the value from cert
for _, id := range lb.SpiffeIds {
if id != spiffeId {
t.Errorf("Unexpected SPIFFE Id, want %v got %v", spiffeId, id)
}
}
//Special case - compare event fields with expected values from authz policy
if name == `Allow All Deny Streaming - Audit All` {
if diff := cmp.Diff(lb.EventContent, generateEventAsMap()); diff != "" {
t.Fatalf("Unexpected message\ndiff (-got +want):\n%s", diff)
}
}
})
}
}

// generateEvent produces an map contaning audit.Event fields.
// It's used to compare captured audit.Event with the matched rule during
// `Allow All Deny Streaming - Audit All` scenario (authz_deny_all rule)
func generateEventAsMap() map[string]string {
dfawley marked this conversation as resolved.
Show resolved Hide resolved
return map[string]string{
"rpc_method": "/grpc.testing.TestService/StreamingInputCall",
"principal": "spiffe://foo.bar.com/client/workload/1",
"policy_name": "authz",
"matched_rule": "authz_deny_all",
"authorized": "false",
}
}
33 changes: 33 additions & 0 deletions testdata/x509/client_with_spiffe_cert.pem
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,33 @@
-----BEGIN CERTIFICATE-----
MIIFxzCCA6+gAwIBAgICA+gwDQYJKoZIhvcNAQELBQAwUDELMAkGA1UEBhMCVVMx
CzAJBgNVBAgMAkNBMQwwCgYDVQQHDANTVkwxDTALBgNVBAoMBGdSUEMxFzAVBgNV
BAMMDnRlc3QtY2xpZW50X2NhMB4XDTIzMDUyMjA1MDA1NVoXDTMzMDUxOTA1MDA1
NVowTjELMAkGA1UEBhMCVVMxCzAJBgNVBAgMAkNBMQwwCgYDVQQHDANTVkwxDTAL
BgNVBAoMBGdSUEMxFTATBgNVBAMMDHRlc3QtY2xpZW50MTCCAiIwDQYJKoZIhvcN
AQEBBQADggIPADCCAgoCggIBANXyLXGYzQFwLGwjzkeuo/y41voDH1Y9J+ee4qJU
OFuMKKXx5ai7n7dik4//J12OqJbbr416cFkKmcojwwbAdncXMV58EF82Bt8QRov0
Vtoio/wxlyRlxDlVYwr56W+0EVP9Q+kzA/dTnMgOQYIeSix96CUQRy8XDu1YX3rk
fiUkND9xxuQw8OXi3LXguv/lilLVC/lXiXwa0RWEgMZZU2S1/lAElAG3aZuuWULG
K+PpKPuqkcptbUPCvNN1eUs9/D82aoFuqRCmpTC+7bUO+SJSggpUHcgTbXT9i6OO
9eR0ijcaQjtb0Y6ro+Cv60YOnlGC8It3KoY2SxioyqdceRUohqs4T4hjBEckzz11
AC0Pj0Gp4NJPcOY68EjhD5rvncn76RRr3z2XZpd+2Nz+Fldxk/aaejfdgqs9lo1g
C+aP+nk9oqSpFAc+rpHsblLZehUur/FHhenn1pYWqkSJsAG0sFW4sDHATRIfva3c
HNHB5kBzruGymywBGO0xOw7+s5XzPiNnbXT5FBY1rKG7RwlqdtDh6LWJRHmEblWV
tPHNiY+rrStv0rN7Hk/YKcSXd5JiTjk3GXjO1YJJVEraEWHlxzdGy+xu/m0iJLed
pxZwuxxdZ/Q2+Ht+X9pO2DsW8BQFbddCwbooxKygwSlmHCN1gRSWqWMZY5nzsxxY
tic9AgMBAAGjgawwgakwDAYDVR0TAQH/BAIwADAdBgNVHQ4EFgQUyiXne0d3g9zN
gjhCdl2d9ykxIfgwDgYDVR0PAQH/BAQDAgXgMBYGA1UdJQEB/wQMMAoGCCsGAQUF
BwMCMDEGA1UdEQQqMCiGJnNwaWZmZTovL2Zvby5iYXIuY29tL2NsaWVudC93b3Jr
bG9hZC8xMB8GA1UdIwQYMBaAFOr3a0MblN9W9Opu7VsDn3crpoDCMA0GCSqGSIb3
DQEBCwUAA4ICAQB3pt3mLXDDcReko9eTFahkNyU2zGP7CSi1RcgfP1aJDLBTjePb
JUhoY14tSpOGSliXWscXbNveW+Yk+tB411r8SJuXIkaYZM2BJQDWFzL7aLfAQSx5
rf8tHVyKO89uBoQtgEnxZp9BFhBp/b2y5DLrZWjM6W9s21C9S9UIFjD8UwrKicNH
HGxIC6AZ6yc0x2Nsq/KW1IZ6HDueZRB4tud75wwkPVpS5fb+XqIJEBP7lgYrJjGp
aLLxV2vn1kX2/qbH31hhWVpNyPkpFsT+IbkPFLDyQoZKHbewD6M56+KBRTTENETQ
hFLgJB0HiICJ2I6cqw1UbDJMJFkcnThsuI8Wg9dxZ+OffYeZ5bnFCVIg0WUi9oMK
JDXZAqYDwBaQHyNszaYzZ5VE2Gd/K8PEDevW4RblI+vAOamIM5w1DjQHWf7n1byt
nGwnxt4IQ5vwlrdX3FDcEkhacHdcniX/FTpYrfOistPh+QpBAvA92DG1CbAf2nKY
yXLx+Ho7tUEBGioU4XvRHccwumfatf5z+JO/EvIi2yWd1tanl5J3o/sSs9ixJfx4
aSuM+zAwf8EM+YGqYMCZ896+T6/r7NAg+YIDYu1K5b5QqYyPanqNqUf9VTR4oQ4v
+jdb5PkujXbjENvkAhNbUyUbQJ+IU0KHm3/sdhRPN5tuc9C+BTSQvlmKkw==
-----END CERTIFICATE-----