Skip to content

Commit 962a10c

Browse files
authored
PR #2: Structured Logging System (#392)
Implements structured logging with verbosity control to separate results from diagnostics. The logger outputs to stderr keeping stdout clean for results and provides three verbosity levels for flexible output control. Default mode shows clean results only with no progress messages. Verbose mode adds progress messages and statistics for monitoring scan operations. Debug mode includes elapsed time prefixes for performance analysis. Commands now support --verbose and --debug flags for controlling output detail. Warning and Error messages are always shown regardless of verbosity level. Timing tracking is included for performance measurement. All tests pass with 97.2% coverage for the logger package. Binary builds successfully and passes linting with zero issues. Part of the output standardization feature.
1 parent a6a882a commit 962a10c

21 files changed

+601
-140
lines changed

python-dsl/codepathfinder/matchers.py

Lines changed: 16 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -106,17 +106,25 @@ def to_ir(self) -> dict:
106106

107107
# Add positional argument constraints
108108
if self.match_position:
109-
ir["positionalArgs"] = {
110-
str(pos): self._make_constraint(value)
111-
for pos, value in self.match_position.items()
112-
}
109+
positional_args = {}
110+
for pos, value in self.match_position.items():
111+
constraint = self._make_constraint(value)
112+
# Propagate wildcard flag from pattern to argument constraints
113+
if self.wildcard:
114+
constraint["wildcard"] = True
115+
positional_args[str(pos)] = constraint
116+
ir["positionalArgs"] = positional_args
113117

114118
# Add keyword argument constraints
115119
if self.match_name:
116-
ir["keywordArgs"] = {
117-
name: self._make_constraint(value)
118-
for name, value in self.match_name.items()
119-
}
120+
keyword_args = {}
121+
for name, value in self.match_name.items():
122+
constraint = self._make_constraint(value)
123+
# Propagate wildcard flag from pattern to argument constraints
124+
if self.wildcard:
125+
constraint["wildcard"] = True
126+
keyword_args[name] = constraint
127+
ir["keywordArgs"] = keyword_args
120128

121129
return ir
122130

sourcecode-parser/cmd/analyze.go

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@ import (
66

77
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph"
88
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph"
9+
"github.com/shivasurya/code-pathfinder/sourcecode-parser/output"
910
"github.com/spf13/cobra"
1011
)
1112

