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
Show file tree
Hide file tree
Changes from 18 commits
Commits
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
372 changes: 372 additions & 0 deletions authz/audit/audit_logging_test.go
@@ -0,0 +1,372 @@
/*
*
* Copyright 2023 gRPC authors.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*
*/

package audit_test

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

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

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

var permissionDeniedStatus = status.New(codes.PermissionDenied, "unauthorized RPC request rejected")

type s struct {
grpctest.Tester
}

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

type statAuditLogger struct {
authzDecisionStat map[bool]int // Map to hold the counts of authorization decisions
lastEvent *audit.Event // Field to store last received event
}

func (s *statAuditLogger) Log(event *audit.Event) {
s.authzDecisionStat[event.Authorized]++
*s.lastEvent = *event
}

type loggerBuilder struct {
authzDecisionStat map[bool]int
lastEvent *audit.Event
}

func (loggerBuilder) Name() string {
return "stat_logger"
}

func (lb *loggerBuilder) Build(audit.LoggerConfig) audit.Logger {
return &statAuditLogger{
authzDecisionStat: lb.authzDecisionStat,
lastEvent: lb.lastEvent,
}
}

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

// TestAuditLogger examines audit logging invocations using four different
// authorization policies. It covers scenarios including a disabled audit,
// auditing both 'allow' and 'deny' outcomes, and separately auditing 'allow'
// and 'deny' outcomes. 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), and a structure to check if
// the audit.Event fields are properly populated.
tests := []struct {
name string
authzPolicy string
wantAuthzOutcomes map[bool]int
eventContent *audit.Event
}{
{
name: "No audit",
authzPolicy: `{
"name": "authz",
"allow_rules": [
{
"name": "allow_UnaryCall",
"request": {
"paths": [
"/grpc.testing.TestService/UnaryCall"
]
}
}
],
"audit_logging_options": {
"audit_condition": "NONE",
"audit_loggers": [
{
"name": "stat_logger",
"config": {},
"is_optional": false
}
]
}
}`,
wantAuthzOutcomes: map[bool]int{true: 0, false: 0},
},
{
name: "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
}
]
}
}`,
wantAuthzOutcomes: map[bool]int{true: 2, false: 1},
eventContent: &audit.Event{
FullMethodName: "/grpc.testing.TestService/StreamingInputCall",
Principal: "spiffe://foo.bar.com/client/workload/1",
PolicyName: "authz",
MatchedRule: "authz_deny_all",
Authorized: false,
},
},
{
name: "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
}
]
}
}`,
wantAuthzOutcomes: map[bool]int{true: 2, false: 0},
},
{
name: "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
}
]
}
}`,
wantAuthzOutcomes: map[bool]int{true: 0, false: 3},
},
}
// Construct the credentials for the tests and the stub server
serverCreds := loadServerCreds(t)
clientCreds := loadClientCreds(t)
ss := &stubserver.StubServer{
UnaryCallF: func(ctx context.Context, in *testpb.SimpleRequest) (*testpb.SimpleResponse, error) {
return &testpb.SimpleResponse{}, nil
},
FullDuplexCallF: func(stream testgrpc.TestService_FullDuplexCallServer) error {
_, err := stream.Recv()
if err != io.EOF {
return err
}
return nil
},
}
for _, test := range tests {
t.Run(test.name, func(t *testing.T) {
// Setup test statAuditLogger, gRPC test server with authzPolicy, unary
// and stream interceptors.
lb := &loggerBuilder{
authzDecisionStat: map[bool]int{true: 0, false: 0},
lastEvent: &audit.Event{},
}
audit.RegisterLoggerBuilder(lb)
i, _ := authz.NewStatic(test.authzPolicy)

s := grpc.NewServer(
grpc.Creds(serverCreds),
grpc.ChainUnaryInterceptor(i.UnaryInterceptor),
grpc.ChainStreamInterceptor(i.StreamInterceptor))
defer s.Stop()
testgrpc.RegisterTestServiceServer(s, ss)
lis, err := net.Listen("tcp", "localhost:0")
if err != nil {
t.Fatalf("Error listening: %v", err)
}
go s.Serve(lis)

// Setup gRPC test client with certificates containing a SPIFFE Id.
clientConn, err := grpc.Dial(lis.Addr().String(), grpc.WithTransportCredentials(clientCreds))
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()

_, err = client.UnaryCall(ctx, &testpb.SimpleRequest{})
validateCallResult(t, err)
Copy link
Member

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
Member

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
Member

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

_, err = client.UnaryCall(ctx, &testpb.SimpleRequest{})
validateCallResult(t, err)
stream, _ := client.StreamingInputCall(ctx)
Copy link
Member

Choose a reason for hiding this comment

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

Please check the error.

req := &testpb.StreamingInputCallRequest{
Payload: &testpb.Payload{
Body: []byte("hi"),
},
}
validateCallResult(t, stream.Send(req))
_, err = stream.CloseAndRecv()
validateCallResult(t, err)

// Compare expected number of allows/denies with content of the internal
// map of statAuditLogger.
if diff := cmp.Diff(lb.authzDecisionStat, test.wantAuthzOutcomes); diff != "" {
t.Fatalf("Authorization decisions do not match\ndiff (-got +want):\n%s", diff)
}
// Compare last event received by statAuditLogger with expected event.
if test.eventContent != nil {
if diff := cmp.Diff(lb.lastEvent, test.eventContent); diff != "" {
t.Fatalf("Unexpected message\ndiff (-got +want):\n%s", diff)
}
}
})
}
}

// loadServerCreds constructs TLS containing server certs and CA
func loadServerCreds(t *testing.T) credentials.TransportCredentials {
t.Helper()
cert := loadKeys(t, "x509/server1_cert.pem", "x509/server1_key.pem")
certPool := loadCACerts(t, "x509/client_ca_cert.pem")
return credentials.NewTLS(&tls.Config{
ClientAuth: tls.RequireAndVerifyClientCert,
Certificates: []tls.Certificate{cert},
ClientCAs: certPool,
})
}

// loadClientCreds constructs TLS containing client certs and CA
func loadClientCreds(t *testing.T) credentials.TransportCredentials {
t.Helper()
cert := loadKeys(t, "x509/client_with_spiffe_cert.pem", "x509/client_with_spiffe_key.pem")
roots := loadCACerts(t, "x509/server_ca_cert.pem")
return credentials.NewTLS(&tls.Config{
Certificates: []tls.Certificate{cert},
RootCAs: roots,
ServerName: "x.test.example.com",
})

}

// loadKeys loads X509 key pair from the provided file paths.
// It is used for loading both client and server certificates for the test
func loadKeys(t *testing.T, certPath, key string) tls.Certificate {
t.Helper()
cert, err := tls.LoadX509KeyPair(testdata.Path(certPath), testdata.Path(key))
if err != nil {
t.Fatalf("tls.LoadX509KeyPair(%q, %q) failed: %v", certPath, key, err)
}
return cert
}

// 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 {
t.Helper()
ca, err := os.ReadFile(testdata.Path(certPath))
if err != nil {
t.Fatalf("os.ReadFile(%q) failed: %v", certPath, err)
}
roots := x509.NewCertPool()
if !roots.AppendCertsFromPEM(ca) {
t.Fatal("Failed to append certificates")
}
return roots
}

// validateCallResult checks if the error resulting from making a call can be
// ignored. It is used for both unary and streaming calls in this test.
func validateCallResult(t *testing.T, err error) {
t.Helper()
if err == nil || err == io.EOF {
return
}
if errStatus := status.Convert(err); errStatus.Code() != permissionDeniedStatus.Code() || errStatus.Message() != permissionDeniedStatus.Message() {
t.Errorf("Call failed:%v", err)
}
}