AI-Assisted Log Analysis
Typical applications have a few GB of data and their log files are also a few GB. So, any computer can easily process this amount data. You can process it on the spot with Unix tools and pipes. But writing those pipes takes some time, especially if you do not analyze logs daily.
In my opinion, AI clankers are a game changer for looking through log files. I ask the AI questions, and the AI clanker answers them using Unix pipes, Unix tools, and small Python scripts.
For example, a few days ago I investigated slow responses:
1. An unknown log file format
I didn’t know the log file format, so I simply asked:
> What can these logs tell me. What information is in it?
# AI는 생각하고 도구 호출
# Python 스크립트 3개 사용했어요.
These are AWS Application Load Balancer (ALB) access logs for the load balancer.
They record one line per HTTP(S) request handled by the ALB.
What each entry can tell you
They include:
Timestamp in UTC
Client source IP and port
Backend target that served the request, e.g. 10.1.2.151:8090
Request method, URL/path, protocol, such as GET /healthcheck HTTP/1.1
Host header and User-Agent
ALB and backend HTTP status codes
Timing:
time spent receiving the request
backend/target processing time
time spent returning the response
Request/response byte sizes
TLS version and cipher
Target group, selected target, routing action (forward or redirect)
AWS trace ID, useful for correlating with application tracing
# 그리고 나중에
Response outcomes
ALB status Count Interpretation
----------- ------- -------------------------------------------
200 2,693 Successful
301 212 Permanent redirect, likely HTTP -> HTTPS
302 188 Temporary redirect
404 532 Resource not found
400 129 Invalid/malformed request; many rejected at the ALB
405 10 Unsupported method
401 9 Authentication required/failed
406 3 Not acceptable
460 6 Client disconnected before the target responded
# ...
Performance
For requests that reached a target:
Median backend processing time: 4 ms
95th percentile: 685 ms
99th percentile: 1.864 s
Slowest request: 24.181 s
# ....2. Asking about the problematic time
I knew when the problem occurred, so I asked what was going on during that time.
> Around the time Sep 11, 2026 08:20:00 UTC, what requests got answered. What was the response time, status code etc.
> Overview of a window of 10 minutes before and after the provided timestamp.
# AI는 스크립트 더 사용했어요.
# ...
Notable events
08:10:49.040 — GET /v1/some-endpoint, routed to 10.1.2.252:8090, resulted in ALB 460.
This means the client disconnected before a response was completed; consequently, no target status or target duration was recorded.
08:11:18.717 — GET /v1/some-endpoint, served by 10.1.2.151:8090:
ALB status / target status: 200 / 200
Target processing: 24.181 s
This is the clear latency outlier in the window.
08:29:36.410 — GET /v1/some-endpoint, served by 10.1.2.151:8090:
Status: 200 / 200
Target processing: 7.347 s
A second, less severe slow request.
# ...3. Analyzing another log file together
So, I now knew there were slow HTTP requests. I also had log files from another system. So I analyzed them together:
> In the @other-system-log-2026-09-14.csv, is there any slow request that reponds to the slow times in the access logs.
Longer than 5 secons?
# AI는 생각하고 도구 호출
I matched on the endpoint and completion timestamp. The CSV message timestamp includes Z (UTC), and for the successful requests below it is within 1–8 ms of the ALB log timestamp. All are:
GET /v1/some-endpoint
Completion time (UTC) ALB target (s) App logged (s) App request ID
------------------------ --------------- --------------- ------------------------------------
2026-09-11 01:51:43.109 7.331 6.484 f19460c8-2377-43e3-95dd-1cac292f7aab
2026-09-11 07:33:18.573 23.563 23.637 adfbebe6-6641-48e9-9f70-4a93b0d135a6
2026-09-11 07:33:36.271 22.168 21.892 f391b41f-c774-4f7a-b2cf-95af7c847c77
2026-09-11 07:33:55.070 10.284 10.338 e6d8499b-acb4-473d-9a25-2db694cd1059
2026-09-11 07:50:43.006 5.391 5.377 a349c7d7-60ec-45ae-be3c-a1c5e025bf81
2026-09-11 08:11:18.717 24.181 24.209 67bd04c9-6ebc-45d3-9c8c-b173a6a0962d
2026-09-11 08:29:36.411 7.347 7.408 dbf81ef9-d6c9-40a7-b7ce-ed7b023dd0e8
2026-09-11 10:39:52.976 15.441 15.396 defaa4da-2f36-40fe-b354-3782caef6f5d
2026-09-11 11:35:42.570 5.299 5.184 53333c14-c6e5-4c1e-870b-5e733b0f03464. Timeline
Then I wanted to know the timeline of a slow request.
> Create a timeline for the request f391b41f-c774-4f7a-b2cf-95af7c847c77
# The AI thinks and makes tool calls
UTC time Elapsed Event
---------------------- ------------- ------------------------------------------------------------
07:33:14.099 +0 ms ALB created the request.
07:33:14.103 +4 ms Approximate start of ALB target processing.
07:33:14.378 +279 ms Application began handling GET /v1/some-endpoint on worker nio-8090-exec-6.
07:33:14.585 +486 ms Began fetching the requested data, data-ids etc.
07:33:15.466 +1.367 s Initial file fetch completed: 890 ms, 793 bytes. Rendering began.
07:33:15.578 +1.479 s Began fetching extra data 1.
07:33:15.965 +1.866 s extra data 2 fetched: 388 ms, 3,880 bytes.
07:33:15.980 +1.881 s Began fetching extra data 2.
07:33:16.265 +2.166 s extra data 2 fetched: 285 ms, 250 bytes.
07:33:16.274 +2.175 s Began fetching extra data 3.
07:33:16.465 +2.366 s extra 3 fetched: 191 ms, 893 bytes.
07:33:16.471 +2.372 s Began fetching extra data 4.
07:33:16.865 +2.766 s extra data 4 fetched: 394 ms, 2,775 bytes.
07:33:16.872 +2.773 s Began fetching extra data 5.
07:33:17.165 +3.066 s extra data 5 fetched: 294 ms, 279 bytes.
...
07:33:17.567-17.571 +3.47 s More stuff happened.
07:33:17.571-29.081 11.510 s gap No request-specific application log events. This is likely uninstrumented processing/rendering time.
07:33:29.081-29.087 +14.98 s Some stuff got skipped
07:33:29.087-36.086 6.999 s gap No request-specific application log events before rendering finishes.
07:33:36.086 +21.987 s Application logged "Processing complete."
07:33:36.269 +22.170 s Application completed the request: 21,891.538 ms.
07:33:36.271 +22.172 s ALB recorded 200 / 200; target processing was 22.168 s.
# AI abbreviated ...5. Java Flight Recorder data
Maybe there was a JVM problem, like GC pause? So I also added the Java Flight Recorder file. And now the AI uses Java: It writes small Java snippets to analyze the Flight recording and incoperates it into the analysis.
> There is now a @debug.jfr for the Java Flight recorder. Are there any events from when are large gaps in the logs?
# The AI thinks and makes tool calls
JFR findings during Sep 14 slow-request windows
Log window Slow request durations JFR execution samples Some-Feature-related samples
------------------- ------------------------------ ---------------------- ------------------------
08:19:38-08:19:45 6.103 s 60 60 / 60
08:44:03-08:44:43 7.097-33.556 s 160 156 / 160
09:00:51-09:01:09 5.211 s and 17.797 s 6 6 / 6
The sampled stacks are dominated by Some-Feature rendering and PNG generation, including:
net.a.library.*
net.a.library.png.SomeOperation.*
net.a.library.png.Png.write
com.sun.imageio.plugins.png.PNGImageWriter.encodePass
java.awt.image.BufferedImage.*
References to other code
For example, in the 08:19 slow request window, the JFR repeatedly sampled:
BufferedImage.getRGB
SomeOperation.packMeIfPossible
Png.write
GraphicStuff.writeToStream
ImageBuilder.writeImageInternal
# ...
GC activity during the 08:44 slow-request burst
There was also substantial G1 old-generation GC activity while four requests took 7–34 seconds:
Start time (UTC) GC event Wall-clock duration Longest stop-the-world pause
----------------- ------------------------------------------ -------------------- -----------------------------
08:44:12.901 G1 Old, triggered by humongous allocation 3.104 s 491 ms
08:44:19.384 G1 Old 2.816 s 293 ms
08:44:26.290 G1 Old 3.498 s 535 ms
09:00:51.875 G1 Old, triggered by humongous allocation 2.210 s 464 ms6. I analyzed further, but you get the gist
I analyzed further. For example, I found the top 10 slowest requests and looked for similar operations among the slow requests.
Thanks to AI, you can think about the questions instead of thinking about Unix pipes.
I highly can recommend using a Clanker to investigate log files.
