feat: audit log steel thread (#364)

* chore: clean up old approach to reduce noise

* chore: cleanup audit logging interface for new usages

* chore: fix existing tests (audit integration test needs new target)

* chore: improve integration config defaults

* feat: add audit logging to UpdateUser

This adds a new `AuditableContext` method to the Database, which wraps the Gorm Transaction method with some auditing context and ensures the two phase commit of the audit log is run

* feat: add audit logging to DeleteSAMLProvider
fix: use actual AuditData instead of the direct model

* feat: CreateAssetGroup and DeleteAssetGroup are now back to auditable
fix: broken tests

* feat: plumb commitID for real this time
fix: incorrect formatting of audit log action names
fix: additional test fixes

* fix: additional test fixes

* review comments

---------

Co-authored-by: Irshad Ahmed <iahmed@specterops.io>

.github/config/integration.config.json

@@ -7,6 +7,8 @@
     "collectors_base_path": "/tmp/collectors",
     "log_level": "ERROR",
     "log_path": "bhapi.log",
+    "enable_startup_wait_period": false,
+    "datapipe_interval": 1,
     "features": {
         "enable_auth": true
     },

cmd/api/src/api/error.go

@@ -111,8 +111,6 @@ func BuildErrorResponse(httpStatus int, message string, request *http.Request) *
 // HandleDatabaseError writes an error (not found or other) depending on the database error encountered
 // Alternate: FormatDatabaseError()
 func HandleDatabaseError(request *http.Request, response http.ResponseWriter, err error) {
-	ctx.SetErrorContext(request, err)
-
 	if errors.Is(err, database.ErrNotFound) {
 		WriteErrorResponse(request.Context(), BuildErrorResponse(http.StatusNotFound, ErrorResponseDetailsResourceNotFound, request), response)
 	} else {

cmd/api/src/api/middleware/logging.go

@@ -170,14 +170,6 @@ func LoggingMiddleware(cfg config.Configuration, idResolver auth.IdentityResolve
 			logEvent.Int64("response_bytes", loggedResponse.bytesWritten)
 			logEvent.Int("status", loggedResponse.statusCode)
 			logEvent.Duration("elapsed", time.Since(requestContext.StartTime.UTC()))
-
-			if requestContext.AuditCtx.Action != "" {
-				requestContext.AuditCtx.SetStatus(loggedResponse.statusCode)
-
-				if err := db.AppendAuditLog(*requestContext, "", requestContext.AuditCtx.Model); err != nil {
-					log.Errorf("error writing to audit log: %s", err)
-				}
-			}
 		})
 	}
 }

cmd/api/src/api/v2/agi.go

@@ -178,8 +178,6 @@ func (s Resources) UpdateAssetGroup(response http.ResponseWriter, request *http.
 		assetGroup              model.AssetGroup
 	)
 
