Medición del tiempo de ejecución de una función dentro del kernel de Linux

Question

Estoy usando los ganchos de Linux Security Module para agregar alguna funcionalidad personalizada a la llamada al sistema recv(). Quiero medir la sobrecarga de esta funcionalidad en comparación con la prvine recv(). Escribí un servidor tcp simple con el que corro y sin mi módulo. Este servidor tcp llama a una función recv() 'N' número de veces. Se mide el tiempo necesario para cada recv con algo como:

clock_gettime(before); 
recv() 
clock_gettime(after); 
global_time += after - before. 

Al final, imprimo el tiempo promedio para un solo recv() con "global_time/N". Llamemos a esta vez como hora "user_space_avg_recv".

Dentro de mi módulo, quiero colocar funciones de medición de tiempo para calcular el tiempo exacto de ejecución de mi gancho. Intenté 3 métodos.

1. que utilizan unidades de tiempo de la siguiente manera:

   sj = jiffies; 
   my_hook(); 
   ej = jiffies; 
   current->total_oh = ej - sj; 
   

   pero veo que no hay diferencia entre SJ y EJ valores. Por lo tanto, total_oh no se modifica.

2. He usado current_kernel_time() ya que pensé que devuelve el tiempo en nanosegundos. Sin embargo, una vez más, no hubo diferencia en antes y después del tiempo.

3. Utilicé get_cycles. Imprimo el total de ciclos cuando el proceso finaliza. Sin embargo, cuando convierto los valores de ciclos totales en milisegundos, sale mucho más que el valor "user_space_avg_recv". Esto no tiene sentido ya que el valor medido dentro del núcleo siempre es menor que el valor del tiempo medido desde el espacio del usuario. Esto podría significar que no estoy midiendo con la API correcta o estoy cometiendo un error al convertir el valor de ciclos a milisegundos.

estoy usando básicamente siguiente fórmula para convertir los ciclos de milisegundos:

avg overhead of my hook in milliseconds = 
      (((cycles/2.99)/10^6)/N) 

2,99 porque mi frecuencia de reloj es 2.99Ghz

Algunos puntos:

• Mi usuario el programa espacial está vinculado a un único núcleo que usa la afinidad establecida.

• estoy usando kernel 2.6.22.14

• Para detener núcleo de conmutación de contextos, mientras que dentro de mi gancho, yo uso preempt_disable() y preempt_enable(). Por lo tanto, no contará los tiempos de ejecución de otros hilos del kernel. Incluso entonces, dado que mi gancho usa algo de E/S, mi hilo podría liberar el control voluntariamente o podría ocurrir alguna interrupción que podría aumentar el recuento total de ciclos.

Pregunta: ¿Cómo puedo medir tiempos de ejecución de la función precisa en el interior del núcleo?

Answer 1

Puede usar el function tracer API para obtener un seguimiento de todas las llamadas y devoluciones de funciones, con marcas de tiempo de alta precisión. Esto incluye eventos de interrupción e interruptores de contexto. A continuación, puede analizar la traza resultante en el espacio de usuario para tener una idea precisa del tiempo que tarda su función en ejecutarse.

Si no puede usar la API del rastreador de funciones, puede llamar a la llamada do_gettimeofday() para obtener una marca de tiempo de resolución de microsegundos, o getnstimeofday() para una resolución de nanosegundos. Estas son las mismas funciones que la llamada del espacio de usuario gettimeofday() usa internamente. Por supuesto, para funciones muy rápidas esto puede no ser suficiente precisión; cualquier precisión más rápida que eso y es probable que necesite profundizar en el código del temporizador para ver cómo implementa las conversiones de ciclo. Tenga en cuenta también que el hecho de que tengan alta resolución no significa que tengan mucha precisión, pero deberían ser útiles para la evaluación comparativa.

Tenga en cuenta que cualquier tipo de trazado dará como resultado una latencia adicional - do_gettimeofday() requiere una serie de operaciones de comparación y de intercambio atómicas, y ftrace pone código de sesión en cada función y pre epílogo. Debe tener esto en cuenta al interpretar los resultados.

Answer 2

No estoy seguro de que obtenga el resultado que desea, pero usamos el siguiente código para tener microsegundos.

double Microsecs() 
{ 
    static struct timeval _t; 
    static struct timezone tz; 
    gettimeofday(&_t, &tz); 
    return (double)_t.tv_sec + (double)_t.tv_usec/(1000*1000); 
} 

Que lo llame antes y después de la llamada que desee y vea cuántas veces.
Hemos estado utilizando este método para evaluar el tiempo de I/O en la operación de lectura/escritura/búsqueda para optimizar el rendimiento y estamos obteniendo buenos resultados.

HTH.

Answer 3

¿Ha intentado utilizar OProfile?