Skip to content

chore: Expand logging in ADCS Post-Process - BED-8305 #2791

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

Merged
StephenHinck merged 2 commits into from
May 18, 2026
Merged

chore: Expand logging in ADCS Post-Process - BED-8305 #2791

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
7557889
chore: Expand logging in ADCS Post-Process - BED-8305
StephenHinck May 18, 2026
2a9af2f
PFC
StephenHinck May 18, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 7 additions & 11 deletions cmd/api/src/services/upload/streamdecoder.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -295,13 +295,13 @@ func (s ValidationReport) BuildAPIError() []string {
func (s ValidationReport) Error() string {
var sb strings.Builder
if len(s.CriticalErrors) > 0 {
sb.WriteString(fmt.Sprintf("(%d) critical error(s): [%s]", len(s.CriticalErrors), formatAggregateErrors(s.CriticalErrors)))
fmt.Fprintf(&sb, "(%d) critical error(s): [%s]", len(s.CriticalErrors), formatAggregateErrors(s.CriticalErrors))
if len(s.ValidationErrors) > 0 {
sb.WriteString(", ")
}
}
if len(s.ValidationErrors) > 0 {
sb.WriteString(fmt.Sprintf("(%d) validation error(s): [%s]", len(s.ValidationErrors), formatAggregateErrors(s.ValidationErrors)))
fmt.Fprintf(&sb, "(%d) validation error(s): [%s]", len(s.ValidationErrors), formatAggregateErrors(s.ValidationErrors))
}
return sb.String()
}
Expand All @@ -310,7 +310,7 @@ func formatSchemaValidationError(arrayName string, index int, err error) string
var sb strings.Builder
if ve, ok := err.(*jsonschema.ValidationError); ok {
numberOfViolations := len(ve.Causes)
sb.WriteString(fmt.Sprintf("%s[%d] schema validation failed with %d error(s): ", arrayName, index, numberOfViolations))
fmt.Fprintf(&sb, "%s[%d] schema validation failed with %d error(s): ", arrayName, index, numberOfViolations)

sb.WriteString("[")

Expand All @@ -328,17 +328,13 @@ func formatSchemaValidationError(arrayName string, index int, err error) string
switch {
// Case: property value is an object (not allowed)
case isPropertyError && isTypeError(cause, "object"):
sb.WriteString(fmt.Sprintf(
"Invalid property '%s': objects are not allowed in the property bag. Use only strings, numbers, booleans, nulls, or arrays of these types.",
propertyName,
))
fmt.Fprintf(&sb, "Invalid property '%s': objects are not allowed in the property bag. Use only strings, numbers, booleans, nulls, or arrays of these types.",
propertyName)

// Case: array contains a nested object (also not allowed)
case isPropertyError && isNotError(cause):
sb.WriteString(fmt.Sprintf(
"Invalid property '%s': array contains an object. Arrays must contain only primitive values (string, number, boolean, or null).",
propertyName,
))
fmt.Fprintf(&sb, "Invalid property '%s': array contains an object. Arrays must contain only primitive values (string, number, boolean, or null).",
propertyName)

default:
sb.WriteString(cause.Error())
Expand Down
137 changes: 137 additions & 0 deletions packages/go/analysis/ad/adcs.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,15 @@ func PostADCS(ctx context.Context, db graph.Database, localGroupData *LocalGroup
} else if step2Stats, err := postADCSPreProcessStep2(ctx, db, cache); err != nil {
return &post.AtomicPostProcessingStats{}, cache, fmt.Errorf("failed adcs pre-processing step 2: %w", err)
} else {
defer measure.ContextMeasure(
ctx,
slog.LevelInfo,
"ADCS ESC Processing",
attr.Namespace("analysis"),
attr.Function("PostADCS"),
attr.Scope("routine"),
)()

operation := post.NewPostRelationshipOperation(ctx, db, "ADCS Post Processing")

operation.Stats.Merge(step1Stats)
Expand All @@ -85,6 +94,15 @@ func PostADCS(ctx context.Context, db graph.Database, localGroupData *LocalGroup

// postADCSPreProcessStep1 processes the edges that are not dependent on any other post-processed edges
func postADCSPreProcessStep1(ctx context.Context, db graph.Database, enterpriseCertAuthorities, rootCertAuthorities, aiaCertAuthorities, certTemplates []*graph.Node) (*post.AtomicPostProcessingStats, error) {
defer measure.ContextMeasure(
ctx,
slog.LevelInfo,
"ADCS Post-processing Step 1",
attr.Namespace("analysis"),
attr.Function("postADCSPreProcessStep1"),
attr.Scope("routine"),
)()

operation := post.NewPostRelationshipOperation(ctx, db, "ADCS Post Processing Step 1")
// TODO clean up the operation.Done() calls below

Expand All @@ -107,6 +125,15 @@ func postADCSPreProcessStep1(ctx context.Context, db graph.Database, enterpriseC

// postADCSPreProcessStep2 Processes the edges that are dependent on those processed in postADCSPreProcessStep1
func postADCSPreProcessStep2(ctx context.Context, db graph.Database, cache ADCSCache) (*post.AtomicPostProcessingStats, error) {
defer measure.ContextMeasure(
ctx,
slog.LevelInfo,
"ADCS Post-processing Step 2",
attr.Namespace("analysis"),
attr.Function("postADCSPreProcessStep2"),
attr.Scope("routine"),
)()

operation := post.NewPostRelationshipOperation(ctx, db, "ADCS Post Processing Step 2")

if err := PostEnrollOnBehalfOf(cache, operation); err != nil {
Expand All @@ -119,6 +146,16 @@ func postADCSPreProcessStep2(ctx context.Context, db graph.Database, cache ADCSC

func processEnterpriseCAWithValidCertChainToDomain(enterpriseCA *graph.Node, targetDomains *graph.NodeSet, localGroupData *LocalGroupData, cache ADCSCache, operation post.StatTrackedOperation[post.EnsureRelationshipJob]) {
operation.Operation.SubmitReader(func(ctx context.Context, tx graph.Transaction, outC chan<- post.EnsureRelationshipJob) error {
defer measure.ContextMeasureWithThreshold(
ctx,
slog.LevelInfo,
"Post-processing GoldenCert",
attr.Namespace("analysis"),
attr.Function("processEnterpriseCAWithValidCertChainToDomain"),
attr.Scope("routine"),
slog.Uint64("enterprise_ca_id", uint64(enterpriseCA.ID)),
)()

if err := PostGoldenCert(ctx, tx, outC, enterpriseCA, targetDomains); errors.Is(err, graph.ErrPropertyNotFound) {
slog.WarnContext(
ctx,
Expand All @@ -136,6 +173,16 @@ func processEnterpriseCAWithValidCertChainToDomain(enterpriseCA *graph.Node, tar
})

operation.Operation.SubmitReader(func(ctx context.Context, tx graph.Transaction, outC chan<- post.EnsureRelationshipJob) error {
defer measure.ContextMeasureWithThreshold(
ctx,
slog.LevelInfo,
"Post-processing ADCSESC1",
attr.Namespace("analysis"),
attr.Function("processEnterpriseCAWithValidCertChainToDomain"),
attr.Scope("routine"),
slog.Uint64("enterprise_ca_id", uint64(enterpriseCA.ID)),
)()

if err := PostADCSESC1(ctx, tx, outC, localGroupData, enterpriseCA, targetDomains, cache); errors.Is(err, graph.ErrPropertyNotFound) {
slog.WarnContext(
ctx,
Expand All @@ -153,6 +200,16 @@ func processEnterpriseCAWithValidCertChainToDomain(enterpriseCA *graph.Node, tar
})

operation.Operation.SubmitReader(func(ctx context.Context, tx graph.Transaction, outC chan<- post.EnsureRelationshipJob) error {
defer measure.ContextMeasureWithThreshold(
ctx,
slog.LevelInfo,
"Post-processing ADCSESC3",
attr.Namespace("analysis"),
attr.Function("processEnterpriseCAWithValidCertChainToDomain"),
attr.Scope("routine"),
slog.Uint64("enterprise_ca_id", uint64(enterpriseCA.ID)),
)()

if err := PostADCSESC3(ctx, tx, outC, localGroupData, enterpriseCA, targetDomains, cache); errors.Is(err, graph.ErrPropertyNotFound) {
slog.WarnContext(
ctx,
Expand All @@ -170,6 +227,16 @@ func processEnterpriseCAWithValidCertChainToDomain(enterpriseCA *graph.Node, tar
})

operation.Operation.SubmitReader(func(ctx context.Context, tx graph.Transaction, outC chan<- post.EnsureRelationshipJob) error {
defer measure.ContextMeasureWithThreshold(
ctx,
slog.LevelInfo,
"Post-processing ADCSESC4",
attr.Namespace("analysis"),
attr.Function("processEnterpriseCAWithValidCertChainToDomain"),
attr.Scope("routine"),
slog.Uint64("enterprise_ca_id", uint64(enterpriseCA.ID)),
)()

if err := PostADCSESC4(ctx, tx, outC, localGroupData, enterpriseCA, targetDomains, cache); errors.Is(err, graph.ErrPropertyNotFound) {
slog.WarnContext(
ctx,
Expand All @@ -187,6 +254,16 @@ func processEnterpriseCAWithValidCertChainToDomain(enterpriseCA *graph.Node, tar
})

operation.Operation.SubmitReader(func(ctx context.Context, tx graph.Transaction, outC chan<- post.EnsureRelationshipJob) error {
defer measure.ContextMeasureWithThreshold(
ctx,
slog.LevelInfo,
"Post-processing ADCSESC6a",
attr.Namespace("analysis"),
attr.Function("processEnterpriseCAWithValidCertChainToDomain"),
attr.Scope("routine"),
slog.Uint64("enterprise_ca_id", uint64(enterpriseCA.ID)),
)()

if err := PostADCSESC6a(ctx, tx, outC, localGroupData, enterpriseCA, targetDomains, cache); errors.Is(err, graph.ErrPropertyNotFound) {
slog.WarnContext(
ctx,
Expand All @@ -204,6 +281,16 @@ func processEnterpriseCAWithValidCertChainToDomain(enterpriseCA *graph.Node, tar
})

operation.Operation.SubmitReader(func(ctx context.Context, tx graph.Transaction, outC chan<- post.EnsureRelationshipJob) error {
defer measure.ContextMeasureWithThreshold(
ctx,
slog.LevelInfo,
"Post-processing ADCSESC6b",
attr.Namespace("analysis"),
attr.Function("processEnterpriseCAWithValidCertChainToDomain"),
attr.Scope("routine"),
slog.Uint64("enterprise_ca_id", uint64(enterpriseCA.ID)),
)()

if err := PostADCSESC6b(ctx, tx, outC, localGroupData, enterpriseCA, targetDomains, cache); errors.Is(err, graph.ErrPropertyNotFound) {
slog.WarnContext(
ctx,
Expand All @@ -221,6 +308,16 @@ func processEnterpriseCAWithValidCertChainToDomain(enterpriseCA *graph.Node, tar
})

operation.Operation.SubmitReader(func(ctx context.Context, tx graph.Transaction, outC chan<- post.EnsureRelationshipJob) error {
defer measure.ContextMeasureWithThreshold(
ctx,
slog.LevelInfo,
"Post-processing ADCSESC9a",
attr.Namespace("analysis"),
attr.Function("processEnterpriseCAWithValidCertChainToDomain"),
attr.Scope("routine"),
slog.Uint64("enterprise_ca_id", uint64(enterpriseCA.ID)),
)()

if err := PostADCSESC9a(ctx, tx, outC, localGroupData, enterpriseCA, targetDomains, cache); errors.Is(err, graph.ErrPropertyNotFound) {
slog.WarnContext(
ctx,
Expand All @@ -238,6 +335,16 @@ func processEnterpriseCAWithValidCertChainToDomain(enterpriseCA *graph.Node, tar
})

operation.Operation.SubmitReader(func(ctx context.Context, tx graph.Transaction, outC chan<- post.EnsureRelationshipJob) error {
defer measure.ContextMeasureWithThreshold(
ctx,
slog.LevelInfo,
"Post-processing ADCSESC9b",
attr.Namespace("analysis"),
attr.Function("processEnterpriseCAWithValidCertChainToDomain"),
attr.Scope("routine"),
slog.Uint64("enterprise_ca_id", uint64(enterpriseCA.ID)),
)()

if err := PostADCSESC9b(ctx, tx, outC, localGroupData, enterpriseCA, targetDomains, cache); errors.Is(err, graph.ErrPropertyNotFound) {
slog.WarnContext(
ctx,
Expand All @@ -255,6 +362,16 @@ func processEnterpriseCAWithValidCertChainToDomain(enterpriseCA *graph.Node, tar
})

operation.Operation.SubmitReader(func(ctx context.Context, tx graph.Transaction, outC chan<- post.EnsureRelationshipJob) error {
defer measure.ContextMeasureWithThreshold(
ctx,
slog.LevelInfo,
"Post-processing ADCSESC10a",
attr.Namespace("analysis"),
attr.Function("processEnterpriseCAWithValidCertChainToDomain"),
attr.Scope("routine"),
slog.Uint64("enterprise_ca_id", uint64(enterpriseCA.ID)),
)()

if err := PostADCSESC10a(ctx, tx, outC, localGroupData, enterpriseCA, targetDomains, cache); errors.Is(err, graph.ErrPropertyNotFound) {
slog.WarnContext(
ctx,
Expand All @@ -272,6 +389,16 @@ func processEnterpriseCAWithValidCertChainToDomain(enterpriseCA *graph.Node, tar
})

operation.Operation.SubmitReader(func(ctx context.Context, tx graph.Transaction, outC chan<- post.EnsureRelationshipJob) error {
defer measure.ContextMeasureWithThreshold(
ctx,
slog.LevelInfo,
"Post-processing ADCSESC10b",
attr.Namespace("analysis"),
attr.Function("processEnterpriseCAWithValidCertChainToDomain"),
attr.Scope("routine"),
slog.Uint64("enterprise_ca_id", uint64(enterpriseCA.ID)),
)()

if err := PostADCSESC10b(ctx, tx, outC, localGroupData, enterpriseCA, targetDomains, cache); errors.Is(err, graph.ErrPropertyNotFound) {
slog.WarnContext(
ctx,
Expand All @@ -289,6 +416,16 @@ func processEnterpriseCAWithValidCertChainToDomain(enterpriseCA *graph.Node, tar
})

operation.Operation.SubmitReader(func(ctx context.Context, tx graph.Transaction, outC chan<- post.EnsureRelationshipJob) error {
defer measure.ContextMeasureWithThreshold(
ctx,
slog.LevelInfo,
"Post-processing ADCSESC13",
attr.Namespace("analysis"),
attr.Function("processEnterpriseCAWithValidCertChainToDomain"),
attr.Scope("routine"),
slog.Uint64("enterprise_ca_id", uint64(enterpriseCA.ID)),
)()

if err := PostADCSESC13(ctx, tx, outC, localGroupData, enterpriseCA, targetDomains, cache); errors.Is(err, graph.ErrPropertyNotFound) {
slog.WarnContext(
ctx,
Expand Down
33 changes: 33 additions & 0 deletions packages/go/analysis/ad/adcscache.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -94,6 +94,15 @@ func (s *ADCSCache) BuildCache(ctx context.Context, db graph.Database, enterpris
s.enterpriseCertAuthorities = enterpriseCertAuthorities
s.domains = domains
}
certTemplateMeasure := measure.ContextMeasure(
ctx,
slog.LevelInfo,
"BuildCache cert template loop",
attr.Namespace("analysis"),
attr.Function("BuildCache.CertTemplates"),
attr.Scope("routine"),
)

for _, ct := range s.certTemplates {
// cert template enrollers
if firstDegreePrincipals, err := fetchFirstDegreeNodes(tx, ct, ad.Enroll, ad.GenericAll, ad.AllExtendedRights); err != nil {
Expand Down Expand Up @@ -132,6 +141,17 @@ func (s *ADCSCache) BuildCache(ctx context.Context, db graph.Database, enterpris
}
}

certTemplateMeasure()

ecaMeasure := measure.ContextMeasure(
ctx,
slog.LevelInfo,
"BuildCache enterprise CA loop",
attr.Namespace("analysis"),
attr.Function("BuildCache.EnterpriseCAs"),
attr.Scope("routine"),
)

for _, eca := range s.enterpriseCertAuthorities {
if firstDegreeEnrollers, err := fetchFirstDegreeNodes(tx, eca, ad.Enroll); err != nil {
slog.ErrorContext(
Expand Down Expand Up @@ -187,6 +207,17 @@ func (s *ADCSCache) BuildCache(ctx context.Context, db graph.Database, enterpris
}
}

ecaMeasure()

domainMeasure := measure.ContextMeasure(
ctx,
slog.LevelInfo,
"BuildCache domain loop",
attr.Namespace("analysis"),
attr.Function("BuildCache.Domains"),
attr.Scope("routine"),
)

for _, domain := range s.domains {
//TODO: This code is necessary for ADCS composition during post, but we have scrapped that as part of this initiative. Leaving this code for later use
//if rootCaPaths, err := FetchEnterpriseCAsRootCAForPathToDomainFull(tx, domain); err != nil {
Expand Down Expand Up @@ -249,6 +280,8 @@ func (s *ADCSCache) BuildCache(ctx context.Context, db graph.Database, enterpris
}
}

domainMeasure()

return nil
})
if err != nil {
Expand Down
16 changes: 8 additions & 8 deletions packages/go/schemagen/generator/sql.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -178,7 +178,7 @@ func GenerateExtensionSQLAzure(dir string, azSchema model.Azure) error {
func GenerateExtensionSQL(name string, displayName string, version string, namespace, dir string, fileName string, nodeKinds []model.StringEnum, relationshipKinds []model.StringEnum, pathfindingRelationshipKinds []model.StringEnum) error {
var sb strings.Builder

sb.WriteString(fmt.Sprintf("-- Code generated by Cuelang code gen. DO NOT EDIT!\n-- Cuelang source: %s/", SchemaSourceName))
fmt.Fprintf(&sb, "-- Code generated by Cuelang code gen. DO NOT EDIT!\n-- Cuelang source: %s/", SchemaSourceName)

sb.WriteString(`
CREATE OR REPLACE FUNCTION genscript_upsert_kind(node_kind_name TEXT) RETURNS SMALLINT AS $$
Expand Down Expand Up @@ -300,28 +300,28 @@ $$ LANGUAGE plpgsql;

sb.WriteString("\nDO $$\nDECLARE\n\textension_id INT;\n\tenvironment_id INT;\nBEGIN\n\tLOCK schema_extensions, schema_node_kinds, schema_relationship_kinds, kind;\n\n")

sb.WriteString(fmt.Sprintf("\tIF NOT EXISTS (SELECT id FROM schema_extensions WHERE name = '%s') THEN\n", name))
sb.WriteString(fmt.Sprintf("\t\tINSERT INTO schema_extensions (name, display_name, version, is_builtin, namespace, created_at, updated_at) VALUES ('%s', '%s', '%s', true, '%s', NOW(), NOW()) RETURNING id INTO extension_id;\n", name, displayName, version, namespace))
fmt.Fprintf(&sb, "\tIF NOT EXISTS (SELECT id FROM schema_extensions WHERE name = '%s') THEN\n", name)
fmt.Fprintf(&sb, "\t\tINSERT INTO schema_extensions (name, display_name, version, is_builtin, namespace, created_at, updated_at) VALUES ('%s', '%s', '%s', true, '%s', NOW(), NOW()) RETURNING id INTO extension_id;\n", name, displayName, version, namespace)
sb.WriteString("\tELSE\n")
sb.WriteString(fmt.Sprintf("\t\tUPDATE schema_extensions SET display_name = '%s', version = '%s', namespace = '%s', updated_at = NOW() WHERE name = '%s' RETURNING id INTO extension_id;\n", displayName, version, namespace, name))
fmt.Fprintf(&sb, "\t\tUPDATE schema_extensions SET display_name = '%s', version = '%s', namespace = '%s', updated_at = NOW() WHERE name = '%s' RETURNING id INTO extension_id;\n", displayName, version, namespace, name)
sb.WriteString("\tEND IF;\n\n")

sb.WriteString("\t-- Insert Node Kinds\n")
for _, kind := range nodeKinds {
sb.WriteString(fmt.Sprintf("\tPERFORM genscript_upsert_kind('%s');\n", kind.GetRepresentation()))
fmt.Fprintf(&sb, "\tPERFORM genscript_upsert_kind('%s');\n", kind.GetRepresentation())
}

sb.WriteString("\n\t-- Insert Relationship Kinds\n")
for _, kind := range relationshipKinds {
sb.WriteString(fmt.Sprintf("\tPERFORM genscript_upsert_kind('%s');\n", kind.GetRepresentation()))
fmt.Fprintf(&sb, "\tPERFORM genscript_upsert_kind('%s');\n", kind.GetRepresentation())
}

sb.WriteString("\n")

for _, kind := range nodeKinds {
iconInfo, found := nodeIcons[kind.GetRepresentation()]

sb.WriteString(fmt.Sprintf("\tPERFORM genscript_upsert_schema_node_kind(extension_id, '%s', '%s', '', %t, '%s', '%s');\n", kind.GetRepresentation(), kind.GetRepresentation(), found, iconInfo.Icon, iconInfo.Color))
fmt.Fprintf(&sb, "\tPERFORM genscript_upsert_schema_node_kind(extension_id, '%s', '%s', '', %t, '%s', '%s');\n", kind.GetRepresentation(), kind.GetRepresentation(), found, iconInfo.Icon, iconInfo.Color)
}

traversableMap := make(map[string]struct{})
Expand All @@ -335,7 +335,7 @@ $$ LANGUAGE plpgsql;
for _, kind := range relationshipKinds {
_, traversable := traversableMap[kind.GetRepresentation()]

sb.WriteString(fmt.Sprintf("\tPERFORM genscript_upsert_schema_relationship_kind(extension_id, '%s', '', %t);\n", kind.GetRepresentation(), traversable))
fmt.Fprintf(&sb, "\tPERFORM genscript_upsert_schema_relationship_kind(extension_id, '%s', '', %t);\n", kind.GetRepresentation(), traversable)
}

sb.WriteString("\n")
Expand Down
Loading