Funcionamiento del comando Truss

Mie, 01/13/2010 - 09:25

Un examen detallado de las llamadas a sistema de nuestro equipo nos puede dar una foto detallada de que esta haciendo cada proceso lo cual es una ayuda inestimable para diagnosticar problemas de performance.

Truss es una utilidad que traza las llamadas al sistema y señales para un proceso determinado. Este comando envía el output al stderr.

Nota: en linux el comando equivalente es strace.

Sintáxis

truss  -a  -e  -f  -rall  -wall  -p
truss  -a  -e  -f  -rall  -wall  

-a        Show arguments passed to the exec system calls
-e        Show environment variables passed to the exec system calls
-f        Show forked processes                 (they will have a different pid: in column 1)    
-rall     Show all read data (default is 32 bytes)
-wall     Show all written data (default is 32 bytes)
-p        Hook to an existing process (must be owner or root)
<program> Specify a program to run

Qué procesos son los que generan más llamadas al sistema y qué coste tienen?

Con el comando prstat podemos ver cuantas llamadas ha esta realizando cada proceso. En este ejemplo he ejecutado el prstat en otra terminal, podemos ver que esta generando 1984 llamadas por tiempo de muestreo.

   PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/NLWP
  2390 root       16G 6388M cpu40    0    0   1:47:40 2.5% java/405
  3412 root       16G 5269M cpu32   19    0   1:40:08 1.9% java/407
   210 root     1440K   64K sleep   59    0   0:00:00 0.0% efdaemon/1
   282 daemon   2872K   72K sleep   59    0   0:00:00 0.0% statd/1
   153 root     6728K   72K sleep   59    0   0:00:02 0.0% picld/5
   150 daemon   6256K 3496K sleep   59    0  13:41:55 0.0% kcfd/9
  8433 root     9136K 4672K sleep   59    0   0:00:00 0.0% sshd/1
   290 daemon   2464K    8K sleep   60  -20   0:00:00 0.0% lockd/2
   129 root     2256K    0K sleep   59    0   0:00:00 0.0% drd/2
   257 root     2928K 1048K sleep   59    0   0:34:50 0.0% cron/1
 24679 root     8648K 2992K sleep   59    0   0:00:01 0.0% sshd/1
Total: 141 processes, 1984 lwps, load averages: 5.98, 5.98, 5.57           

Ejemplos

• Podemos ejecutar el comando truss con el comando ls; esto ejectuaría ls pero sacando por la salida de error (stderr) las llamadas al sistema y los resultados de estas.

# truss ls

• Miramos exactamente qué llamadas al sistema está realizando un proceso que está en ejecución:

# ps -ef | grep PROCESO

nobody 27138 27113   0   May 30 ?           0:07 PROCESO

# truss -p 27138

• Con el el parámetro -c, nos mostrará una serie de estadísticas sobre las distintas llamadas a sistema que está ejecutando un proceso:
  
  

truss -c -p 27138

syscall               seconds   calls  errors
read                     .001      42     10
write                    .002      50
open                     .000       8
close                    .000      19
stat                     .006     141     125
fstat                    .000       7
access                   .002      65      15
fcntl                    .000      11
setustack                .000       2
priocntlsys              .001      68
mprotect                 .000       9
yield                    .000       1
lwp_create               .000       2
lwp_exit                 .000       3
lwp_continue             .000       2
lwp_kill                 .000       2       2
lwp_self                 .000       2
lwp_sigmask              .000      10
lwp_mutex_wakeup         .000       1
lwp_cond_wait            .001      38      23
lwp_cond_signal          .000      15
pollsys                  .005      94
schedctl                 .000       2
resolvepath              .001      49      36
lwp_mutex_timedlock      .000       2
so_socket                .000       1
bind                     .000       1
accept                   .000       8
connect                  .000       1
send                     .001      30
getsockname              .000       1
setsockopt               .000       1
                     --------  ------   ----
sys totals:              .030     688    201
usr time:                .109
elapsed:                5.010                                         

En la columna de errores de la llamada read(), de 42 llamadas, 10 son errores, está claro que tenemos un problema con las llamadas de lectura de este proceso, ahora tendremos que averiguar, si los errores afectan a todos los LWP del proceso, si el problema se reproduce en todos los descriptores de ficheros o está localizados en uno en concreto, etc. Dependiendo del resultado de este análisispodremos identificar la causa.