Sommaire

Une des activités des admin systèmes ou réseaux c’est d’extraire des informations d’un fichier de log, pour détecter une erreur, faire des stats ou de la métrologie.

Pour lire ligne à ligne le fichier et l’analyser on peut utiliser une boucle for ou une boucle while. Le traitement à l’intérieur de la boucle va rester le même, mais regardons ce qui se produit en dehors de la boucle et les différences de performance entre les deux méthodes.

extrait du fichier de log :

 12015-08-04 23:07:08 startup archives unpack
 22015-08-04 23:07:09 upgrade libapt-pkg4.12:amd64 1.0.1ubuntu2.8 1.0.1ubuntu2.10
 32015-08-04 23:07:09 status half-configured libapt-pkg4.12:amd64 1.0.1ubuntu2.8
 42015-08-04 23:07:09 status unpacked libapt-pkg4.12:amd64 1.0.1ubuntu2.8
 52015-08-04 23:07:09 status half-installed libapt-pkg4.12:amd64 1.0.1ubuntu2.8
 62015-08-04 23:07:09 status half-installed libapt-pkg4.12:amd64 1.0.1ubuntu2.8
 72015-08-04 23:07:09 status unpacked libapt-pkg4.12:amd64 1.0.1ubuntu2.10
 82015-08-04 23:07:09 status unpacked libapt-pkg4.12:amd64 1.0.1ubuntu2.10
 92015-08-04 23:07:09 startup packages configure
102015-08-04 23:07:09 configure libapt-pkg4.12:amd64 1.0.1ubuntu2.10 <none>
112015-08-04 23:07:09 status unpacked libapt-pkg4.12:amd64 1.0.1ubuntu2.10
122015-08-04 23:07:09 status half-configured libapt-pkg4.12:amd64 1.0.1ubuntu2.10
132015-08-04 23:07:09 status installed libapt-pkg4.12:amd64 1.0.1ubuntu2.10
142015-08-04 23:07:09 status triggers-pending libc-bin:amd64 2.19-0ubuntu6.6
152015-08-04 23:07:09 trigproc libc-bin:amd64 2.19-0ubuntu6.6 <none>
162015-08-04 23:07:09 status half-configured libc-bin:amd64 2.19-0ubuntu6.6
172015-08-04 23:07:10 status installed libc-bin:amd64 2.19-0ubuntu6.6
182015-08-04 23:07:10 startup archives unpack
192015-08-04 23:07:10 upgrade apt:amd64 1.0.1ubuntu2.8 1.0.1ubuntu2.10
202015-08-04 23:07:10 status half-configured apt:amd64 1.0.1ubuntu2.8
212015-08-04 23:07:10 status unpacked apt:amd64 1.0.1ubuntu2.8
222015-08-04 23:07:10 status half-installed apt:amd64 1.0.1ubuntu2.8
232015-08-04 23:07:10 status triggers-pending man-db:amd64 2.6.7.1-1ubuntu1
242015-08-04 23:07:11 status half-installed apt:amd64 1.0.1ubuntu2.8
252015-08-04 23:07:11 status unpacked apt:amd64 1.0.1ubuntu2.10
262015-08-04 23:07:11 status unpacked apt:amd64 1.0.1ubuntu2.10
272015-08-04 23:07:11 trigproc man-db:amd64 2.6.7.1-1ubuntu1 2.6.7.1-1ubuntu1
282015-08-04 23:07:11 status half-configured man-db:amd64 2.6.7.1-1ubuntu1
292015-08-04 23:07:12 status installed man-db:amd64 2.6.7.1-1ubuntu1
302015-08-04 23:07:12 startup packages configure
312015-08-04 23:07:12 configure apt:amd64 1.0.1ubuntu2.10 <none>
322015-08-04 23:07:12 status unpacked apt:amd64 1.0.1ubuntu2.10
332015-08-04 23:07:12 status unpacked apt:amd64 1.0.1ubuntu2.10
342015-08-04 23:07:12 status unpacked apt:amd64 1.0.1ubuntu2.10
352015-08-04 23:07:12 status unpacked apt:amd64 1.0.1ubuntu2.10
362015-08-04 23:07:12 status unpacked apt:amd64 1.0.1ubuntu2.10
372015-08-04 23:07:12 status unpacked apt:amd64 1.0.1ubuntu2.10
382015-08-04 23:07:12 status half-configured apt:amd64 1.0.1ubuntu2.10
392015-08-04 23:07:12 status installed apt:amd64 1.0.1ubuntu2.10
402015-08-04 23:07:12 status triggers-pending libc-bin:amd64 2.19-0ubuntu6.6
412015-08-04 23:07:12 trigproc libc-bin:amd64 2.19-0ubuntu6.6 <none>
422015-08-04 23:07:12 status half-configured libc-bin:amd64 2.19-0ubuntu6.6
432015-08-04 23:07:12 status installed libc-bin:amd64 2.19-0ubuntu6.6
442015-08-04 23:07:12 startup archives unpack
452015-08-04 23:07:12 upgrade libapt-inst1.5:amd64 1.0.1ubuntu2.8 1.0.1ubuntu2.10
462015-08-04 23:07:12 status half-configured libapt-inst1.5:amd64 1.0.1ubuntu2.8

