¿Por qué mi aplicación Python está bloqueada con ‘sistema’ / kernel CPU time?

En primer lugar, no estaba seguro de si debería publicar esto como una pregunta de Ubuntu o aquí. Pero supongo que es más una pregunta de Python que una de sistema operativo.

Mi aplicación Python se ejecuta sobre Ubuntu en un servidor AMD de 64 núcleos. Extrae imágenes de cámaras de 5 GigE a través de la red llamando a ctypes través de ctypes y luego las procesa. Veo frecuentes pausas en mi aplicación que hacen que la biblioteca de la cámara externa suelte los cuadros de las cámaras.

Para depurar esto, he usado el popular paquete psutil Python con el que desconecto las estadísticas de la CPU cada 0.2 segundos en un hilo separado. Duermo durante 0,2 segundos en ese hilo y cuando ese sueño se demora un poco más, también veo que se caen los marcos de la cámara. ¡He visto pausas de hasta 17 segundos de duración! La mayor parte de mi procesamiento es en OpenCV o Numpy (ambos lanzan el GIL) o en una parte de la aplicación un multiprocessing.Pool con 59 procesos (esto es para evitar el Python GIL).

Mi registro de depuración muestra el tiempo de CPU muy alto del ‘sistema’ (es decir, el kernel) en muchos de los subprocesos de mi proceso cuando ocurren las pausas.

Por ejemplo. Veo los tiempos de CPU de la siguiente manera (generalmente cada 0.2 segundos) y luego, de repente, un gran salto (los números de ‘Proceso’ están en la utilización de la CPU, es decir, 1 CPU completamente utilizada sería 1, la top Linux mostrando 123% sería 1.2):

 Process user | Process system | OS system % | OS idle % 19.9 | 10.5 | 6 | 74 5.6 | 2.3 | 4 | 87 6.8 | 1.7 | 11 | 75 4.6 | 5.5 | 43 | 52 0.5 | 26.4 | 4 | 90 

No sé por qué el alto uso del sistema operativo se informa una línea antes de igualar el alto uso del sistema de proceso. Los dos coinciden desde 26.4 de 64 cores = 41%. En ese momento, mi aplicación experimentó una pausa de aproximadamente 3.5 segundos (según lo determinado por el subproceso de registro de información de la CPU usando cv2.getTickCount() OpenCV y también el salto en las cv2.getTickCount() tiempo en la salida del registro de Python) que causó la caída de varios marcos de cámara.

Cuando esto sucede, también he registrado la información de la CPU para cada subproceso de mi proceso. Para el ejemplo anterior, se ejecutaron 25 subprocesos con una utilización de CPU del ‘sistema’ de 0.9 y algunas más con 0.6, que coincide con el total del proceso de 26.4 anterior. En ese momento había alrededor de 183 hilos en ejecución.

Esta pausa por lo general parece ocurrir después de que se utiliza el grupo de multiprocesamiento (se usa para ráfagas cortas), pero de ninguna manera ocurre cada vez que se usa el grupo. Además, si reduzco a la mitad la cantidad de procesamiento que debe suceder fuera de la piscina, entonces no se produce ningún salto de cámara.

Pregunta: ¿Cómo puedo determinar por qué el sistema operativo / el tiempo del kernel de SO pasa repentinamente por el techo? ¿Por qué sucedería eso en una aplicación de Python?

Y, lo que es más importante, ¿alguna idea de por qué sucede esto y cómo evitarlo?

Notas:

  • Esto se ejecuta como root (desafortunadamente para la biblioteca de cámaras) desde upstart
  • Cuando las cámaras se apagan, la aplicación se reinicia (con respawn en el inicio) y esto ocurre varias veces al día, por lo que no se debe a que se esté ejecutando durante mucho tiempo, también he visto que esto ocurre muy poco después de que se inicie el proceso.
  • Es el mismo código que se ejecuta una y otra vez, no se debe a la ejecución de una twig diferente de mi código
  • Actualmente tiene un nice -2, he intentado eliminar el nice sin efecto
  • Ubuntu 12.04.5 LTS
  • Python 2.7
  • La máquina tiene 128 GB de memoria que no estoy ni cerca de usar

DE ACUERDO. Tengo la respuesta a mi propia pregunta. Sí, me ha llevado más de 3 meses llegar tan lejos.

Parece ser que GIL goleó en Python, que es la razón de los picos masivos de CPU del sistema y las pausas asociadas. Aquí hay una buena explicación de dónde viene la paliza . Esa presentación también me apuntó en la dirección correcta.

Python 3.2 introdujo una nueva implementación de GIL para evitar esta paliza. El resultado se puede mostrar con un ejemplo simple de hilos (tomado de la presentación anterior):

 from threading import Thread import psutil def countdown(): n = 100000000 while n > 0: n -= 1 t1 = Thread(target=countdown) t2 = Thread(target=countdown) t1.start(); t2.start() t1.join(); t2.join() print(psutil.Process().cpu_times()) 

En mi Macbook Pro con Python 2.7.9 esto usa 14.7s de la CPU de “usuario” y 13.2s de la CPU de “sistema”.

Python 3.4 usa 15.0s de ‘usuario’ (un poco más) pero solo 0.2s de ‘sistema’.

Por lo tanto, el GIL todavía está en su lugar, aún se ejecuta tan rápido como cuando el código es de un solo hilo, pero evita toda la contención de GIL de Python 2 que se manifiesta como tiempo de CPU del núcleo (‘sistema’). Creo que este argumento es lo que causó los problemas de la pregunta original.

Actualizar

Se encontró una causa adicional al problema de la CPU con OpenCV / TBB. Completamente documentado en esta pregunta SO .