Order Creation Observability Enhancement

Overview

This document describes the comprehensive observability improvements added to the order creation process in ERP-Unlocked. These enhancements provide detailed visibility into every stage of order creation, enabling better monitoring, debugging, and performance optimization.

Table of Contents

• Overview
• What Was Changed
• New Metrics
• Tracing Implementation
• Enhanced Logging
• Trace Events
• Status and Error Message Determination
• Usage Examples
• Dashboard Queries
• Benefits

What Was Changed

Files Modified

1. apps/webapp/src/lib/observability/node-metrics.ts

   • Added 15+ new order-specific metrics
   • Created helper functions for recording metrics

2. apps/webapp/src/services/order.ts

   • Wrapped all major operations in OpenTelemetry spans
   • Added detailed logging with context
   • Integrated metrics recording throughout the flow

3. apps/webapp/src/pages/api/erp/orders/index.ts

   • Added comprehensive tracing to the POST endpoint
   • Enhanced error handling with observability
   • Added metrics for API-level operations

New Metrics

Order Creation Metrics

Counters

Metric Name	Description	Labels
order_creation_started_total	Total order creation attempts started	erp_connection_id, erp_type, item_count
order_creation_completed_total	Total orders successfully created	erp_connection_id, erp_type, status, item_count, successful_items
order_creation_failed_total	Total order creation failures	erp_connection_id, erp_type, item_count
order_creation_partial_total	Total partially successful orders	erp_connection_id, erp_type, item_count, successful_items
order_items_filtered_total	Total items filtered out during creation	erp_connection_id, filter_reason
order_items_skipped_total	Total items skipped during creation	erp_connection_id, skip_reason
order_retry_attempts_total	Total retry attempts	erp_connection_id, retry_reason, problematic_items
order_erp_errors_total	Total ERP-related errors	erp_connection_id, erp_type, error_type
order_db_errors_total	Total database errors	operation, success
order_validation_errors_total	Total validation errors	erp_connection_id, success, error_type

Histograms

Metric Name	Description	Labels
order_creation_duration_seconds	Duration of order creation process	erp_connection_id, erp_type, status, item_count, successful_items
order_validation_duration_seconds	Duration of order validation	erp_connection_id, success, error_type
order_db_insert_duration_seconds	Duration of database insertion	operation, success
order_erp_submission_duration_seconds	Duration of ERP submission	erp_connection_id, erp_type, success, error_type

Tracing Implementation

Span Hierarchy

The order creation process is instrumented with the following span hierarchy:

api.orders.create (root span)
├── api.orders.validate_request
├── api.orders.generate_po_number
├── api.orders.calculate_total
├── api.orders.filter_app_deleted_items
├── api.orders.filter_erp_deleted_items
├── api.orders.erp_create
└── api.orders.store_in_db
    └── order.service.create
        ├── order.service.get_erp_connection
        ├── order.service.prepare_items
        ├── order.service.db_insert
        ├── order.service.fetch_order
        ├── order.service.erp_create_order
        ├── order.service.extract_problematic_items (if retry)
        ├── order.service.update_item_statuses
        └── order.service.update_order_complete

Span Attributes

Each span includes relevant attributes for filtering and analysis:

Root Span (api.orders.create)

• http.method: HTTP method (POST)
• http.route: API route path
• api.request_id: Unique request identifier
• user.id: User ID
• erp.connection_id: ERP connection ID
• erp.type: ERP system type
• order.customer_name: Customer name
• order.item_count: Total item count
• order.valid_item_count: Valid items after filtering
• order.skipped_item_count: Skipped items count
• order.po_number: Purchase order number
• order.total_amount: Order total amount
• order.id: Order ID (after creation)
• order.erp_order_number: ERP order number
• order.final_status: Final order status
• order.successful_items_count: Count of successful items

Service Spans

• order.service.* spans include operation-specific attributes
• Database operation spans include operation and success attributes
• ERP operation spans include erp_type and erp_connection_id

Enhanced Logging

Log Structure

All logs now include comprehensive context:

{
  "timestamp": "2025-01-24T10:30:00.000Z",
  "level": "info",
  "service": "erp-unlocked-webapp",
  "message": "Order created successfully",
  "trace_id": "abc123...",
  "span_id": "def456...",
  "orderId": "order_123",
  "erpOrderNumber": "ERP-456",
  "erpConnectionId": "conn_789",
  "durationSeconds": 2.5,
  "successfulItems": 5,
  "totalItems": 6,
  "requestId": "req_001"
}

Log Levels

• DEBUG: Detailed step-by-step information (PO generation, item filtering)
• INFO: Major milestones (order created, ERP submission started)
• WARN: Non-critical issues (items filtered, retries)
• ERROR: Failures with full context

Status and Error Message Determination

Status Determination Logic

The order status is determined based on a comprehensive analysis of item processing results. The system tracks detailed context for each status determination:

Status Values

• completed: All items were successfully processed
• partial: Some items succeeded, but some failed or were skipped
• failed: No items were successfully processed
• pending: Order is waiting for processing