On veut par exemple extraire le nom du package et sa version (pas celle du programme, juste la version de package)

Cas de la boucle for

Lorsque la boucle for lit tour à tour les informations envoyées par cat elle va parser les chaînes en utilisants les séparateurs de champs afin de positionner la variable i correctement.
Par défaut le séparateur de champs comporte l’espace, la tabulation et le retour chariot. Dans ce cas i va recevoir 2015-08-04 puis 23:07:08 puis startup et ainsi de suite.
Pour éviter cela il faut dire au shell que le séparateur de champs est seulement le retour chariot en initialisant la variable IFS=$'\n'.

 1#!/bin/bash
 2
 3IFS=$'\n'
 4(for i in $(cat dpkg.log)
 5do
 6
 7        status=$(echo "$i" | cut -d ' ' -f 3)
 8
 9        case $status in
10
11                configure|upgrade|configure|trigproc)
12                        field=4
13                        ;;
14                status)
15                        field=5
16                        ;;
17                startup)
18                        continue
19
20        esac
21
22        pkg=$(echo "$i" | cut -d ' ' -f $field | cut -d ':' -f 1)
23        ver=$(echo "$i" | cut -d ' ' -f $(($field + 1))) 
24        echo $pkg:${ver##*-}
25done
26
27echo "The last one : "$pkg:${ver##*-}
28
29) | uniq
...
man-db:1ubuntu1
cowsay:6
linux-firmware:1.127.14
linux-firmware:1.127.15
qemu-utils:2ubuntu1.15
man-db:1ubuntu1
qemu-utils:2ubuntu1.15
qemu-utils:2ubuntu1.16
man-db:1ubuntu1
linux-firmware:1.127.15
qemu-utils:2ubuntu1.16
The last one : qemu-utils:2ubuntu1.16

la dernière ligne affiche le dernier élément traité, on récupère bien les valeurs des variables initialisées à l’intérieur de la boucle.

Cas de la boucle while

Dans ce cas, nullement besoin d’initialiser la variable IFS car c’est la commande read qui va lire les données tour à tour et initialiser i à chaque retour chariot.

 1#!/bin/bash
 2
 3(cat dpkg.log | while read i
 4do
 5
 6        status=$(echo "$i" | cut -d ' ' -f 3)
 7
 8        case $status in
 9
10                configure|upgrade|configure|trigproc)
11                        field=4
12                        ;;
13                status)
14                        field=5
15                        ;;
16                startup)
17                        continue
18
19        esac
20
21        pkg=$(echo "$i" | cut -d ' ' -f $field | cut -d ':' -f 1)
22        ver=$(echo "$i" | cut -d ' ' -f $(($field + 1))) 
23        echo $pkg:${ver##*-}
24done
25
26echo "The last one : "$pkg:${ver##*-}
27
28) | uniq
...
man-db:1ubuntu1
cowsay:6
linux-firmware:1.127.14
linux-firmware:1.127.15
qemu-utils:2ubuntu1.15
man-db:1ubuntu1
qemu-utils:2ubuntu1.15
qemu-utils:2ubuntu1.16
man-db:1ubuntu1
linux-firmware:1.127.15
qemu-utils:2ubuntu1.16
The last one : :

Contrairement à la boucle for on ne récupère pas les valeurs des variables initialisées dans la boucle while. Cela s’explique facilement par le fait que le while s’exécute dans un shell fils, initié par le pipe. Le processus père ne peut pas hériter des variables initialisées par le fils.

Performances

Les deux programmes sont très similaires et les performances aussi.

du -hs dpkg.log
52K	dpkg.log

time (./bouclefor.sh > /dev/null)

real	0m4.648s
user	0m0.716s
sys	0m5.786s

time (./bouclewhile.sh > /dev/null)

real	0m4.929s
user	0m0.728s
sys	0m6.161s
du -hs dpkg.log
572K	dpkg.log

time (./bouclefor.sh > /dev/null)

real	0m57.860s
user	0m8.416s
sys	1m12.783s

time (./bouclewhile.sh > /dev/null)

real	0m53.357s
user	0m8.210s
sys	1m7.005s

A la première exécution (sur le fichier de 52KB) on peut penser que la boucle for est plus performante que la boucle while, ce qui pourrait s’expliquer par le fait que dans la cas de la boucle while il y a un processus fils lancé en plus, mais qu’au final sur une taille plus grande (fichier de 572KB) le read est plus performant. Ma machine étant multi-core ça peut aussi biaiser les mesures.

A la suite d’une remarque de Mathieu D. par mail qui me suggère d’utiliser while avec une redirection sur le stdin, ce qui est une excellente idée. On gagne encore 2 secondes sur le traitement.

 1#!/bin/bash
 2
 3(
 4while read  i
 5do
 6
 7        status=$(echo "$i" | cut -d ' ' -f 3)
 8
 9        case $status in
10
11                configure|upgrade|configure|trigproc)
12                        field=4
13                        ;;
14                status)
15                        field=5
16                        ;;
17                startup)
18                        continue
19
20        esac
21
22        #echo "$i"
23        pkg=$(echo "$i" | cut -d ' ' -f $field | cut -d ':' -f 1)
24        ver=$(echo "$i" | cut -d ' ' -f $(($field + 1))) 
25        echo $pkg:${ver##*-}
26done < dpkg.log
27
28echo "The last one : "$pkg:${ver##*-}
29
30) | uniq
time (./bouclewhile2.sh > /dev/null)

real	0m52.195s
user	0m8.280s
sys	1m5.918s

De plus on peut utiliser des here strings <<< pour envoyer une commande plus complexe. Par contre il ne faut pas oublier les doubles quote, sinon tout est renvoyé sur une seule ligne.

 1#!/bin/bash
 2
 3(
 4while read  i
 5do
 6
 7        status=$(echo "$i" | cut -d ' ' -f 3)
 8
 9        case $status in
10
11                configure|upgrade|configure|trigproc)
12                        field=4
13                        ;;
14                status)
15                        field=5
16                        ;;
17                startup)
18                        continue
19
20        esac
21
22        #echo "$i"
23        pkg=$(echo "$i" | cut -d ' ' -f $field | cut -d ':' -f 1)
24        ver=$(echo "$i" | cut -d ' ' -f $(($field + 1))) 
25        echo $pkg:${ver##*-}
26done <<< "$(grep status dpkg.log)"
27
28echo "The last one : "$pkg:${ver##*-}
29
30) | uniq