DTrace est un outil extrêmement puissant de compréhension du comportement des processus utilisateur. DTrace peut s'avérer précieux lors du débogage, de l'analyse des problèmes de performance ou de la simple compréhension du comportement d'une application complexe. Ce chapitre présente les fonctions de DTrace dédiées au suivi de l'activité des processus utilisateur, ainsi que des exemples illustrant leur utilisation.
L'interaction de DTrace avec les processus diffère légèrement de la plupart des débogueurs ou des outils d'observation classiques. La plupart de ces outils s'exécutent dans l'étendue du processus, ce qui permet aux utilisateurs de déréférencer les pointeurs pour programmer directement les variables. Plutôt que de s'exécuter dans le cadre ou au sein du processus lui-même, les sondes de DTrace s'exécutent dans le noyau de Solaris. Pour accéder aux données du processus, une sonde doit utiliser les sous-routines copyin() ou copyinstr() pour copier les données de processus utilisateur dans l'espace d'adressage du noyau.
Étudiez, par exemple, l'appel système write(2) suivant :
ssize_t write(int fd, const void *buf, size_t nbytes);
Le programme en D suivant illustre une tentative erronée d'impression du contenu d'une chaîne transmise à l'appel système write(2).
syscall::write:entry { printf("%s", stringof(arg1)); /* incorrect use of arg1 */ }
Si vous essayez d'exécuter ce script, DTrace crée des messages d'erreur similaires à l'exemple suivant :
dtrace: error on enabled probe ID 1 (ID 37: syscall::write:entry): \ invalid address (0x10038a000) in action #1 |
La variable arg1, contenant la valeur du paramètre buf, correspond à une adresse renvoyant à la mémoire dans le processus exécutant le système d'appel. Pour lire la chaîne à cette adresse, utilisez la sous-routine copyinstr() et enregistrez son résultat avec l'action printf() :
syscall::write:entry { printf("%s", copyinstr(arg1)); /* correct use of arg1 */
La sortie de ce script présente toutes les chaînes dont la transmission à l'appel système write(2) est en cours. Il se peut, cependant, que vous constatiez occasionnellement des sorties irrégulières similaires à l'exemple suivant :
0 37 write:entry mada��� |
La sous-routine copyinstr() prend en charge un argument d'entrée correspondant à l'adresse utilisateur d'une chaîne ASCII nulle terminée. Cependant, les tampons transmis à l'appel système write(2) peuvent renvoyer à des données binaires plutôt qu'à des chaînes ASCII. Pour n'imprimer que le nombre de chaînes prévu par le programme appelant, utilisez la sous-routine copyin() dont le second argument correspond à une taille :
syscall::write:entry { printf("%s", stringof(copyin(arg1, arg2))); }
Notez l'utilisation obligatoire de l'opérateur stringof de sorte que DTrace convertisse correctement les données utilisateur récupérées à l'aide de copyin() vers une chaîne. L'utilisation de stringof ne s'impose pas si vous utilisez copyinstr() car cette fonction retourne toujours le type string.
Les sous-routines copyin() et copyinstr() ne peuvent pas lire les adresses utilisateur qui n'ont pas encore été touchées. Par conséquent, même une adresse valide peut provoquer une erreur si la page contenant cette adresse n'a pas déjà subi de défaillance lors de l'accès. Examinez l'exemple suivant :
# dtrace -n syscall::open:entry'{ trace(copyinstr(arg0)); }' dtrace: description 'syscall::open:entry' matched 1 probe CPU ID FUNCTION:NAME dtrace: error on enabled probe ID 2 (ID 50: syscall::open:entry): invalid address (0x9af1b) in action #1 at DIF offset 52 |
Dans la sortie de l'exemple ci-dessus, l'application fonctionnait correctement et l'adresse dans arg0 était valide mais renvoyait à une page à laquelle le processus correspondant n'avait pas encore accédé. Pour résoudre ce problème, attendez que le noyau ou l'application utilisent les données avant de procéder au suivi. Attendez, par exemple, le retour de l'appel système pour appliquer copyinstr(), comme illustré dans l'exemple suivant :
# dtrace -n syscall::open:entry'{ self->file = arg0; }' \ -n syscall::open:return'{ trace(copyinstr(self->file)); self->file = 0; }' dtrace: description 'syscall::open:entry' matched 1 probe CPU ID FUNCTION:NAME 2 51 open:return /dev/null |
Si vous suivez chaque appel vers l'appel système write(2), vous allez créer une cascade de sortie. Suite à chaque appel de la fonction write(), la commande dtrace(1M) appelle la fonction write() lorsqu'elle affiche la sortie. Cette boucle d'évaluation est un bon exemple de la manière dont la commande dtrace peut interférer avec les données souhaitées. Vous pouvez utiliser un simple prédicat pour empêcher le suivi des données non désirées :
syscall::write:entry /pid != $pid/ { printf("%s", stringof(copyin(arg1, arg2))); }
La variable de macro $pid développe l'identifiant de processus du processus qui a activé les sondes. La variable pid contient l'identifiant de processus du processus dont le thread est exécuté sur la CPU sur laquelle la sonde a été déclenchée. Par conséquent, le prédicat /pid != $pid/ garantit que le script n'assure le suivi d'aucun événement lié à l'exécution de ce script.
Le fournisseur syscall vous permet de suivre chaque entrée et retour d'appel système. Les appels système peuvent constituer un excellent point de départ à la compréhension du comportement d'un processus, notamment si le temps d'exécution ou de blocage de ce dernier dans le noyau est considérable. Vous pouvez utiliser la commande prstat(1M) pour déterminer à quelles activités ces processus consacrent du temps :
$ prstat -m -p 31337 PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/NLWP 13499 user1 53 44 0.0 0.0 0.0 0.0 2.5 0.0 4K 24 9K 0 mystery/6 |
Cet exemple montre que le processus utilise un temps système considérable. Ce comportement peut notamment s'expliquer par le fait que ce processus exécute un grand nombre d'appels système. Vous pouvez utiliser un programme en D simple spécifié sur la ligne de commande pour déterminer les appels système les plus fréquents :
# dtrace -n syscall:::entry'/pid == 31337/{ @syscalls[probefunc] = count(); }' dtrace: description 'syscall:::entry' matched 215 probes ^C open 1 lwp_park 2 times 4 fcntl 5 close 6 sigaction 6 read 10 ioctl 14 sigprocmask 106 write 1092 |
Ce rapport indique les appels systèmes les plus fréquents. Dans cet exemple, il s'agit de l'appel système write(2). Vous pouvez utiliser le fournisseur syscall pour examiner plus attentivement la source de tous les appels système write() :
# dtrace -n syscall::write:entry'/pid == 31337/{ @writes[arg2] = quantize(arg2); }' dtrace: description 'syscall::write:entry' matched 1 probe ^C value ------------- Distribution ------------- count 0 | 0 1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1037 2 |@ 3 4 | 0 8 | 0 16 | 0 32 |@ 3 64 | 0 128 | 0 256 | 0 512 | 0 1024 |@ 5 2048 | 0 |
La sortie indique que le processus exécute de nombreux appels système write() avec une quantité de données relativement faible. Ce ratio pourrait bien être à l'origine du problème de performances de ce processus particulier. Cet exemple illustre une méthodologie générale d'étude du comportement d'un appel système.
Il est souvent utile de suivre une pile de thread de processus au moment précis de l'activation d'une sonde pour examiner un problème plus en détails. L'action de la fonction ustack() suit la pile du thread utilisateur. Si, par exemple, un processus ouvrant plusieurs fichiers rencontre occasionnellement une défaillance dans l'appel système open(2), vous pouvez utiliser l'action de la fonction ustack() pour rechercher le chemin d'accès au code exécutant la fonction open() en échec :
syscall::open:entry /pid == $1/ { self->path = copyinstr(arg0); } syscall::open:return /self->path != NULL && arg1 == -1/ { printf("open for '%s' failed", self->path); ustack(); }
Ce script illustre également l'utilisation de la variable de macro $1 qui récupère la valeur du premier opérande spécifié sur la ligne de commande de dtrace(1M).
# dtrace -s ./badopen.d 31337 dtrace: script './badopen.d' matched 2 probes CPU ID FUNCTION:NAME 0 40 open:return open for '/usr/lib/foo' failed libc.so.1`__open+0x4 libc.so.1`open+0x6c 420b0 tcsh`dosource+0xe0 tcsh`execute+0x978 tcsh`execute+0xba0 tcsh`process+0x50c tcsh`main+0x1d54 tcsh`_start+0xdc |
L'action de la fonction ustack() enregistre les valeurs (PC) du compteur du programme pour la pile et dtrace(1M) résout ces valeurs PC pour symboliser les noms en effectuant une recherche dans les tables des symboles du processus. Si dtrace ne parvient pas à retrouver le symbole d'une valeur PC, cette dernière est imprimée sous la forme d'un entier hexadécimal.
Si un processus se termine ou est avorté avant le formatage final des données de la fonction ustack(), dtrace risque de ne pas pouvoir convertir les valeurs PC du suivi de pile en noms de symbole et devra les afficher sous forme de nombres hexadécimaux. Pour contourner cette restriction, spécifiez un processus qui vous intéresse avec l'option -dtrace -c ou p. Pour plus d'informations sur ces options (et bien d'autres), reportez-vous au Chapitre14Utilitaire dtrace(1M). En cas d'ignorance préalable de la commande ou de l'ID de processus, vous pouvez utiliser l'exemple suivant de programme en D pour contourner cette restriction :
/* * This example uses the open(2) system call probe, but this technique * is applicable to any script using the ustack() action where the stack * being traced is in a process that may exit soon. */ syscall::open:entry { ustack(); stop_pids[pid] = 1; } syscall::rexit:entry /stop_pids[pid] != 0/ { printf("stopping pid %d", pid); stop(); stop_pids[pid] = 0; }
Le script ci-dessus interrompt un processus juste avant qu'il ne se termine si l'action de la fonction ustack() a été appliquée à un thread dans ce processus. Grâce à cette technique, la commande dtrace peut résoudre les valeurs PC en noms symboliques. Notez que la valeur de stop_pids[pid] est réglée sur 0 après avoir servi à supprimer la variable dynamique. N'oubliez pas de configurer la réexécution des processus interrompus à l'aide de la commande prun(1). Dans le cas contraire, votre système accumulera de nombreux processus interrompus.
Le tableau uregs[] vous permet d'accéder aux enregistrements utilisateur individuels. Les tables suivantes répertorient les index dans le tableau uregs[] correspondant à chaque architecture système Solaris prise en charge.
Tableau 33–1 Constantes uregs[] pour SPARC
Constante |
Enregistrer |
---|---|
R_G0..R_G7 |
Enregistrements globaux %g0..%g7 |
R_O0..R_O7 |
Enregistrements en sortie %o0..%o7 |
R_L0..R_L7 |
Enregistrements locaux %l0..%l7 |
R_I0..R_I7 |
Enregistrements en entrée %i0..%i7 |
R_CCR |
Enregistrement du code de condition %ccr |
R_PC |
Compteur de programme %pc |
R_NPC |
Compteur de programme suivant %npc |
R_Y |
Multiplier/diviser l'enregistrement %y |
R_ASI |
Enregistrement de l'identificateur d'espace d'adressage %asi |
R_FPRS |
État des enregistrements en virgule flottante %fprs |
Tableau 33–2 Constantes de uregs[] pour x86
Constante |
Enregistrer |
---|---|
R_CS |
%cs |
R_GS |
%gs |
R_ES |
%es |
R_DS |
%ds |
R_EDI |
%edi |
R_ESI |
%esi |
R_EBP |
%ebp |
R_EAX |
%eax |
R_ESP |
%esp |
R_EAX |
%eax |
R_EBX |
%ebx |
R_ECX |
%ecx |
R_EDX |
%edx |
R_TRAPNO |
%trapno |
R_ERR |
%err |
R_EIP |
%eip |
R_CS |
%cs |
R_ERR |
%err |
R_EFL |
%efl |
R_UESP |
%uesp |
R_SS |
%ss |
Sur les plates-formes AMD64, le tableau uregs possède le même contenu que sur les plates-formes x86, plus les éléments supplémentaires répertoriés dans la table suivante :
Tableau 33–3 Constantes uregs[] pour amd64
Constante |
Enregistrer |
---|---|
R_RSP |
%rsp |
R_RFL |
%rfl |
R_RIP |
%rip |
R_RAX |
%rax |
R_RCX |
%rcx |
R_RDX |
%rdx |
R_RBX |
%rbx |
R_RBP |
%rbp |
R_RSI |
%rsi |
R_RDI |
%rdi |
R_R8 |
%r8 |
R_R9 |
%r9 |
R_R10 |
%r10 |
R_R11 |
%r11 |
R_R12 |
%r12 |
R_R13 |
%r13 |
R_R14 |
%r14 |
R_R15 |
%r15 |
Les alias répertoriés dans la table suivante sont utilisables sur toutes les plates-formes :
Tableau 33–4 Constantes uregs[] communes
Constante |
Enregistrer |
---|---|
R_PC |
Enregistrement du compteur de programme |
R_SP |
Enregistrement du pointeur de pile |
R_R0 |
Premier code de retour |
R_R1 |
Second code de retour |
Le fournisseur pid vous permet de suivre toutes les instructions d'un processus. Contrairement à la plupart des autres fournisseurs, les sondes pid sont créées à la demande en fonction des descriptions de sonde figurant dans vos programmes en D. En conséquence, aucune sonde pid n'est répertoriée dans la sortie de dtrace -l tant que vous ne les activez pas vous-même.
Le mode de fonctionnement le plus simple du fournisseur pid est, tout comme l'espace utilisateur, analogue au fournisseur fbt. L'exemple de programme suivant suit toutes les entrées et tous les renvois de fonction effectués à partir d'une fonction simple. La variable de macro $1 (le premier opérande sur la ligne de commande) correspond à l'ID de processus du processus à suivre. La variable de macro $2 (le second opérande sur la ligne de commande) correspond au nom de la fonction à partir de laquelle les appels de fonction doivent être suivis.
pid$1::$2:entry { self->trace = 1; } pid$1::$2:return /self->trace/ { self->trace = 0; } pid$1:::entry, pid$1:::return /self->trace/ { }
Saisissez l'exemple de script ci-dessus et enregistrez-le dans le fichier userfunc.d, puis appliquez-lui la commande chmod pour le rendre exécutable. Ce script engendre une sortie similaire à l'exemple suivant :
# ./userfunc.d 15032 execute dtrace: script './userfunc.d' matched 11594 probes 0 -> execute 0 -> execute 0 -> Dfix 0 <- Dfix 0 -> s_strsave 0 -> malloc 0 <- malloc 0 <- s_strsave 0 -> set 0 -> malloc 0 <- malloc 0 <- set 0 -> set1 0 -> tglob 0 <- tglob 0 <- set1 0 -> setq 0 -> s_strcmp 0 <- s_strcmp ... |
Vous ne pouvez utiliser le fournisseur pid que sur les processus dont l'exécution est déjà en cours. Vous pouvez utiliser la variable de macro $target (reportez-vous au Chapitre15Scripts) et les options dtrace -c et -p pour créer et extraire les processus qui vous intéressent, puis les instrumenter à l'aide de DTrace. Par exemple, vous pouvez utiliser l'exemple de script en D suivant pour déterminer la répartition des appels de fonction exécutés vers libc par un processus sujet particulier :
pid$target:libc.so::entry { @[probefunc] = count(); }
Pour déterminer la répartition des appels exécutés par la commande date(1), enregistrez le script dans le fichier libc.d et exécutez la commande suivante :
# dtrace -s libc.d -c date dtrace: script 'libc.d' matched 2476 probes Fri Jul 30 14:08:54 PDT 2004 dtrace: pid 109196 has exited pthread_rwlock_unlock 1 _fflush_u 1 rwlock_lock 1 rw_write_held 1 strftime 1 _close 1 _read 1 __open 1 _open 1 strstr 1 load_zoneinfo 1 ... _ti_bind_guard 47 _ti_bind_clear 94 |
Vous pouvez utiliser le fournisseur pid pour suivre une instruction dans une fonction utilisateur. Le fournisseur pid crée une sonde à la demande pour chaque instruction d'une fonction. Le nom de chaque sonde correspond au décalage de l'instruction correspondante dans la fonction exprimée sous la forme d'un entier hexadécimal. Par exemple, pour activer une sonde associée à l'instruction au niveau du décalage 0x1c dans la fonction foo du module bar.so dans le processus avec PID 123, vous pouvez utiliser la commande suivante :
# dtrace -n pid123:bar.so:foo:1c |
Pour activer toutes les sondes de la fonction foo, y compris la sonde de chaque instruction, vous pouvez utiliser la commande :
# dtrace -n pid123:bar.so:foo: |
Cette commande fait preuve d'une technique extrêmement puissante de débogage et d'analyse des applications utilisateur. Il peut s'avérer difficile de déboguer les erreurs peu fréquentes car elles peuvent être difficiles à reproduire. En règle générale, vous pouvez identifier un problème après l'apparition de la défaillance, soit trop tard pour reconstruire le chemin d'accès au code. L'exemple suivant montre la méthode de combinaison du fournisseur pid avec le suivi spéculatif (reportez-vous au Chapitre13Suivi spéculatif) pour résoudre ce problème en suivant chaque instruction d'une fonction.
pid$1::$2:entry { self->spec = speculation(); speculate(self->spec); printf("%x %x %x %x %x", arg0, arg1, arg2, arg3, arg4); } pid$1::$2: /self->spec/ { speculate(self->spec); } pid$1::$2:return /self->spec && arg1 == 0/ { discard(self->spec); self->spec = 0; } pid$1::$2:return /self->spec && arg1 != 0/ { commit(self->spec); self->spec = 0; }
L'exécution de errorpath.d produit une sortie similaire à l'exemple suivant :
# ./errorpath.d 100461 _chdir dtrace: script './errorpath.d' matched 19 probes CPU ID FUNCTION:NAME 0 25253 _chdir:entry 81e08 6d140 ffbfcb20 656c73 0 0 25253 _chdir:entry 0 25269 _chdir:0 0 25270 _chdir:4 0 25271 _chdir:8 0 25272 _chdir:c 0 25273 _chdir:10 0 25274 _chdir:14 0 25275 _chdir:18 0 25276 _chdir:1c 0 25277 _chdir:20 0 25278 _chdir:24 0 25279 _chdir:28 0 25280 _chdir:2c 0 25268 _chdir:return |