Status Determination Reasons

Each status determination includes a reason that explains why that status was chosen:

Reason	Description	Status
all_items_successful	All items processed successfully	completed
some_items_failed	Some items failed, but some succeeded	partial
some_items_skipped	Some items were skipped, but some succeeded	partial
all_items_failed	No items were successfully processed	failed
no_valid_items	No valid items to submit (all filtered)	failed
erp_submission_failed	ERP API call failed	failed
erp_error_response	ERP returned an error response	failed
exception_during_processing	Exception occurred during processing	failed
db_error	Database operation failed	failed
validation_error	Validation failed	failed
erp_connection_error	ERP connection error	failed

Status Determination Context

When a status is determined, the system records:

{
  erpConnectionId: string;
  totalItems: number;
  successfulItems: number;
  failedItems: number;
  skippedItems: number;
  hasSuccessfulItems: boolean;
  hasFailedItems: boolean;
  hasSkippedItems: boolean;
}

Error Message Sources

Error messages are tracked with their source to understand where failures originate:

Error Message Sources

Source	Description	When It Occurs
no_valid_items	No valid items to submit	All items filtered out
erp_error_response	Error from ERP system	ERP API returns error
erp_connection_error	ERP connection failed	Network/connection issues
db_error	Database operation failed	DB insert/update fails
validation_error	Validation failed	Request validation fails
exception	Unexpected exception	Unhandled exception
item_extraction_error	Item extraction failed	Error extracting items
unknown	Unknown source	Fallback for unclassified errors

Error Message Tracking

Each error message is recorded with:

• Source: Where the error originated
• Error Type: Classification of the error (if available)
• ERP Connection ID: Which connection had the issue
• Full Error Message: Complete error text

Status Determination Flow

1. Check if ERP submission was skipped
   ├─ Yes → Return with current status (no change)
   └─ No → Continue

2. Check if ERP submission succeeded
   ├─ No → Status = 'failed', Reason = 'erp_submission_failed'
   └─ Yes → Continue

3. Analyze item statuses
   ├─ Count successful items
   ├─ Count failed items
   └─ Count skipped items

4. Determine status based on item analysis
   ├─ Has successful items?
   │  ├─ Yes → Has failed/skipped items?
   │  │  ├─ Yes → Status = 'partial', Reason = 'some_items_failed' or 'some_items_skipped'
   │  │  └─ No → Status = 'completed', Reason = 'all_items_successful'
   │  └─ No → Status = 'failed', Reason = 'all_items_failed'
   └─ Record determination with full context

Metrics for Status Determination

order_status_determined_total

Counter tracking each status determination with labels:

• status: The determined status
• reason: Why this status was chosen
• erp_connection_id: ERP connection involved
• total_items: Total items in order
• successful_items: Count of successful items
• failed_items: Count of failed items
• skipped_items: Count of skipped items
• has_successful_items: Boolean flag
• has_failed_items: Boolean flag
• has_skipped_items: Boolean flag

order_status_determination_reason_total

Counter tracking the reasons for status determinations (same labels as above).

order_error_message_source_total

Counter tracking error message sources with labels:

• source: Where the error originated
• error_type: Type of error (if available)
• erp_connection_id: ERP connection involved

Span Attributes for Status

Each span includes attributes that capture the status determination:

• order.final_status: The determined status
• order.status_reason: Why this status was chosen
• order.successful_items_count: Number of successful items
• order.failed_items_count: Number of failed items
• order.skipped_items_count: Number of skipped items
• order.has_successful_items: Boolean flag
• order.has_failed_items: Boolean flag
• order.has_skipped_items: Boolean flag
• order.failure_reason: Reason for failure (if failed)
• order.error_source: Source of error message
• order.error_type: Type of error (if available)
• order.error_message: Full error message

Trace Events for Status

Events are recorded at key decision points:

• order_status_determined: Status was determined with full context
• order_status_determined_no_items: Status = ‘failed’ due to no valid items
• order_status_determined_erp_failed: Status = ‘failed’ due to ERP error
• order_status_determined_all_items_failed: Status = ‘failed’, all items failed
• order_status_determined_partial: Status = ‘partial’, some items succeeded

Trace Events

Key events are recorded throughout the order creation process:

Request Lifecycle Events

• order_creation_request_received - API request received
• order_creation_started - Order creation process started
• order_creation_completed - Order creation completed successfully
• order_creation_error - Error occurred during creation

Database Events

• order_inserted_to_db - Order inserted into database
• order_fetched_from_db - Order retrieved from database
• order_updated_in_db - Order updated in database

ERP Events

• order_erp_submission_started - ERP submission started
• order_created_in_erp - Order created in ERP system
• order_created_in_erp_success - ERP creation succeeded
• order_erp_submission_failed - ERP submission failed
• order_erp_creation_failed - ERP creation failed

Item Processing Events

• items_skipped - Items were skipped
• items_filtered_app_deleted - Items filtered (app-level deletion)
• items_filtered_erp_deleted - Items filtered (ERP-level deletion)
• problematic_items_identified - Problematic items identified

