Monitoring & Observability

This page provides detailed, step-by-step guidance on how the monitoring system works, with real examples and Docker commands to verify results.

Table of Contents

1. Technical Concepts
2. Admin Dashboard
3. How It Works (Flow)
4. Step-by-Step Tutorial
5. Docker Verification
6. Real Output Examples

1. Admin Dashboard (New)

We have added a built-in dashboard to view performance metrics directly in the application.

Access:/admin/monitor

Features:

• View realtime performance stats (Avg, Max, Total Duration)
• Identify slow endpoints (Hotspots)
• Monitor memory usage per controller
• Clear metrics cache

1. Technical Concepts

Before diving into examples, let's understand the key concepts:

What is Observability?

Observability is the ability to understand what's happening inside your application by examining its outputs. It answers questions like:

• "Why is this page slow?"
• "Which database query is the bottleneck?"
• "How many requests are we handling per second?"

The Three Pillars

Key Terms Explained

2. How It Works (Flow)

2. Automatic Tracing

Automatic Request Tracking

Every HTTP request is automatically tracked without any code changes. Here's the flow:

Data Storage Flow

3. Step-by-Step Tutorial

Scenario: You want to monitor a slow OrderService

Let's say you have an OrderService and you suspect processOrder() is slow. Here's how to add monitoring:

Step 1: Add the Attributes

Open your service file and add #[Trace] and #[Monitor]:

<?php
namespace App\Domain\Order\Services;

use App\Attributes\Trace;
use App\Attributes\Monitor;

class OrderService
{
    /**
     * Process an order
     * 
     * We add #[Trace] to see this in distributed traces
     * We add #[Monitor] to track performance (only if > 50ms)
     */
    #[Trace(name: 'order.process')]
    #[Monitor(threshold: 50)]
    public function processOrder(int $orderId): Order
    {
        // Your existing code
        $order = $this->orderRepo->find($orderId);
        $this->validateOrder($order);
        $this->reserveInventory($order);
        $this->chargePayment($order);
        return $order;
    }

    #[Trace(name: 'order.validate')]
    private function validateOrder(Order $order): void
    {
        // Validation logic
    }

    #[Trace(name: 'order.payment')]
    #[Monitor(threshold: 100)]  // Payment should be fast
    private function chargePayment(Order $order): void
    {
        // Payment gateway call
    }
}

Step 2: Generate Some Traffic

Make some requests to the endpoint that uses this service:

# Make 10 requests
for i in {1..10}; do curl -s http://localhost:81/api/orders/1; done

Step 3: Check Redis (Immediate)

Data is stored in Redis immediately. Check it:

# Connect to Redis in Docker
docker-compose exec redis redis-cli

# List all performance keys
KEYS perf:*

# Example output:
# 1) "perf:Api:OrderController:show:202601041830"
# 2) "perf:Domain:OrderService:processOrder:202601041830"

# View the data in a key
LRANGE perf:Api:OrderController:show:202601041830 0 -1

# Example output:
# 1) "{\"d\":145.2,\"m\":12.5,\"t\":1704326400}"
# 2) "{\"d\":132.8,\"m\":11.9,\"t\":1704326401}"

Step 4: Flush to MySQL

Move data from Redis to MySQL for long-term storage:

# Run the flush command
docker-compose exec php php spark monitor:flush

# Output:
# Output:
# Flushed 15 records from Redis to MySQL

Step 5: Analyze Performance

Use the analyze command to find hotspots:

# Analyze last 60 minutes
docker-compose exec php php spark monitor:analyze

# Or analyze last 2 hours, top 10 results
docker-compose exec php php spark monitor:analyze 120 10

4. Docker Verification

Check if Filters are Running

# View PHP logs
docker-compose logs -f php

# Look for lines like:
# [DEBUG] TracingFilter: Started trace abc123
# [DEBUG] PerformanceFilter: Recorded 145ms for Api::OrderController::show

