multithreading - programacion - hilos sistemas operativos pdf

Rastreando el misterioso hilo de alta prioridad suspendido dentro del kernel

Question

Descripción

Estoy trabajando en un sistema Linux integrado (usando kernel 3.4 y bionic, similar a Android) que se ejecuta en un SoC ARMv7a de múltiples núcleos. Tenemos un subproceso de espacio de usuario que básicamente está atendiendo eventos que salen del kernel. Los eventos se generan a partir de una IRQ y el espacio de usuario debe reaccionar con una latencia muy baja.

Un hilo se ejecuta con la prioridad 0 de SCHED_FIFO. Es el único hilo de prioridad 0 en el sistema. Código aproximado para el hilo:

 while (1)
{
struct pollfd fds[1];
fds[0].fd = fd;
fds[0].events = POLLIN|POLLRDNORM|POLLPRI;
int ret = poll(fds, 1, reallyLongTimeout);
FTRACE("poll() exit");
if (ret > 0)
{
// notify worker threads of pending events
}
}

Generalmente obtenemos una latencia muy buena (el hilo hace un viaje completo de vuelta a poll () dentro del mismo milisegundo que ocurrió el IRQ), sin embargo al azar tenemos retrasos en las decenas de milisegundos que arruinan todo. Después de rastrearlo por todos lados, llegué a la conclusión de que el retraso se produce después de que se dispare la IRQ y antes de que vuelva la llamada del sistema poll (), porque el hilo se queda dormido. Luego, un tiempo después, de alguna manera, se despierta con una fuerza desconocida y todo continúa.

Sospeché algún otro IRQ, pero después de habilitar sched:, irq:, timer: * tracing tuve que descartarlo. Tuve algunas dificultades para trasladar syscalls: * trazadores al núcleo ARM. Los rastreadores de syscalls funcionan, pero si también habilito la programación: * Recibo todo tipo de ataques de pánico dentro del código ring_buffer.

Después de insertar algunos puntos de rastreo personalizados en sys_poll (), llegué a la incómoda conclusión de que mi hilo se queda dormido después de que sys_poll () haya vuelto, pero antes de que vuelva a aparecer en el espacio del usuario.

Aquí hay un seguimiento anotado con mis puntos de seguimiento personalizados en fs / select.c:

 <my thread>-915 [001] ...1 17.589394: custom: do_poll:786 - calling do_pollfd
<my thread>-915 [001] ...1 17.589399: custom: do_poll:794 - failed, no events
<my thread>-915 [001] ...1 17.589402: custom: do_poll:823 - going to sleep, count = 0, timed_out = 0
.... // everything going OK, then the IRQ happens, which runs a tasklet:
<random proc>-834 [000] d.h1 17.616541: irq_handler_entry: irq=17 name=hwblock handler=hw_block_process_irq
<random proc>-834 [000] d.h1 17.616569: softirq_raise: vec=6 [action=TASKLET]
<random proc>-834 [000] d.h1 17.616570: irq_handler_exit: irq=17 ret=handled
<random proc>-834 [000] ..s2 17.616627: softirq_entry: vec=6 [action=TASKLET]
.... // the tasklet signals the wait queue of the poll, which wakes up my thread:
<my thread>-915 [001] ...1 17.616827: custom: do_poll:826 - woke up, count = 0, timed_out = 0
<my thread>-915 [001] ...1 17.616833: custom: do_poll:772 - start of loop
<my thread>-915 [001] ...1 17.616840: custom: do_poll:786 - calling do_pollfd
<my thread>-915 [001] ...1 17.616852: custom: do_poll:788 - success, event!
<my thread>-915 [001] ...1 17.616859: custom: do_poll:810 - bailing, count = 1, timed_out = 0
<my thread>-915 [001] ...1 17.616862: custom: do_sys_poll:880 - before free_wait()
<my thread>-915 [001] ...1 17.616867: custom: do_sys_poll:882 - before __put_user()
<my thread>-915 [001] ...1 17.616872: custom: sys_poll:940 - do_sys_poll - exit
.... // the tasklet exits, and my thread appears to be about to be
<random proc>-834 [000] .Ns2 17.616922: softirq_exit: vec=6 [action=TASKLET]
.... // wait wait, why is my thread going back to sleep, and what was it doing for 75us?
<my thread>-915 [001] d..3 17.616947: sched_stat_wait: comm=<another thread> pid=1165 delay=1010000 [ns]
<my thread>-915 [001] ...2 17.616957: sched_switch: prev_comm=<my thread> prev_pid=915 prev_prio=0 prev_state=S ==> next_comm=<another thread> next_pid=1165 next_prio=120
.... // everything running on for 20ms as if nothing is wrong, then my thread suddenly gets woken up.
.... // nothing pid 947 is doing should have any effect on <my thread>
<random proc>-947 [000] d..4 17.636087: sched_wakeup: comm=<my thread> pid=915 prio=0 success=1 target_cpu=001
<random proc>-1208 [001] ...2 17.636212: sched_switch: prev_comm=<rancom proc> prev_pid=1208 prev_prio=120 prev_state=R ==> next_comm=<my thread> next_pid=915 next_prio=0
<my thread>-915 [001] ...1 17.636713: tracing_mark_write: poll() exit