-	ctx.SetAuditContext(request, model.AuditContext{Action: "UpdateAssetGroup", Model: &assetGroup})
-
 	if assetGroupID, err := strconv.Atoi(rawAssetGroupID); err != nil {
 		api.WriteErrorResponse(request.Context(), api.BuildErrorResponse(http.StatusBadRequest, api.ErrorResponseDetailsIDMalformed, request), response)
 	} else if err := api.ReadJSONRequestPayloadLimited(&updateAssetGroupRequest, request); err != nil {
@@ -200,11 +198,9 @@ func (s Resources) UpdateAssetGroup(response http.ResponseWriter, request *http.
 func (s Resources) CreateAssetGroup(response http.ResponseWriter, request *http.Request) {
 	var createRequest CreateAssetGroupRequest
 
-	ctx.SetAuditContext(request, model.AuditContext{Action: "CreateAssetGroup", Model: &createRequest})
-
 	if err := api.ReadJSONRequestPayloadLimited(&createRequest, request); err != nil {
 		api.WriteErrorResponse(request.Context(), api.BuildErrorResponse(http.StatusBadRequest, err.Error(), request), response)
-	} else if newAssetGroup, err := s.DB.CreateAssetGroup(createRequest.Name, createRequest.Tag, false); err != nil {
+	} else if newAssetGroup, err := s.DB.CreateAssetGroup(request.Context(), createRequest.Name, createRequest.Tag, false); err != nil {
 		api.HandleDatabaseError(request, response, err)
 	} else {
 		assetGroupURL := *ctx.Get(request.Context()).Host
@@ -222,15 +218,13 @@ func (s Resources) DeleteAssetGroup(response http.ResponseWriter, request *http.
 		assetGroup      model.AssetGroup
 	)
 
-	ctx.SetAuditContext(request, model.AuditContext{Action: "DeleteAssetGroup", Model: &assetGroup})
-
 	if assetGroupID, err := strconv.Atoi(rawAssetGroupID); err != nil {
 		api.WriteErrorResponse(request.Context(), api.BuildErrorResponse(http.StatusBadRequest, api.ErrorResponseDetailsIDMalformed, request), response)
 	} else if assetGroup, err = s.DB.GetAssetGroup(int32(assetGroupID)); err != nil {
 		api.HandleDatabaseError(request, response, err)
 	} else if assetGroup.SystemGroup {
 		api.WriteErrorResponse(request.Context(), api.BuildErrorResponse(http.StatusConflict, "Cannot delete a system defined asset group.", request), response)
-	} else if err := s.DB.DeleteAssetGroup(assetGroup); err != nil {
+	} else if err := s.DB.DeleteAssetGroup(request.Context(), assetGroup); err != nil {
 		api.HandleDatabaseError(request, response, err)
 	} else {
 		response.WriteHeader(http.StatusOK)
@@ -282,8 +276,6 @@ func (s Resources) DeleteAssetGroupSelector(response http.ResponseWriter, reques
 		rawAssetGroupSelectorID = pathVars[api.URIPathVariableAssetGroupSelectorID]
 	)
 
-	ctx.SetAuditContext(request, model.AuditContext{Action: "DeleteAssetGroupSelector", Model: &assetGroupSelector})
-
 	if assetGroupID, err := strconv.Atoi(rawAssetGroupID); err != nil {
 		api.WriteErrorResponse(request.Context(), api.BuildErrorResponse(http.StatusBadRequest, api.ErrorResponseDetailsIDMalformed, request), response)
 	} else if _, err := s.DB.GetAssetGroup(int32(assetGroupID)); err != nil {

cmd/api/src/api/v2/agi_test.go

@@ -20,15 +20,16 @@ import (
 	"context"
 	"encoding/json"
 	"fmt"
-	"github.com/specterops/bloodhound/headers"
-	"github.com/specterops/bloodhound/mediatypes"
-	"github.com/specterops/bloodhound/src/auth"
-	"github.com/specterops/bloodhound/src/test/must"
 	"net/http"
 	"net/http/httptest"
 	"net/url"
 	"testing"
 
+	"github.com/specterops/bloodhound/headers"
+	"github.com/specterops/bloodhound/mediatypes"
+	"github.com/specterops/bloodhound/src/auth"
+	"github.com/specterops/bloodhound/src/test/must"
+
 	"github.com/gorilla/mux"
 	"github.com/specterops/bloodhound/dawgs/graph"
 	"github.com/specterops/bloodhound/errors"
@@ -348,20 +349,7 @@ func TestResources_UpdateAssetGroup(t *testing.T) {
 		Require().
 		ResponseStatusCode(http.StatusBadRequest)
 
-	// Audit Log fails
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(fmt.Errorf("exploded"))
-
-	requestTemplate.
-		WithURLPathVars(map[string]string{
-			"asset_group_id": "1234",
-		}).
-		WithBody(v2.UpdateAssetGroupRequest{}).
-		OnHandlerFunc(resources.UpdateAssetGroup).
-		Require().
-		ResponseStatusCode(http.StatusInternalServerError)
-
 	// GetAssetGroup DB fails
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil)
 	mockDB.EXPECT().GetAssetGroup(int32(1234)).Return(model.AssetGroup{}, fmt.Errorf("exploded"))
 
 	requestTemplate.
@@ -374,7 +362,6 @@ func TestResources_UpdateAssetGroup(t *testing.T) {
 		ResponseStatusCode(http.StatusInternalServerError)
 
 	// UpdateAssetGroup DB fails
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil)
 	mockDB.EXPECT().GetAssetGroup(int32(1234)).Return(model.AssetGroup{}, nil)
 	mockDB.EXPECT().UpdateAssetGroup(model.AssetGroup{}).Return(fmt.Errorf("exploded"))
 
@@ -388,7 +375,6 @@ func TestResources_UpdateAssetGroup(t *testing.T) {
 		ResponseStatusCode(http.StatusInternalServerError)
 
 	// Success
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil)
 	mockDB.EXPECT().GetAssetGroup(int32(1234)).Return(model.AssetGroup{}, nil)
 	mockDB.EXPECT().UpdateAssetGroup(model.AssetGroup{}).Return(nil)
 
@@ -420,18 +406,8 @@ func TestResources_CreateAssetGroup(t *testing.T) {
 		Require().
 		ResponseStatusCode(http.StatusBadRequest)
 
-	// Audit Log fails
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(fmt.Errorf("exploded"))
-
-	requestTemplate.
-		WithBody(v2.CreateAssetGroupRequest{}).
-		OnHandlerFunc(resources.CreateAssetGroup).
-		Require().
-		ResponseStatusCode(http.StatusInternalServerError)
-
 	// Create DB Query fails
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil)
-	mockDB.EXPECT().CreateAssetGroup(gomock.Any(), gomock.Any(), gomock.Any()).Return(model.AssetGroup{}, fmt.Errorf("exploded"))
+	mockDB.EXPECT().CreateAssetGroup(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Return(model.AssetGroup{}, fmt.Errorf("exploded"))
 
 	requestTemplate.
 		WithBody(v2.CreateAssetGroupRequest{}).
@@ -440,8 +416,7 @@ func TestResources_CreateAssetGroup(t *testing.T) {
 		ResponseStatusCode(http.StatusInternalServerError)
 
 	// Success
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil)
-	mockDB.EXPECT().CreateAssetGroup(gomock.Any(), gomock.Any(), gomock.Any()).Return(model.AssetGroup{}, nil)
+	mockDB.EXPECT().CreateAssetGroup(gomock.Any(), gomock.Any(), gomock.Any(), gomock.Any()).Return(model.AssetGroup{}, nil)
 
 	requestTemplate.
 		WithContext(&ctx.Context{
@@ -730,18 +705,6 @@ func TestResources_DeleteAssetGroup(t *testing.T) {
 	// GetAssetGroup DB fails
 	mockDB.EXPECT().GetAssetGroup(int32(1234)).Return(model.AssetGroup{}, fmt.Errorf("exploded"))
 
-	requestTemplate.
-		WithURLPathVars(map[string]string{
-			"asset_group_id": "1234",
-		}).
-		OnHandlerFunc(resources.DeleteAssetGroup).
-		Require().
-		ResponseStatusCode(http.StatusInternalServerError)
-
-	// Audit Log DB fails
-	mockDB.EXPECT().GetAssetGroup(int32(1234)).Return(model.AssetGroup{}, nil)
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(fmt.Errorf("exploded"))
-
 	requestTemplate.
 		WithURLPathVars(map[string]string{
 			"asset_group_id": "1234",
@@ -752,8 +715,7 @@ func TestResources_DeleteAssetGroup(t *testing.T) {
 
 	// DeleteAssetGroup DB fails
 	mockDB.EXPECT().GetAssetGroup(int32(1234)).Return(model.AssetGroup{}, nil)
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil)
-	mockDB.EXPECT().DeleteAssetGroup(model.AssetGroup{}).Return(fmt.Errorf("exploded"))
+	mockDB.EXPECT().DeleteAssetGroup(gomock.Any(), model.AssetGroup{}).Return(fmt.Errorf("exploded"))
 
 	requestTemplate.
 		WithURLPathVars(map[string]string{
@@ -765,8 +727,7 @@ func TestResources_DeleteAssetGroup(t *testing.T) {
 
 	// Success
 	mockDB.EXPECT().GetAssetGroup(int32(1234)).Return(model.AssetGroup{}, nil)
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil)
-	mockDB.EXPECT().DeleteAssetGroup(model.AssetGroup{}).Return(nil)
+	mockDB.EXPECT().DeleteAssetGroup(gomock.Any(), model.AssetGroup{}).Return(nil)
 
 	requestTemplate.
 		WithURLPathVars(map[string]string{
@@ -847,24 +808,9 @@ func TestResources_DeleteAssetGroupSelector(t *testing.T) {
 		Require().
 		ResponseStatusCode(http.StatusConflict)
 
-	// Audit Log DB fails
-	mockDB.EXPECT().GetAssetGroup(int32(1234)).Return(model.AssetGroup{}, nil)
-	mockDB.EXPECT().GetAssetGroupSelector(int32(1234)).Return(model.AssetGroupSelector{}, nil)
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(fmt.Errorf("exploded"))
-
-	requestTemplate.
-		WithURLPathVars(map[string]string{
-			"asset_group_id":          "1234",
-			"asset_group_selector_id": "1234",
-		}).
-		OnHandlerFunc(resources.DeleteAssetGroupSelector).
-		Require().
-		ResponseStatusCode(http.StatusInternalServerError)
-
 	// DeleteAssetGroupSelector DB fails
 	mockDB.EXPECT().GetAssetGroup(int32(1234)).Return(model.AssetGroup{}, nil)
 	mockDB.EXPECT().GetAssetGroupSelector(int32(1234)).Return(model.AssetGroupSelector{}, nil)
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil)
 	mockDB.EXPECT().DeleteAssetGroupSelector(model.AssetGroupSelector{}).Return(fmt.Errorf("exploded"))
 
 	requestTemplate.
@@ -879,7 +825,6 @@ func TestResources_DeleteAssetGroupSelector(t *testing.T) {
 	// Success
 	mockDB.EXPECT().GetAssetGroup(int32(1234)).Return(model.AssetGroup{}, nil)
 	mockDB.EXPECT().GetAssetGroupSelector(int32(1234)).Return(model.AssetGroupSelector{}, nil)
-	mockDB.EXPECT().AppendAuditLog(gomock.Any(), gomock.Any(), gomock.Any()).Return(nil)
 	mockDB.EXPECT().DeleteAssetGroupSelector(model.AssetGroupSelector{}).Return(nil)
 
 	requestTemplate.

cmd/api/src/api/v2/audit_integration_test.go

@@ -57,11 +57,26 @@ func Test_ListAuditLogs(t *testing.T) {
 
 		// Expect one audit log entry from the deletion
 		auditLogs := testCtx.ListAuditLogs(deletionTimestamp, time.Now(), 0, 1000)
-		require.Equal(t, 1, len(auditLogs), "Expected only 1 audit log entry but saw %d", len(auditLogs))
+		require.Equal(t, 2, len(auditLogs), "Expected exactly 2 audit log entries but saw %d", len(auditLogs))
+
+		// Make sure these two actions are from the same request
+		require.Equal(t, auditLogs[0].RequestID, auditLogs[1].RequestID)
+
+		// Makes sure these two actions are from the same two phase commit
+		require.Equal(t, auditLogs[0].CommitID, auditLogs[1].CommitID)
+
+		// Audit logs are in LIFO order
+		require.Equal(t, auditLogs[0].Status, "success")
+		require.Equal(t, auditLogs[1].Status, "intent")
 
 		testCtx.AssetAuditLog(auditLogs[0], "DeleteAssetGroup", map[string]any{
 			"asset_group_name": newAssetGroup.Name,
 			"asset_group_tag":  newAssetGroup.Tag,
 		})
+
+		testCtx.AssetAuditLog(auditLogs[1], "DeleteAssetGroup", map[string]any{
+			"asset_group_name": newAssetGroup.Name,
+			"asset_group_tag":  newAssetGroup.Tag,
+		})
 	})
 }