system-info.sh answered questions about an instant. Logs answer questions about time: what happened, when it started, how long it lasted and whether it is happening again. At Veloz Envíos there are two files nobody looks at until something breaks —/var/log/veloz/access.log and /var/log/veloz/app.log— and then somebody opens a tail -f and guesses. This project replaces guessing with analyze-logs.sh, the most ambitious tool in the course when it comes to text processing: it aggregates, draws, detects anomalies and emits a report in text or JSON, over live, rotated and compressed files.

Contents

  1. The questions it must answer
  2. Requirements and design decisions
  3. Reading any log: the open_log function
  4. Version 1: counting response codes
  5. Why awk for access.log and BASH_REMATCH for app.log
  6. Filters by date and by level
  7. The aggregations in a single pass
  8. The hourly histogram
  9. Anomaly detection
  10. The report: text and JSON
  11. Performance over a million lines
  12. Anonymizing before sharing

  1. The questions it must answer

A log analyzer is not designed by listing functions, but by writing down the questions somebody will ask at three in the morning:

Question File What it implies
How many requests per hour, and when was the peak? access.log Group by hour and draw
Which paths and which IPs concentrate the traffic? access.log Top-N with counts
What 5xx error rate do we have? access.log A ratio, not an absolute value
Which component generates the most ERROR, and when did a pattern first and last appear? app.log Extract the component and the extreme timestamps
Is there an IP with a disproportionate number of requests? access.log Compare against the median

Derived requirements: a single pass per file, support for .1 and .2.gz, filters by date range and by level, output in text and JSON, and the ability to anonymize IPs.

  1. Requirements and design decisions

Three decisions shape the whole script:

  1. One pass, not six. The naive version runs one grep per metric: six reads of the file. With awk and associative arrays (06-01) everything is computed in one. In 08-02 we measured why: over a large log, the difference is an order of magnitude, and not because of awk itself, but because of reading the disk once instead of six times.
  2. Reading is abstracted away. The rest of the script must not know whether the file is compressed: an open_log function returns the stream and that is that.
  3. Collection and presentation separated, just as in 09-01: awk produces metric<TAB>key<TAB>value lines, and the formatters turn them into a text report or into JSON.

  1. Reading any log: the open_log function

Rotated logs are access.log, access.log.1 and access.log.2.gz. Handling them separately would duplicate the code; the solution is to pick the reader by extension (05-01):

open_log() {  # $1 = path -> writes the content to stdout
  local f=$1
  [[ -r $f ]] || { veloz_log_error "not readable: $f"; return 1; }
  case $f in
    *.gz) zcat -- "$f" ;;
    *)    cat  -- "$f" ;;
  esac
}

expand_logs() {  # $1 = base path -> rotated files from oldest to newest
  local base=$1 f
  for f in "$base".[0-9]*.gz "$base".[0-9]* "$base"; do
    [[ -e $f ]] && printf '%s\n' "$f"
  done
}

# consumption, with process substitution (05-05)
while IFS= read -r file; do
  open_log "$file" || continue
done < <(expand_logs "$LOG") | awk -f "$LIBEXEC/access.awk"

The case on the name is the 04-05 technique and avoids running file. The -- guards against names starting with a dash (08-03). The order of expand_logs is not accidental —oldest to newest, so the report comes out chronological without sorting afterwards—. And done < <(...) is used and not expand_logs | while for the reason given in 05-05: in a pipeline, the while runs in a subshell and any counter it increments is lost on exit.

  1. Version 1: counting response codes

open_log /var/log/veloz/access.log | awk '{c[$9]++} END {for (k in c) print c[k], k}' | sort -rn

The first useful version fits in one line and already answers half a question: $9 is the response code in the combined format. From here on, each improvement adds a metric to the same awk instead of adding a new grep; that is the entire construction method of this lesson.

  1. Why awk for access.log and BASH_REMATCH for app.log

The two files have very different formats and deserve different tools:

203.0.113.7 - - [03/Aug/2026:10:15:22 +0200] "GET /envios?ciudad=Valencia HTTP/1.1" 200 1843
2026-08-03 10:15:22 [ERROR] api.envios: timeout querying courier jruiz

access.log is positional: fields separated by spaces, always the same number, the path in $7, the code in $9, the bytes in $10. That is exactly what awk exists for (06-01): splitting into fields is free and the volume is high.

app.log is semi-structured: the fixed part is the date, the time and the level; the rest is prose where the component appears before the colon, but not always. Here a regular expression with capture is the right call (05-04):

