Update: La versión de github del script ya es capaz de monitorizar n pids en ejecución y n programas que todavía no lo estén.

Para retomar un poco el blog, y como hace mucho que no escribo nada sobre SystemTap, me he planteado otro sencillo ejercicio "de repaso".

La verdad es que en la actualidad ya hay un buen montón de artículos, documentación y ejemplos sobre lo que se puede hacer con SystemTap, ya sea para la inspección del kernel como para la de aplicaciones tipo mysql, postgresql o python. El rpm de Scientific Linux 6, por ejemplo, incluye más de 80 ejemplos de todo tipo, desde el análisis de procesos hasta el del tráfico de red.

Aún así, como digo, aquí va un ejemplo más.

El problema

Vamos a suponer que tenemos un proceso ejecutando en una máquina, y que queremos vigilar los ficheros que va abriendo.

Para ir un poco más lejos, queremos que se muestren también los ficheros abierto por los hijos de ese proceso principal (sólo un nivel por ahora).

Y ya puestos, queremos poder limitar la monitorización a los ficheros de ciertas rutas. Por ejemplo, podemos querer mostrar sólo los ficheros que se abrán en /etc, o en /lib.

Vamos, que el ejercicio es prácticamente una extensión de uno de los scripts de un post anterior de este mismo blog. Pero que le voy a hacer, sólo se me ocurren ejercicios sobre ficheros.

Resumiendo, y poniendo un ejemplo, tenemos un servidor postfix, con sus habituales procesos hijo:

  master─┬─pickup
         │─qmgr
         └─tlsmgr

Queremos saber que ficheros abren todos los procesos que cuelgan de master, ya sean los tres que se están ejecutando en este momento, ya sean los nuevos que se vayan creando. Además, queremos poder limitar el número de ficheros vigilados a una serie de rutas determinadas.

La solución

El núcleo de la solución está en dos "probes":

  • syscall.open.return
  • syscall.close.return

O sea, las llamadas al sistema open y close. Más concretamente, al momento en el que terminan de ejecutarse (return).

Además, vamos a usar el probe "begin" para leer argumentos, preparar variables y demás parafernalia.

Comenzamos:

  probe begin {
          procesoArgumento = $1
          printf ("El pid que vamos a tratar es %d\n", procesoArgumento);
          if (argc > 1) {
                  for (i=2; i <= argc; i++) {
                          ficherosEnPath[argv[i]] = argv[i]
                          numeroPaths += 1
                  }
          }
  }

Poca explicación hace falta. En $1 tenemos el primer argumento, que va a ser el pid a vigilar. A partir del segundo argumento, y de manera opcional, se pueden incluir una serie de rutas a monitorizar. Todas estas son llamadas válidas:

  stap -v monitorFicheros.stp $(pidof master)
  stap -v monitorFicheros.stp $(pidof master) /etc
  stap -v monitorFicheros.stp $(pidof master) /etc /usr/lib

Una vez definido este bloque básico, pasamos a la llamada al sistema "open":

  probe syscall.open.return {
         proceso = pid()
         padre = ppid()
         hilo = tid()
         ejecutable = execname()
         insertarEnTabla = 0

         if ( (procesoArgumento == proceso) || (procesoArgumento == padre) || (procesoArgumento == hilo) ) {
                 if ( (procesoArgumento == proceso) && (env_var("PWD") != "") ) {
                         pwd = env_var("PWD")
                 }
                 localpwd = (isinstr(env_var("PWD"), "/"))?env_var("PWD"):pwd;

                 filename = user_string($filename)
                 descriptor = $return

                 filename = (substr(filename, 0, 1) == "/")?filename:localpwd . "/" . filename;

                 if ([proceso,padre,hilo,descriptor] in tablaProcesos)  {
                         printf ("{codigo: \"error\", proceso: \"%s\", pid: %d, ppid: %d, tid: %d, fichero: \"%s\", descriptor: %d}\n", ejecutable, proceso, padre, hilo, filename, descriptor)
                 } else {
                         if (descriptor >= 0) {
                                 if (numeroPaths > 0 ) {
                                         foreach (ruta in ficherosEnPath) {
                                                 if (substr(filename, 0, strlen(ruta)) == ruta) {
                                                         insertarEnTabla = 1
                                                         break
                                                 }
                                         }
                                 }
                                 if ( (insertarEnTabla == 1) || (numeroPaths == 0) ) {
                                         tablaProcesos[proceso,padre,hilo,descriptor] = gettimeofday_ms()
                                         tablaFicheros[proceso,padre,hilo,descriptor] = filename
                                         printf ("{codigo: \"open\", proceso: \"%s\", pid: %d, ppid: %d, tid: %d, fichero: \"%s\", descriptor: %d, date: %d}\n", ejecutable, proceso, padre, hilo, filename, descriptor, tablaProcesos[proceso,padre,hilo,descriptor])
                                 }
                         }
                 }
         }
  }

