Tại sao ứng dụng Python của tôi bị ngừng lại với thời gian CPU 'hệ thống'/hạt nhân

Question

Trước tiên, tôi không chắc mình có nên đăng bài này dưới dạng câu hỏi Ubuntu hay không. Nhưng tôi đoán nó là một câu hỏi Python hơn là một câu hỏi hệ điều hành.

Ứng dụng Python của tôi đang chạy trên Ubuntu trên máy chủ AMD lõi 64. Nó lấy hình ảnh từ 5 máy ảnh GigE qua mạng bằng cách gọi đến một .so qua ctypes và sau đó xử lý chúng. Tôi thấy các lần tạm dừng thường xuyên trong ứng dụng của mình khiến thư viện máy ảnh bên ngoài từ bỏ các khung máy ảnh.

Để gỡ lỗi này, tôi đã sử dụng gói phổ biến psutil Python mà tôi đăng xuất số liệu thống kê CPU cứ sau 0,2 giây trong một chuỗi riêng biệt. Tôi ngủ trong 0,2 giây trong chủ đề đó và khi giấc ngủ đó mất nhiều thời gian hơn tôi cũng thấy các khung máy ảnh bị rơi. Tôi đã thấy tạm dừng tối đa 17 giây! Hầu hết quá trình xử lý của tôi là OpenCV hoặc Numpy (cả hai đều phát hành GIL) hoặc trong một phần của ứng dụng là multiprocessing.Pool với 59 quy trình (điều này để thực hiện xung quanh GIL Python).

Nhật ký gỡ lỗi của tôi hiển thị thời gian CPU 'hệ thống' rất cao (tức là hạt nhân) trên nhiều luồng của quá trình của tôi khi tạm dừng xảy ra.

Ví dụ: Tôi thấy thời gian CPU như sau (thường là 0,2 giây) và sau đó đột nhiên nhảy lớn (số 'Process' đang sử dụng CPU, tức là 1 CPU được sử dụng đầy đủ sẽ là 1, Linux top hiển thị 123% sẽ là 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 

Tôi không biết tại sao việc sử dụng hệ thống hệ điều hành cao được báo cáo một dòng trước khi phù hợp với việc sử dụng hệ thống quy trình cao. Hai kết quả phù hợp kể từ 26,4 trong số 64 lõi = 41%. Tại thời điểm đó, ứng dụng của tôi trải qua khoảng tạm dừng 3,5 giây (được xác định bởi chuỗi ghi nhật ký thông tin CPU của tôi bằng cách sử dụng cv2.getTickCount() của OpenCV và cũng nhảy dấu thời gian trong đầu ra nhật ký Python) khiến nhiều khung máy ảnh bị xóa.

Khi điều này xảy ra, tôi cũng đã ghi lại thông tin CPU cho từng luồng của quy trình của tôi. Đối với ví dụ trên 25 chủ đề đang chạy ở mức sử dụng CPU 'hệ thống' là 0,9 và một số ít hơn 0,6, phù hợp với tổng số cho quá trình 26,4 ở trên. Tại thời điểm đó có khoảng 183 chủ đề đang chạy. Tạm dừng này thường dường như xảy ra sau khi sử dụng bể đa xử lý (nó được sử dụng cho các vụ nổ ngắn) nhưng không có nghĩa là xảy ra mỗi lần sử dụng hồ bơi. Ngoài ra, nếu tôi giảm một nửa số lượng xử lý cần phải xảy ra bên ngoài hồ bơi thì không xảy ra tình trạng bỏ qua máy ảnh.

Câu hỏi: làm thế nào tôi có thể xác định lý do tại sao hệ điều hành '/' thời gian hạt nhân đột nhiên đi qua mái nhà? Tại sao điều đó lại xảy ra trong một ứng dụng Python?

Và quan trọng hơn: bất kỳ ý tưởng nào tại sao điều này đang xảy ra và cách tránh nó?

Ghi chú:

• này chạy với quyền root (nó phải cho thư viện camera không may) từ upstart
• Khi máy ảnh được tắt khởi động lại ứng dụng (sử dụng respawn trong mới nổi) và điều này xảy ra nhiều thời gian một ngày, do đó, không phải do chạy dài, tôi cũng thấy điều này xảy ra rất sớm sau khi quá trình bắt đầu
• Mã giống nhau đang chạy liên tục, không phải do chạy một chi nhánh khác của mã của tôi
• Hiện nay có một nice của -2, tôi đã cố gắng loại bỏ các nice không có ảnh hưởng đến
• Ubuntu 12.04.5 LTS
• Python 2.7
• Máy có bộ nhớ 128GB mà tôi không có nơi gần bằng

Answer 1

OK. Tôi có câu trả lời cho câu hỏi của riêng tôi. Phải, tôi mất hơn 3 tháng để đạt được điều này.

Dường như có lỗi GIL trong Python, đó là lý do cho các đột biến CPU 'hệ thống' lớn và tạm dừng liên quan. Đây là good explanation of where the thrashing comes from. Bài thuyết trình đó cũng chỉ cho tôi đúng hướng.

Python 3.2 introduced a new GIL implementation để tránh sự cố này. Kết quả có thể được hiển thị với một ví dụ đơn giản ren (lấy từ phần trình bày ở trên):

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())  

On Macbook Pro của tôi với Python 2.7.9 này sử dụng 14.7s của CPU 'user' và 13.2s của 'hệ thống' CPU.

Python 3.4 sử dụng 15.0s 'người dùng' (hơi nhiều hơn) nhưng chỉ có 0,2s 'hệ thống'.

Vì vậy, GIL vẫn được đặt, nó vẫn chỉ chạy nhanh như khi mã đơn luồng, nhưng nó tránh tất cả các tranh chấp GIL của Python 2 biểu hiện dưới dạng thời gian CPU hạt nhân ('hệ thống'). Sự tranh cãi này, tôi tin, là những gì đã gây ra các vấn đề của câu hỏi ban đầu.

Cập nhật

Nguyên nhân bổ sung cho vấn đề CPU được phát hiện là với OpenCV/TBB. Được ghi lại đầy đủ trong số SO question này.