The art of extracting metrics

Awk

filtering between log timestamps

second precision

awk \
  -v from="$(date +'%s' -d '2021-10-29 02:34' --utc)" \
  -v to="$(date +'%s' -d '2021-10-29 02:36' --utc)" \
  '
  split($0, parts, /[\- :]/) {
    linefmt=""
    for(i=1;i<=6;i++) linefmt = sprintf("%s %s",linefmt, parts[i]);
    ts=mktime(sprintf("%s UTC", linefmt))
    if (ts > from && ts < to) print
  }
  '<<<'2021-10-29 04:50:00 172.31.43.164'

awk \
  -v from="$(date +'%s' -d '2021-11-27 04:15:00 UTC' --utc)" \
  -v to="$(date +'%s' -d 'now UTC' --utc)" \
  '
  patsplit($1, p, /[0-9]+/) {
    ts=mktime(sprintf("%d %d %d %d %d %d", p[1], p[2], p[3], p[4], p[5], p[6]), 1)
    if (ts > from && ts < to) print
  }
  ' <(tac /var/log/frr/frr.log)|head

perl alternative

from="$(date -Is -d '2021-11-27T04:15:00 UTC' --utc)" \
to="$(date -Is -d 'now UTC' --utc)" \
perl \
  -MDate::Parse \
  -lane \
  '
  $ts=str2time($F[0]);
  $f=str2time($ENV{from});
  $t=str2time($ENV{to});
  print if ($ts >= $f && $ts <= $t )
  ' <(zcat -f /var/log/syslog*) | tee "/syslog-$(date -Im)"

from ms precision unix timestamp

awk \
  -v format="%F %T" \
  -v from="$(date +'%s' -d '2021-10-29 02:34' --utc)" \
  -v to="$(date +'%s' -d '2021-10-29 02:36' --utc)" \
  '{
  ts=substr($0, 0, index($0, ".")-1)
  if (ts > from && ts < to) print strftime(format, ts), substr($0,index($0,$1))
  }
  ' <<<'2021-10-29 04:50:00 172.31.43.164'

Sed

Filtering interesting lines for nxos. Note, NXOS has an ancient version of sed, it only supports the -n flag.

monitoring procfs

Continuously monitor a procfs file, output is tabular.

cat /proc/pressure/cpu
some avg10=1.34 avg60=1.63 avg300=2.33 total=2483371233
full avg10=0.18 avg60=0.03 avg300=0.06 total=827064553

sleep trap: https://stackoverflow.com/questions/65644307/ctrl-c-doesnt-always-terminate-a-shell-script
getline summary: https://www.gnu.org/software/gawk/manual/gawk.html#Getline-Summary
printf formatting: https://bl831.als.lbl.gov/~gmeigs/scripting_help/printf_awk_notes.txt, https://www.gnu.org/software/gawk/manual/html_node/Printf.html

awk -F'[ =]' -vlinefmt="%-8s%-8s%-10s%-10s%-8s\n" -vcpu_pressure="/proc/pressure/cpu" 'BEGIN {
    printf linefmt, "avg10", "avg60", "avg300", "increase", "total"
    do {
        if (system("trap true INT; sleep 1")) {
            exit
        }
        if ($1=="full") {
            printf linefmt, $3, $5, $7, int($9-prev_tot), $9
            prev_tot = $9
        }
    } while ((getline < cpu_pressure) || (close(cpu_pressure) == 0))
}'

avg10   avg60   avg300    increase  total
0.36    0.17    0.07      829472174 829472174
0.36    0.17    0.07      0         829472174
0.24    0.16    0.07      24957     829497131

collect metrics for all PSI.

awk -F'[ =\t]' -vlinefmt="%-14s" -vfields='"cpuavg10", "cpuavg60", "cpuavg300", "cputotal", "cpuincrease", "ioavg10", "ioavg60", "ioavg300", "iototal", "ioincrease", "memavg10", "memavg60", "memavg300", "memtotal","memincrease"' -vcpu_pressure="bash -c 'paste /proc/pressure/{cpu,io,memory}'" \
'BEGIN { patsplit(fields, fmts, /[^", ]+/)
    do {
        if (system("trap true INT; sleep 1")) {
            exit
        }
        if ($1=="some") {
            for(x in fmts) {
                printf linefmt, fmts[x]
            }
            printf "\n"
            for(i=3;i<=NF;i+=2) {
                if(i%9 == 0 && i%3 == 0) {
                    printf linefmt""linefmt, $(i), int($(i)-increase[i]) 
                    increase[i]=$i
                    i+=1
                } else {
                    printf linefmt, $i
                }
                
            }
            printf "\n\n"
        }
    } while ((cpu_pressure|getline) || (close(cpu_pressure) == 0))
}'

histograms

The .1 decimal for size helps tie breakers when min == max.

while :; do
  ss -n -t -o $(printf " state %s" {fin-wait-1,fin-wait-2,time-wait,close-wait,last-ack,closing}) |\
    awk -v bmin=0 -vsize=10000.1 'BEGIN{tm["sec"] = 1000;tm["min"] = "60000"} match($6,/,([0-9.]+)(sec|ms|min)/,m){t=(m[2]=="ms"?int(m[1]):int(tm[m[2]]*m[1]) );b=int(t/size);a[b]++;bmax=b>bmax?b:bmax; bmin=b<bmin?b:bmin} END{for(i=bmin;i<=bmax;++i) printf "%d %d %d\n", (i*size)/tm["sec"],((i+1)*size)/tm["sec"],a[i]}'
  sleep 1
done

Using time functions.

LC_ALL=C awk -v bmin=0 -vsize=10.1 -v date="2022 03 06" 'split($4,p,/[: ]/){t=mktime(date" "p[2]" "p[3]" "p[4]); b=int(t/size);a[b]++;bmax=b>bmax?b:bmax; bmin=b<bmin?b:bmin} END{for(i=bmin;i<=bmax;++i) if(a[i]) printf "%s %s %d\n", strftime("%T",(i*size)),strftime("%T",((i+1)*size)),a[i]}' gopkg.in-access.log-2022-03-06T13\:00.log

Useful squid one

for i in $(awk '!s[$4]++{print $4}' squid-access.log); do  LC_ALL=C awk -v bmin=0 -vsize=300.1 -vhist="$i" '$0 !~ hist{next} {t=int($1);b=int(t/size);a[b]++;bmax=b>bmax?b:bmax; bmin=b<bmin?b:bmin} END{printf "%s 300s histogram\n", hist;for(i=bmin;i<=bmax;++i) if(a[i]) printf "%s %s %d\n", strftime("%T",(i*size)),strftime("%T",((i+1)*size)),a[i] > "histograms.sout"}' squid-access.log; done

LC_ALL=C awk -v bmin=0 -vsize=10.1 -v date="2022 03 06" \
'split($4, p, /[: ]/) {
  t = mktime(date " " p[2] " " p[3] " " p[4])
  b = int(t / size)
  a[b]++
  bmax = b > bmax ? b : bmax
  bmin = b < bmin ? b : bmin
}

END {
  for (i = bmin; i <= bmax; ++i) {
    if (a[i]) {
      printf "%s %s %d\n", strftime("%T", (i * size)), strftime("%T", ((i + 1) * size)), a[i]
    }
  }
}'

iptables filtering

sudo iptables -t nat  -nL |awk -vrgxp="$(rgxg cidr 10.131.31.0/24)" '/^(Chain|target)/{f=1} f==1||$0 ~ rgxp{s[NR]=$0;f++}; length($0)==0{if(f>2){for(i in s) print s[i]};split("",s);f=0}'