A través de las funciones pid(), ppid() y tid() vemos si el proceso que está ejecutando open en este momento es el proceso que nos interesa o un hijo suyo.

Si cumple este requerimiento, pasamos al bloque que revisa si el fichero que se está abriendo está en el path que nos interesa. En este caso, para hacer el ejercicio más completo, he optado por dar unas cuantas vueltas "de más", y he usado la función env_var("PWD") para acceder al entorno del proceso. En la práctica esta no es la mejor forma, y por eso hay más control en el probe, ya que no siempre existe la variable PWD en el entorno de los procesos que llegan a este open.

La llamada al sistema open carga las variables $return (el valor de retorno de la función es el id del descriptor del fichero) y $filename (el nombre del fichero). Ojo! Cada llamada al sistema tiene unos argumentos, y con ello "ofrece" unas variables para nuestros scripts. Por ejemplo, mientras que en open tenemos filename, flags y mode; en close tenemos fd, filp, files, fdt y retval. El propio SystemTap, Google y el código fuente del kernel son ... vuestros amigos.

En cualquier caso, lo importante es que, cuando se dan todas las condiciones, hacemos lo siguiente:

  tablaProcesos[proceso,padre,hilo,descriptor] = gettimeofday_ms()
  tablaFicheros[proceso,padre,hilo,descriptor] = filename
  printf ("{codigo: \"open\", proceso: \"%s\", pid: %d, ppid: %d, tid: %d, fichero: \"%s\", descriptor: %d, date: %d}\n", ejecutable, proceso, padre, hilo, filename, descriptor, tablaProcesos[proceso,padre,hilo,descriptor])

Con el printf escribimos la información del fichero abierto por salida estándar. Las dos tablas (tablaProcesos y tablaFicheros) sirven para guardar el momento en el que se ha abierto el fichero (con una precisión de milisegundos), y el nombre del fichero en sí mismo, con lo que lo tendremos más a mano cuando pasemos a la llamada al sistema close. Para identificar un fichero usamos el índice formado con [el proceso, el padre, el hilo y el descriptor] del fichero que se ha abierto.

Con toda la información en su sitio ya tenemos la primera parte del script. Seguimos:

  probe syscall.close.return {
         proceso = pid()
         padre = ppid()
         hilo = tid()
         descriptor = $fd
         ejecutable = execname()

         if ( ( procesoArgumento == proceso ) || ( procesoArgumento == padre ) || (procesoArgumento == hilo ) ) {
                 if ([proceso,padre,hilo,descriptor] in tablaProcesos) {
                         filename = tablaFicheros[proceso,padre,hilo,descriptor]
                         date = gettimeofday_ms() - tablaProcesos[proceso,padre,hilo,descriptor]
                         printf ("{codigo: \"close\", proceso: \"%s\", pid: %d, ppid: %d, tid: %d, fichero: \"%s\", descriptor: %d, date: %d}\n", ejecutable, proceso, padre, hilo, filename, descriptor, date)
                         delete tablaProcesos[proceso,padre,hilo,descriptor]
                         delete tablaFicheros[proceso,padre,hilo,descriptor]
                 }
         }
  }