Check Redis Data

# Connect to Redis
docker-compose exec redis redis-cli

# Count all performance keys
KEYS perf:* | wc -l

# Get all keys with pattern
KEYS perf:*

# Check specific key data
LRANGE perf:Admin:DashboardController:index:202601041830 0 5

# Check key TTL (time to live)
TTL perf:Admin:DashboardController:index:202601041830
# Returns seconds until expiration (e.g., 3200)

Check MySQL Data

# Connect to MySQL
docker-compose exec mysql mysql -u root -p ci4_database

# Count records
SELECT COUNT(*) FROM performance_logs;

# View recent records
SELECT module, service, method, duration_ms, memory_mb, created_at 
FROM performance_logs 
ORDER BY created_at DESC 
LIMIT 10;

# Find slowest endpoints
SELECT module, service, method, 
       AVG(duration_ms) as avg_ms, 
       MAX(duration_ms) as max_ms,
       COUNT(*) as calls
FROM performance_logs 
WHERE created_at > DATE_SUB(NOW(), INTERVAL 1 HOUR)
GROUP BY module, service, method
ORDER BY avg_ms DESC
LIMIT 10;

Check Prometheus Metrics

# Fetch metrics endpoint
curl http://localhost:81/metrics

# Or from inside Docker network
docker-compose exec php curl http://localhost/metrics

5. Real Output Examples

5.1 Redis Data Format

When you run LRANGE perf:Admin:UserController:index:202601041830 0 -1:

1) "{\"d\":45.23,\"m\":8.5,\"t\":1704326400}"
2) "{\"d\":52.10,\"m\":9.1,\"t\":1704326401}"
3) "{\"d\":38.75,\"m\":7.8,\"t\":1704326402}"
4) "{\"d\":125.50,\"m\":15.2,\"t\":1704326403}"
5) "{\"d\":41.20,\"m\":8.2,\"t\":1704326404}"

Explanation:

• d = duration in milliseconds
• m = memory usage in MB
• t = Unix timestamp

5.2 monitor:analyze Output

$ docker-compose exec php php spark monitor:analyze

Analyzing performance logs for past 60 minutes...

┌────────┬──────────────────┬─────────────┬───────┬──────────┬──────────┬────────────┐
│ Module │ Service          │ Method      │ Count │ Avg (ms) │ Max (ms) │ Total (ms) │
├────────┼──────────────────┼─────────────┼───────┼──────────┼──────────┼────────────┤
│ Admin  │ UserController   │ index       │ 150   │ 85.23    │ 450.50   │ 12784.50   │
│ Api    │ OrderController  │ show        │ 320   │ 145.00   │ 890.00   │ 46400.00   │
│ Web    │ HomeController   │ index       │ 520   │ 35.50    │ 120.00   │ 18460.00   │
│ Domain │ OrderService     │ processOrder│ 320   │ 125.30   │ 750.00   │ 40096.00   │
│ Domain │ PaymentService   │ charge      │ 280   │ 95.40    │ 520.00   │ 26712.00   │
└────────┴──────────────────┴─────────────┴───────┴──────────┴──────────┴────────────┘

Top Hotspot Analysis: Api::OrderController::show

    Percentiles:
    ├── p50: 120.50 ms  (50% of requests are faster than this)
    ├── p95: 350.30 ms  (95% of requests are faster than this)
    └── p99: 750.10 ms  (99% of requests are faster than this)

    Percentiles:
    ├── p50: 120.50 ms  (50% of requests are faster than this)
    ├── p95: 350.30 ms  (95% of requests are faster than this)
    └── p99: 750.10 ms  (99% of requests are faster than this)

    WARNING: p99 is 6x higher than p50, indicating occasional slow requests.
    Consider investigating: database locks, external API timeouts, or GC pauses.

5.3 Prometheus /metrics Output

$ curl http://localhost:81/metrics

