xpu.Event reporting erroneous times

[garrett361]

Describe the bug

Hi, I am trying to time xpu operations using xpu.Event analogously to how cuda.Event is used and getting unexpected results. Is xpu.Event supported? I didn't see this behavior reported elsewhere.

The following script times multiple one-second chunks and prints out the results:

import time

import torch

try:
    assert torch.cuda.is_available()
    from torch import cuda as accel

except AssertionError:
    import intel_extension_for_pytorch as ipex  # noqa
    from torch import xpu as accel


if __name__ == "__main__":
    times_s = []
    for _ in range(10):
        start = accel.Event(enable_timing=True)
        stop = accel.Event(enable_timing=True)
        accel.synchronize()
        start.record()
        time.sleep(1)
        stop.record()
        accel.synchronize()
        time_s = (start.elapsed_time(stop)) / 1e3
        times_s.append(time_s)

    print(f"Measured times: {times_s}. Should all be ~= 1.0")

On CUDA this works fine:

# Output on CUDA

Measured times: [1.00120068359375, 1.0011451416015624, 1.0012142944335938, 1.0011526489257812, 1.0012322998046874, 1.001233642578125, 1.0011287841796874, 1.0012332763671874, 1.0012276000976563, 1.0012169799804687]. Should all be ~= 1.0

But on xpu:

# Output on xpu

Measured times: [44.5279296875, 43.52808203125, 42.52821484375, 41.52835546875, 40.52846484375, 39.528609375, 38.52871484375, 37.52885546875, 36.52896484375, 35.52910546875]. Should all be ~= 1.0

The specific results on xpu also vary widely. Running the same script a few more times converges to outputs which more typically look like:

# XPU again
Measured times: [292.29025, 291.290375, 290.29053125, 289.2906875, 288.29078125, 287.29090625, 286.291, 285.29115625, 284.2911875, 283.2913125]. Should all be ~= 1.0

Versions

Results of collect_env.py:

Collecting environment information...
PyTorch version: N/A
PyTorch CXX11 ABI: N/A
IPEX version: N/A
IPEX commit: N/A
Build type: N/A

OS: SUSE Linux Enterprise Server 15 SP5 (x86_64)
GCC version: (SUSE Linux) 7.5.0
Clang version: N/A
IGC version: N/A
CMake version: version 3.20.4
Libc version: glibc-2.3.4

Python version: 3.6.15 (default, Sep 23 2021, 15:41:43) [GCC] (64-bit runtime)
Python platform: Linux-5.14.21-150500.55.31_13.0.62-cray_shasta_c-x86_64-with-glibc2.3.4
Is XPU available: N/A
DPCPP runtime version: N/A
MKL version: N/A
GPU models and configuration:
N/A
Intel OpenCL ICD version: N/A
Level Zero version: N/A

CPU:
Architecture:                       x86_64
CPU op-mode(s):                     32-bit, 64-bit
Address sizes:                      52 bits physical, 57 bits virtual
Byte Order:                         Little Endian
CPU(s):                             208
On-line CPU(s) list:                0-207
Vendor ID:                          GenuineIntel
Model name:                         Intel(R) Xeon(R) Platinum 8465C CPU @2.10GHz
CPU family:                         6
Model:                              143
Thread(s) per core:                 2
Core(s) per socket:                 52
Socket(s):                          2
Stepping:                           5
Frequency boost:                    enabled
CPU max MHz:                        2101.0000
CPU min MHz:                        800.0000
BogoMIPS:                           4200.00
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 art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq 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 3dnowprefetch cpuid_fault epb cat_l3 cat_l2 cdp_l3 invpcid_single intel_ppin cdp_l2 ssbd mba ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm cqm rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves cqm_llc cqm_occup_llc cqm_mbm_total cqm_mbm_local split_lock_detect avx_vnni avx512_bf16 wbnoinvd dtherm ida arat pln pts hwp hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke waitpkg avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg tme avx512_vpopcntdq la57 rdpid bus_lock_detect cldemote movdiri movdir64b enqcmd fsrm md_clear serialize tsxldtrk arch_lbr avx512_fp16 amx_tile flush_l1d arch_capabilities
Virtualization:                     VT-x
L1d cache:                          4.9 MiB (104 instances)
L1i cache:                          3.3 MiB (104 instances)
L2 cache:                           208 MiB (104 instances)
L3 cache:                           210 MiB (2 instances)
NUMA node(s):                       2
NUMA node0 CPU(s):                  0-51,104-155
NUMA node1 CPU(s):                  52-103,156-207
Vulnerability Gather data sampling: Not affected
Vulnerability Itlb multihit:        Not affected
Vulnerability L1tf:                 Not affected
Vulnerability Mds:                  Not affected
Vulnerability Meltdown:             Not affected
Vulnerability Mmio stale data:      Not affected
Vulnerability Retbleed:             Not affected
Vulnerability Spec rstack overflow: Not affected
Vulnerability Spec store bypass:    Mitigation; Speculative Store Bypass disabled via prctl and seccomp
Vulnerability Spectre v1:           Mitigation; usercopy/swapgs barriers and __user pointer sanitization
Vulnerability Spectre v2:           Mitigation; Enhanced IBRS, IBPB conditional, RSB filling, PBRSB-eIBRS SW sequence
Vulnerability Srbds:                Not affected
Vulnerability Tsx async abort:      Not affected

Versions of relevant libraries:
[pip3] numpy==1.19.5
[conda] N/A

aand some xpu-smi discovery printout:

+-----------+--------------------------------------------------------------------------------------+
| Device ID | Device Information                                                                   |
+-----------+--------------------------------------------------------------------------------------+
| 0         | Device Name: Intel(R) Data Center GPU Max 1550                                       |
|           | Vendor Name: Intel(R) Corporation                                                    |
|           | SOC UUID: 00000000-0000-0018-0000-002f0bd68086                                       |
|           | PCI BDF Address: 0000:18:00.0                                                        |
|           | DRM Device: /dev/dri/card0                                                           |
|           | Function Type: physical                                                              |
+

[hueyline]

Hi @garrett361, I will try to reproduce the issue and get back to you.

[garrett361]

Hi @hueyline have you been able to reproduce this?

[ZhaoqiongZ]

Hi @garrett361 , thank you for reporting this, I can reproduce the inconsistency and I have report it to dev team and they will fix it!

[guangyey]

WIP...