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
- The questions it must answer
- Requirements and design decisions
- Reading any log: the
open_logfunction - Version 1: counting response codes
- Why
awkforaccess.logandBASH_REMATCHforapp.log - Filters by date and by level
- The aggregations in a single pass
- The hourly histogram
- Anomaly detection
- The report: text and JSON
- Performance over a million lines
- Anonymizing before sharing
- 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.
- Requirements and design decisions
Three decisions shape the whole script:
- One pass, not six. The naive version runs one
grepper metric: six reads of the file. Withawkand 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 ofawkitself, but because of reading the disk once instead of six times. - Reading is abstracted away. The rest of the script must not know whether the file is compressed: an
open_logfunction returns the stream and that is that. - Collection and presentation separated, just as in 09-01:
awkproducesmetric<TAB>key<TAB>valuelines, and the formatters turn them into a text report or into JSON.
- Reading any log: the
open_log function
open_log functionRotated 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.
- Version 1: counting response codes
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.
- Why
awk for access.log and BASH_REMATCH for app.log
awk for access.log and BASH_REMATCH for app.logThe 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.
- 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.
- 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"; }.
- 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.
- 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.
- 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.
- 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.
- 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:
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
grepper 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 theawk. - Sorting inside
awk.awkdoes not guarantee the order offor (k in array). Sort outside withsort -rn, or useasortiif you tie yourself to GNU awk. - Forgetting the rotated files. An analysis of "the last seven days" that only reads
access.loglies as soon as there is daily rotation.expand_logsis 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-03in arithmetic is not a date, compare it as a string. - Tip: save the three-column intermediate file to a temporary with
mktempandtrap EXIT(05-02). It lets you recompute different views without re-reading the log and it is what makes text and JSON agree.
Exercises
- Top user agents. The combined format carries the
User-Agentin the last quoted field. Add theagentmetric to theawk, grouping by family (Chrome, Firefox, curl, bot) instead of by the full string. --followmode. Add a mode that analyzes in real time withtail -f, showing every 10 seconds the requests of the last minute and warning if the 5xx rate exceeds the threshold.- 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
- What Is Bash?
- Setting Up Your Environment
- Basic Command Line Navigation
- Understanding the Shell
- Finding Help: man, help and --help
Module 2: Basic Bash Commands
- File and Directory Operations
- Text Processing Commands
- File Permissions and Ownership
- Redirection and Piping
- Wildcards and Path Expansion
- History and Keyboard Shortcuts
Module 3: Scripting Fundamentals
- Creating and Running a Script
- Variables and Constants
- Basic Operators
- Conditional Statements
- Arguments and User Input
- Quoting, Expansion and Substitution
Module 4: Intermediate Scripting
- Loops in Bash
- Functions in Bash
- Arrays and Associative Arrays
- String Manipulation
- The case Statement and Interactive Menus
- Arithmetic and Numeric Calculations
Module 5: Advanced Scripting Techniques
- Advanced File Operations
- Process Management
- Error Handling and Debugging
- Regular Expressions
- Advanced I/O: Descriptors and Here-Documents
- Modular Scripts and Reusable Libraries
Module 6: Working with External Tools
Module 7: Automation and Scheduling
- Cron Jobs
- Automating Tasks
- Backup and Restore Scripts
- Monitoring and Logging
- Services and Timers with systemd
- Remote Automation with SSH
Module 8: Best Practices and Optimization
- Writing Readable Code
- Optimizing Bash Scripts
- Security Considerations
- Version Control with Git
- Static Analysis with ShellCheck and shfmt
- Automated Testing with Bats
- Portability: POSIX sh versus Bashisms