# HELP ci4_request_duration_seconds HTTP request duration in seconds
# TYPE ci4_request_duration_seconds histogram
ci4_request_duration_seconds_bucket{module="Admin",controller="UserController",method="index",status="200",le="0.01"} 12
ci4_request_duration_seconds_bucket{module="Admin",controller="UserController",method="index",status="200",le="0.05"} 45
ci4_request_duration_seconds_bucket{module="Admin",controller="UserController",method="index",status="200",le="0.1"} 98
ci4_request_duration_seconds_bucket{module="Admin",controller="UserController",method="index",status="200",le="0.5"} 145
ci4_request_duration_seconds_bucket{module="Admin",controller="UserController",method="index",status="200",le="1"} 150
ci4_request_duration_seconds_bucket{module="Admin",controller="UserController",method="index",status="200",le="+Inf"} 150
ci4_request_duration_seconds_sum{module="Admin",controller="UserController",method="index",status="200"} 12.7845
ci4_request_duration_seconds_count{module="Admin",controller="UserController",method="index",status="200"} 150

# HELP ci4_request_total Total HTTP requests
# TYPE ci4_request_total counter
ci4_request_total{module="Admin",controller="UserController",method="index",status="200"} 150
ci4_request_total{module="Api",controller="OrderController",method="show",status="200"} 320
ci4_request_total{module="Web",controller="HomeController",method="index",status="200"} 520

# HELP ci4_memory_usage_bytes Memory usage in bytes
# TYPE ci4_memory_usage_bytes gauge
ci4_memory_usage_bytes{module="Admin"} 8912345

5.4 Trace Span Hierarchy

When you view traces (in logs or a tracing UI like Jaeger):

Trace ID: abc123def456789
Start: 2026-01-04 18:30:00.000

├── HTTP GET /api/orders/42                    [0ms - 145ms] 145ms
│   │
│   ├── order.process                          [5ms - 140ms] 135ms
│   │   │
│   │   ├── db.query (SELECT * FROM orders...) [8ms - 15ms]   7ms
│   │   │
│   │   ├── order.validate                     [16ms - 20ms]  4ms
│   │   │
│   │   ├── order.reserve_inventory            [21ms - 35ms] 14ms
│   │   │   └── db.query (UPDATE inventory...) [22ms - 34ms] 12ms
│   │   │
│   │   └── order.payment                      [36ms - 138ms] 102ms
│   │       ├── stripe.create_intent           [40ms - 95ms]  55ms
│   │       └── stripe.confirm                 [96ms - 135ms] 39ms
│   │
│   └── render.view                            [141ms - 144ms] 3ms

End: 2026-01-04 18:30:00.145

Reading this trace:

• Total request took 145ms
• Most time (102ms) spent in payment processing
• Stripe API calls are the bottleneck (55ms + 39ms = 94ms)
• Database queries are fast (7ms + 12ms = 19ms)

5.5 MySQL Query Results

mysql> SELECT module, service, method, duration_ms, memory_mb, created_at 
       FROM performance_logs 
       ORDER BY duration_ms DESC 
       LIMIT 5;

+--------+------------------+---------------+-------------+-----------+---------------------+
| module | service          | method        | duration_ms | memory_mb | created_at          |
+--------+------------------+---------------+-------------+-----------+---------------------+
| Api    | OrderController  | export        |      890.50 |     45.20 | 2026-01-04 18:25:30 |
| Admin  | ReportController | generate      |      750.25 |     38.50 | 2026-01-04 18:20:15 |
| Api    | OrderController  | show          |      520.10 |     22.30 | 2026-01-04 18:28:45 |
| Domain | PaymentService   | charge        |      450.75 |     15.80 | 2026-01-04 18:27:00 |
| Admin  | UserController   | index         |      350.20 |     18.90 | 2026-01-04 18:22:30 |
+--------+------------------+---------------+-------------+-----------+---------------------+

Quick Reference: All Commands