Easy Request Log Analysis with BigQuery and Data Studio

Recently, I encountered an issue where my running application was "occasionally slow." The feeling was that about once in every 10 requests, there would be a slight, momentary hang. To find the root cause, I analyzed the request logs using BigQuery and Data Studio, and successfully identified the source of the problem. This is a very easy-to-configure and sustainable method, so I would like to introduce it.

Step 1: Send Request Logs to BigQuery

Request logs can be in any format as long as they contain the URL and Latency. In this case, the application was running on Google Cloud's App Engine (flexible environment), so I transferred the nginx logs, which are output to Cloud Logging by default, to BigQuery using the Cloud Logging Log Router (Sink).

For the Sink configuration, set the destination to "BigQuery dataset" and configure the log filter as follows:

resource.type="gae_app"
log_name="projects/PROJECT_ID/logs/appengine.googleapis.com%2Fnginx.request"
httpRequest.requestUrl!="/nginx_metrics"

After a short while, new logs should be transferred to BigQuery, and the dataset schema should be registered automatically.

Step 2: Analyze Logs with Data Studio

Connect Data Studio to BigQuery so that you can reference the request log dataset.

Identify Endpoints with High Request Volume and High Latency Using a Distribution Chart

While a "Scatter Chart" works, I choose a "Bubble Chart" as it is more visually intuitive.

• Dimension: Column corresponding to URL
• Metric X: Sum of Record Count
• Metric Y: Average of the column corresponding to Latency
• Bubble Size Metric: Sum of Record Count
• Metric Slider: ON
• Sort: Descending by Sum of Record Count // You can experiment with this setting

Below is the chart from the time the issue occurred.

You can see many endpoints with high latency, even though their request counts are low. (In reality, these are different paths due to path parameters, so it is actually one endpoint.)

Through this graph, I realized the cause of this issue was "shortening the cache TTL for an endpoint that already had high latency." While processing requests for that high-latency endpoint, wait times occurred for other requests more frequently, leading to the "occasionally slow" issue.

Below is the graph after taking corrective measures.

Instead of adjusting cache times, I fixed the underlying cause of the high latency. You can see that the number of high-latency endpoints has clearly decreased.

Since there is a limit to the number of data points that can be displayed in a single graph, changing the sort or filtering with the metric slider reveals different aspects of the data. For example, filtering for Latency >= 0.2 produces the following. There is still room for improvement!

Analyze Latency Fluctuations by Comparing Periods with a Line Chart

Issues like the one I experienced can happen no matter how careful you are. To detect such problems more quickly, I created a graph that helps track fluctuations in latency.

Select a "Line Chart" for the visualization.

• Dimension: timestamp
• Metric: Average of the column corresponding to Latency
• Default Date Range: Past 7 days (excluding today)
• Comparison Period: Previous period

Below is the graph from around the time the issue occurred.

Compared to the graph from the previous period (light blue), you can see that the latency for the current period (dark blue) is higher. With such a significant fluctuation in the graph, it is easy to tell that something went wrong.

Data Studio has a feature that can email reports periodically, so I recommend using that to keep an eye on things.

Conclusion

This was my first time using Data Studio, and I found it extremely easy to perform log analysis. While the same thing can be done with off-the-shelf monitoring tools, actually manipulating the data with Data Studio graphs or BigQuery queries makes you more interested in the data and allows for more proactive analysis. I highly recommend it.