analyze_app() {
  local line log_date log_time level comp
  declare -A by_level by_component
  local re='^([0-9]{4}-[0-9]{2}-[0-9]{2}) ([0-9:]{8}) \[(INFO|WARN|ERROR)\] ([a-z.]+):'
  while IFS= read -r line; do
    [[ $line =~ $re ]] || { ((malformed++)); continue; }
    log_date=${BASH_REMATCH[1]}; log_time=${BASH_REMATCH[2]}
    level=${BASH_REMATCH[3]}; comp=${BASH_REMATCH[4]}
    [[ -n $FROM && $log_date < $FROM ]] && continue
    ((by_level[$level]++)); ((by_component[$comp]++))
  done
}

The practical rule: awk when the format is tabular and the volume high; =~ with BASH_REMATCH when you have to capture chunks of an irregular line and decide different things depending on what you captured. And a warning measured in 08-02: this loop processes about 50,000 lines per second, while awk goes past a million. For app.log (thousands of lines a day) it is more than enough; if it grew to millions, the pattern would have to move inside awk.

  1. Filters by date and by level

The options follow the 09-01 pattern, with an explicit validation of the date before using it:

validate_date() {
  [[ $1 =~ ^[0-9]{4}-[0-9]{2}-[0-9]{2}$ ]] || veloz_die 2 "invalid date: $1 (use YYYY-MM-DD)"
  date -d "$1" >/dev/null 2>&1 || veloz_die 2 "nonexistent date: $1"
}

Two checks because both are needed: the regex rejects 03/08/2026 and date -d rejects 2026-02-31, which has the right shape and does not exist. Filtering by date with string comparison ([[ $log_date < $FROM ]]) works only because the YYYY-MM-DD format sorts the same as text as it does as a date; that is why the format was chosen in 07-04 and one of the best decisions anyone designing a log can make. In access.log, on the other hand, the date arrives as 03/Aug/2026, so the awk normalizes it with a month table:

