Блог

У меня есть функция C, которая выполняет некоторые операции ввода-вывода и декодирование, которые я хотел бы вызвать из скрипта Python.

Функция C отлично работает при компиляции компилятором C командной строки Visual Studio, а также отлично работает при вызове через Cython с отключенной многопоточностью. Но при вызове с использованием многопоточности OpenMP отлично работает в течение первых нескольких миллионов циклов, но затем загрузка процессора медленно снижается в течение следующих нескольких миллионов циклов, пока он, наконец, не останавливается и не завершается сбоем, но и не продолжает вычисления.

Файл C выглядит следующим образом:

 //block_reader.c

#include "block_reader.h" //contains block_data_t, decode_block, get_block_data
#include <stdio.h>
#include <stdlib.h>

#define NTHREADS 8

int decode_blocks(block_data_t *block_data_array, int num_blocks, int *values){
  int block;
#pragma omp parallel for num_threads(NTHREADS)
  for(block=0; block<num_blocks; block  ){
    decode_block(block_data_array[i], values);
  }

}

int main(int argc, char *argv[]) {
  int num_blocks = 250000, block_size = 4096;
  block_data_t *block_data_array = get_block_data();

  int *values = (long long *)malloc(num_blocks * block_size * sizeof(int));

  int i, block;
  for(i=0; i<1000; i  ){
    printf("experiment #%dn", i 1);

    decode_blocks(block_data_array, values)
    }
  }
}
  

при компиляции с cl /W3 -openmp block_reader.c block_helper.c zstd.lib в командной строке visual studio x64 цикл основной функции доходит до experiment # 1000, при этом загрузка процессора все время составляет 90% (на моей машине 8 логических потоков, я понятия не имею, почему в чистом C она ограничена 90%, я получаю ту же проблему, когда я удаляю num_threads (NTHREADS) из OpenMP pragma, но я не очень беспокоюсь об этом).

Однако, когда я оборачиваю его в Cython и зацикливаю на python:

 #block_reader_wrapper.pyx

from libc.stdlib cimport malloc
from libc.stdio cimport printf
cimport openmp
cimport block_reader_defns #contains block_data_t

import numpy as np
cimport numpy as np

cimport cython

@cython.boundscheck(False)  # Deactivate bounds checking.
@cython.wraparound(False)   # Deactivate negative indexing.
cpdef tuple read_blocks(block_data_array):

  cdef np.ndarray[np.int32_t, ndim=1] values = np.zeros(size, dtype=np.int32_t)
  cdef int[::1] values_view = values

  decode_blocks(block_data_array, len(block_data_array), num_blocks, amp;values_view[0])

  return values

cdef extern from "block_reader.h":
  int decode_blocks(char**, b_metadata*, unsigned int, unsigned long long*, long long*, int*)



#setup.block_reader_wrapper.py

from setuptools import setup, Extension
from Cython.Build import cythonize
import numpy

ext_modules = [
    Extension(
        "block_reader_wrapper",
        ["block_reader_wrapper.pyx", "block_reader.c", "block_helper.c"],
        libraries=["zstd"],
        library_dirs=["{dir}/vcpkg/installed/x64-windows/lib"],
        include_dirs=['{dir}/vcpkg/installed/x64-windows/include', numpy.get_include()],
        extra_compile_args=['/openmp', '-O2'], #Have tried -O2, -O3 and no optimization
        extra_link_args=['/openmp'], #always gets LINK : warning LNK4044: unrecognized option '/openmp'; ignored despite the docs asking for it https://cython.readthedocs.io/en/latest/src/userguide/parallelism.html
    )
]

setup(
    ext_modules = cythonize(ext_modules,
                            gdb_debug=True,
                            annotate=True,
                            )
)


#experiment.py

from block_reader_wrapper import read_blocks
from block_data_gen import get_block_data

for i in range(1000):
  print("experiment", i 1)
  read_blocks(get_block_data())
  

I get to experiment #10 with CPU usage at 100% (and running a little faster than the 90% capped pure C), but then between experiment #11 — experiment #16 the CPU usage slowly decreases in increments of 1 logical thread worth of resources, until the CPU usage hits the bottom of 1 logical thread, however despite my task manager claiming python is using ~20% of my CPU usage, the process stops outputting data. Memory Usage is always fairly low (~10%).

I figure this must have something to do with Cython’s linking of OpenMP, perhaps implicitly limiting the number of payloads that I can pass to its worker threads.

Any insight would be greatly appreciated, I need this to ultimately work on Windows and Ubuntu, which is why I choose openMP in the first place.

Edit 1: As per DavidW ‘s suggestion I replaced:

 cdef np.ndarray[np.int32_t, ndim=1] values = np.zeros(size, dtype=np.int32_t)
  

с:

 cdef array.array values, values_temp
values_temp = array.array('q', [])
values = array.clone(values_temp, size, zero=True)
  

К сожалению, это не устранило проблему.

Редактировать 2 и 3: После профилирования процесса, когда он «останавливается», я вижу, что значительная часть процессорного времени тратится на ожидание. В частности, функции free_base и malloc_base из модуля ucrtbase.dll

Правка 4: Я переписал оболочку с использованием ctypes вместо cython, который использует преимущества того же C -> Python API, поэтому, возможно, неудивительно, что существует та же проблема (хотя она останавливается примерно в два раза быстрее с использованием ctypes вместо Cython).

Сводка VTune:

 Elapsed Time:   285419.416s
    CPU Time:   22708.709s
    Effective Time: 9230.924s
    Spin Time:  13477.785s
    Overhead Time:  0s
    Total Thread Count: 10
    Paused Time:    0s


Top Hotspots
    Function    Module  CPU Time
    free_base   ucrtbase.dll    9061.852s
    malloc_base ucrtbase.dll    8308.887s
    NtWaitForSingleObject   ntdll.dll   1283.721s
    func@0x180020020    USER32.dll  820.759s
    func@0x18001c630    tsc_block_reader.cp38-win_amd64.pyd 753.774s
    [Others]    N/A*    2479.716s

Effective CPU Utilization Histogram
    Simultaneously Utilized Logical CPUs    Elapsed Time    Utilization threshold

    0   279744.7901384001   Idle
    1   5446.2851121    Poor
    2   177.8078306 Poor
    3   40.3033061  Poor
    4   10.2292884  Poor
    5   0   Poor
    6   0   Poor
    7   0   Ok
    8   0   Ideal
  

Хотя в нем говорится, что около 80% процессорного времени находится в режиме ожидания, цикл, который должен завершиться за 30 секунд, не был завершен даже через 2 дня, так что это намного больше, чем 80% времени простоя.

Похоже, что большая часть времени простоя тратится на ucrtbase.dll