Al Mòdul 5 vas aprendre a mesurar. El mètode USE, vmstat, iostat, free, sar i pidstat et diuen quant: la CPU està al 80 %, el disc té 22 ms de latència d'escriptura, queden 300 MB de memòria disponible. Amb allò vas resoldre l'incident del web lent als matins, perquè els comptadors assenyalaven l'E/S i l'E/S tenia un culpable identificable.

Però hi ha una classe de problema per a la qual els comptadors no serveixen: quan tots són en verd i el servei va malament igualment. La CPU ociosa, el disc tranquil, la memòria de sobres, i l'aplicació trigant deu vegades més del que hauria. En aquell punt la pregunta deixa de ser quant i passa a ser què està fent exactament aquest procés, i per respondre-la calen eines que no mesurin agregats, sinó que observin esdeveniments individuals.

Aquesta lliçó te'n dona tres, en ordre creixent de sofisticació i decreixent de cost: strace per veure les crides al sistema una per una, perf per perfilar on es consumeixen els cicles de debò, i eBPF per instrumentar el nucli en producció sense penalització apreciable. I et trobaràs de cara amb una conseqüència de la teva pròpia feina del Mòdul 6.

Contingut

  1. Quan els comptadors no basten
  2. strace: les crides al sistema una per una
  3. L'obstacle que tu mateix vas posar: ptrace_scope
  4. ltrace i el nivell de les biblioteques
  5. perf: perfilat per mostreig
  6. Gràfics de flama
  7. eBPF: instrumentar el nucli en producció
  8. Les eines de bpfcc i quina pregunta respon cadascuna
  9. Taula de decisió: quina eina per a quina pregunta
  10. Cas Tramontana: de 400 ms a 40 ms

Quan els comptadors no basten

La diferència entre les dues famílies d'eines és la unitat d'observació:

Comptadors (M5) Traçat i perfilat (aquesta lliçó)
Què observen Agregats i mitjanes en un interval Esdeveniments individuals
Exemples vmstat, iostat, free, sar strace, perf, bpftrace
Cost Menyspreable; es deixen corrent sempre De menyspreable a prohibitiu
Responen a Quant, on Què, per què
Punt cec El que no és a la mitjana Necessiten una hipòtesi prèvia

Aquell últim punt és important i ordena tota la lliçó: les eines de traçat no substitueixen els comptadors, els continuen. Es fan servir quan ja tens una hipòtesi que vols confirmar o refutar. Llançar strace sobre un procés sense saber què busques produeix cent mil línies il·legibles i alenteix el servei.

La metodologia, doncs, té tres passos i l'ordre no és negociable:

  1. Símptoma mesurat. «L'aplicació triga 400 ms a respondre; la línia base diu 40 ms.» No «va lenta».
  2. Hipòtesis descartades amb comptadors. CPU? Disc? Memòria? Xarxa? És gratis i elimina la majoria dels casos.
  3. Mesura dirigida amb l'eina adequada. Una hipòtesi concreta, una eina, una resposta.

strace: les crides al sistema una per una

Recorda les capes del Mòdul 1: maquinari → nucli → crides al sistema → shell i biblioteques → aplicacions. Una crida al sistema és l'única manera que té un programa de demanar alguna cosa al nucli: obrir un fitxer, llegir d'un sòcol, reservar memòria, esperar. Tot el que un procés fa de cara a l'exterior hi passa.

strace intercepta aquelles crides i les imprimeix. És literalment veure la conversa entre el programa i el nucli.

$ sudo apt install strace