Fácil. Si se está haciendo un close de uno de los ficheros monitorizados, se calcula el tiempo que ha estado abierto y se muestra por la salida estándar.

Un ejemplo de ejecución del monitor es el siguiente:

  # stap -v monitorFicheros.stp $(pidof master)
  Pass 1: parsed user script and 76 library script(s) using 96688virt/22448res/2744shr kb, in 120usr/10sys/133real ms.
  Pass 2: analyzed script: 8 probe(s), 22 function(s), 7 embed(s), 8 global(s) using 251840virt/48200res/3952shr kb, in 420usr/120sys/551real ms.
  Pass 3: using cached /root/.systemtap/cache/02/stap_02e370ac4942b188c248e7ec11ac8e2c_19586.c
  Pass 4: using cached /root/.systemtap/cache/02/stap_02e370ac4942b188c248e7ec11ac8e2c_19586.ko
  Pass 5: starting run.

  El pid que vamos a tratar es 1082
  {codigo: "open", proceso: "smtpd", pid: 5817, ppid: 1082, tid: 5817, fichero: "/etc/hosts", descriptor: 12, date: 1310920975000}
  {codigo: "close", proceso: "smtpd", pid: 5817, ppid: 1082, tid: 5817, fichero: "/etc/hosts", descriptor: 12, date: 0}

Sorpresa! Los printf se formatéan como datos json, por si alguna vez quisiera hacer algo con node.js y aplicaciones como log.io.

En cuanto a los "date: 0", se debe a que la precisión de milisegundos es demasiado baja para estos ficheros y para esta prueba sin tráfico de correo de ningún tipo.

El código completo (en este post sólo falta la definición de variables globales) está accesible en github, como siempre.

Limitaciones y trabajo futuro

Como ya he comentado, este script está lejos de ser óptimo. Además de mi propia incapacidad, en algunos momentos he optado por dar más vueltas de las necesarias para usar así más funciones y variables.

Mi primer objetivo era permitir la monitorización de procesos que todavía no estuvieran en ejecución. En esta versión, sin embargo, el proceso principal sí tiene que estar ejecutando antes de lanzar el stap. Esto no es algo técnicamente complicado, pero no se hace solo, y no aporta demasiado desde el punto de vista conceptual al post, así que lo he dejado.

¿Y qué pasa si el pidof da más de un pid? Me habéis pillado. Por ahora sólo trato un pid.

Para el que esté interesado, SystemTap permite guardar la salida estándar en un fichero usando el parámetro -o. A partir de aquí es trivial que otro script perl, python, bash, node.js o lo que sea trabaje con él.


Monitorización del kernel con SystemTap II

sáb, 11 abr 2009 by Foron

A veces (seguro que pocas), nos encontramos ante una máquina que por algún motivo ha dejado de trabajar como se esperaba. Digamos que el rendimiento o el IO del equipo baja, sin motivo visible. Digamos que no hay logs que indiquen problemas, ni errores del sistema. Nada. Este es el momento para el kung fu, el voodoo o todo tipo de técnicas adivinatorias que tanto usamos los informáticos. Muchas veces es suficiente, pero no siempre, y no hay nada peor que no ser capaz de dar una explicación a un problema.

Systemtap

Supongamos que tenemos la arquitectura de la imagen, con un par de balanceadores de carga, unas cuantas máquinas iguales que pueden ser servidores web, ftp, pop, smtp o cualquier otra cosa, y un par de servidores de almacenamiento nfs. Teniendo en cuenta que los balanceadores de carga suelen dar la posibilidad de asignar diferentes pesos a cada máquina balanceada, ¿Por qué no usar uno de estos servidores para la monitorización del sistema? Es perfectamente posible enviar un poco menos de tráfico a la máquina destinada a SystemTap, de tal manera que no afecte al rendimiento global, para que podamos darnos un mecanismo para tener nuestra infraestructura controlada.