Entonces, en algún lugar, mi hilo se está convirtiendo en TASK_INTERRUPTIBLE y luego TASK_INTERRUPTIBLE voluntariamente en el programador, y luego ... despertando aparentemente sin ninguna razón 20 ms después.

La aparición de esto parece depender, al menos en cierta medida, de la sincronización, y los intentos de observarlo a menudo dificultan su reproducción.

Preguntas

1. ¿Alguna idea de qué está causando esto?
2. ¿Alguna sugerencia sobre formas fáciles de descubrir dónde se está quedando dormido mi hilo?
3. ¿Alguna sugerencia sobre formas fáciles de descubrir por qué mi hilo se despierta?
4. He considerado de alguna manera la adaptación de unwind_backtrace() para generar una sola cadena que puedo meter en cada llamada trace_sched_switch() pero eso parece un poco desalentador. ¿Algo más simple a lo largo de las mismas líneas?
5. ¿Alguna idea de por qué rastrear syscalls: * y sched: * lo hace explotar con un error de página no manejado dentro del código del búfer de anillo donde necesita mover la cola? Parece que se está desviando la referencia de un puntero de espacio de usuario (basado en la similitud numérica) pero diferente cada vez.

Cosas que ya he probado y comprobado.

1. No es un IRQ normal que se ejecute demasiado tiempo o algo con interrupciones inhabilitadas. Rastreo con irq: * muestra eso. Puede ser una especie de NMI de TrustZone pero de alguna manera lo dudo.

2. No debería ser una limitación de RT / timeslicing de ningún tipo, porque:

   a) sched_rt_runtime_us = 10000 y sched_rt_period_us = 10000

   b) El hilo tiene un ciclo de trabajo bastante bajo (<30 ms por segundo, en 60-80 eventos por segundo)

3. Es probable que no sea un artefacto de tener que rastrear o escribir en /sys/kernel/debug/tracing/trace_marker desde el espacio de usuario; sucede sin esa macro y con el rastreo deshabilitado (incluso compilado fuera del kernel). También el código relacionado con eso en trace.c y ring_buffer.c parece ser en su mayoría sin bloqueo.

4. No hay nada más con prioridad 0, y no se está adelantando, sino que parece anularse voluntariamente.

5. Puse un panic () en la parte superior de syscall_trace() para asegurarme de no caer accidentalmente en una de las rutas de rastreo / auditoría en mi camino fuera de sys_poll() . No disparó, así que no es eso.

Muchas gracias por adelantado

Actualización # 1

unwind_backtrace_to_str() a encontrar algo fácil e implementé una función unwind_backtrace_to_str() que me permite instrumentar varios puntos de rastreo con información de seguimiento. Después de agregar backtraces a trace_sched_switch () y trace_sched_wake () logré aislar varias causas de latencia, siendo las dos principales:

• Inversión de prioridad debido a que mm-> mmap_sem está siendo tomado por otro hilo en el mismo proceso haciendo un fork() / mmap() / munmap() y por lo tanto no está disponible durante futex_wait() o tracing_mark_write() para el hilo RT. Esto se puede evitar principalmente mediante la reestructuración de algunos códigos y el uso de vfork () en lugar de fork () en algunos lugares.

• sched_wake() al ejecutar la tarea programada cuando se llama a sched_wake() desde una CPU de origen diferente a la CPU que necesita para ejecutarse. Esto parece ser un problema más grande. Lo rastreé a través del programador y parece que en el caso malo wake_up_process() llama a try_to_wake_up() que termina llamando a ttwu_queue() que es donde las cosas se ponen interesantes.