@@ -24,7 +25,7 @@ var analyzeCmd = &cobra.Command{
2425
codeGraph := graph.Initialize(projectInput)
2526

2627
fmt.Println("Building call graph and analyzing security patterns...")
27-
cg, registry, patternRegistry, err := callgraph.InitializeCallGraph(codeGraph, projectInput)
28+
cg, registry, patternRegistry, err := callgraph.InitializeCallGraph(codeGraph, projectInput, output.NewLogger(output.VerbosityDefault))
2829
if err != nil {
2930
fmt.Println("Error building call graph:", err)
3031
return

sourcecode-parser/cmd/ci.go

Lines changed: 27 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,6 @@ package cmd
33
import (
44
"encoding/json"
55
"fmt"
6-
"log"
76
"os"
87

98
sarif "github.com/owenrumney/go-sarif/v2/sarif"
@@ -12,6 +11,7 @@ import (
1211
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/builder"
1312
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/core"
1413
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/registry"
14+
"github.com/shivasurya/code-pathfinder/sourcecode-parser/output"
1515
"github.com/spf13/cobra"
1616
)
1717

@@ -35,6 +35,17 @@ Examples:
3535
rulesPath, _ := cmd.Flags().GetString("rules")
3636
projectPath, _ := cmd.Flags().GetString("project")
3737
outputFormat, _ := cmd.Flags().GetString("output")
38+
verbose, _ := cmd.Flags().GetBool("verbose")
39+
debug, _ := cmd.Flags().GetBool("debug")
40+
41+
// Setup logger with appropriate verbosity
42+
verbosity := output.VerbosityDefault
43+
if debug {
44+
verbosity = output.VerbosityDebug
45+
} else if verbose {
46+
verbosity = output.VerbosityVerbose
47+
}
48+
logger := output.NewLogger(verbosity)
3849

3950
if rulesPath == "" {
4051
return fmt.Errorf("--rules flag is required")
@@ -49,47 +60,47 @@ Examples:
4960
}
5061

5162
// Build code graph (AST)
52-
log.Printf("Building code graph from %s...\n", projectPath)
63+
logger.Progress("Building code graph from %s...", projectPath)
5364
codeGraph := graph.Initialize(projectPath)
5465
if len(codeGraph.Nodes) == 0 {
5566
return fmt.Errorf("no source files found in project")
5667
}
57-
log.Printf("Code graph built: %d nodes\n", len(codeGraph.Nodes))
68+
logger.Statistic("Code graph built: %d nodes", len(codeGraph.Nodes))
5869

5970
// Build module registry
60-
log.Printf("Building module registry...\n")
71+
logger.Progress("Building module registry...")
6172
moduleRegistry, err := registry.BuildModuleRegistry(projectPath)
6273
if err != nil {
63-
log.Printf("Warning: failed to build module registry: %v\n", err)
74+
logger.Warning("failed to build module registry: %v", err)
6475
moduleRegistry = core.NewModuleRegistry()
6576
}
6677

6778
// Build callgraph
68-
log.Printf("Building callgraph...\n")
69-
cg, err := builder.BuildCallGraph(codeGraph, moduleRegistry, projectPath)
79+
logger.Progress("Building callgraph...")
80+
cg, err := builder.BuildCallGraph(codeGraph, moduleRegistry, projectPath, logger)
7081
if err != nil {
7182
return fmt.Errorf("failed to build callgraph: %w", err)
7283
}
73-
log.Printf("Callgraph built: %d functions, %d call sites\n",
84+
logger.Statistic("Callgraph built: %d functions, %d call sites",
7485
len(cg.Functions), countTotalCallSites(cg))
7586

7687
// Load Python DSL rules
77-
log.Printf("Loading rules from %s...\n", rulesPath)
88+
logger.Progress("Loading rules from %s...", rulesPath)
7889
loader := dsl.NewRuleLoader(rulesPath)
7990
rules, err := loader.LoadRules()
8091
if err != nil {
8192
return fmt.Errorf("failed to load rules: %w", err)
8293
}
83-
log.Printf("Loaded %d rules\n", len(rules))
94+
logger.Statistic("Loaded %d rules", len(rules))
8495

8596
// Execute rules against callgraph
86-
log.Printf("Running security scan...\n")
97+
logger.Progress("Running security scan...")
8798
allDetections := make(map[string][]dsl.DataflowDetection)
8899
totalDetections := 0
89100
for _, rule := range rules {
90101
detections, err := loader.ExecuteRule(&rule, cg)
91102
if err != nil {
92-
log.Printf("Error executing rule %s: %v\n", rule.Rule.ID, err)
103+
logger.Error("executing rule %s: %v", rule.Rule.ID, err)
93104
continue
94105
}
95106

@@ -99,8 +110,8 @@ Examples:
99110
}
100111
}
101112

102-
log.Printf("Scan complete. Found %d vulnerabilities.\n", totalDetections)
103-
log.Printf("Generating %s output...\n", outputFormat)
113+
logger.Statistic("Scan complete. Found %d vulnerabilities", totalDetections)
114+
logger.Progress("Generating %s output...", outputFormat)
104115

105116
// Generate output
106117
if outputFormat == "sarif" {
@@ -270,6 +281,8 @@ func init() {
270281
ciCmd.Flags().StringP("rules", "r", "", "Path to Python DSL rules file or directory (required)")
271282
ciCmd.Flags().StringP("project", "p", "", "Path to project directory to scan (required)")
272283
ciCmd.Flags().StringP("output", "o", "sarif", "Output format: sarif or json (default: sarif)")
284+
ciCmd.Flags().BoolP("verbose", "v", false, "Show progress and statistics")
285+
ciCmd.Flags().Bool("debug", false, "Show debug diagnostics with timestamps")
273286
ciCmd.MarkFlagRequired("rules")
274287
ciCmd.MarkFlagRequired("project")
275288
}

sourcecode-parser/cmd/query.go

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ import (
99
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/builder"
1010
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/core"
1111
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/registry"
12+
"github.com/shivasurya/code-pathfinder/sourcecode-parser/output"
1213
"github.com/spf13/cobra"
1314
)
1415

@@ -55,7 +56,7 @@ Examples:
5556

5657
// Build callgraph
5758
log.Printf("Building callgraph...\n")
58-
cg, err := builder.BuildCallGraph(codeGraph, moduleRegistry, projectPath)
59+
cg, err := builder.BuildCallGraph(codeGraph, moduleRegistry, projectPath, output.NewLogger(output.VerbosityDefault))
5960
if err != nil {
6061
return fmt.Errorf("failed to build callgraph: %w", err)
6162
}

sourcecode-parser/cmd/resolution_report.go

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@ import (
77
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph"
88
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph"
99
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/core"
10+
"github.com/shivasurya/code-pathfinder/sourcecode-parser/output"
1011
"github.com/spf13/cobra"
1112
)
1213

@@ -34,7 +35,7 @@ improvements to the resolution logic.`,
3435
codeGraph := graph.Initialize(projectInput)
3536

3637
fmt.Println("Building call graph...")
37-
cg, registry, _, err := callgraph.InitializeCallGraph(codeGraph, projectInput)
38+
cg, registry, _, err := callgraph.InitializeCallGraph(codeGraph, projectInput, output.NewLogger(output.VerbosityDefault))
3839
if err != nil {
3940
fmt.Printf("Error building call graph: %v\n", err)
4041
return

sourcecode-parser/cmd/scan.go

Lines changed: 27 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,6 @@ package cmd
22

33
import (
44
"fmt"
5-
"log"
65
"os"
76
"path/filepath"
87

@@ -11,6 +10,7 @@ import (
1110
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/builder"
1211
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/core"
1312
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/registry"
13+
"github.com/shivasurya/code-pathfinder/sourcecode-parser/output"
1414
"github.com/spf13/cobra"
1515
)
1616

@@ -31,6 +31,17 @@ Examples:
3131
RunE: func(cmd *cobra.Command, args []string) error {
3232
rulesPath, _ := cmd.Flags().GetString("rules")
3333
projectPath, _ := cmd.Flags().GetString("project")
34+
verbose, _ := cmd.Flags().GetBool("verbose")
35+
debug, _ := cmd.Flags().GetBool("debug")
36+
37+
// Setup logger with appropriate verbosity
38+
verbosity := output.VerbosityDefault
39+
if debug {
40+
verbosity = output.VerbosityDebug
41+
} else if verbose {
42+
verbosity = output.VerbosityVerbose
43+
}
44+
logger := output.NewLogger(verbosity)
3445

3546
if rulesPath == "" {
3647
return fmt.Errorf("--rules flag is required")
@@ -48,47 +59,47 @@ Examples:
4859
projectPath = absProjectPath
4960

5061
// Step 1: Build code graph (AST)
51-
log.Printf("Building code graph from %s...\n", projectPath)
62+
logger.Progress("Building code graph from %s...", projectPath)
5263
codeGraph := graph.Initialize(projectPath)
5364
if len(codeGraph.Nodes) == 0 {
5465
return fmt.Errorf("no source files found in project")
5566
}
56-
log.Printf("Code graph built: %d nodes\n", len(codeGraph.Nodes))
67+
logger.Statistic("Code graph built: %d nodes", len(codeGraph.Nodes))
5768

5869
// Step 2: Build module registry
59-
log.Printf("Building module registry...\n")
70+
logger.Progress("Building module registry...")
6071
moduleRegistry, err := registry.BuildModuleRegistry(projectPath)
6172
if err != nil {
62-
log.Printf("Warning: failed to build module registry: %v\n", err)
73+
logger.Warning("failed to build module registry: %v", err)
6374
// Create empty registry as fallback
6475
moduleRegistry = core.NewModuleRegistry()
6576
}
6677

6778
// Step 3: Build callgraph
68-
log.Printf("Building callgraph...\n")
69-
cg, err := builder.BuildCallGraph(codeGraph, moduleRegistry, projectPath)
79+
logger.Progress("Building callgraph...")
80+
cg, err := builder.BuildCallGraph(codeGraph, moduleRegistry, projectPath, logger)
7081
if err != nil {
7182
return fmt.Errorf("failed to build callgraph: %w", err)
7283
}
73-
log.Printf("Callgraph built: %d functions, %d call sites\n",
84+
logger.Statistic("Callgraph built: %d functions, %d call sites",
7485
len(cg.Functions), countTotalCallSites(cg))
7586

7687
// Step 4: Load Python DSL rules
77-
log.Printf("Loading rules from %s...\n", rulesPath)
88+
logger.Progress("Loading rules from %s...", rulesPath)
7889
loader := dsl.NewRuleLoader(rulesPath)
7990
rules, err := loader.LoadRules()
8091
if err != nil {
8192
return fmt.Errorf("failed to load rules: %w", err)
8293
}
83-
log.Printf("Loaded %d rules\n", len(rules))
94+
logger.Statistic("Loaded %d rules", len(rules))
8495

8596
// Step 5: Execute rules against callgraph
86-
log.Printf("\n=== Running Security Scan ===\n")
97+
logger.Progress("\n=== Running Security Scan ===")
8798
totalDetections := 0
8899
for _, rule := range rules {
89100
detections, err := loader.ExecuteRule(&rule, cg)
90101
if err != nil {
91-
log.Printf("Error executing rule %s: %v\n", rule.Rule.ID, err)
102+
logger.Error("executing rule %s: %v", rule.Rule.ID, err)
92103
continue
93104
}
94105

@@ -99,8 +110,8 @@ Examples:
99110
}
100111

101112
// Step 6: Print summary
102-
log.Printf("\n=== Scan Complete ===\n")
103-
log.Printf("Total vulnerabilities found: %d\n", totalDetections)
113+
logger.Progress("\n=== Scan Complete ===")
114+
logger.Statistic("Total vulnerabilities found: %d", totalDetections)
104115

105116
if totalDetections > 0 {
106117
os.Exit(1) // Exit with error code if vulnerabilities found
@@ -143,6 +154,8 @@ func init() {
143154
rootCmd.AddCommand(scanCmd)
144155
scanCmd.Flags().StringP("rules", "r", "", "Path to Python DSL rules file or directory (required)")
145156
scanCmd.Flags().StringP("project", "p", "", "Path to project directory to scan (required)")
157+
scanCmd.Flags().BoolP("verbose", "v", false, "Show progress and statistics")
158+
scanCmd.Flags().Bool("debug", false, "Show debug diagnostics with timestamps")
146159
scanCmd.MarkFlagRequired("rules")
147160
scanCmd.MarkFlagRequired("project")
148161
}

sourcecode-parser/graph/callgraph/benchmark_test.go

Lines changed: 5 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ import (
88
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/core"
99
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/registry"
1010
"github.com/shivasurya/code-pathfinder/sourcecode-parser/graph/callgraph/resolution"
11+
"github.com/shivasurya/code-pathfinder/sourcecode-parser/output"
1112
)
1213

1314
// Benchmark project paths
@@ -238,7 +239,7 @@ func BenchmarkInitializeCallGraph_Small(b *testing.B) {
238239
for i := 0; i < b.N; i++ {
239240
// Include full pipeline: graph initialization + call graph initialization
240241
codeGraph := graph.Initialize(smallProjectPath)
241-
callGraph, registry, patternRegistry, err := InitializeCallGraph(codeGraph, smallProjectPath)
242+
callGraph, registry, patternRegistry, err := InitializeCallGraph(codeGraph, smallProjectPath, output.NewLogger(output.VerbosityDefault))
242243
if err != nil {
243244
b.Fatalf("Failed to initialize call graph: %v", err)
244245
}
@@ -265,7 +266,7 @@ func BenchmarkInitializeCallGraph_Medium(b *testing.B) {
265266

266267
for i := 0; i < b.N; i++ {
267268
codeGraph := graph.Initialize(mediumProjectPath)
268-
callGraph, registry, patternRegistry, err := InitializeCallGraph(codeGraph, mediumProjectPath)
269+
callGraph, registry, patternRegistry, err := InitializeCallGraph(codeGraph, mediumProjectPath, output.NewLogger(output.VerbosityDefault))
269270
if err != nil {
270271
b.Fatalf("Failed to initialize call graph: %v", err)
271272
}
@@ -287,7 +288,7 @@ func BenchmarkInitializeCallGraph_Medium(b *testing.B) {
287288
func BenchmarkPatternMatching_Small(b *testing.B) {
288289
// Pre-build call graph and pattern registry
289290
codeGraph := graph.Initialize(smallProjectPath)
290-
callGraph, registry, patternRegistry, err := InitializeCallGraph(codeGraph, smallProjectPath)
291+
callGraph, registry, patternRegistry, err := InitializeCallGraph(codeGraph, smallProjectPath, output.NewLogger(output.VerbosityDefault))
291292
if err != nil {
292293
b.Fatalf("Failed to initialize call graph: %v", err)
293294
}
@@ -310,7 +311,7 @@ func BenchmarkPatternMatching_Small(b *testing.B) {
310311
func BenchmarkPatternMatching_Medium(b *testing.B) {
311312
// Pre-build call graph and pattern registry
312313
codeGraph := graph.Initialize(mediumProjectPath)
313-
callGraph, registry, patternRegistry, err := InitializeCallGraph(codeGraph, mediumProjectPath)
314+
callGraph, registry, patternRegistry, err := InitializeCallGraph(codeGraph, mediumProjectPath, output.NewLogger(output.VerbosityDefault))
314315
if err != nil {
315316
b.Fatalf("Failed to initialize call graph: %v", err)
316317
}

0 commit comments

Comments
 (0)