En este post sólo voy a referenciar algunos scripts que están disponibles en la web y en el redpaper. Además, el propio software viene con muchos ejemplos. En CentOS se puede instalar el rpm "systemtap-testsuite" para probar varios scripts.

Vamos a empezar con un par de ejemplos para usar más en un entorno académico que en la práctica.

Digamos que queremos aprender "lo que pasa" cuando hacemos un "ls" en un directorio de una partición ext3. Con este sencillo script:

  #! /usr/bin/env stap

  probe module("ext3").function("*").call
  {
     printf("%s -> %s\n", thread_indent(1), probefunc())
  }
  probe module("ext3").function("*").return
  {
     printf("%s <- %s\n", thread_indent(-1), probefunc())
  }

Vamos a hacer un printf cada vez que comience y termine la ejecución de cualquier función del módulo ext3. En el printf vamos a tabular el nombre de la función que se ha ejecutado. El resultado es algo así:

  ...
  2 ls(31789): <- ext3_permission
   0 ls(31789): -> ext3_dirty_inode
   8 ls(31789):  -> ext3_journal_start_sb
  21 ls(31789):  <- ext3_journal_start_sb
  26 ls(31789):  -> ext3_mark_inode_dirty
  31 ls(31789):   -> ext3_reserve_inode_write
  35 ls(31789):    -> ext3_get_inode_loc
  39 ls(31789):     -> __ext3_get_inode_loc
  52 ls(31789):     <- __ext3_get_inode_loc
  56 ls(31789):    <- ext3_get_inode_loc
  61 ls(31789):   <- ext3_reserve_inode_write
  67 ls(31789):   -> ext3_mark_iloc_dirty
  74 ls(31789):   <- ext3_mark_iloc_dirty
  77 ls(31789):  <- ext3_mark_inode_dirty
  83 ls(31789):  -> __ext3_journal_stop
  87 ls(31789):  <- __ext3_journal_stop
  90 ls(31789): <- ext3_dirty_inode
   0 ls(31789): -> ext3_permission
  ...

Como he dicho, no es algo demasiado práctico, pero puede servir a algún profesor para suspender a un buen porcentaje de pobres alumnos :-) Sigamos con algún otro ejemplo. Digamos que queremos programar un "nettop" que nos diga qué conexiones se están abriendo en una máquina en cada momento. Con un script similar al siguiente lo tendremos en unos minutos:

  #! /usr/bin/env stap

  global ifxmit, ifrecv

  probe netdev.transmit
  {
    ifxmit[pid(), dev_name, execname(), uid()] <<< length
  }

  probe netdev.receive
  {
    ifrecv[pid(), dev_name, execname(), uid()] <<< length
  }

  function print_activity()
  {
    printf("%5s %5s %-7s %7s %7s %7s %7s %-15s\n",
           "PID", "UID", "DEV", "XMIT_PK", "RECV_PK",
           "XMIT_KB", "RECV_KB", "COMMAND")

    foreach ([pid, dev, exec, uid] in ifrecv-) {
      n_xmit = @count(ifxmit[pid, dev, exec, uid])
      n_recv = @count(ifrecv[pid, dev, exec, uid])
      printf("%5d %5d %-7s %7d %7d %7d %7d %-15s\n",
             pid, uid, dev, n_xmit, n_recv,
             n_xmit ? @sum(ifxmit[pid, dev, exec, uid])/1024 : 0,
             n_recv ? @sum(ifrecv[pid, dev, exec, uid])/1024 : 0,
             exec)
    }
    print("\n")
    delete ifxmit
    delete ifrecv
  }

  probe timer.ms(5000), end, error
  {
    print_activity()
  }

