Improve indexing

bin/distributed-test/DIAGNOSTICS.md

@@ -0,0 +1,274 @@
+# Server-Side Diagnostics & Load Test Correlation
+
+The diagnostics endpoint (`GET /api/v1/system/diagnostics`) provides a single-call performance snapshot of the OpenMetadata server. Combined with the load test script, it enables pinpointing **where** time is spent during high-load scenarios and produces actionable tuning recommendations.
+
+## The Diagnostics Endpoint
+
+### Basic Usage
+
+```bash
+curl -H "Authorization: Bearer $TOKEN" \
+  http://localhost:8585/api/v1/system/diagnostics | python3 -m json.tool
+```
+
+### Response Structure
+
+```json
+{
+  "timestamp": "2026-03-02T19:00:00Z",
+  "jvm": { ... },
+  "jetty": { ... },
+  "database": { ... },
+  "bulk_executor": { ... },
+  "request_latency": { ... }
+}
+```
+
+Each section is explained below.
+
+---
+
+## Understanding Each Section
+
+### JVM
+
+| Field | What It Tells You |
+|-------|-------------------|
+| `heap_used_bytes` / `heap_max_bytes` | Current heap consumption vs maximum. |
+| `heap_usage_pct` | If >85% after load, GC pressure is likely adding tail latency. |
+| `gc_pause_total_ms` | Cumulative GC pause time since JVM start. Compare before/after load to see how much GC occurred during the test. |
+| `gc_count` | Total GC collections. A large delta during load means frequent stop-the-world pauses. |
+| `thread_count` / `thread_peak` | Active JVM threads. Correlate with Jetty thread pool. |
+| `cpu_process_pct` | Process CPU utilization (0-100). If pinned at 100%, the server is CPU-bound. |
+| `uptime_seconds` | Useful to confirm the server wasn't restarted mid-test. |
+
+### Jetty (Thread Pool)
+
+| Field | What It Tells You |
+|-------|-------------------|
+| `threads_busy` / `threads_max` | How many request-handling threads are in use. |
+| `utilization_pct` | **Key metric.** If >90% with `queue_size > 0`, the thread pool is saturated and requests are queuing. |
+| `queue_size` | Requests waiting for a free thread. Non-zero means latency is being added by queuing. |
+| `queue_time_avg_ms` | Average time a request waits in the queue before getting a thread. |
+| `virtual_threads_enabled` | Whether Java 21 virtual threads are active (eliminates thread pool as a bottleneck). |
+
+### Database (HikariCP Pool)
+
+| Field | What It Tells You |
+|-------|-------------------|
+| `pool_active` / `pool_max` | Active DB connections vs maximum pool size. |
+| `pool_usage_pct` | **Key metric.** If >80%, connection contention is likely. Requests wait for a free connection. |
+| `pool_pending` | Threads waiting for a DB connection. If >0 during load, the pool is undersized. |
+| `pool_idle` | Spare connections. If 0 during load, the pool is fully utilized. |
+
+### Bulk Executor
+
+| Field | What It Tells You |
+|-------|-------------------|
+| `queue_depth` / `queue_capacity` | Items in the async processing queue. |
+| `queue_usage_pct` | If >70%, approaching the rejection threshold (HTTP 503 errors). |
+| `active_threads` / `max_threads` | Worker threads actively processing bulk operations. |
+| `has_capacity` | `false` means the next bulk submission will be rejected with 503. |
+
+### Request Latency (Per-Endpoint Breakdown)
+
+This is the most actionable section. For each `METHOD /endpoint` combination:
+
+| Field | What It Tells You |
+|-------|-------------------|
+| `count` | Total requests processed for this endpoint. |
+| `avg_total_ms` | Average end-to-end latency. |
+| `avg_db_ms` / `db_pct` | Time spent in database queries and its percentage of total. |
+| `avg_search_ms` / `search_pct` | Time spent in search/Elasticsearch operations. |
+| `avg_internal_ms` / `internal_pct` | Time in Java code (serialization, validation, business logic). |
+| `avg_db_ops` / `avg_search_ops` | Average number of DB/search round-trips per request. |
+
+**Reading the breakdown:** If `PUT /v1/tables` shows `db_pct: 56%`, then 56% of the request time is spent waiting for database queries. Combined with `database.pool_usage_pct: 85%`, this tells you the DB connection pool is the bottleneck.
+
+---
+
+## Load Test Integration
+
+The load test script automatically queries the diagnostics endpoint at three points:
+
+1. **Before load** — baseline snapshot
+2. **During load** — sampled every 10 seconds by the health monitor
+3. **After load** — final snapshot for comparison
+
+### Running a Load Test with Diagnostics
+
+```bash
+# Basic: diagnostics are collected automatically
+./perf-test.sh --scale small --server http://localhost:8585 --admin-port 8586
+
+# With explicit token
+./perf-test.sh --scale medium --server http://localhost:8585 \
+  --admin-port 8586 --token "$MY_TOKEN" --output /tmp/bench.json
+```
+
+The `--admin-port` flag enables both Prometheus scraping and diagnostics collection. Diagnostics work without it too (they use the main API port).
+
+### Console Output
+
+After the benchmark table, you'll see a `SERVER-SIDE BREAKDOWN` section:
+
+```
+SERVER-SIDE BREAKDOWN (from /api/v1/system/diagnostics):
+  JVM:  heap 1.2GB/2GB (60%), GC pauses +450ms during load
+  Jetty: 142/150 threads busy (95%), queue depth: 23
+  DB Pool: 85/100 active (85%), 12 pending connections
+  Bulk Executor: queue 450/1000 (45%)
+
+  Latency Breakdown (PUT endpoints):
+    Endpoint                          Total    DB%   Search%   Internal%
+    /v1/tables                        320ms   56.2%     14.1%      29.7%
+    /v1/topics                        180ms   48.0%     22.0%      30.0%
+    /v1/dashboards                    250ms   52.0%     18.0%      30.0%
+
+  BOTTLENECK: DB bottleneck on PUT /v1/tables: 56.2% of request time in DB, pool at 85.0% utilization
+```
+
+### JSON Report
+
+The report includes top-level `diagnostics_before` and `diagnostics_after` objects, plus `cluster_sizing.server_side_analysis`:
+
+```bash
+cat /tmp/bench.json | python3 -c "
+import json, sys
+r = json.load(sys.stdin)
+
+# Check if diagnostics were available
+diag = r.get('diagnostics_after', {})
+if diag:
+    jvm = diag['jvm']
+    print(f'Heap: {jvm[\"heap_usage_pct\"]}%')
+    print(f'GC pauses: {jvm[\"gc_pause_total_ms\"]}ms')
+
+    jetty = diag['jetty']
+    print(f'Jetty: {jetty[\"threads_busy\"]}/{jetty[\"threads_max\"]} ({jetty[\"utilization_pct\"]}%)')
+
+    db = diag['database']
+    print(f'DB pool: {db[\"pool_active\"]}/{db[\"pool_max\"]} ({db[\"pool_usage_pct\"]}%)')
+
+    for ep, data in diag.get('request_latency', {}).items():
+        print(f'{ep}: total={data[\"avg_total_ms\"]}ms '
+              f'DB={data[\"db_pct\"]}% Search={data[\"search_pct\"]}% '
+              f'Internal={data[\"internal_pct\"]}%')
+else:
+    print('Diagnostics not available (server may be older version)')
+"
+```
+
+---
+
+## Bottleneck Detection Rules
+
+The load test applies these rules automatically and surfaces them in findings:
+
+| Condition | Diagnosis | Recommended Fix |
+|-----------|-----------|-----------------|
+| `db_pct > 60%` AND `pool_usage_pct > 80%` | DB is the bottleneck | `export DB_CONNECTION_POOL_MAX_SIZE=150` |
+| `jetty.utilization_pct > 90%` AND `queue_size > 0` | Thread pool saturated | `export SERVER_MAX_THREADS=300` or enable virtual threads |
+| `search_pct > 30%` for any endpoint | Search indexing consuming latency | `export ELASTICSEARCH_MAX_CONN_TOTAL=50` |
+| `bulk_executor.queue_usage_pct > 70%` | Near bulk rejection threshold | `export BULK_OPERATION_QUEUE_SIZE=2000` |
+| `jvm.heap_usage_pct > 85%` after load | Memory pressure / GC tail latency | Increase JVM heap (`-Xmx`) |
+
+---
+
+## Common Scenarios
+
+### Scenario 1: High Latency, DB is the Bottleneck
+
+**Symptoms:** p95 latency >2s, `db_pct` >60%, `pool_usage_pct` >80%.
+
+```
+  Latency Breakdown:
+    /v1/tables   320ms   DB=62%   Search=12%   Internal=26%
+  DB Pool: 95/100 active (95%), 8 pending
+```
+
+**What's happening:** Every PUT requires multiple DB round-trips. At 95% pool utilization with 8 pending connections, requests are waiting for a free connection.
+
+**Fix:**
+```bash
+export DB_CONNECTION_POOL_MAX_SIZE=150
+export DB_CONNECTION_TIMEOUT=10000   # Fail fast instead of waiting 30s
+```
+
+### Scenario 2: Thread Pool Exhaustion
+
+**Symptoms:** Connection refused errors, `utilization_pct` >95%, `queue_size` growing.
+
+```
+  Jetty: 148/150 threads busy (99%), queue depth: 45
+```
+
+**What's happening:** All Jetty threads are busy. New requests queue up, adding latency. If the queue fills, connections get refused.
+
+**Fix:**
+```bash
+export SERVER_MAX_THREADS=300
+# OR enable virtual threads (preferred for I/O-bound workloads):
+export SERVER_ENABLE_VIRTUAL_THREAD=true
+```
+
+### Scenario 3: GC Pressure
+
+**Symptoms:** Periodic latency spikes, `heap_usage_pct` >85%, large GC pause delta.
+
+```
+  JVM: heap 1.8GB/2GB (90%), GC pauses +2300ms during load
+```
+
+**What's happening:** The JVM is spending significant time in garbage collection. This manifests as periodic latency spikes and throughput drops.
+
+**Fix:**
+```bash
+# Increase heap
+export OPENMETADATA_HEAP_OPTS="-Xmx4g -Xms4g"
+```
+
+### Scenario 4: Bulk Executor Queue Filling
+
+**Symptoms:** HTTP 503 errors on PUT endpoints.
+
+```
+  Bulk Executor: queue 980/1000 (98%)
+  has_capacity: false
+```
+
+**What's happening:** The async processing queue is full. New requests that need bulk processing are rejected with 503.
+
+**Fix:**
+```bash
+export BULK_OPERATION_QUEUE_SIZE=2000
+export BULK_OPERATION_MAX_THREADS=20
+```
+
+---
+
+## Comparing Before/After Snapshots
+
+The most valuable analysis comes from comparing diagnostics before and after load:
+
+| Metric | Before | After | Interpretation |
+|--------|--------|-------|----------------|
+| `heap_usage_pct` | 25% | 85% | Significant memory allocation during load |
+| `gc_pause_total_ms` | 200 | 2500 | 2.3s of GC pauses during the test |
+| `pool_active` | 2 | 95 | Pool went from idle to near-max |
+| `pool_pending` | 0 | 8 | Connection contention appeared |
+| `queue_depth` | 0 | 450 | Bulk queue built up under load |
+
+If the `diagnostics_during` samples are available in the health monitor data, you can plot these metrics over time to see exactly when bottlenecks emerged.
+
+---
+
+## Graceful Fallback
+
+If the server doesn't have the diagnostics endpoint (older version), the load test:
+- Prints a notice: `Diagnostics endpoint returned status=404 (may not be available)`
+- Falls back to Prometheus scraping (if `--admin-port` is set)
+- Skips the `SERVER-SIDE BREAKDOWN` section in the console output
+- Omits `diagnostics_before`/`diagnostics_after` from the JSON report
+
+No hard dependency — the load test works with or without it.