Finding the Incident Time in Access Logs

Goal

From an access log of 1269 lines, you will find the time of the incident and the causal path within 10 minutes, and be able to state the size of the surge as a number compared with the normal value.

Why it matters

"There are 103 errors" is not information. If the usual was 5, it is serious, and if it was 120, things improved. So log analysis begins not with finding the cause but with building a baseline, and at an unfamiliar customer there is no baseline document, so you must build it from within the same log. The remainder after excluding the incident interval is the normal value.

And you must always look at 4xx and 5xx separately. 4xx means the client sent something wrong and 5xx means the server broke, so whether the two numbers move together or separately tells you the direction of the cause. If only 4xx increased after a deployment, the API contract changed, and if only 5xx increased, something inside broke.

The format of /opt/data/web.log is five space-separated fields.

10.9.4.21 04:52:15 GET /api/pay 200
IP        시각      메서드 경로     상태코드

Steps

1. Create the /root/incident directory.
2. Write the total number of requests with status code 500 in /root/incident/total_500.txt.
3. Write the total number of requests with status code 404 in /root/incident/total_404.txt.
4. Write the minute in which 500 occurred most in the form HH:MM in /root/incident/peak_minute.txt.
5. Write the path on which 500 occurred most in /root/incident/endpoint.txt.
6. Write the number of 500s that occurred within that peak minute in /root/incident/peak_count.txt.
7. Write the number of 500s in the remaining time slots, excluding the peak minute, in /root/incident/baseline.txt.
8. Write a summary containing all four of the values above in /root/incident/summary.txt.

Notes

• awk '$5==500' /opt/data/web.log | wc -l
• Per-minute aggregation: awk '$5==500 {print substr($2,1,5)}' /opt/data/web.log | sort | uniq -c | sort -rn | head
• Path distribution: awk '$5==500 {print $4}' /opt/data/web.log | sort | uniq -c | sort -rn
• Common mistake 1: writing the whole HH:MM:SS in step 4. If you cut by the second, the distribution scatters and the peak is not visible.
• Common mistake 2: subtracting the total number of log lines in step 7. What you must subtract is the count of 500s in the peak minute.

Create the working directory

Create the /root/incident directory.

You collect the analysis results under /root/incident.

Count the total of 500s

Write the total number of requests with status code 500 in /root/incident/total_500.txt.

The last field of web.log is the status code. Use awk to count only the lines where that field is 500.

Count the total of 404s

Write the total number of requests with status code 404 in /root/incident/total_404.txt.

4xx and 5xx have different causes. To see whether they move together or separately, you have to count them separately.

Find the time of the incident

Write the minute in which 500 occurred most in the form HH:MM in /root/incident/peak_minute.txt.

The second field is HH:MM:SS. Cut off only the first 5 characters and find the minute where 500s are most concentrated.

Find the causal path

Write the path on which 500 occurred most in /root/incident/endpoint.txt.

Pick only the lines with 500 and look at the distribution of the fourth field. It splits into whether they are concentrated on one path or spread out.

Count the errors in the peak minute

Write the number of 500s that occurred within that peak minute in /root/incident/peak_count.txt.

How many 500s there are within that one minute alone. Use the result of the previous step as it is.

Work out the normal error volume

Write the number of 500s in the remaining time slots, excluding the peak minute, in /root/incident/baseline.txt.

It is the number of 500s in the remaining time slots excluding the peak minute. Just subtract the peak from the total.

Write the analysis summary

Write a summary containing all four of the values above in /root/incident/summary.txt.

Gather four things in one file: the total number of 500s, the time of the incident, the causal path, and the normal value.