Repository navigation
feat: enhance logging across services - #3
henryjandrews wants to merge 3 commits into
Conversation
gjanco
left a comment
gjanco
left a comment
There was a problem hiding this comment.
Just a rename suggestion, but not required.
f197126 to
52e2b55
Compare
There was a problem hiding this comment.
Pull request overview
This PR enhances logging capabilities across the payment, catalog, and recommendation services by adding comprehensive observability with OpenTelemetry trace context, system metrics, and detailed error reporting. The changes introduce structured logging with performance monitoring, memory leak detection, and cache behavior tracking.
Key Changes
- Added trace context propagation and system metrics collection to all three services
- Implemented detailed cache monitoring and memory leak detection in the recommendation service
- Enhanced error logging with contextual information including transaction details and system state
Reviewed changes
Copilot reviewed 6 out of 6 changed files in this pull request and generated 12 comments.
Show a summary per file
| File | Description |
|---|---|
| src/recommendation/recommendation_server.py | Added comprehensive logging with trace context, system metrics, cache operations monitoring, and memory leak detection |
| src/recommendation/logger.py | Enhanced JSON formatter to include OpenTelemetry trace context in all log records |
| src/product-catalog/main.go | Added trace context and system metrics helpers; enhanced error and success logging with detailed context |
| src/payment/logger.js | Added trace context to logger mixin for consistent tracing across log entries |
| src/payment/charge.js | Implemented cache leak simulation, enhanced error logging with system metrics, and detailed transaction context |
| src/flagd/demo.flagd.json | Added new feature flag paymentCacheLeak for testing cache overflow scenarios |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| 'cache_cleanup_error': True, | ||
| 'error_type': type(cleanup_error).__name__, | ||
| 'error_message': str(cleanup_error), | ||
| 'error_stack': str(cleanup_error.__traceback__) if hasattr(cleanup_error, '__traceback__') else 'unavailable', |
There was a problem hiding this comment.
Converting traceback objects to strings using str() produces uninformative output like '<traceback object at 0x...>'. Use traceback.format_exc() or traceback.format_tb() to generate meaningful stack traces that include file names, line numbers, and code context.
| 'request_id': f"req_{self.request_count}", | ||
| 'error_type': type(e).__name__, | ||
| 'error_message': str(e), | ||
| 'error_stack': str(e.__traceback__) if hasattr(e, '__traceback__') else 'unavailable', |
There was a problem hiding this comment.
Converting traceback objects to strings using str() produces uninformative output like '<traceback object at 0x...>'. Use traceback.format_exc() or traceback.format_tb() to generate meaningful stack traces that include file names, line numbers, and code context.
| 'page_faults_major': getattr(process.memory_full_info() if hasattr(process, 'memory_full_info') else memory_info, 'pfaults', 0), | ||
| 'page_faults_minor': getattr(process.memory_full_info() if hasattr(process, 'memory_full_info') else memory_info, 'pageins', 0) |
There was a problem hiding this comment.
The process.memory_full_info() method is called twice per invocation when available, potentially causing performance overhead. Call it once, store the result in a variable, and reuse it for both page fault metrics.
| 'context_switches_voluntary': getattr(process, 'num_ctx_switches', lambda: (0, 0))().voluntary, | ||
| 'context_switches_involuntary': getattr(process, 'num_ctx_switches', lambda: (0, 0))().involuntary, |
There was a problem hiding this comment.
The num_ctx_switches() method is called twice per invocation, potentially causing performance overhead. Call it once, store the result in a variable, and reuse it for both voluntary and involuntary context switch counts.
| "go.opentelemetry.io/contrib/bridges/otelslog" | ||
| "go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc" | ||
| "go.opentelemetry.io/contrib/instrumentation/runtime" | ||
| otelruntime "go.opentelemetry.io/contrib/instrumentation/runtime" |
There was a problem hiding this comment.
The alias otelruntime is used to avoid collision with the standard runtime package imported on line 17. However, consider using a more descriptive alias like otelruntimemetrics or otelruntimeinstrumentation to better clarify its purpose as an OpenTelemetry instrumentation package rather than just "runtime".
| slog.String("database.connection_status", "timeout"), | ||
| slog.String("database.last_successful_query", "unknown"), | ||
| slog.Int("database.active_connections", 0), |
There was a problem hiding this comment.
These database-related log fields are misleading since the product catalog reads from JSON files (as seen in readProductFiles()), not a database. Either remove these database references or clearly prefix them with a namespace indicating they are simulated/mock values for the feature flag scenario.
| slog.String("database.connection_status", "timeout"), | ||
| slog.String("database.last_successful_query", "unknown"), | ||
| slog.Int("database.active_connections", 0), | ||
| slog.String("error.stack_trace", "ProductCatalogService.GetProduct() -> DatabaseConnection.timeout"), |
There was a problem hiding this comment.
The stack trace references "DatabaseConnection.timeout" but the product catalog reads from JSON files, not a database. This creates a misleading error trail. Either remove the database reference or clearly indicate this is simulated for demonstration purposes.
| slog.Float64("database_timeout_duration_ms", float64(operationDuration.Nanoseconds())/1000000), | ||
| slog.String("performance.database_latency", "timeout"), |
There was a problem hiding this comment.
These database timeout metrics are misleading since the product catalog reads from JSON files, not a database. The field names suggest database operations that don't actually exist in this service.
| hrTime: hrTime[0] * 1000000000 + hrTime[1] // nanoseconds since process start | ||
| }, | ||
| performance: { | ||
| eventLoopDelay: Math.round(Math.random() * 10), // Simulated event loop delay in ms |
There was a problem hiding this comment.
Using Math.random() to simulate event loop delay provides meaningless metrics. Consider using actual event loop monitoring libraries like perf_hooks.monitorEventLoopDelay() or remove this metric entirely if real measurement isn't feasible.
| tokenType: 'loyalty_access_token' | ||
| }, | ||
| performance: { | ||
| duration: Math.floor(Math.random() * 500) + 100, // Simulate processing time |
There was a problem hiding this comment.
Using Math.random() to simulate processing duration provides meaningless metrics that don't reflect actual performance. Either measure the actual operation duration or remove this field from the logs.
Changes
Enhanced logging across payment, catalog, and recommendation services
Merge Requirements
For new features contributions, please make sure you have completed the following
essential items:
CHANGELOG.mdupdated to document new feature additionsMaintainers will not merge until the above have been completed. If you're unsure
which docs need to be changed ping the
@open-telemetry/demo-approvers.