[Performance]: Periodic slow down in InferRequest.infer

[whhu]

OpenVINO Version

2023.3.0

Operating System

Other (Please specify in description)

Device used for inference

CPU

OpenVINO installation

PyPi

Programming Language

Python

Hardware Architecture

x86 (64 bits)

Model used

models/intel/person-attributes-recognition-crossroad-0230 in open_model_zoo

Model quantization

No

Target Platform

lscpu

Architecture:          x86_64
CPU op-mode(s):        32-bit, 64-bit
Byte Order:            Little Endian
CPU(s):                40
On-line CPU(s) list:   0-39
Thread(s) per core:    2
Core(s) per socket:    10
Socket(s):             2
NUMA node(s):          2
Vendor ID:             GenuineIntel
CPU family:            6
Model:                 63
Model name:            Intel(R) Xeon(R) CPU E5-2660 v3 @ 2.60GHz
Stepping:              2
CPU MHz:               1597.229
CPU max MHz:           3300.0000
CPU min MHz:           1200.0000
BogoMIPS:              5199.91
Virtualization:        VT-x
L1d cache:             32K
L1i cache:             32K
L2 cache:              256K
L3 cache:              25600K
NUMA node0 CPU(s):     0,2,4,6,8,10,12,14,16,18,20,22,24,26,28,30,32,34,36,38
NUMA node1 CPU(s):     1,3,5,7,9,11,13,15,17,19,21,23,25,27,29,31,33,35,37,39
Flags:                 fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm epb invpcid_single ssbd rsb_ctxsw ibrs ibpb stibp tpr_shadow vnmi flexpriority ept vpid fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid cqm xsaveopt cqm_llc cqm_occup_llc dtherm ida arat pln pts md_clear spec_ctrl intel_stibp flush_l1d

lscpu -e

CPU NODE SOCKET CORE L1d:L1i:L2:L3 ONLINE MAXMHZ    MINMHZ
0   0    0      0    0:0:0:0       yes    3300.0000 1200.0000
1   1    1      1    1:1:1:1       yes    3300.0000 1200.0000
2   0    0      2    2:2:2:0       yes    3300.0000 1200.0000
3   1    1      3    3:3:3:1       yes    3300.0000 1200.0000
4   0    0      4    4:4:4:0       yes    3300.0000 1200.0000
5   1    1      5    5:5:5:1       yes    3300.0000 1200.0000
6   0    0      6    6:6:6:0       yes    3300.0000 1200.0000
7   1    1      7    7:7:7:1       yes    3300.0000 1200.0000
8   0    0      8    8:8:8:0       yes    3300.0000 1200.0000
9   1    1      9    9:9:9:1       yes    3300.0000 1200.0000
10  0    0      10   10:10:10:0    yes    3300.0000 1200.0000
11  1    1      11   11:11:11:1    yes    3300.0000 1200.0000
12  0    0      12   12:12:12:0    yes    3300.0000 1200.0000
13  1    1      13   13:13:13:1    yes    3300.0000 1200.0000
14  0    0      14   14:14:14:0    yes    3300.0000 1200.0000
15  1    1      15   15:15:15:1    yes    3300.0000 1200.0000
16  0    0      16   16:16:16:0    yes    3300.0000 1200.0000
17  1    1      17   17:17:17:1    yes    3300.0000 1200.0000
18  0    0      18   18:18:18:0    yes    3300.0000 1200.0000
19  1    1      19   19:19:19:1    yes    3300.0000 1200.0000
20  0    0      0    0:0:0:0       yes    3300.0000 1200.0000
21  1    1      1    1:1:1:1       yes    3300.0000 1200.0000
22  0    0      2    2:2:2:0       yes    3300.0000 1200.0000
23  1    1      3    3:3:3:1       yes    3300.0000 1200.0000
24  0    0      4    4:4:4:0       yes    3300.0000 1200.0000
25  1    1      5    5:5:5:1       yes    3300.0000 1200.0000
26  0    0      6    6:6:6:0       yes    3300.0000 1200.0000
27  1    1      7    7:7:7:1       yes    3300.0000 1200.0000
28  0    0      8    8:8:8:0       yes    3300.0000 1200.0000
29  1    1      9    9:9:9:1       yes    3300.0000 1200.0000
30  0    0      10   10:10:10:0    yes    3300.0000 1200.0000
31  1    1      11   11:11:11:1    yes    3300.0000 1200.0000
32  0    0      12   12:12:12:0    yes    3300.0000 1200.0000
33  1    1      13   13:13:13:1    yes    3300.0000 1200.0000
34  0    0      14   14:14:14:0    yes    3300.0000 1200.0000
35  1    1      15   15:15:15:1    yes    3300.0000 1200.0000
36  0    0      16   16:16:16:0    yes    3300.0000 1200.0000
37  1    1      17   17:17:17:1    yes    3300.0000 1200.0000
38  0    0      18   18:18:18:0    yes    3300.0000 1200.0000
39  1    1      19   19:19:19:1    yes    3300.0000 1200.0000