¿Qué es lo que hemos hecho? Hemos generado tres "probes". Por un lado, cuando se recibe o trasmite a través de la red añadimos a los arrays "ifxmit, ifrecv" información sobre qué proceso y en qué interfaz ha enviado o recibido. Por otro lado, cada 5000 ms o cuando haya un error o termine el script mostramos la información por pantalla. El resultado puede ser algo similar a lo siguiente:

   PID   UID DEV     XMIT_PK RECV_PK XMIT_KB RECV_KB COMMAND
 31485   500 eth0          1       1       0       0 sshd

 y pasados unos miles de milisegundos ...

   PID   UID DEV     XMIT_PK RECV_PK XMIT_KB RECV_KB COMMAND
 15337    48 eth0          4       5       5       0 httpd
 31485   500 eth0          1       1       0       0 sshd

Como se ve, tengo una sesión ssh abierta permanentemente, y he consultado una página web en el servidor monitorizado. Por supuesto, esto puede no ser muy práctico en servidores muy activos, pero puede dar alguna idea a algún administrador. Igual que hemos hecho un "nettop", también podemos hacer un "disktop" que muestre un resultado como el siguiente:

 Sat Apr 11 17:22:03 2009 , Average:   0Kb/sec, Read:       0Kb, Write:      0Kb
      UID      PID     PPID                       CMD   DEVICE    T        BYTES
       48    15342    15239                     httpd     dm-0    W          210
       48    15343    15239                     httpd     dm-0    W          210
       48    15337    15239                     httpd     dm-0    W          210
       48    15336    15239                     httpd     dm-0    W          210

