coder · johnstcn · Feb 14, 2023 · Jan 27, 2023 · Jan 30, 2023 · Jan 30, 2023
diff --git a/coderd/authzquery/apikey.go b/coderd/authzquery/apikey.go
@@ -10,11 +10,11 @@ import (
 )
 
 func (q *AuthzQuerier) DeleteAPIKeyByID(ctx context.Context, id string) error {
-	return authorizedDelete(q.authorizer, q.database.GetAPIKeyByID, q.database.DeleteAPIKeyByID)(ctx, id)
+	return authorizedDelete(q.logger, q.authorizer, q.database.GetAPIKeyByID, q.database.DeleteAPIKeyByID)(ctx, id)
 }
 
 func (q *AuthzQuerier) GetAPIKeyByID(ctx context.Context, id string) (database.APIKey, error) {
-	return authorizedFetch(q.authorizer, q.database.GetAPIKeyByID)(ctx, id)
+	return authorizedFetch(q.logger, q.authorizer, q.database.GetAPIKeyByID)(ctx, id)
 }
 
 func (q *AuthzQuerier) GetAPIKeysByLoginType(ctx context.Context, loginType database.LoginType) ([]database.APIKey, error) {
@@ -26,7 +26,7 @@ func (q *AuthzQuerier) GetAPIKeysLastUsedAfter(ctx context.Context, lastUsed tim
 }
 
 func (q *AuthzQuerier) InsertAPIKey(ctx context.Context, arg database.InsertAPIKeyParams) (database.APIKey, error) {
-	return authorizedInsertWithReturn(q.authorizer,
+	return authorizedInsertWithReturn(q.logger, q.authorizer,
 		rbac.ActionRead,
 		rbac.ResourceAPIKey.WithOwner(arg.UserID.String()),
 		q.database.InsertAPIKey)(ctx, arg)
@@ -36,5 +36,5 @@ func (q *AuthzQuerier) UpdateAPIKeyByID(ctx context.Context, arg database.Update
 	fetch := func(ctx context.Context, arg database.UpdateAPIKeyByIDParams) (database.APIKey, error) {
 		return q.GetAPIKeyByID(ctx, arg.ID)
 	}
-	return authorizedUpdate(q.authorizer, fetch, q.database.UpdateAPIKeyByID)(ctx, arg)
+	return authorizedUpdate(q.logger, q.authorizer, fetch, q.database.UpdateAPIKeyByID)(ctx, arg)
 }
diff --git a/coderd/authzquery/audit.go b/coderd/authzquery/audit.go
@@ -8,7 +8,7 @@ import (
 )
 
 func (q *AuthzQuerier) InsertAuditLog(ctx context.Context, arg database.InsertAuditLogParams) (database.AuditLog, error) {
-	return authorizedInsertWithReturn(q.authorizer, rbac.ActionCreate, rbac.ResourceAuditLog, q.database.InsertAuditLog)(ctx, arg)
+	return authorizedInsertWithReturn(q.logger, q.authorizer, rbac.ActionCreate, rbac.ResourceAuditLog, q.database.InsertAuditLog)(ctx, arg)
 }
 
 func (q *AuthzQuerier) GetAuditLogsOffset(ctx context.Context, arg database.GetAuditLogsOffsetParams) ([]database.GetAuditLogsOffsetRow, error) {

diff --git a/coderd/authzquery/authz.go b/coderd/authzquery/authz.go
@@ -3,6 +3,9 @@ package authzquery
 import (
 	"context"
 	"database/sql"
+	"fmt"
+
+	"cdr.dev/slog"
 
 	"golang.org/x/xerrors"
 
@@ -17,20 +20,51 @@ var (
 	// NoActorError wraps ErrNoRows for the api to return a 404. This is the correct
 	// response when the user is not authorized.
 	NoActorError = xerrors.Errorf("no authorization actor in context: %w", sql.ErrNoRows)
-	// TODO: Log this error every time it occurs.
-	NotAuthorizedError = xerrors.Errorf("unauthorized: %w", sql.ErrNoRows)
 )
 
+// NotAuthorizedError is a sentinal error that unwraps to sql.ErrNoRows.
+// This allows the internal error to be read by the caller if needed. Otherwise
+// it will be handled as a 404.
+type NotAuthorizedError struct {
+	Err error
+}
+
+func (e NotAuthorizedError) Error() string {
+	return fmt.Sprintf("unauthorized: %s", e.Err.Error())
+}
+
+// Unwrap will always unwrap to a sql.ErrNoRows so the API returns a 404.
+// So 'errors.Is(err, sql.ErrNoRows)' will always be true.
+func (e NotAuthorizedError) Unwrap() error {
+	return sql.ErrNoRows
+}
+
+func LogNotAuthorizedError(ctx context.Context, logger slog.Logger, err error) error {
+	// Only log the errors if it is an UnauthorizedError error.
+	internalError := new(rbac.UnauthorizedError)
+	if err != nil && xerrors.As(err, internalError) {
+		logger.Debug(ctx, "unauthorized",
+			slog.F("internal", internalError.Internal()),
+			slog.F("input", internalError.Input()),
+			slog.Error(err),
+		)
+	}
+	return NotAuthorizedError{
+		Err: err,
+	}
+}
+
 func authorizedInsert[ArgumentType any,
 	Insert func(ctx context.Context, arg ArgumentType) error](
 	// Arguments
+	logger slog.Logger,
 	authorizer rbac.Authorizer,
 	action rbac.Action,
 	object rbac.Objecter,
 	insertFunc Insert) Insert {
 
 	return func(ctx context.Context, arg ArgumentType) error {
-		_, err := authorizedInsertWithReturn(authorizer, action, object, func(ctx context.Context, arg ArgumentType) (rbac.Objecter, error) {
+		_, err := authorizedInsertWithReturn(logger, authorizer, action, object, func(ctx context.Context, arg ArgumentType) (rbac.Objecter, error) {
 			return rbac.Object{}, insertFunc(ctx, arg)
 		})(ctx, arg)
 		return err
@@ -40,6 +74,7 @@ func authorizedInsert[ArgumentType any,
 func authorizedInsertWithReturn[ObjectType any, ArgumentType any,
 	Insert func(ctx context.Context, arg ArgumentType) (ObjectType, error)](
 	// Arguments
+	logger slog.Logger,
 	authorizer rbac.Authorizer,
 	action rbac.Action,
 	object rbac.Objecter,
@@ -55,7 +90,7 @@ func authorizedInsertWithReturn[ObjectType any, ArgumentType any,
 		// Authorize the action
 		err = authorizer.Authorize(ctx, act, action, object.RBACObject())
 		if err != nil {
-			return empty, NotAuthorizedError
+			return empty, LogNotAuthorizedError(ctx, logger, err)
 		}
 
 		// Insert the database object
@@ -67,11 +102,12 @@ func authorizedDelete[ObjectType rbac.Objecter, ArgumentType any,
 	Fetch func(ctx context.Context, arg ArgumentType) (ObjectType, error),
 	Delete func(ctx context.Context, arg ArgumentType) error](
 	// Arguments
+	logger slog.Logger,
 	authorizer rbac.Authorizer,
 	fetchFunc Fetch,
 	deleteFunc Delete) Delete {
 
-	return authorizedFetchAndExec(authorizer,
+	return authorizedFetchAndExec(logger, authorizer,
 		rbac.ActionDelete, fetchFunc, deleteFunc)
 }
 
@@ -80,23 +116,25 @@ func authorizedUpdateWithReturn[ObjectType rbac.Objecter,
 	Fetch func(ctx context.Context, arg ArgumentType) (ObjectType, error),
 	UpdateQuery func(ctx context.Context, arg ArgumentType) (ObjectType, error)](
 	// Arguments
+	logger slog.Logger,
 	authorizer rbac.Authorizer,
 	fetchFunc Fetch,
 	updateQuery UpdateQuery) UpdateQuery {
 
-	return authorizedFetchAndQuery(authorizer, rbac.ActionUpdate, fetchFunc, updateQuery)
+	return authorizedFetchAndQuery(logger, authorizer, rbac.ActionUpdate, fetchFunc, updateQuery)
 }
 
 func authorizedUpdate[ObjectType rbac.Objecter,
 	ArgumentType any,
 	Fetch func(ctx context.Context, arg ArgumentType) (ObjectType, error),
 	Exec func(ctx context.Context, arg ArgumentType) error](
 	// Arguments
+	logger slog.Logger,
 	authorizer rbac.Authorizer,
 	fetchFunc Fetch,
 	updateExec Exec) Exec {
 
-	return authorizedFetchAndExec(authorizer, rbac.ActionUpdate, fetchFunc, updateExec)
+	return authorizedFetchAndExec(logger, authorizer, rbac.ActionUpdate, fetchFunc, updateExec)
 }
 
 // authorizedFetchAndExecWithConverter uses authorizedFetchAndQueryWithConverter but
@@ -107,12 +145,13 @@ func authorizedFetchAndExec[ObjectType rbac.Objecter,
 	Fetch func(ctx context.Context, arg ArgumentType) (ObjectType, error),
 	Exec func(ctx context.Context, arg ArgumentType) error](
 	// Arguments
+	logger slog.Logger,
 	authorizer rbac.Authorizer,
 	action rbac.Action,
 	fetchFunc Fetch,
 	execFunc Exec) Exec {
 
-	f := authorizedFetchAndQuery(authorizer, action, fetchFunc, func(ctx context.Context, arg ArgumentType) (empty ObjectType, err error) {
+	f := authorizedFetchAndQuery(logger, authorizer, action, fetchFunc, func(ctx context.Context, arg ArgumentType) (empty ObjectType, err error) {
 		return empty, execFunc(ctx, arg)
 	})
 	return func(ctx context.Context, arg ArgumentType) error {
@@ -125,6 +164,7 @@ func authorizedFetchAndQuery[ObjectType rbac.Objecter, ArgumentType any,
 	Fetch func(ctx context.Context, arg ArgumentType) (ObjectType, error),
 	Query func(ctx context.Context, arg ArgumentType) (ObjectType, error)](
 	// Arguments
+	logger slog.Logger,
 	authorizer rbac.Authorizer,
 	action rbac.Action,
 	fetchFunc Fetch,
@@ -146,7 +186,7 @@ func authorizedFetchAndQuery[ObjectType rbac.Objecter, ArgumentType any,
 		// Authorize the action
 		err = authorizer.Authorize(ctx, act, action, object.RBACObject())
 		if err != nil {
-			return empty, NotAuthorizedError
+			return empty, LogNotAuthorizedError(ctx, logger, err)
 		}
 
 		return queryFunc(ctx, arg)
@@ -156,10 +196,11 @@ func authorizedFetchAndQuery[ObjectType rbac.Objecter, ArgumentType any,
 func authorizedFetch[ObjectType rbac.Objecter, ArgumentType any,
 	Fetch func(ctx context.Context, arg ArgumentType) (ObjectType, error)](
 	// Arguments
+	logger slog.Logger,
 	authorizer rbac.Authorizer,
 	fetchFunc Fetch) Fetch {
 
-	return authorizedQuery(authorizer, rbac.ActionRead, fetchFunc)
+	return authorizedQuery(logger, authorizer, rbac.ActionRead, fetchFunc)
 }
 
 // authorizedQuery is a generic function that wraps a database
@@ -175,6 +216,7 @@ func authorizedFetch[ObjectType rbac.Objecter, ArgumentType any,
 func authorizedQuery[ArgumentType any, ObjectType rbac.Objecter,
 	DatabaseFunc func(ctx context.Context, arg ArgumentType) (ObjectType, error)](
 	// Arguments
+	logger slog.Logger,
 	authorizer rbac.Authorizer,
 	action rbac.Action,
 	f DatabaseFunc) DatabaseFunc {
@@ -195,7 +237,7 @@ func authorizedQuery[ArgumentType any, ObjectType rbac.Objecter,
 		// Authorize the action
 		err = authorizer.Authorize(ctx, act, action, object.RBACObject())
 		if err != nil {
-			return empty, NotAuthorizedError
+			return empty, LogNotAuthorizedError(ctx, logger, err)
 		}
 
 		return object, nil
@@ -236,6 +278,7 @@ func authorizedFetchSet[ArgumentType any, ObjectType rbac.Objecter,
 // are predicated on the RBAC permissions of the related Template object.
 func authorizedQueryWithRelated[ObjectType any, ArgumentType any, Related rbac.Objecter](
 	// Arguments
+	logger slog.Logger,
 	authorizer rbac.Authorizer,
 	action rbac.Action,
 	relatedFunc func(ObjectType, ArgumentType) (Related, error),

diff --git a/coderd/authzquery/authz_test.go b/coderd/authzquery/authz_test.go
@@ -2,19 +2,42 @@ package authzquery_test
 
 import (
 	"context"
+	"database/sql"
 	"reflect"
 	"testing"
 
-	"cdr.dev/slog"
+	"github.com/stretchr/testify/require"
+
+	"cdr.dev/slog/sloggers/slogtest"
+
+	"golang.org/x/xerrors"
 
 	"github.com/google/uuid"
 
+	"cdr.dev/slog"
 	"github.com/coder/coder/coderd/authzquery"
 	"github.com/coder/coder/coderd/coderdtest"
 	"github.com/coder/coder/coderd/database/databasefake"
 	"github.com/coder/coder/coderd/rbac"
 )
 
+func TestNotAuthorizedError(t *testing.T) {
+	t.Parallel()
+
+	t.Run("Is404", func(t *testing.T) {
+		t.Parallel()
+
+		testErr := xerrors.New("custom error")
+
+		err := authzquery.LogNotAuthorizedError(context.Background(), slogtest.Make(t, nil), testErr)
+		require.ErrorIs(t, err, sql.ErrNoRows, "must be a sql.ErrNoRows")
+
+		var authErr authzquery.NotAuthorizedError
+		require.ErrorAs(t, err, &authErr, "must be a NotAuthorizedError")
+		require.ErrorIs(t, authErr.Err, testErr, "internal error must match")
+	})
+}
+
 // TestAuthzQueryRecursive is a simple test to search for infinite recursion
 // bugs. It isn't perfect, and only catches a subset of the possible bugs
 // as only the first db call will be made. But it is better than nothing.

diff --git a/coderd/authzquery/authzquerier.go b/coderd/authzquery/authzquerier.go
@@ -7,8 +7,6 @@ import (
 
 	"cdr.dev/slog"
 
-	"golang.org/x/xerrors"
-
 	"github.com/coder/coder/coderd/database"
 	"github.com/coder/coder/coderd/rbac"
 )
@@ -58,12 +56,12 @@ func (q *AuthzQuerier) InTx(function func(querier database.Store) error, txOpts
 func (q *AuthzQuerier) authorizeContext(ctx context.Context, action rbac.Action, object rbac.Objecter) error {
 	act, ok := ActorFromContext(ctx)
 	if !ok {
-		return xerrors.Errorf("no authorization actor in context")
+		return NoActorError
 	}
 
 	err := q.authorizer.Authorize(ctx, act, action, object.RBACObject())
 	if err != nil {
-		return xerrors.Errorf("unauthorized: %w", err)
+		return LogNotAuthorizedError(ctx, q.logger, err)
 	}
 	return nil
 }
diff --git a/coderd/authzquery/file.go b/coderd/authzquery/file.go
@@ -11,13 +11,13 @@ import (
 )
 
 func (q *AuthzQuerier) GetFileByHashAndCreator(ctx context.Context, arg database.GetFileByHashAndCreatorParams) (database.File, error) {
-	return authorizedFetch(q.authorizer, q.database.GetFileByHashAndCreator)(ctx, arg)
+	return authorizedFetch(q.logger, q.authorizer, q.database.GetFileByHashAndCreator)(ctx, arg)
 }
 
 func (q *AuthzQuerier) GetFileByID(ctx context.Context, id uuid.UUID) (database.File, error) {
-	return authorizedFetch(q.authorizer, q.database.GetFileByID)(ctx, id)
+	return authorizedFetch(q.logger, q.authorizer, q.database.GetFileByID)(ctx, id)
 }
 
 func (q *AuthzQuerier) InsertFile(ctx context.Context, arg database.InsertFileParams) (database.File, error) {
-	return authorizedInsertWithReturn(q.authorizer, rbac.ActionCreate, rbac.ResourceFile.WithOwner(arg.CreatedBy.String()), q.database.InsertFile)(ctx, arg)
+	return authorizedInsertWithReturn(q.logger, q.authorizer, rbac.ActionCreate, rbac.ResourceFile.WithOwner(arg.CreatedBy.String()), q.database.InsertFile)(ctx, arg)
 }
diff --git a/coderd/authzquery/group.go b/coderd/authzquery/group.go
@@ -11,20 +11,20 @@ import (
 )
 
 func (q *AuthzQuerier) DeleteGroupByID(ctx context.Context, id uuid.UUID) error {
-	return authorizedDelete(q.authorizer, q.database.GetGroupByID, q.database.DeleteGroupByID)(ctx, id)
+	return authorizedDelete(q.logger, q.authorizer, q.database.GetGroupByID, q.database.DeleteGroupByID)(ctx, id)
 }
 
 func (q *AuthzQuerier) DeleteGroupMember(ctx context.Context, userID uuid.UUID) error {
 	// Deleting a group member counts as updating a group.
-	return authorizedUpdate(q.authorizer, q.database.GetGroupByID, q.database.DeleteGroupMember)(ctx, userID)
+	return authorizedUpdate(q.logger, q.authorizer, q.database.GetGroupByID, q.database.DeleteGroupMember)(ctx, userID)
 }
 
 func (q *AuthzQuerier) GetGroupByID(ctx context.Context, id uuid.UUID) (database.Group, error) {
-	return authorizedFetch(q.authorizer, q.database.GetGroupByID)(ctx, id)
+	return authorizedFetch(q.logger, q.authorizer, q.database.GetGroupByID)(ctx, id)
 }
 
 func (q *AuthzQuerier) GetGroupByOrgAndName(ctx context.Context, arg database.GetGroupByOrgAndNameParams) (database.Group, error) {
-	return authorizedFetch(q.authorizer, q.database.GetGroupByOrgAndName)(ctx, arg)
+	return authorizedFetch(q.logger, q.authorizer, q.database.GetGroupByOrgAndName)(ctx, arg)
 }
 
 func (q *AuthzQuerier) GetGroupMembers(ctx context.Context, groupID uuid.UUID) ([]database.User, error) {
@@ -41,23 +41,23 @@ func (q *AuthzQuerier) GetGroupMembers(ctx context.Context, groupID uuid.UUID) (
 
 func (q *AuthzQuerier) InsertAllUsersGroup(ctx context.Context, organizationID uuid.UUID) (database.Group, error) {
 	// This method creates a new group.
-	return authorizedInsertWithReturn(q.authorizer, rbac.ActionCreate, rbac.ResourceGroup.InOrg(organizationID), q.database.InsertAllUsersGroup)(ctx, organizationID)
+	return authorizedInsertWithReturn(q.logger, q.authorizer, rbac.ActionCreate, rbac.ResourceGroup.InOrg(organizationID), q.database.InsertAllUsersGroup)(ctx, organizationID)
 }
 
 func (q *AuthzQuerier) InsertGroup(ctx context.Context, arg database.InsertGroupParams) (database.Group, error) {
-	return authorizedInsertWithReturn(q.authorizer, rbac.ActionCreate, rbac.ResourceGroup.InOrg(arg.OrganizationID), q.database.InsertGroup)(ctx, arg)
+	return authorizedInsertWithReturn(q.logger, q.authorizer, rbac.ActionCreate, rbac.ResourceGroup.InOrg(arg.OrganizationID), q.database.InsertGroup)(ctx, arg)
 }
 
 func (q *AuthzQuerier) InsertGroupMember(ctx context.Context, arg database.InsertGroupMemberParams) error {
 	fetch := func(ctx context.Context, arg database.InsertGroupMemberParams) (database.Group, error) {
 		return q.database.GetGroupByID(ctx, arg.GroupID)
 	}
-	return authorizedUpdate(q.authorizer, fetch, q.database.InsertGroupMember)(ctx, arg)
+	return authorizedUpdate(q.logger, q.authorizer, fetch, q.database.InsertGroupMember)(ctx, arg)
 }
 
 func (q *AuthzQuerier) UpdateGroupByID(ctx context.Context, arg database.UpdateGroupByIDParams) (database.Group, error) {
 	fetch := func(ctx context.Context, arg database.UpdateGroupByIDParams) (database.Group, error) {
 		return q.database.GetGroupByID(ctx, arg.ID)
 	}
-	return authorizedUpdateWithReturn(q.authorizer, fetch, q.database.UpdateGroupByID)(ctx, arg)
+	return authorizedUpdateWithReturn(q.logger, q.authorizer, fetch, q.database.UpdateGroupByID)(ctx, arg)
 }
diff --git a/coderd/authzquery/license.go b/coderd/authzquery/license.go
@@ -16,23 +16,23 @@ func (q *AuthzQuerier) GetLicenses(ctx context.Context) ([]database.License, err
 }
 
 func (q *AuthzQuerier) InsertLicense(ctx context.Context, arg database.InsertLicenseParams) (database.License, error) {
-	return authorizedInsertWithReturn(q.authorizer, rbac.ActionCreate, rbac.ResourceLicense, q.database.InsertLicense)(ctx, arg)
+	return authorizedInsertWithReturn(q.logger, q.authorizer, rbac.ActionCreate, rbac.ResourceLicense, q.database.InsertLicense)(ctx, arg)
 }
 
 func (q *AuthzQuerier) InsertOrUpdateLogoURL(ctx context.Context, value string) error {
-	return authorizedInsert(q.authorizer, rbac.ActionUpdate, rbac.ResourceDeploymentConfig, q.database.InsertOrUpdateLogoURL)(ctx, value)
+	return authorizedInsert(q.logger, q.authorizer, rbac.ActionUpdate, rbac.ResourceDeploymentConfig, q.database.InsertOrUpdateLogoURL)(ctx, value)
 }
 
 func (q *AuthzQuerier) InsertOrUpdateServiceBanner(ctx context.Context, value string) error {
-	return authorizedInsert(q.authorizer, rbac.ActionUpdate, rbac.ResourceDeploymentConfig, q.database.InsertOrUpdateServiceBanner)(ctx, value)
+	return authorizedInsert(q.logger, q.authorizer, rbac.ActionUpdate, rbac.ResourceDeploymentConfig, q.database.InsertOrUpdateServiceBanner)(ctx, value)
 }
 
 func (q *AuthzQuerier) GetLicenseByID(ctx context.Context, id int32) (database.License, error) {
-	return authorizedFetch(q.authorizer, q.database.GetLicenseByID)(ctx, id)
+	return authorizedFetch(q.logger, q.authorizer, q.database.GetLicenseByID)(ctx, id)
 }
 
 func (q *AuthzQuerier) DeleteLicense(ctx context.Context, id int32) (int32, error) {
-	err := authorizedDelete(q.authorizer, q.database.GetLicenseByID, func(ctx context.Context, id int32) error {
+	err := authorizedDelete(q.logger, q.authorizer, q.database.GetLicenseByID, func(ctx context.Context, id int32) error {
 		_, err := q.database.DeleteLicense(ctx, id)
 		return err
 	})(ctx, id)