# El mes simple: tracar una ordre des del principi
$ strace -f ls /opt/tramontana 2>&1 | head -12
execve("/usr/bin/ls", ["ls", "/opt/tramontana"], 0x7ffd1c4a2b18 /* 24 vars */) = 0
brk(NULL)                               = 0x5f8c1a2f4000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, {st_mode=S_IFREG|0644, st_size=71234, ...}, 0) = 0
mmap(NULL, 71234, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f2a1c4b0000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
...
openat(AT_FDCWD, "/opt/tramontana", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3
getdents64(3, 0x5f8c1a2f5b40 /* 5 entries */, 32768) = 160
write(1, "app  HISTORIAL  releases  shared\n", 33) = 33

Cada línia té la mateixa estructura: nom de la crida, arguments entre parèntesis, i el valor retornat després de l'=. Si el valor és negatiu, apareix el nom simbòlic de l'error (ENOENT, EACCES, EAGAIN) i la seva descripció. Aquella tercera part és on sol ser la resposta.

Fixa't en la línia de /etc/ld.so.preload: retorna ENOENT. No és un error, és normal —aquell fitxer rarament existeix—, i això il·lustra una cosa que cal interioritzar: strace mostra moltíssims errors esperats. Saber quins són normals és la meitat de l'ofici.

Les opcions que es fan servir de debò

Opció Què fa Quan
-f Segueix els processos i fils fills Gairebé sempre; sense ella en perds la meitat
-p PID S'adjunta a un procés ja en marxa Diagnòstic en producció
-e trace=<llista> Només les crides indicades Imprescindible per no ofegar-te
-c Només el resum estadístic al final El primer pas, gairebé sempre
-T Afegeix el temps que va trigar cada crida Quan busques latència
-tt Marca de temps amb microsegons Correlacionar amb registres
-s N Longitud màxima de les cadenes (32 per defecte) -s 200 per veure rutes i dades completes
-o fitxer Escriu a fitxer en lloc de stderr Sessions llargues
-y Mostra la ruta de cada descriptor de fitxer Molt útil amb sòcols i fitxers
-k Mostra la pila de crides Quan necessites saber qui va cridar

Els grups de -e trace= estalvien memoritzar noms:

$ strace -c -e trace=%file ls /opt/tramontana >/dev/null
Grup Inclou
%file Totes les que reben un nom de fitxer (openat, stat, unlink…)
%desc Operacions sobre descriptors (read, write, close, poll…)
%network socket, connect, accept, send, recv…
%process fork, execve, wait, exit…
%memory mmap, brk, munmap…
%signal Senyals

El resum estadístic: per on començar sempre

$ sudo strace -f -c -p 4318
strace: Process 4318 attached with 4 threads
^Cstrace: Process 4318 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 89.14    2.417882        8062       300           connect
  6.02    0.163291         272       600           sendto
  3.11    0.084372         140       602           recvfrom
  0.98    0.026573          44       604           epoll_wait
  0.41    0.011118          18       617           futex
  0.34    0.009229          15       602        12 read
------ ----------- ----------- --------- --------- ----------------
100.00    2.712465                  3325        12 total

Això és el primer pas de qualsevol diagnòstic amb strace, i per una raó pràctica: cap en una pantalla i diu immediatament on se'n va el temps. Aquí el 89 % del temps és a connect, amb 300 crides a 8 ms cadascuna. Això és una pista enorme: el procés està obrint connexions noves constantment i cadascuna costa 8 mil·lisegons.

Les columnes: % time és la proporció del temps total dins de crides al sistema (no del temps total del procés: si el programa crema CPU al seu propi codi, aquí no es veu); usecs/call és la mitjana per crida; errors compta els retorns amb error.

El cas clàssic: «no troba el seu fitxer de configuració»

L'ús més rendible d'strace, i el que cal tenir memoritzat. Un programa falla dient que no troba un fitxer, i tu estàs segur que el fitxer existeix:

$ sudo -u svc-tramontana /opt/tramontana/app/tramontana --config /etc/tramontana/app.conf
error: no s ha pogut carregar la configuracio

$ ls -l /etc/tramontana/app.conf
-rw-r----- 1 root tramontana 341 ago 18 12:04 /etc/tramontana/app.conf

El fitxer hi és. La pregunta és què està buscant el programa realment:

$ sudo -u svc-tramontana strace -f -e trace=openat,newfstatat -s 200 \
    /opt/tramontana/app/tramontana --config /etc/tramontana/app.conf 2>&1 \
    | grep -E 'ENOENT|EACCES' | grep -v 'lib\|locale\|gconv'
openat(AT_FDCWD, "/etc/tramontana/app.conf.local", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/tramontana/secrets/db_password", O_RDONLY) = -1 EACCES (Permission denied)

Aquí està, i no era el que semblava. El fitxer de configuració s'obre bé; el .local que no existeix és opcional. L'error real és EACCES sobre el fitxer de la credencial: el programa el busca a /etc/tramontana/secrets/db_password, però des de 06-05 la credencial l'entrega systemd a $CREDENTIALS_DIRECTORY, i executat a mà aquella variable no existeix. El programa funciona correctament sota systemd i falla executat directament.

Aquell és el patró general i per això val la pena memoritzar-lo:

# La linia que resol la meitat dels "no troba el fitxer"
$ strace -f -e trace=%file <ordre> 2>&1 | grep -E 'ENOENT|EACCES'

El cost, dit clarament

strace funciona amb ptrace, que atura el procés a cada crida al sistema, transfereix el control al traçador, i el reprèn. Això significa dos canvis de context per crida.

Càrrega del procés Alentiment típic amb strace
Intensiu en CPU, poques crides ×1,2 – ×2
Mixt ×5 – ×20
Intensiu en E/S, moltes crides ×50 – ×100

Un procés que fa 50.000 crides per segon pot tornar-se cent vegades més lent. Les conseqüències operatives:

  • Mai strace sense -e trace= ni -c sobre un procés de producció amb càrrega. Si ho has de fer, fes-ho amb un límit de temps: timeout 5 strace -f -c -p PID.
  • Un procés al qual estàs adjuntat i mates strace amb SIGKILL pot quedar aturat. Surt sempre amb Ctrl+C, que fa un detach net.
  • Per a producció, perf trace i eBPF fan el mateix amb un cost un o dos ordres de magnitud menor. És la raó que existeixin.

L'obstacle que tu mateix vas posar: ptrace_scope

Intenta adjuntar-te al procés de l'aplicació com el teu usuari:

$ pgrep -u svc-tramontana tramontana
4318
$ strace -p 4318
strace: attach: ptrace(PTRACE_SEIZE, 4318): Operation not permitted

No és una fallada. És el kernel.yama.ptrace_scope = 1 que vas posar a /etc/sysctl.d/60-enfortiment.conf a 06-06, i que aquell dia venia amb un avís escrit al costat precisament per això:

$ sysctl kernel.yama.ptrace_scope
kernel.yama.ptrace_scope = 1

Els quatre valors possibles:

Valor Qui pot traçar qui
0 Qualsevol procés pot traçar qualsevol altre del mateix usuari
1 Només descendents directes (el valor que vas posar)
2 Només processos amb CAP_SYS_PTRACE (és a dir, root)
3 Ningú, ni root. Irreversible fins a reiniciar

I per què la mesura és correcta, que és la part que cal entendre i no només esquivar: amb ptrace_scope = 0, un procés compromès pot llegir tota la memòria de qualsevol altre procés del mateix usuari. Això inclou la credencial de la base de dades que tanta feina va costar xifrar a 06-05: és en clar a la memòria del procés que la fa servir. Un atacant que aconsegueixi executar codi com a svc-tramontana en un procés qualsevol podria extreure-la del procés de l'aplicació sense tocar cap fitxer. El valor 1 tanca exactament aquella via.

Les dues sortides legítimes:

# Sortida A: fer servir sudo. CAP_SYS_PTRACE ignora la restriccio de Yama.
$ sudo strace -f -c -p 4318
# funciona
# Sortida B: abaixar-lo temporalment. Nomes si necessites tracar SENSE
# privilegis, cosa rara. I SEMPRE amb la tornada enrere garantida.
$ sudo sysctl -w kernel.yama.ptrace_scope=0
kernel.yama.ptrace_scope = 0
$ strace -f -c -p 4318 ; sudo sysctl -w kernel.yama.ptrace_scope=1
kernel.yama.ptrace_scope = 1

Per a la sortida B, la forma disciplinada és un script amb trap, aplicant el de 04-06, perquè un Ctrl+C a mitges deixaria el sistema amb la protecció desactivada:

$ cat ~/scripts/tracar_temporal.sh
#!/usr/bin/env bash
# tracar_temporal.sh - Abaixa ptrace_scope, executa el tracat, i el restaura
#                      SEMPRE, fins i tot si s interromp.
# Us: tracar_temporal.sh <pid>
set -euo pipefail

readonly SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)"
# shellcheck source=lib/comuns.sh
source "${SCRIPT_DIR}/lib/comuns.sh"

readonly ETIQUETA_LOG="tracar-temporal"

restaurar() {
    sudo sysctl -q -w kernel.yama.ptrace_scope="$VALOR_ORIGINAL"
    log "ptrace_scope restaurat a $VALOR_ORIGINAL"
}

main() {
    local pid="${1:?us: tracar_temporal.sh <pid>}"
    es_numero "$pid" || morir 64 "el pid ha de ser un numero: $pid"
    requereix_comanda strace

    VALOR_ORIGINAL="$(sysctl -n kernel.yama.ptrace_scope)"
    readonly VALOR_ORIGINAL
    trap restaurar EXIT INT TERM

    log "abaixant ptrace_scope temporalment (era $VALOR_ORIGINAL)"
    sudo sysctl -q -w kernel.yama.ptrace_scope=0

    timeout 10 strace -f -c -p "$pid" || true
}

main "$@"

A la pràctica, la sortida A —sudo— és la correcta el 95 % de les vegades. La sortida B només té sentit amb eines que no funcionen bé sota sudo, i en un servidor de producció la resposta honesta és que no s'abaixa ptrace_scope: es fa servir eBPF, que no necessita ptrace en absolut. És un altre argument a favor de la tercera secció d'aquesta lliçó.

ltrace i el nivell de les biblioteques

strace veu la frontera entre el programa i el nucli. N'hi ha una altra, de frontera, un nivell més amunt: entre el programa i les biblioteques compartides que fa servir.

$ sudo apt install ltrace
$ ltrace -e 'malloc+free' ./programa 2>&1 | head -5
programa->malloc(1024)                        = 0x5f8c1a2f5000
programa->malloc(4096)                        = 0x5f8c1a2f5410
programa->free(0x5f8c1a2f5000)                = <void>

És útil per entendre el comportament d'un programa propi —fuites de memòria, ús d'una biblioteca criptogràfica, crides a libcurl— però té dos límits seriosos: només veu crides a biblioteques dinàmiques (un binari estàtic és opac), i el seu cost és encara més gran que el d'strace. A la pràctica es fa servir poc, i en un servidor gairebé mai. strace per a la frontera amb el nucli, perf per a l'interior del procés.

perf: perfilat per mostreig

perf és l'eina de rendiment del nucli de Linux mateix, i opera amb un model radicalment diferent:

Traçat (strace) Mostreig (perf)
Mètode Intercepta tots els esdeveniments Fa una foto N vegades per segon
Precisió Exacta Estadística, però suficient
Cost ×10 – ×100 1 – 5 %
Veu el codi propi del procés No Sí
Apte per a producció No Sí

La diferència clau és la penúltima fila. strace no et pot dir res d'un procés que crema CPU al seu propi bucle, perquè allà no hi ha crides al sistema. perf sí.

$ sudo apt install linux-tools-common linux-tools-$(uname -r)
$ perf --version
perf version 6.8.12

En una VM, alguns comptadors de maquinari no estan disponibles perquè l'hipervisor no els exposa. Els esdeveniments de programari (task-clock, context-switches, page-faults) sí que funcionen sempre.

perf stat: la foto d'eficiència

$ sudo perf stat -p 4318 -- sleep 10

 Performance counter stats for process id '4318':

          1.284,17 msec task-clock                #    0,128 CPUs utilized
             3.412      context-switches          #    2,657 K/sec
                48      cpu-migrations            #   37,378 /sec
             1.204     page-faults                #    0,938 K/sec
     3.108.442.190      cycles                    #    2,421 GHz
     1.882.104.556      instructions              #    0,61  insn per cycle
       412.887.204      branches                  #  321,52 M/sec
        18.442.109      branch-misses             #    4,47% of all branches
       104.882.441      cache-references          #   81,68 M/sec
        41.204.882      cache-misses              #   39,28% of all cache refs

      10,002841 seconds time elapsed

Com llegir això, línia per línia, perquè cadascuna respon a una pregunta diferent:

Mètrica Què significa Valor de referència
CPUs utilized Fracció d'un nucli consumida 0,128: el procés està pràcticament ociós
context-switches Vegades que va deixar la CPU Alt + CPU baixa = està esperant alguna cosa
insn per cycle (IPC) Instruccions per cicle: l'eficiència real >1 bo; <0,5 el processador espera memòria
branch-misses Prediccions de salt fallades <5 % normal; >10 % codi molt ramificat
cache-misses Accessos que van anar a la RAM <10 % bo; >30 % problema de localitat

I la conclusió d'aquesta mesura concreta: 0,128 CPU utilitzades. El procés no està treballant, està esperant. Els 3.412 canvis de context en 10 segons ho confirmen: entra i surt de la CPU constantment perquè es bloqueja. Amb això queda descartada la CPU com a causa del problema de latència, que era l'objectiu del pas 2 de la metodologia.

L'IPC de 0,61 i el 39 % de fallades de memòria cau són mediocres, però irrellevants aquí: amb el procés al 12,8 % d'un nucli, millorar la seva eficiència de CPU no canviaria la latència.

perf top i perf record

# En viu: quines funcions consumeixen CPU ara mateix, a tot el sistema
$ sudo perf top --sort comm,dso
Samples: 84K of event 'cpu-clock:pppH', 4000 Hz
  18,42%  postgres         postgres
  11,04%  tramontana       tramontana
   8,87%  swapper          [kernel.kallsyms]
   4,12%  tramontana       libssl.so.3
# Enregistrar amb piles de crides (-g) durant 30 segons
$ sudo perf record -F 99 -g -p 4318 -- sleep 30
[ perf record: Woken up 3 times to write data ]
[ perf record: Captured and wrote 1,842 MB perf.data (2841 samples) ]

$ sudo perf report --stdio --sort overhead,symbol | head -14
# Overhead  Symbol
    64,12%  [k] __x64_sys_connect
    18,44%  [k] tcp_v4_connect
     6,02%  [.] tramontana_db_connectar
     3,18%  [.] SSL_connect
     1,84%  [k] finish_task_switch

-F 99 fixa la freqüència de mostreig en 99 Hz. És una convenció amb motiu: fer servir 100 Hz corre el risc de sincronitzar-se amb esdeveniments periòdics del sistema que també són de 100 Hz, i esbiaixar la mostra. Un nombre primer proper ho evita.

Les marques [k] i [.] distingeixen l'espai de nucli del d'usuari. Aquí el 82 % del temps de CPU és a connect i tcp_v4_connect, tots dos al nucli, i tramontana_db_connectar apareix a l'espai d'usuari. Tres eines diferents apuntant al mateix lloc: el procés es passa la vida obrint connexions.

Gràfics de flama

Un perf report amb piles de crides és difícil de llegir perquè la informació és jeràrquica i la sortida és plana. El gràfic de flama (flame graph) ho resol visualment, i s'ha convertit en l'estàndard de l'àrea.

Com es llegeix, que és el que cal aprendre:

  • L'eix horitzontal NO és temps. És l'agrupació alfabètica de les piles. L'amplada d'un bloc és la proporció de mostres en què aquella funció era a la pila.
  • L'eix vertical és la profunditat de la pila. A baix el punt d'entrada, a dalt la funció que s'estava executant en aquell instant.
  • El que busques són altiplans amples, especialment a la part alta: una funció ampla a dalt és una funció on el procés passa molt de temps realment executant. Una funció ampla a baix amb moltes torres fines a sobre és només un punt de pas.
$ git clone --depth 1 https://github.com/brendangregg/FlameGraph ~/FlameGraph
$ sudo perf record -F 99 -g -p 4318 -- sleep 30
$ sudo perf script > sortida.perf
$ ~/FlameGraph/stackcollapse-perf.pl sortida.perf > sortida.folded
$ ~/FlameGraph/flamegraph.pl sortida.folded > flama-tramontana.svg

El resultat és un SVG interactiu: s'obre en un navegador, es pot fer clic per ampliar una branca i cercar per nom de funció.

Existeix una variant molt útil que gairebé ningú no coneix: el gràfic de flama fora de CPU (off-CPU). El normal mostra on es consumeix CPU; el de fora de CPU mostra on el procés està bloquejat esperant. Per a un problema de latència com el nostre —procés al 12 % de CPU— el segon és molt més informatiu, i es construeix amb eBPF en lloc de amb perf:

$ sudo offcputime-bpfcc -df -p 4318 30 > fora-cpu.folded
$ ~/FlameGraph/flamegraph.pl --title "Fora de CPU" --countname us \
    fora-cpu.folded > flama-espera.svg

I perf trace, que mereix una menció perquè resol el problema de cost d'strace:

$ sudo perf trace -p 4318 --duration 5 2>&1 | head -6
     0,000 ( 8,412 ms): tramontana/4318 connect(fd: 12, uservaddr: 10.0.2.15:5432) = 0
     8,441 ( 0,182 ms): tramontana/4318 sendto(fd: 12, buff: 0x7f2a..., len: 96) = 96
     8,712 ( 6,204 ms): tramontana/4318 recvfrom(fd: 12, ...) = 412

Mateixa informació que strace -T, amb un cost molt menor perquè fa servir la infraestructura d'esdeveniments del nucli en lloc de ptrace — i, de passada, no l'afecta ptrace_scope.

eBPF: instrumentar el nucli en producció

eBPF és el canvi més important en l'observabilitat de Linux de l'última dècada. La idea: permetre carregar programes propis dins del nucli, que s'executen quan es produeix un esdeveniment, amb tres garanties que el fan segur:

  1. Un verificador analitza el programa abans de carregar-lo i rebutja tot allò que pugui penjar el nucli: bucles no acotats, accessos a memòria arbitrària, crides no permeses.
  2. Es compila a codi natiu amb un JIT, així que s'executa a velocitat de nucli.
  3. No pot bloquejar ni modificar el flux del nucli; només observar i agregar.

Per què això ho canvia tot: abans, per saber la latència de cada operació de disc havies de triar entre un comptador agregat (iostat, que dona la mitjana i amaga la cua) o traçar-ho tot (strace, prohibitiu). Amb eBPF pots calcular l'histograma complet dins del nucli i treure'n només el resultat. El cost és de fraccions de percentatge.

$ sudo apt install bpfcc-tools bpftrace linux-headers-$(uname -r)

I aquí apareix el segon sysctl de 06-06 amb conseqüències:

$ sysctl kernel.unprivileged_bpf_disabled
kernel.unprivileged_bpf_disabled = 1

Això impedeix que un usuari sense privilegis carregui programes eBPF, i és correcte: el subsistema BPF ha tingut vulnerabilitats d'escalada de privilegis, i la seva superfície és gran. La conseqüència pràctica és que totes les eines d'aquesta secció s'executen amb sudo, que és exactament el que vols en un servidor.

bpftrace: una línia, una resposta

bpftrace és un llenguatge d'una línia per a eBPF, amb sintaxi inspirada en awk —que ja coneixes del Mòdul 3—: esdeveniment { acció }.

# 1. Comptar crides al sistema per proces durant 10 segons
$ sudo timeout 10 bpftrace -e '
    tracepoint:raw_syscalls:sys_enter { @[comm] = count(); }'
Attaching 1 probe...
@[systemd-journal]: 412
@[postgres]: 8841
@[tramontana]: 33204

# 2. Latencia de les crides connect(), en histograma
$ sudo timeout 30 bpftrace -e '
    tracepoint:syscalls:sys_enter_connect { @inici[tid] = nsecs; }
    tracepoint:syscalls:sys_exit_connect  /@inici[tid]/ {
        @us = hist((nsecs - @inici[tid]) / 1000);
        delete(@inici[tid]);
    }'
@us:
[1, 2)                 4 |@                                    |
[2, 4)                12 |@@@@                                 |
[4, 8)               142 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[8, 16)              128 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@   |
[16, 32)              14 |@@@@                                 |

# 3. Quins fitxers obre un proces concret, en viu
$ sudo bpftrace -e '
    tracepoint:syscalls:sys_enter_openat /comm == "tramontana"/ {
        printf("%s -> %s\n", comm, str(args->filename));
    }'

# 4. Quants bytes escriu cada proces al disc
$ sudo timeout 20 bpftrace -e '
    tracepoint:block:block_rq_issue { @bytes[comm] = sum(args->bytes); }'

L'histograma de l'exemple 2 és la classe d'informació que cap altra eina no dona fàcilment: 300 crides a connect, amb la massa entre 4 i 16 microsegons... espera. Aquell histograma diu microsegons, i strace -c deia 8 mil·lisegons per crida. La discrepància és la pista: la crida connect al nucli és ràpida; el temps se'n va en una altra part del procés de connexió. Hi tornarem al cas pràctic.

Fixa't en la mecànica de l'exemple 2, perquè és el patró de mesura de latència amb eBPF: guardar nsecs en un mapa indexat per tid a l'entrada, restar a la sortida, i agregar amb hist(). El càlcul sencer passa dins del nucli; l'única cosa que surt a l'espai d'usuari és l'histograma final.

Les eines de bpfcc i quina pregunta respon cadascuna

bpfcc-tools instal·la unes cent cinquanta eines ja escrites. Aquestes són les que es fan servir de debò:

Eina Pregunta que respon
execsnoop-bpfcc Quins processos s'estan llançant? (processos efímers que ps no veu)
opensnoop-bpfcc Quins fitxers s'obren, i quins fallen?
biolatency-bpfcc Quina és la distribució de latència de disc, no la mitjana?
biosnoop-bpfcc Quin procés fa cada operació de disc?
tcpconnect-bpfcc Qui obre connexions sortints, i cap a on?
tcpaccept-bpfcc Qui es connecta als meus serveis?
tcpretrans-bpfcc Hi ha retransmissions TCP? (problema de xarxa real)
tcplife-bpfcc Quant duren les connexions i quants bytes mouen?
runqlat-bpfcc Quant esperen els processos a la cua de la CPU?
cachestat-bpfcc Quina és la taxa d'encert de la memòria cau de pàgina?
ext4slower-bpfcc Quines operacions de sistema de fitxers triguen més de N ms?
profile-bpfcc Perfilat per mostreig, alternativa a perf record
offcputime-bpfcc On està bloquejat esperant el procés?
funclatency-bpfcc Quant triga una funció concreta del nucli?

Dues d'elles mereixen un comentari pel que aporten sobre els comptadors clàssics:

# biolatency: la DISTRIBUCIO, no la mitjana. Una mitjana de 5 ms pot amagar
# que l 1% de les operacions triga 500 ms, i aquell 1% es el que es nota.
$ sudo biolatency-bpfcc -m 30 1
     msecs               : count     distribution
         0 -> 1          : 8412     |****************************************|
         2 -> 3          : 1204     |*****                                   |
         4 -> 7          :  412     |*                                       |
         8 -> 15         :   88     |                                        |
        16 -> 31         :   12     |                                        |
       256 -> 511        :    3     |                                        |

Aquells tres esdeveniments de 256-511 ms no apareixen en cap mitjana. Si coincideixen amb les peticions lentes, són la causa.

# runqlat: quant esperen els processos per entrar a la CPU.
# Es la resposta a "la CPU no esta saturada pero tot va lent".
$ sudo runqlat-bpfcc 10 1
     usecs               : count     distribution
         0 -> 1          : 12841    |****************************************|
         2 -> 3          :  2104    |******                                  |
         4 -> 7          :   412    |*                                       |

Taula de decisió: quina eina per a quina pregunta

La taula que resumeix la lliçó i a la qual tornar quan tinguis un problema al davant:

Pregunta Eina Cost
Hi ha algun recurs saturat? vmstat, iostat, free, sar (M5) Nul
Per què va fallar el servei? journalctl -u <unitat> (M5) Nul
Quin fitxer busca i no troba? strace -e trace=%file | grep ENOENT Alt, breu
On se'n va el temps d'un procés? strace -f -c (primer), després perf Alt / baix
Quant triga cada crida? strace -T o perf trace Alt / baix
Quina funció consumeix CPU? perf top, perf record -g + gràfic de flama Baix
És eficient el codi (IPC, memòria cau)? perf stat Nul
On està bloquejat esperant? offcputime-bpfcc + gràfic de flama Baix
Quina és la distribució de latència de disc? biolatency-bpfcc Molt baix
Qui obre connexions i cap a on? tcpconnect-bpfcc, tcplife-bpfcc Molt baix
Hi ha processos efímers que no veig? execsnoop-bpfcc Molt baix
Espera per entrar a la CPU? runqlat-bpfcc Molt baix
Alguna cosa molt específica del nucli bpftrace a mida Molt baix
Per què va caure el procés? gdb sobre l'abocament, coredumpctl N/A

I la regla d'ordre: comptadors → perf stat → eBPF → strace. De menor a major cost, i strace en últim lloc precisament perquè és el més car. La intuïció contrària —començar per strace perquè és el més conegut— és la que produeix diagnòstics que degraden el servei que intenten arreglar.

Una nota sobre abocaments: si el problema és una caiguda, no una lentitud, l'eina és una altra. Recorda que a 06-06 vas posar * hard core 0 a limits.conf perquè els abocaments no exposessin secrets; per depurar una caiguda caldria revertir-ho temporalment, i coredumpctl de systemd és la via moderna.

Cas Tramontana: de 400 ms a 40 ms

revisio_salut.sh comença a retornar 1. La línia base de 05-07 diu que l'aplicació respon en 40 ms; ara triga 400.

Pas 1: el símptoma, mesurat

$ for i in {1..5}; do
      curl -s -o /dev/null -w '%{time_total}\n' http://127.0.0.1:8080/cases
  done
0,412844
0,398201
0,421077
0,404118
0,397882

$ grep -c 'ms=[0-9]\{3,\}' /var/log/tramontana/acces.log
389

Confirmat i reproduïble: ~400 ms, no un pic aïllat.

Pas 2: descartar amb comptadors (gratis)

$ vmstat 2 5
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0      0 1284412 104882 1841204   0    0     0    12  412  882  3  2 95  0  0
 0  0      0 1284188 104882 1841204   0    0     0     8  388  841  2  2 96  0  0

$ iostat -xz 2 3 | grep -A2 'Device'
Device   r/s   rkB/s  w/s   wkB/s   r_await  w_await  aqu-sz  %util
sda     0,50    8,00  2,00   16,00     0,42     0,88    0,01   0,40

$ free -h | head -2
               total        used        free      shared  buff/cache   available
Mem:           3,8Gi       1,2Gi       1,3Gi        12Mi       1,4Gi       2,4Gi

CPU al 95 % ociosa, disc al 0,4 % d'utilització, 2,4 GB de memòria disponible. Cap recurs no està saturat. Aquest és exactament l'escenari que anunciava el tancament de 07-01: els comptadors en verd i el servei malament.

Pas 3: perf stat confirma que espera, no treballa

$ sudo perf stat -p $(pgrep -u svc-tramontana -f tramontana) -- sleep 10 2>&1 | \
      grep -E 'CPUs utilized|context-switches|insn per cycle'
          1.284,17 msec task-clock                #    0,128 CPUs utilized
             3.412      context-switches          #    2,657 K/sec
     1.882.104.556      instructions              #    0,61  insn per cycle

12,8 % d'un nucli i 3.412 canvis de context. El procés es bloqueja constantment. La hipòtesi passa a ser: està esperant alguna cosa externa. Els candidats són disc (descartat per iostat) i xarxa — és a dir, PostgreSQL.

Pas 4: strace -c localitza el temps

Amb sudo, pel ptrace_scope, i amb límit de temps pel cost:

$ sudo timeout 10 strace -f -c -p $(pgrep -u svc-tramontana -f tramontana)
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 89.14    2.417882        8062       300           connect
  6.02    0.163291         272       600           sendto
  3.11    0.084372         140       602           recvfrom
------ ----------- ----------- --------- --------- ----------------

300 crides a connect en 10 segons, a 8 ms cadascuna. Amb ~75 peticions en aquell interval, en surten unes 4 connexions noves per petició. Una aplicació amb un grup de connexions no n'hauria d'obrir cap.

Pas 5: eBPF troba la causa real

Aquí és on la discrepància que vam deixar pendent es resol:

$ sudo timeout 20 tcplife-bpfcc
PID   COMM        LADDR      LPORT RADDR      RPORT TX_KB RX_KB MS
4318  tramontana  10.0.2.15  48812 10.0.2.15   5432     1     3 8.42
4318  tramontana  10.0.2.15  48814 10.0.2.15   5432     1     2 8.11
4318  tramontana  10.0.2.15  48816 10.0.2.15   5432     1     4 8.38
[... 297 linies mes ...]

Tres-centes connexions a PostgreSQL, cadascuna de 8 ms de vida i uns pocs KB. S'obren, fan una consulta i es tanquen. Això és un grup de connexions que no funciona.

I l'histograma explica els 8 ms, que la crida connect sola no justificava:

$ sudo timeout 30 bpftrace -e '
    tracepoint:syscalls:sys_enter_connect /comm == "tramontana"/ { @i[tid] = nsecs; }
    tracepoint:syscalls:sys_exit_connect  /@i[tid]/ {
        @us_syscall = hist((nsecs - @i[tid]) / 1000); delete(@i[tid]); }'
@us_syscall:
[4, 8)               142 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[8, 16)              128 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@    |

La crida al sistema triga microsegons. Els 8 mil·lisegons que veia strace inclouen tot el que envolta la connexió: l'establiment TCP, i sobretot l'autenticació i l'arrencada de sessió de PostgreSQL. perf report ja ho insinuava amb SSL_connect a la pila.

$ sudo timeout 20 offcputime-bpfcc -p 4318 -f | sort -k2 -rn | head -3
tramontana;db_connectar;SSL_connect;read;schedule 18412042
tramontana;db_consultar;read;schedule 1204882
tramontana;epoll_wait;schedule 882104

18,4 de 20 segons bloquejat dins de db_connectar. Confirmat des d'una quarta eina independent.

Pas 6: la causa arrel i la correcció

La peça que faltava és una dada que ja tenies. Recorda l'incident de 05-07: errors.log amb connexions_actives=200 i db_timeout. Aleshores es va resoldre la saturació d'E/S, però el max_connexions=200 va quedar allà:

$ grep -E 'max_connexions|pool' /etc/tramontana/app.conf
max_connexions=200

$ sudo -u postgres psql -tAc "SHOW max_connections;"
100

Aquí està la causa arrel, i és de configuració, no de codi: l'aplicació es pensa que pot tenir 200 connexions, PostgreSQL només n'accepta 100. Quan el grup intenta créixer més enllà de 100, les connexions noves són rebutjades, l'aplicació desisteix del grup i obre connexions directes per petició, i cadascuna costa 8 ms d'establiment i autenticació.

# Corregir: el grup per sota del limit real, amb marge per a la resta
$ sudo cp -p /etc/tramontana/app.conf /etc/tramontana/app.conf.bak-$(date +%F)
$ sudo chattr -i /etc/tramontana/app.conf
$ sudo sed -i.bak-$(date +%F) 's/^max_connexions=200$/max_connexions=80/' \
      /etc/tramontana/app.conf
$ sudo chattr +i /etc/tramontana/app.conf
$ sudo diff -u /etc/tramontana/app.conf.bak-$(date +%F) /etc/tramontana/app.conf
@@ -5,7 +5,7 @@
-max_connexions=200
+max_connexions=80
$ sudo systemctl restart tramontana.service

Pas 7: mesurar després

$ for i in {1..5}; do
      curl -s -o /dev/null -w '%{time_total}\n' http://127.0.0.1:8080/cases
  done
0,041882
0,038204
0,042118
0,039877
0,040412

$ sudo timeout 20 tcplife-bpfcc | wc -l
81

$ sudo timeout 10 strace -f -c -p $(pgrep -u svc-tramontana -f tramontana) 2>&1 | \
      grep -E 'connect|total'
  0.42    0.000841          10        80           connect
100.00    0.198442                  1841        12 total

$ ~/scripts/revisio_salut.sh; echo "estat: $?"
estat: 0

De 400 ms a 40 ms. De 300 connexions cada 10 segons a 80 en total, que és la mida del grup establint-se una sola vegada. I revisio_salut.sh torna a 0.

El que fa vàlid aquest diagnòstic no és cap eina en particular, sinó la convergència de cinc mesures independents —perf stat, strace -c, tcplife, bpftrace i offcputime— assenyalant el mateix punt, més una hipòtesi final verificada per comparació abans/després. I la nota per al manual d'operació: canviar un límit en un costat d'una relació client-servidor sense comprovar l'altre costat és l'error que va provocar això, i va passar fa tres mòduls.

Errors Comuns i Consells

  • Començar per strace. És l'eina més coneguda i la més cara. L'ordre és comptadors → perf stat → eBPF → strace.
  • strace sense -e trace= ni -c en producció. Cent mil línies il·legibles i un servei cent vegades més lent. Si has de traçar en producció, timeout 5 strace -f -c -p PID.
  • Oblidar -f. Sense seguir fills i fils, en una aplicació multifil en perds gairebé tot.
  • Confondre el temps d'strace -c amb el temps total del procés. % time és la proporció dins de crides al sistema. Si el programa crema CPU al seu codi, allà no apareix: per a això hi ha perf.
  • Matar strace amb SIGKILL. Pot deixar el procés traçat aturat. Surt amb Ctrl+C.
  • Interpretar tots els ENOENT com a errors. Una arrencada normal en genera desenes buscant biblioteques i locales. Filtra el soroll abans de concloure.
  • Abaixar ptrace_scope i oblidar restaurar-lo. Deixa oberta la lectura de memòria entre processos del mateix usuari, i amb ella els secrets. Fes servir sudo, o un script amb trap.
  • Refiar-se de la mitjana de latència. iostat pot donar 1 ms de mitjana mentre l'1 % de les operacions triga 500 ms. biolatency-bpfcc mostra la distribució, i la cua és el que l'usuari nota.
  • Mostrejar a 100 Hz. Es pot sincronitzar amb esdeveniments periòdics del sistema i esbiaixar la mostra. Fes servir un primer proper: -F 99.
  • Buscar el problema de latència en un gràfic de flama normal. El de CPU mostra on es consumeix; per a un procés que espera necessites el de fora de CPU (offcputime-bpfcc).
  • Concloure amb una sola eina. Aquest cas es va resoldre amb cinc mesures convergents. Una de sola hauria donat una resposta plausible i probablement incompleta.
  • Consell de mètode. Guarda les mesures del diagnòstic al costat de la línia base de 05-07: què mesuraves, amb quina ordre, i el valor normal. La propera vegada, el pas 2 són trenta segons en lloc de vint minuts.

Exercicis

Exercici 1

copia_tramontana.sh trigava 40 minuts i ara triga 3 hores, cosa que fa que la còpia de les 02:30 no acabi abans del pic del matí — l'incident de 05-07 una altra vegada. iostat mostra el disc al 45 % d'utilització, molt lluny de la saturació. Dissenya el procediment de diagnòstic indicant quina eina faries servir a cada pas i per què, sabent que la còpia fa servir restic sobre un volum xifrat amb LUKS.

Exercici 2

Escriu un script diagnostic_latencia.sh que, donat el nom d'un servei de systemd, executi automàticament els passos 2, 3 i 4 de la metodologia —comptadors, perf stat i strace -c— i produeixi un informe llegible. Ha de respectar les convencions del curs, gestionar el ptrace_scope de forma segura, i no deixar residus.

Exercici 3

Un company proposa posar kernel.yama.ptrace_scope = 0 de forma permanent «perquè així podem diagnosticar sense sudo». Redacta la resposta tècnica: què s'hi guanya, què s'hi perd exactament, i quina alternativa proposes.

Solucions

Solució 1

La clau de l'enunciat és «45 % d'utilització», que descarta la saturació però no descarta la latència: són dues coses diferents i confondre-les és l'error habitual. Un disc al 45 % pot tenir una cua de peticions lentes.

# Pas 1. El simptoma, mesurat i comparat amb la linia base
$ sudo journalctl -u tramontana-copia.service --since "7 days ago" \
    | grep -E 'Started|Finished|Succeeded'
$ systemd-analyze --no-pager verify tramontana-copia.service
# I la font directa: quant triga cada execucio
$ sudo systemctl show tramontana-copia.service -p ExecMainStartTimestamp \
    -p ExecMainExitTimestamp
# Pas 2. Comptadors, gratis, mentre la copia corre.
# El que es busca aqui: %util NO es l indicador; w_await i aqu-sz si.
$ iostat -xz 5 6
Device   r/s   rkB/s  w/s   wkB/s  r_await  w_await  aqu-sz  %util
dm-1     2,00   32,0  84,0  1024,0    1,12    38,42    3,21   45,10
$ vmstat 5 6      # mirar la columna 'wa' i la 'b' (processos bloquejats)
$ mpstat -P ALL 5 3   # buscar un nucli al 100% en 'sy': senyal de xifratge

Amb w_await de 38 ms i %util del 45 %, ja hi ha una anomalia: hi ha latència sense saturació, cosa que apunta a operacions individualment lentes o a un coll d'ampolla en algun punt de la pila.

# Pas 3. Distribucio, no mitjana. Es L eina per a aquest simptoma.
$ sudo biolatency-bpfcc -D 60 1
# -D separa per dispositiu: permet veure si el problema es a dm-1 (LUKS)
# o a sda (el disc fisic de sota)

I aquí està el raonament específic de l'exercici: /srv/tramontana/backups és un volum LUKS sobre LVM sobre sda. Són tres capes, i la latència cal atribuir-la a una:

Dispositiu Capa Si la latència és aquí…
sda Disc físic El problema és l'emmagatzematge; no és cosa de la còpia
vg-dades/lv-backups LVM Poc probable; LVM hi afegeix molt poc
dm-1 (backups-xifrat) LUKS El xifratge és el coll d'ampolla
# Pas 4. Confirmar si el xifratge es el coll: l operacio consumeix CPU
# de nucli als fils de kcryptd.
$ sudo timeout 30 profile-bpfcc -f 30 | grep -iE 'crypt|aes' | head -5
$ ps -eLo comm,pcpu | grep -E 'kcryptd|restic' | sort -k2 -rn | head -5
$ cryptsetup luksDump /dev/vg-dades/lv-backups | grep -E 'Cipher|PBKDF'

# I comprovar si el maquinari accelera AES. Si no, el xifratge va per programari
# i es entre 5 i 10 vegades mes lent.
$ grep -o -m1 aes /proc/cpuinfo || echo "SENSE acceleracio AES-NI"
# Pas 5. Descartar que sigui restic i no el xifratge. Un proces pot anar
# lent per E/S o per CPU, i cal saber quin dels dos.
$ sudo perf stat -p $(pgrep -f 'restic backup') -- sleep 20 2>&1 \
    | grep -E 'CPUs utilized|context-switches'
$ sudo timeout 30 offcputime-bpfcc -p $(pgrep -f 'restic backup') -f \
    | sort -k2 -rn | head -5

La interpretació, que és el que es demana:

  • CPUs utilized a prop d'1,00 i profile-bpfcc mostrant funcions d'AES: el coll és el xifratge per programari. Causes possibles: la VM no exposa AES-NI a l'hoste, o la CPU no el té. Es comprova amb /proc/cpuinfo i es resol activant host-passthrough a la configuració de la VM (ho veuràs a 07-04) o canviant el xifratge de LUKS.
  • CPUs utilized baix i offcputime mostrant espera en E/S: el coll és el disc. Aleshores biolatency -D diu si la latència ja ve de sda, i el pas següent és ext4slower-bpfcc per veure quines operacions concretes triguen.
  • Canvis de context molt alts amb tots dos baixos: contenció entre restic i un altre procés. runqlat-bpfcc ho confirmaria.

I dues hipòtesis alternatives que cal descartar abans de tocar res, perquè són més probables que un problema de maquinari:

# a) Ha crescut el volum de dades? Una copia mes gran triga mes.
$ sudo restic -r /srv/tramontana/backups/restic stats latest
$ du -sh /opt/tramontana/releases/*/ /home/operador/dades/

# b) S ha degradat la deduplicacio, o falta un prune?
$ sudo restic -r /srv/tramontana/backups/restic snapshots | wc -l
$ sudo restic -r /srv/tramontana/backups/restic stats --mode raw-data

Un repositori de restic sense forget --prune acumula dades i alenteix cada operació. Si la retenció GFS 14/8/12 va deixar d'executar-se, aquella és l'explicació més simple — i comprovar-ho és gratis. Abans de diagnosticar el maquinari, descarta l'avorrit.

Nota final de mètode: l'ionice que es va posar a 05-07 continua aplicant-se i és correcte que el procés cedeixi E/S. Però si la còpia ja no cap a la seva finestra, ionice deixa de ser suficient i cal atacar la causa, no el símptoma.

Solució 2

$ cat ~/scripts/diagnostic_latencia.sh
#!/usr/bin/env bash
# diagnostic_latencia.sh - Diagnostic guiat de latencia d un servei.
#   Executa els passos 2, 3 i 4 de la metodologia: comptadors, perf stat i
#   strace -c, i produeix un informe llegible.
# Us: diagnostic_latencia.sh [-d segons] [-o fitxer] <unitat.service>
# Sortida: 0 informe generat | 64 us incorrecte | 69 falta una eina
set -euo pipefail

readonly SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)"
# shellcheck source=lib/comuns.sh
source "${SCRIPT_DIR}/lib/comuns.sh"

readonly ETIQUETA_LOG="diagnostic-latencia"
readonly DURADA_PER_DEFECTE=10

us() {
    sed -n '2,6s/^# \?//p' "$0"
}

seccio() {
    printf '\n===== %s =====\n\n' "$1" >>"$INFORME"
}

main() {
    local durada="${TRAMONTANA_DIAG_DURADA:-$DURADA_PER_DEFECTE}"
    local sortida=""

    while getopts ":d:o:h" opcio; do
        case "$opcio" in
            d) durada="$OPTARG" ;;
            o) sortida="$OPTARG" ;;
            h) us; return 0 ;;
            *) us >&2; morir 64 "opcio no valida: -$OPTARG" ;;
        esac
    done
    shift $((OPTIND - 1))

    local unitat="${1:-}"
    [[ -n "$unitat" ]] || { us >&2; morir 64 "falta la unitat de systemd"; }
    es_numero "$durada" || morir 64 "la durada ha de ser un numero"

    requereix_comanda systemctl
    requereix_comanda vmstat
    requereix_comanda iostat

    # Un sol temporal, netejat per trap: convencio de 04-06
    local tmp
    tmp="$(mktemp -d)"
    INFORME="${sortida:-${tmp}/informe.txt}"
    readonly INFORME
    trap 'rm -rf "$tmp"' EXIT

    # El PID principal es la font de veritat; pgrep podria agafar un altre proces
    local pid
    pid="$(systemctl show "$unitat" -p MainPID --value)"
    [[ "$pid" =~ ^[0-9]+$ && "$pid" -gt 0 ]] \
        || morir 69 "la unitat $unitat no te un proces principal actiu"

    log "diagnosticant $unitat (PID $pid) durant ${durada}s"

    {
        printf 'INFORME DE DIAGNOSTIC DE LATENCIA\n'
        printf 'Unitat:    %s\n' "$unitat"
        printf 'PID:       %s\n' "$pid"
        printf 'Maquina:   %s\n' "$(hostname)"
        printf 'Durada:    %ss\n' "$durada"
    } >"$INFORME"

    # ---- Pas 2: comptadors. Cost nul, s executa sempre. ----
    seccio "PAS 2 - COMPTADORS (metode USE)"
    {
        printf '# CPU i memoria (vmstat)\n'
        vmstat 2 3
        printf '\n# Disc (iostat -xz)\n'
        iostat -xz 2 2 | sed -n '/Device/,$p'
        printf '\n# Memoria (free -h)\n'
        free -h
        printf '\n# Socols del proces (ss)\n'
        ss -tanp 2>/dev/null | grep -F "pid=${pid}," || printf '(cap)\n'
    } >>"$INFORME" 2>&1

    # ---- Pas 3: perf stat. Cost ~nul, requereix root. ----
    seccio "PAS 3 - PERF STAT (treballa o espera?)"
    if command -v perf >/dev/null 2>&1; then
        sudo perf stat -p "$pid" -- sleep "$durada" >>"$INFORME" 2>&1 || \
            printf '(perf stat ha fallat: comptadors no disponibles en aquesta VM?)\n' >>"$INFORME"
    else
        printf '(perf no instal·lat: apt install linux-tools-%s)\n' "$(uname -r)" >>"$INFORME"
    fi

    # ---- Pas 4: strace -c. COSTOS: sempre amb timeout i nomes el resum. ----
    seccio "PAS 4 - STRACE -c (on se n va el temps de crides al sistema)"
    printf 'ATENCIO: strace alenteix el proces. Nomes resum, amb limit.\n\n' >>"$INFORME"
    if command -v strace >/dev/null 2>&1; then
        # Amb sudo: ignora ptrace_scope sense tocar el sysctl (veure 06-06).
        # || true perque timeout retorna 124 en tallar, i aixo es l esperat.
        sudo timeout "$durada" strace -f -c -p "$pid" >>"$INFORME" 2>&1 || true
    else
        printf '(strace no instal·lat)\n' >>"$INFORME"
    fi

    # ---- Extra: eBPF si esta disponible. Cost molt baix. ----
    if command -v tcplife-bpfcc >/dev/null 2>&1; then
        seccio "EXTRA - CONNEXIONS (tcplife)"
        sudo timeout "$durada" tcplife-bpfcc 2>/dev/null \
            | awk -v p="$pid" 'NR==1 || $1==p' >>"$INFORME" || true
    fi

    seccio "PAS SEGUENT SUGGERIT"
    {
        printf 'Si CPUs utilized es ALT   -> perf record -g + grafic de flama\n'
        printf 'Si CPUs utilized es BAIX  -> offcputime-bpfcc (esta bloquejat)\n'
        printf 'Si domina connect/sendto  -> tcplife-bpfcc, tcpconnect-bpfcc\n'
        printf 'Si domina read/write      -> biolatency-bpfcc, ext4slower-bpfcc\n'
    } >>"$INFORME"

    if [[ -n "$sortida" ]]; then
        log "informe escrit a $sortida"
    else
        cat "$INFORME"
    fi
}

main "$@"
$ chmod +x ~/scripts/diagnostic_latencia.sh
$ shellcheck ~/scripts/diagnostic_latencia.sh && echo "sense avisos"
sense avisos
$ ~/scripts/diagnostic_latencia.sh -d 5 tramontana.service | head -20

Les decisions de disseny que fan que aquest script sigui utilitzable en producció i no un perill:

  1. MainPID en lloc de pgrep. systemctl show -p MainPID dona el procés que systemd considera principal. pgrep -f tramontana podria agafar el mateix script, un grep, o un procés d'un altre release.
  2. L'ordre dels passos és el de cost creixent, i strace va l'últim. Si el problema es veu al pas 2, ja tens la resposta abans de pagar res.
  3. sudo per a strace, mai tocar ptrace_scope. És la sortida A de la lliçó, i és l'única acceptable en un script que pot executar qualsevol.
  4. timeout obligatori a strace, amb || true perquè el codi 124 de timeout és el resultat esperat, no una fallada. Sense això, set -e avortaria l'script just abans d'escriure les conclusions.
  5. Degradació elegant. Si perf o eBPF no hi són, l'informe ho diu i continua. Un script de diagnòstic que falla perquè falta una eina opcional és inútil precisament quan més el necessites.
  6. Un mktemp -d amb trap, segons 04-06: no deixa residus ni en interrompre's.
  7. La secció final orienta el pas següent. L'script automatitza els passos mecànics; la interpretació continua sent humana, i donar a l'operador l'arbre de decisió és més útil que intentar concloure automàticament.

Solució 3

Resposta tècnica: proposta de fixar kernel.yama.ptrace_scope = 0

Què s'hi guanya. Poder executar strace, gdb i perf contra processos del mateix usuari sense sudo. A la pràctica això estalvia escriure quatre caràcters, perquè a srv-tramontana l'aplicació corre com a svc-tramontana i nosaltres com a operador: amb ptrace_scope = 0 continuaríem necessitant sudo, ja que el valor 0 només permet traçar processos del propi usuari. El benefici real de la proposta, en el nostre cas concret, és zero.

Què s'hi perd, exactament. ptrace permet llegir i escriure tota la memòria d'un altre procés. La memòria del procés de l'aplicació conté, en clar i necessàriament:

  • La contrasenya de la base de dades, que a 06-05 vam treure d'app.conf i vam xifrar amb systemd-creds precisament perquè no fos llegible.
  • La clau privada TLS, si el procés la carrega.
  • Les dades personals d'hostes de les peticions en curs.

Amb ptrace_scope = 0, qualsevol procés compromès que s'executi com el mateix usuari pot extreure tot allò sense tocar cap fitxer: sense escriptures que AIDE detecti, sense accessos que auditd registri a les rutes que vigilem, i sense deixar rastre als registres. És a dir, anul·laria a la pràctica la feina de dues lliçons senceres del mòdul anterior.

Concretant sobre el nostre model d'amenaces de 06-06: la segona amenaça per probabilitat és la credencial filtrada, i la quarta l'abús d'accés legítim. Aquesta proposta obre una via directa per a totes dues i no en tanca cap.

Alternatives, en ordre de preferència.

  1. Fer servir sudo. És la resposta correcta el 95 % de les vegades. CAP_SYS_PTRACE ignora la restricció de Yama, queda registrat a auth.log —cosa que és un avantatge, no un inconvenient— i no canvia la postura del sistema. Cost: cinc caràcters.
  2. Fer servir eBPF, que és millor eina. perf trace, tcplife-bpfcc, biolatency-bpfcc, offcputime-bpfcc i bpftrace no fan servir ptrace en absolut, així que ptrace_scope no els afecta. I són entre deu i cent vegades més barates, cosa que les fa les úniques realment aptes per a producció. Si la motivació de fons és «diagnosticar amb comoditat», aquesta és la resposta tècnica, no abaixar una protecció.
  3. Si de debò cal traçar sense privilegis, hi ha una via intermèdia: donar CAP_SYS_PTRACE únicament al binari de diagnòstic, en lloc d'obrir el sistema sencer:
    $ sudo setcap cap_sys_ptrace+ep /usr/bin/strace
    
    Reprenent les capabilities de 05-02. Continua sent un augment de superfície —qualsevol que pugui executar strace podrà traçar—, però acotat a un binari en lloc de a tot el sistema. Tot i així no ho recomano aquí: no resol el nostre cas real (usuaris diferents) i afegeix un binari privilegiat per auditar.
  4. Abaixar-lo temporalment, només durant una sessió de diagnòstic, amb restauració garantida per trap (~/scripts/tracar_temporal.sh). Acceptable al laboratori; en producció és innecessari atès el punt 2.

Recomanació. Mantenir kernel.yama.ptrace_scope = 1. La proposta no aporta cap benefici a la nostra configuració —continuaríem necessitant sudo— i obre una via d'extracció de credencials i dades personals que no deixa rastre. Si el problema de fons és la fricció en diagnosticar, la solució és instal·lar i aprendre bpfcc-tools i bpftrace, que a més ens permetran diagnosticar en producció i amb càrrega, cosa que strace no permet en cap cas.

Hi afegeixo dues notes per al manual d'operació: el valor 1 està documentat a /etc/sysctl.d/60-enfortiment.conf amb un comentari que ja advertia d'aquest efecte secundari; i convé registrar aquí que el diagnòstic de l'incident de latència d'aquesta setmana es va resoldre íntegrament amb eBPF i sudo strace, sense necessitat de tocar el paràmetre.

Conclusió

Ja saps mirar dins d'un procés en marxa. Tens tres famílies d'eines i —el més important— el criteri per triar entre elles: els comptadors del Mòdul 5 responen a quant i són gratis, perf stat diu si un procés treballa o espera amb un cost menyspreable, eBPF instrumenta el nucli en producció amb histogrames que revelen les cues que les mitjanes amaguen, i strace dona la resposta exacta a costa d'alentir el procés fins a cent vegades. L'ordre comptadors → perf stat → eBPF → strace és la lliçó pràctica que cal endur-se, juntament amb la línia que resol la meitat dels misteris de configuració: strace -e trace=%file | grep ENOENT.

Has resolt un cas complet seguint la metodologia: símptoma mesurat i reproduïble, hipòtesis descartades amb comptadors gratuïts, i cinc mesures independents convergint en la mateixa causa —un max_connexions=200 contra un max_connections=100, un desajust que feia tres mòduls que hi era— amb la correcció verificada de 400 ms a 40 ms. I t'has topat amb la conseqüència del teu propi enfortiment: el ptrace_scope = 1 que impedeix traçar sense privilegis, que resulta que està bé perquè la memòria d'un procés conté en clar exactament els secrets que tanta feina va costar xifrar. Que la solució correcta a aquella fricció sigui fer servir eBPF, i no abaixar la protecció, és la classe de decisió que distingeix un administrador d'algú que segueix receptes.

Fixa't en un detall d'aquest diagnòstic que orienta el que ve: la causa era un valor de configuració, i el vas trobar comparant dos costats d'una mateixa relació. Aquell és el terreny de la lliçó següent, amb una diferència important: aquí el valor era a l'aplicació, i ara tocaràs els del nucli. A la lliçó 07-03: Optimització del Nucli de Linux aprendràs a ajustar sysctl per rendiment —no per seguretat, que ja ho vas fer a 06-06—: la memòria virtual amb swappiness i els llindars de pàgines brutes, la xarxa amb somaxconn i el control de congestió BBR, els límits de fitxers i processos, el planificador d'E/S i per què un NVMe vol none, i les pàgines enormes transparents que tota base de dades demana desactivar. Veuràs també els mòduls del nucli, dkms, i una resposta honesta a si compilar el nucli té sentit en un servidor de producció. I ho faràs amb la regla que governa tot l'assumpte i que aquesta lliçó ja t'ha ensenyat a aplicar: no s'ajusta el que no s'ha mesurat, un sol canvi cada vegada, i mesurar abans i després. Recorda que el somaxconn per defecte continua allà, i que aquell errors.log amb connexions_actives=200 tenia més d'una causa.

Curs de Linux: De Principiant a Administrador de Sistemes

Mòdul 1: Introducció a Linux

Mòdul 2: Comandes Bàsiques de Linux

Mòdul 3: Habilitats Avançades en la Línia de Comandes

Mòdul 4: Scripting en Shell

Mòdul 5: Administració del Sistema

Mòdul 6: Xarxes i Seguretat

Mòdul 7: Temes Avançats

Mòdul 8: Projectes Pràctics

© Copyright 2026. Tots els drets reservats