Lo que hecho es hacer el mismo wget varias veces. Para el que tenga curiosidad, los procesos httpd (que por cierto usa el usuario id=48) ejecutando en el servidor son:

 # pstree -p | grep http
         |-httpd(15239)-+-httpd(15336)
         |              |-httpd(15337)
         |              |-httpd(15338)
         |              |-httpd(15339)
         |              |-httpd(15340)
         |              |-httpd(15341)
         |              |-httpd(15342)
         |              `-httpd(15343)

El script disktop está disponible en "/usr/share/systemtap/testsuite/systemtap.examples/io" del rpm "systemtap-testsuite".

Volvamos al primer ejemplo del post. Teníamos un grupo de servidores que han dejado de funcionar como deben. Digamos que sospechamos de la velocidad con la que nuestros servidores nfs están sirviendo el contenido de los servidores web. Podemos probar aquellos ficheros que necesiten más de 1 segundo para abrirse:

 #!/usr/bin/stap

 global open , names
 probe begin {
         printf("%10s %12s %30s\n","Process" , "Open time(s)" , "File Name")
 }
 probe kernel.function("sys_open").return{
         open[execname(),task_tid(task_current()),$return] = gettimeofday_us()
         names[execname(),task_tid(task_current()),$return] = user_string($filename)
 }
 probe kernel.function("sys_close"){
         open_time_ms = (gettimeofday_us() - open[execname(),task_tid(task_current()), $fd])
         open_time_s = open_time_ms / 1000000
         if ((open_time_s >= 1) && (names[execname(),task_tid(task_current()), $fd] != "")) {
                 printf("%10s %6d.%.5d %30s\n", execname(),
 open_time_s,open_time_ms%1000000,names[execname(),task_tid(task_current()), $fd])
         }
 }

Con este sencillo script estaría hecho:

    Process Open time(s)                      File Name
      httpd      8.471285 /var/www/html/lectura_lenta.html

En este caso al servidor web le ha costado 8.5 segundos servir el fichero lectura_lenta.html. Después será responsabilidad nuestra buscar, en su caso, la solución.

En definitiva, systemtap es una herramienta muy completa, pero que como tal requiere algo de práctica para ser útil. No sé si alguna vez va a tener mucho éxito en entornos de producción, pero no está de más saber que existe.

read more

Monitorización del kernel con SystemTap I

sáb, 28 feb 2009 by Foron

Empiezo otra serie de dos posts. En este caso sobre algo que tenía "pendiente" desde hace ya tiempo. De hecho, normalmente escribiría mis propios ejemplos para publicarlos aquí, pero para ir más rápido me voy a limitar a referenciar los scripts que usaré para mostrar las funcionalidades de ..... SystemTap. SystemTap es una herramienta que sirve para monitorizar en tiempo real lo que está pasando con un kernel linux. Quitando el detalle de que el kernel tiene que tener ciertas opciones compiladas (luego las comento), SystemTap tiene la gran ventaja de no requerir ningún tipo de reinicio para empezar a trabajar.

¿Qué podemos monitorizar con SystemTap?

Pues ..... prácticamente todo lo que queramos. La segunda parte de este post tratará algunos ejemplos, pero por dar alguna pista, con este software podemos desde vigilar los procesos que más I/O están generando a programarnos un "nettop" que diga los procesos que más están usando la red.

¿Cómo funciona SystemTap?

Con SystemTap se le dice al kernel que ejecute una rutina cuando ocurre un evento, que puede basarse, por citar dos ejemplos, en el tiempo (cada n segundos) o en una llamada del sistema (al ejecutarse un vfs_read). Para esto se usa un lenguaje de programación propio con el que se definen los "probe points" y las diferentes funciones. A pesar de ofrecer muchas posibilidades, el propio lenguaje tiene un control especial sobre los bucles infinitos, el acceso a memoria o la recursividad, por poner tres ejemplos. ¿Por qué tanto control? Pues porque a partir de este código se genera un módulo de kernel que se carga en el sistema. Claro, no hace falta decir las consecuencias de un bucle "mal hecho" a tan bajo nivel.

¿Qué necesita el kernel de linux para poder usar SystemTap?

Para empezar, cómo no, necesitamos un núcleo capaz de cargar módulos. Después, deberemos activar el soporte para los distintos tipos de debug que tiene el kernel, como el del sistema de ficheros, el del propio kernel o los kprobes. Traducido a formato .config, necesitamos las opciones CONFIG_DEBUG_INFO, CONFIG_KPROBES, CONFIG_RELAY, CONFIG_DEBUG_FS, CONFIG_MODULES y CONFIG_MODULES_UNLOAD. Algunas distribuciones incluyen kernels específicos con estas opciones ya activadas.

¿Por qué SystemTap y no strace o gdb?

Bueno, esta seguramente sea una buena pregunta, al menos hasta ver los ejemplos de la segunda parte de este post; pero resumiendo, con SystemTap podemos:

  • Ver de forma integrada y unificada lo que pasa en el kernel y en las aplicaciones que ejecuta.
  • Probar aplicaciones multihilo.
  • Monitorizar aplicaciones multiproceso, como las cliente-servidor, en las que ambos componentes son procesos independientes.
  • Monitorizar en tiempo real y a prácticamente la velocidad de ejecución original.
  • Escribir nuestros propios monitores que den detalles que aplicaciones "generalistas" no son capaces de dar.

¿Cuáles son los aspectos negativos del invento?

Evidentemente, no todos son ventajas con SystemTap. Podríamos hablar de los inconvenientes técnicos, porque las opciones de debug del kernel ralentizan un poco la velocidad del sistema, pero yo creo que los mayores problemas vienen por el aprendizaje necesario para usar el software. Para empezar, hay que tener un cierto conocimiento del kernel de linux; después, hay que saber las posibilidades del lenguaje de programación, y por último hay que ser capaz de interpretar los resultados. Todo esto desmoralizará a más de uno, seguro, que preferirá seguir con top, htop, vmstat y demás familia antes de meterse en este embolado. Afortunadamente, ya hay multitud de scripts disponibles en Internet para todo tipo de situaciones.

Suelo terminar los posts con una referencia bibliográfica. En este caso no creo que haya ningún libro sobre SystemTap, pero sí que hay un redpaper de IBM (que debería pasar a ser un redBOOK pronto :-) ): SystemTap: Instrumenting the Linux Kernel for Analyzing Performance and Functional Problems

read more