BEGIN { split("Jan Feb Mar Apr May Jun Jul Aug Sep Oct Nov Dec", m, " ")
        for (i in m) num[m[i]] = sprintf("%02d", i) }
{ split($4, t, /[:\[\/]/); iso = t[4] "-" num[t[3]] "-" t[2]; hour = t[5] }

split with a character class as the separator (06-01) splits [03/Aug/2026:10:15:22 in one go, with no prior sed and no extra pipes.

  1. The aggregations in a single pass

The core of the project lives in libexec/access.awk, not in a string embedded between quotes: that way it is more readable, shellcheck does not fight with it and it can be tested on its own.

$0 ~ /^$/ { next }
{
  split($4, t, /[:\[\/]/); iso = t[4] "-" num[t[3]] "-" t[2]; hour = t[5]
  if (from != "" && iso < from) next
  if (to != "" && iso > to) next
  total++; bytes += $10
  path = $7; sub(/\?.*/, "", path)     # group /envios?ciudad=X as /envios
  by_hour[iso " " hour]++; by_path[path]++; by_ip[$1]++
  code = substr($9, 1, 1) "xx"; by_code[code]++
  if (code == "5xx") { err5++; if (first5 == "") first5 = iso " " hour }
}
END {
  printf "summary\ttotal\t%d\nsummary\tbytes\t%d\n", total, bytes
  printf "summary\trate5xx\t%.2f\n", (total ? err5 * 100 / total : 0)
  printf "summary\tfirst5xx\t%s\n", (first5 == "" ? "-" : first5)
  for (k in by_hour) printf "hour\t%s\t%d\n", k, by_hour[k]
  for (k in by_path) printf "path\t%s\t%d\n", k, by_path[k]
  for (k in by_ip)   printf "ip\t%s\t%d\n",   k, by_ip[k]
  for (k in by_code) printf "code\t%s\t%d\n", k, by_code[k]
}

All the work happens in one read. sub(/\?.*/, "", path) groups the query string, because otherwise /envios?ciudad=Valencia and /envios?ciudad=Madrid count as different paths and the top-N fills up with noise. substr($9,1,1) "xx" turns 503 into 5xx with a string operation instead of a cascade of if. And the output is the three-column internal format: metric, key, value, which in Bash is collected with mapfile or filtered with awk -F'\t' '$1=="path"'.

Sorting the top-N is done outside, where it is cheap and with the right tools: top_n() { awk -F'\t' -v m="$1" '$1 == m {print $3 "\t" $2}' "$RAW" | sort -rn | head -n "$2"; }.

  1. The hourly histogram

A number per hour is hard to grasp; a bar is understood at a glance. The technique is to scale the maximum value to a fixed width:

repeat() { local i s=''; for ((i = 0; i < $2; i++)); do s+=$1; done; printf '%s' "$s"; }
histogram() {  # reads "label<TAB>value" on stdin
  local width=40 max=0 label val f rows=()
  mapfile -t rows
  for f in "${rows[@]}"; do val=${f##*$'\t'}; ((val > max)) && max=$val; done
  for f in "${rows[@]}"; do
    label=${f%%$'\t'*}; val=${f##*$'\t'}
    printf '  %-16s %6d %s\n' "$label" "$val" "$(repeat '█' "$(( max ? val * width / max : 0 ))")"
  done
}

${f%%$'\t'*} and ${f##*$'\t'} split the line on the tab without launching cut (04-04, and the process saving from 08-02). The integer arithmetic val * width / max multiplies before dividing: the other way round, val / max would be 0 for everything and every bar would come out empty, one of the classic mistakes from 04-06. And the max ? ... : 0 avoids the division by zero when the filtered range has no data.

  1. Anomaly detection

Three simple detections cover most of the real incidents at Veloz Envíos:

detect_anomalies() {
  local rate ip requests median
  rate=$(awk -F'\t' '$1=="summary" && $2=="rate5xx" {print $3}' "$RAW")
  awk -v t="$rate" -v u="$THRESHOLD_5XX" 'BEGIN {exit !(t+0 > u)}' &&
    warn "5xx rate of ${rate}% (threshold ${THRESHOLD_5XX}%) since $(first5xx)"
  median=$(top_n ip 1000 | awk '{v[NR]=$1} END {print v[int(NR/2)]+0}')
  while read -r requests ip; do
    (( median > 0 && requests > median * 20 )) &&
      warn "IP $ip with $requests requests (median $median): possible scan"
  done < <(top_n ip 5)
}

Comparing against the median and not against a fixed number is what keeps the detection valid when traffic doubles: an absolute threshold of "1000 requests" has to be readjusted every quarter; "twenty times the median" adjusts itself.

The third detection, an error burst, is done over app.log by converting the time into seconds (04-06) and checking how many ERRORs fit in a window:

error_burst() {  # N errors in less than M seconds
  awk -v n="$1" -v m="$2" '
    $3 == "[ERROR]" { t[++i] = mktime(gensub(/[-:]/, " ", "g", $1 " " $2))
      if (i >= n && t[i] - t[i-n+1] <= m) { print "burst:", n, "errors in", t[i]-t[i-n+1], "s up to", $1, $2; exit } }'
}

GNU awk's mktime converts 2026 08 03 10 15 22 into seconds since the epoch, and gensub prepares that format by replacing dashes and colons with spaces (06-01). Subtracting positions n-1 apart in the array is the cheapest possible sliding window.

  1. The report: text and JSON

The text report assembles the pieces already built; the JSON comes out of the same intermediate file:

report_json() {
  jq -Rn --slurpfile _ /dev/null '
    [inputs | split("\t") | {metric: .[0], key: .[1], value: .[2]}]
    | group_by(.metric)
    | map({(.[0].metric): map({key: .key, value: (.value | tonumber? // .value)}) | from_entries})
    | add' < "$RAW"
}

jq -Rn with inputs reads raw lines (06-05), group_by groups by metric and from_entries turns each group into an object. The tonumber? // .value keeps numbers as numbers and leaves strings intact —the ? prevents jq from aborting on a non-numeric value—. That the JSON comes out of the same intermediate file as the text guarantees that both reports say the same thing, which is the reason for having separated collection and presentation in both projects.

  1. Performance over a million lines

With a real log generated for the test, the 08-02 figures are confirmed:

Approach Time (1,000,000 lines) Why
Six chained grep/cut/sort 11.4 s Six reads of the file
A while read loop in pure Bash 96 s One interpreter cycle per line
A single awk 1.7 s One read, everything in memory
The same awk with LC_ALL=C 0.9 s No per-character UTF-8 decoding

An export LC_ALL=C at the top of the script nearly halves the time and changes no result, because IPs, dates and codes are ASCII. Measure before optimizing is still the rule: here the measurement says the bottleneck was the number of passes, not the language.

  1. Anonymizing before sharing

An IP is personal data, and a report that leaves the server —to a ticket, to a vendor, to a chat channel— must not carry them (08-03). lib/common.sh already has the piece:

veloz_anonymize_log() { sed -E 's/\b([0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3})\.[0-9]{1,3}\b/\1.0/g'; }

It masks the last octet (06-02): the network is preserved, which is what serves to detect the scan, and the individual's identifier is lost. The script applies it with --anonymize, and the runbook says that any report leaving the infrastructure goes through that option. Watch out for the order: you anonymize when presenting, not when collecting, because grouping by truncated IP would merge different machines.

Common Mistakes and Tips

  • One grep per metric. It is the number one cause of slowness. If the script walks the file more than once, there is an aggregation that should be inside the awk.
  • Sorting inside awk. awk does not guarantee the order of for (k in array). Sort outside with sort -rn, or use asorti if you tie yourself to GNU awk.
  • Forgetting the rotated files. An analysis of "the last seven days" that only reads access.log lies as soon as there is daily rotation. expand_logs is not a luxury.
  • Dividing before multiplying in the histogram scale: every bar comes out at zero (04-06). And do not compare ISO dates as numbers: 2026-08-03 in arithmetic is not a date, compare it as a string.
  • Tip: save the three-column intermediate file to a temporary with mktemp and trap EXIT (05-02). It lets you recompute different views without re-reading the log and it is what makes text and JSON agree.

Exercises

  1. Top user agents. The combined format carries the User-Agent in the last quoted field. Add the agent metric to the awk, grouping by family (Chrome, Firefox, curl, bot) instead of by the full string.
  2. --follow mode. Add a mode that analyzes in real time with tail -f, showing every 10 seconds the requests of the last minute and warning if the 5xx rate exceeds the threshold.
  3. First and last appearance. Add --pattern REGEX, reporting how many times the pattern appears, with its first and last timestamp.

Solutions

1. Inside the awk, the agent is the last compound field; it is extracted with a regex over $0 and classified with a cascade:

{ match($0, /"[^"]*"$/); ua = substr($0, RSTART+1, RLENGTH-2)
  fam = (ua ~ /bot|spider/) ? "bot" : (ua ~ /curl|wget/) ? "cli" :
        (ua ~ /Firefox/) ? "firefox" : (ua ~ /Chrome/) ? "chrome" : "other"
  by_agent[fam]++ }

Grouping by family is what makes the top useful: without grouping, every minor version of Chrome would be a separate row.

2. Follow mode cannot use the awk with END, because END never comes. It is processed by windows:

follow() {
  local -a window=(); local now
  tail -F -n0 "$LOG" | while IFS= read -r line; do
    now=$(date +%s); window+=("$now ${line}")
    window=("${window[@]/#$((now - 60))*/}")   # discard the old
    (( now % 10 == 0 )) && summarize_window "${window[@]}"
  done
}

tail -F (uppercase) is used and not -f: it follows the file by name, so it survives logrotate's rotation, exactly the 07-04 scenario.

3. --pattern is solved with a three-line awk: $0 ~ p { n++; if (first=="") first = stamp; last = stamp } END { print n, first, last }, passing the pattern with -v p="$PATTERN" and never interpolating it into the program, which would be the injection of 08-03 applied to awk.

Conclusion

analyze-logs.sh already answers the six questions of section 1 over live, rotated and compressed files, with filters by date and level, a histogram, three anomaly detections and a report in text and JSON. The project's lessons are four. A single pass: the cost is in re-reading the file, not in the language, and the 08-02 measurement confirmed it with a factor of ten. Each tool in its format: awk for the tabular and voluminous, BASH_REMATCH for capturing from irregular lines where a decision has to be made. An explicit intermediate format (metric<TAB>key<TAB>value) that makes it impossible for the text report and the JSON to contradict each other. And anonymize when presenting, not when collecting, so as not to lose the information needed to detect the attack. Along the way we used zcat and globbing of rotated files (05-01), done < <(...) (05-05), string expansions instead of cut (04-04), integer arithmetic with care for the order (04-06), jq -Rn with group_by (06-05) and sed -E for the masking (06-02).

In 09-03 the risk changes. A wrong report gets corrected; a wrong backup is discovered the day you have to restore and there is nothing left to do. We will take backup.sh —the sketch from 07-03— to a complete system with configurable profiles, a manifest and verification, retention with promotion, remote copy, encryption and a weekly automatic restore test, under the principle that an unverified backup does not exist.

Bash Programming Course

Module 1: Introduction to Bash

Module 2: Basic Bash Commands

Module 3: Scripting Fundamentals

Module 4: Intermediate Scripting

Module 5: Advanced Scripting Techniques

Module 6: Working with External Tools

Module 7: Automation and Scheduling

Module 8: Best Practices and Optimization

Module 9: Real-World Projects

© Copyright 2026. All rights reserved