Dentro de ttwu_queue() no ingresamos el ''if'' porque cpus_share_cache() siempre devuelve true para cualquiera de nuestros núcleos (que suena bien, L2 compartido). Lo que significa que simplemente llama a ttwu_do_activate() para la tarea y sale. ttwu_do_activate() parece que solo coloca la tarea en la cola de ejecución correcta y la marca como TASK_RUNNING , pero no tiene ningún manejo de SMP.

p->state = TASK_RUNNING; siguiente después de p->state = TASK_RUNNING; en ttwu_do_wakeup()

#ifdef CONFIG_SMP
if (task_cpu(p) != smp_processor_id())
smp_send_reschedule(task_cpu(p));
#endif

y soluciona el problema obligando a la CPU de destino a ejecutar el programador. Sin embargo, sospecho que no es así como se supone que funciona, e incluso si se trata de un error real, es probable que haya una solución más refinada. Revisé el último kernel (3.14) y el código en core.c se ve bastante parecido.

¿Alguna idea de por qué esto es? ¿Por qué no llama a ttwu_queue_remote() si cpus_share_cache() devuelve true? Entonces, ¿qué sucede si comparten el caché? Puedo ver si eso es relevante para una decisión de migración, pero si la activación se realiza de forma local o remota. Tal vez nuestro cpus_share_cache() debería devolver falso? Esa función no parece estar bien documentada (o no estoy buscando en los lugares correctos)

Answer 1

Solo una suposición descabellada, ya que aún no hay respuesta. Usted dice que el sistema es multinúcleo. ¿Asigna la afinidad para que el hilo de usuario se ejecute en el mismo núcleo donde se produce la interrupción? ¿Y la interrupción ocurre solo en el núcleo específico? Sospecho una situación en la que un hilo de usuario se ejecuta en un núcleo, pero la interrupción ocurre en el otro y no puede reanudarse aquí de inmediato (¿aún no está durmiendo?). Probablemente una carrera de datos le permite quedarse dormida, por ejemplo, justo antes de que el controlador de interrupciones publique algunos datos que el hilo sondea. Por lo tanto, se suspende hasta la próxima interrupción del sistema (por ejemplo, temporizador).

Entonces, intente asignar la interrupción y el hilo al mismo núcleo para serializarlos y evitar posibles carreras de datos.

en respuesta a la actualización # 1

Parece que estaba en lo cierto acerca de la carrera de datos entre los núcleos desde que el aumento de IRQ en el núcleo objetivo soluciona el problema. Supongo que no está en el código del kernel debido a la excesiva reprogramación de las IRQ y, por lo tanto, a las sobrecargas de programación adicionales solo en casos muy raros o simplemente porque se puede hacer más rápido utilizando la sincronización habitual, asumiendo que se comparte el caché.

Y hay una cierta sincronización que parece ser la dirección correcta pero aparentemente se pierde algo. Intentaría ejecutar un reproductor en una arquitectura / versiones diferentes para entender si se trata de un error general o simplemente específico de su plataforma / versiones de kernel. Espero que no sea una valla perdida en p->on_cpu load / store ..

De todos modos, volviendo a su problema específico, si no puede o no quiere usar la compilación personalizada del kernel con su hot-fix, mi sugerencia con la afinidad del hilo sigue siendo real y válida.

Además, si no puede anclar la interrupción en un núcleo en particular, es posible que desee ejecutar un subproceso de sondeo de este tipo en cada núcleo (también se le vincula explícitamente) para garantizar que al menos uno de los subprocesos recibirá el evento inmediatamente después de la IRQ. Por supuesto, conduce a una carga de sincronización adicional en el código de subproceso del usuario.

Answer 2

Terminamos yendo con las siguientes correcciones:

• smp_send_reschedule(task_cpu(p)); mencionado anteriormente en el programador para permitir la prevención de CPU cruzada. Seguiré con un mantenedor para ver si es la solución correcta.

• Implementando get_user_pages_fast() para nuestra plataforma que no bloquea mmap_sem si no tiene que hacerlo. Esto eliminó la contención entre mmap/munmap y futex_wait

• Cambiar a vfork() + execve() en un par de lugares en el código de espacio de usuario donde fork() era necesario. Esto eliminó la contención entre mmap/munmap y las llamadas que generan otros procesos.

Parece que todo está funcionando bien ahora.

Gracias por toda tu ayuda.