Performance issue description

A periodic slow down is observed when the InferRequest.infer are continually called, when the OpenVINO inference engine is single threaded and bounded to CPU 0 with all-ones input. The peaks in the inference times are evidently away from the average, and regularly spaced as shown in the following figure.

The phenomenon is reproducible for a much slower model in figure, with almost the same peak positions along the wall-clock time with different starting point.

The inference engine is expected to behave without large peaks or fluctuations.

Step-by-step reproduction

"""
model from openvinotoolkit/open_model_zoo/tree/master/models/intel
taskset -c 0 python3 main.py

Python 3.8.13
numpy==1.24.2
openvino==2023.3.0

Intel(R) Xeon(R) CPU E5-2660 v3 @ 2.60GHz
CentOS Linux release 7.9.2009 (Core)
3.10.0-1160.102.1.el7.x86_64
"""
import time

import openvino.runtime as ov  # 2023.3
import numpy as np

MODEL_PATH = 'person-attributes-recognition-crossroad-0230.xml'
NUM_THREADS = 1
PRECISION = ov.Type.f32
DEVICE_NAME = 'CPU'
BATCH_SIZE = 1

WARMUP = 30  # in unit of seconds
BENCHMARK = 600  # in unit of seconds


def create_workload_fn(model_path: str):
    config = dict()
    config.setdefault(ov.properties.inference_num_threads(), NUM_THREADS)
    config.setdefault(ov.properties.hint.inference_precision(), PRECISION)
    config.setdefault(
        ov.properties.affinity(), ov.properties.Affinity.NONE)

    core = ov.Core()
    model = core.read_model(model_path)
    compiled_model = core.compile_model(
        model=model, device_name=DEVICE_NAME, config=config)
    infer_request = compiled_model.create_infer_request()

    inputs = list()
    for input_layer in compiled_model.inputs:
        shape = input_layer.partial_shape.get_min_shape()
        shape[0] = BATCH_SIZE
        dtype = input_layer.element_type.to_dtype()

        value = np.ones(shape=shape, dtype=dtype)
        inputs.append(value)

    def workload_fn():
        _ = infer_request.infer(inputs=inputs)

    return workload_fn


def main():
    workload_fn = create_workload_fn(MODEL_PATH)

    expiry = time.perf_counter_ns() + int(WARMUP * 1e9)
    while expiry > time.perf_counter_ns():
        workload_fn()

    timestamps = list()
    start = time.perf_counter_ns()
    expiry = start + int(BENCHMARK * 1e9)
    current = start
    timestamps.append(current)
    while expiry > current:
        workload_fn()
        current = time.perf_counter_ns()
        timestamps.append(current)

    x_data = list(map(lambda x: (x - start) * 1e-9, timestamps[1:]))
    y_data = list(map(
        lambda x, y: (x - y) * 1e-6, timestamps[1:], timestamps[:-1]))

    # # plot from x_data and y_data
    # import matplotlib.pyplot as plt
    # fig, ax = plt.subplots()
    # ax.plot(x_data, y_data, '.-')
    # ax.set_xlabel('wall-clock time / s')
    # ax.set_ylabel('inference time / ms')
    # ax.grid()
    # fig.savefig('main.png', dpi=300)


if __name__ == '__main__':
    main()

Issue submission checklist

• I'm reporting a performance issue. It's not a question.
• I checked the problem with the documentation, FAQ, open issues, Stack Overflow, etc., and have not found a solution.
• There is reproducer code and related data files such as images, videos, models, etc.

[peterchen-intel]

Can be reproduced. WIP to figure out a recommendation.