Status Events

• order_status_determined - Final order status determined
• order_retry_initiated - Retry process initiated
• order_erp_submission_skipped - ERP submission skipped

Usage Examples

Querying Metrics

Get order creation success rate

rate(order_creation_completed_total{status="completed"}[5m])
/
rate(order_creation_started_total[5m])

Get status determination breakdown

sum(rate(order_status_determined_total[5m])) by (status, reason)

Get error message sources

sum(rate(order_error_message_source_total[5m])) by (source, error_type)

Analyze failure reasons

sum(rate(order_status_determination_reason_total{status="failed"}[5m])) by (reason)

Get average order creation duration

histogram_quantile(0.95,
  rate(order_creation_duration_seconds_bucket[5m])
)

Get error rate by type

sum(rate(order_erp_errors_total[5m])) by (error_type)

Get filtered items count

sum(rate(order_items_filtered_total[5m])) by (filter_reason)

Tracing a Specific Order

1. Find the order ID or ERP order number
2. Search logs for that order ID
3. Extract the trace_id from the log entry
4. Use the trace ID in BetterStack to view the complete trace

Analyzing Performance

Identify slow operations

histogram_quantile(0.95,
  rate(order_db_insert_duration_seconds_bucket[5m])
)

Compare ERP submission times by ERP type

histogram_quantile(0.95,
  rate(order_erp_submission_duration_seconds_bucket[5m])
) by (erp_type)

Dashboard Queries

Order Creation Overview

# Total orders created
sum(rate(order_creation_completed_total[5m]))

# Success rate
sum(rate(order_creation_completed_total{status="completed"}[5m]))
/
sum(rate(order_creation_started_total[5m]))

# Average duration
histogram_quantile(0.50,
  rate(order_creation_duration_seconds_bucket[5m])
)

Error Analysis

# Error rate
sum(rate(order_creation_failed_total[5m]))
/
sum(rate(order_creation_started_total[5m]))

# Errors by type
sum(rate(order_erp_errors_total[5m])) by (error_type)
sum(rate(order_db_errors_total[5m])) by (operation)
sum(rate(order_validation_errors_total[5m])) by (error_type)

# Status determination breakdown
sum(rate(order_status_determined_total[5m])) by (status, reason)

# Error message sources
sum(rate(order_error_message_source_total[5m])) by (source, error_type)

# Failure reasons analysis
sum(rate(order_status_determination_reason_total{status="failed"}[5m])) by (reason)

Item Processing

# Filtered items
sum(rate(order_items_filtered_total[5m])) by (filter_reason)

# Skipped items
sum(rate(order_items_skipped_total[5m])) by (skip_reason)

# Average items per order
sum(rate(order_creation_completed_total[5m]))
/
sum(rate(order_creation_started_total[5m]))

Performance Metrics

# P95 duration by stage
histogram_quantile(0.95,
  rate(order_validation_duration_seconds_bucket[5m])
)
histogram_quantile(0.95,
  rate(order_db_insert_duration_seconds_bucket[5m])
)
histogram_quantile(0.95,
  rate(order_erp_submission_duration_seconds_bucket[5m])
)

Benefits

1. Complete Visibility

Every stage of order creation is now instrumented, providing:

• End-to-end traceability
• Performance metrics for each operation
• Error tracking with context
• Item-level processing details

2. Performance Optimization

Identify bottlenecks quickly:

• Which operations take the longest?
• Are ERP submissions slow?
• Is database insertion a bottleneck?
• How does performance vary by ERP type?

3. Error Analysis

Understand failures better:

• What types of errors occur most frequently?
• Which ERP connections have issues?
• Are validation errors common?
• What causes retries?
• Why was a specific status chosen? (via status_reason)
• Where did error messages originate? (via error_source)
• What’s the breakdown of item processing? (successful vs failed vs skipped)

4. Business Metrics

Track business KPIs:

• Order creation success rate
• Average items per order
• Filtered items percentage
• Retry rate

5. Debugging

When issues occur:

• Find the exact trace ID from logs
• View the complete request flow in BetterStack
• See all spans and their durations
• Identify where failures occurred

6. Alerting

Set up alerts for:

• High error rates
• Slow order creation
• Excessive retries
• High item filtering rates
• Specific failure reasons (e.g., erp_submission_failed)
• Error message sources (e.g., db_error spikes)

Best Practices

1. Monitor Key Metrics

Set up dashboards for:

• Order creation success rate (target: >95%)
• Average creation duration (target: <5 seconds)
• Error rate (target: <1%)
• Item filtering rate (monitor trends)

2. Set Up Alerts

Configure alerts for:

• Error rate > 5%
• P95 duration > 10 seconds
• Retry rate > 10%
• Database errors

3. Regular Analysis

Review weekly:

• Error patterns
• Performance trends
• Filtered items reasons
• ERP-specific issues

4. Trace Correlation

Always include trace IDs in:

• Support tickets
• Bug reports
• Performance investigations