Back to projects

API Latency Dashboards

Tying API, external call and DB timings together by trace ID, with OpenSearch Dashboards to find slow and repeated calls

Filebeat ships logs that share a single trace ID into OpenSearch, and OpenSearch Dashboards trend charts show the latency and call volume of each API, external API and DB call. The team can see at a glance which APIs are slow, which are called most, and which requests call the same external API repeatedly or run N+1 DB queries, without digging through logs one entry at a time.

Role
Requirements Analysis, Architecture Design, Development, Testing
Tech
JavaSpring BootSLF4J MDCFilebeatOpenSearchOpenSearch Dashboards
01.

The Problem

When the system slowed down or misbehaved, the team had to guess which API was responsible and then dig through logs one entry at a time to confirm it, which took a long time.

Three things were hard to see: which APIs respond slowly, which APIs are called most, and which APIs call the same external API repeatedly within one request or run N+1 DB queries.

This dashboard records the timing of every node a request passes through (API, external call, DB) and links them with a single trace ID, turning the question from guessing into looking.

02.

How It Works

  1. 01

    Request arrives

    A trace ID is generated at the entry point and put into MDC, so every log line of that request carries it.

  2. 02

    Record node timings

    The API itself, each external API call and each DB call record their own duration and target as structured logs.

  3. 03

    Filebeat collects

    Filebeat reads the log files and ships them to OpenSearch.

  4. 04

    Index and fields

    Trace ID, type, API name, call target and duration become searchable, aggregatable fields.

  5. 05

    Dashboards

    OpenSearch Dashboards shows latency, call counts and repeated calls as trend and summary charts.

  6. 06

    Drill down

    From a problem API, use the trace ID to list every external call and SQL statement of that request.

03.

Three Questions It Answers

Each question has its own set of charts. Trend charts show change over time and make before/after-release comparison easy.

  • Which APIs are slow

    Latency per API (p95 rather than the average), shown as a trend chart. A sudden rise can be compared against release times to find the cause.

  • Which APIs are called most

    Call counts per API over a time range, to find the busiest APIs and set optimisation priorities.

  • Which APIs call an external API repeatedly or have N+1

    Per trace ID, count how often the same external API or the same kind of SQL appears within one request. Unusually high counts are the ones to inspect.

04.

Log Example

Under one trace ID, a request leaves records for the API, an external call and several DB calls. In the example below the same SQL appears repeatedly, the classic N+1 pattern.

{"traceId":"a1b2c3d4","type":"API","api":"GET /orders/{id}","durationMs":1280}
{"traceId":"a1b2c3d4","type":"EXTERNAL","target":"POST payment-service/query","durationMs":310}
{"traceId":"a1b2c3d4","type":"EXTERNAL","target":"POST payment-service/query","durationMs":295}
{"traceId":"a1b2c3d4","type":"EXTERNAL","target":"POST payment-service/query","durationMs":302}
{"traceId":"a1b2c3d4","type":"DB","sqlId":"selectOrderItemByOrderId","durationMs":12}
{"traceId":"a1b2c3d4","type":"DB","sqlId":"selectOrderItemByOrderId","durationMs":11}
{"traceId":"a1b2c3d4","type":"DB","sqlId":"selectOrderItemByOrderId","durationMs":13}

Illustrative log format. API names, SQL names and numbers are all made up.

05.

Outcome

  • >Slow APIs and high-traffic APIs are ranked and trended on the dashboard, instead of judged by impression.
  • >Repeated external API calls and N+1 DB queries can be counted, with no need to read logs one by one.
  • >Following the trace ID from one request down to each external call and SQL speeds up troubleshooting.