| Summary: | heaptrack stalls forever in LineReader::getLine | ||
|---|---|---|---|
| Product: | [Applications] Heaptrack | Reporter: | Giuseppe Bilotta <giuseppe.bilotta> |
| Component: | general | Assignee: | Milian Wolff <mail> |
| Status: | CONFIRMED --- | ||
| Severity: | normal | ||
| Priority: | NOR | ||
| Version First Reported In: | unspecified | ||
| Target Milestone: | --- | ||
| Platform: | Debian unstable | ||
| OS: | Linux | ||
| Latest Commit: | Version Fixed/Implemented In: | ||
| Sentry Crash Report: | |||
| Attachments: | Thread stack on the debuggee (clinfo) after stalling | ||
|
Description
Giuseppe Bilotta
2017-11-14 21:40:31 UTC
Created attachment 108868 [details]
Thread stack on the debuggee (clinfo) after stalling
The backtrace I showed was only relevant to heaptrack itself. I'm attaching here the output of a `thread apply all bt full` for clinfo after the stall is achieved. It seems that mesa deadlocks somewhere, possibly due to the heaptrack preload.
hm very odd! I couldn't reproduce this exact issue, but instead for me I get:
heaptrack output will be written to "/tmp/heaptrack.clinfo.11170.gz"
starting application, this might take some time...
failed to parse line: t
/home/milian/projects/compiled/other/bin/heaptrack: line 194: 11186 Segmentation fault (core dumped) LD_PRELOAD=$LIBHEAPTRACK_PRELOAD${LD_PRELOAD:+:$LD_PRELOAD} DUMP_HEAPTRACK_OUTPUT="$pipe" "$client" "$@"
so clearly something fishy is going on. Potentially your data stream is also somehow messed up leading to the infinite loop
disabling the unsetenv calls in heaptrack_preload.cpp and then using `valgrind --trace-children=yes --track-origins=yes` we eventually see something like this:
==11099== Invalid read of size 8
==11099== at 0x723EE81: ??? (in /opt/intel/opencl-runtime/lib64/libintelocl.so)
==11099== by 0x71A13FD: clGetPlatformInfo (in /opt/intel/opencl-runtime/lib64/libintelocl.so)
==11099== by 0x4E3DE4C: ??? (in /usr/lib/libOpenCL.so.1.0.0)
==11099== by 0x4E3F21E: ??? (in /usr/lib/libOpenCL.so.1.0.0)
==11099== by 0x4E3FE83: clGetPlatformIDs (in /usr/lib/libOpenCL.so.1.0.0)
==11099== by 0x401277: ??? (in /usr/bin/clinfo)
==11099== by 0x527CF69: (below main) (in /usr/lib/libc-2.26.so)
==11099== Address 0x8 is not stack'd, malloc'd or (recently) free'd
==11099==
==11099==
==11099== Process terminating with default action of signal 11 (SIGSEGV): dumping core
==11099== Access not within mapped region at address 0x8
==11099== at 0x723EE81: ??? (in /opt/intel/opencl-runtime/lib64/libintelocl.so)
==11099== by 0x71A13FD: clGetPlatformInfo (in /opt/intel/opencl-runtime/lib64/libintelocl.so)
==11099== by 0x4E3DE4C: ??? (in /usr/lib/libOpenCL.so.1.0.0)
==11099== by 0x4E3F21E: ??? (in /usr/lib/libOpenCL.so.1.0.0)
==11099== by 0x4E3FE83: clGetPlatformIDs (in /usr/lib/libOpenCL.so.1.0.0)
==11099== by 0x401277: ??? (in /usr/bin/clinfo)
==11099== by 0x527CF69: (below main) (in /usr/lib/libc-2.26.so)
==11099== If you believe this happened as a result of a stack
==11099== overflow in your program's main thread (unlikely but
==11099== possible), you can try to increase the size of the
==11099== main thread stack using the --main-stacksize= flag.
==11099== The main thread stack size used in this run was 8388608.
which matches what I see in GDB:
Thread 1 "clinfo" received signal SIGSEGV, Segmentation fault.
0x00007ffff5c3fe81 in ?? () from /opt/intel/opencl-runtime/lib64/libintelocl.so
(gdb) bt
#0 0x00007ffff5c3fe81 in ?? () from /opt/intel/opencl-runtime/lib64/libintelocl.so
#1 0x00007ffff5ba23fe in clGetPlatformInfo () from /opt/intel/opencl-runtime/lib64/libintelocl.so
#2 0x00007ffff7bbde4d in ?? () from /usr/lib/libOpenCL.so.1
#3 0x00007ffff7bbf21f in ?? () from /usr/lib/libOpenCL.so.1
#4 0x00007ffff7bbfe84 in clGetPlatformIDs () from /usr/lib/libOpenCL.so.1
#5 0x0000000000401278 in ?? ()
#6 0x00007ffff761df6a in __libc_start_main () from /usr/lib/libc.so.6
#7 0x000000000040150a in ?? ()
Running clinfo without heaptrack doesn't show these issues. I still have no clue what is going on... Is one of the dlopened opencl libs maybe also messing around with malloc & friends? I see e.g. /opt/intel/opencl-runtime/lib64/libtbbmalloc.so.2 hmmm but just dlopening that lib or some of the others doesn't trigger that crash for me. Seems like I'll have to compile libintelocl.so from sources with debug symbols.
@Giuseppe: What opencl backends do you have? Only the mesa one?
If I uninstall the intel backend, heaptrack works fine for me on clinfo:
└$ heaptrack clinfo
heaptrack output will be written to "/tmp/heaptrack.clinfo.22644.gz"
starting application, this might take some time...
Number of platforms 1
Platform Name Clover
Platform Vendor Mesa
Platform Version OpenCL 1.1 Mesa 17.2.5
Platform Profile FULL_PROFILE
Platform Extensions cl_khr_icd
Platform Extensions function suffix MESA
Platform Name Clover
Number of devices 0
NULL platform behavior
clGetPlatformInfo(NULL, CL_PLATFORM_NAME, ...) Clover
clGetDeviceIDs(NULL, CL_DEVICE_TYPE_ALL, ...) Clover
clCreateContext(NULL, ...) [default] No devices found in platform
clCreateContextFromType(NULL, CL_DEVICE_TYPE_CPU) No devices found in platform
clCreateContextFromType(NULL, CL_DEVICE_TYPE_GPU) No devices found in platform
clCreateContextFromType(NULL, CL_DEVICE_TYPE_ACCELERATOR) No devices found in platform
clCreateContextFromType(NULL, CL_DEVICE_TYPE_CUSTOM) No devices found in platform
clCreateContextFromType(NULL, CL_DEVICE_TYPE_ALL) No devices found in platform
ICD loader properties
ICD loader Name OpenCL ICD Loader
ICD loader Vendor OCL Icd free software
ICD loader Version 2.2.11
ICD loader Profile OpenCL 2.1
heaptrack stats:
allocations: 1512
leaked allocations: 1102
temporary allocations: 80
Heaptrack finished! Now run the following to investigate the data:
heaptrack --analyze "/tmp/heaptrack.clinfo.22644.gz"
Also works fine with the NVidia backend which I could actually use on my machine:
$ primusrun heaptrack clinfo
heaptrack output will be written to "/home/milian/heaptrack.clinfo.2262.gz"
starting application, this might take some time...
Number of platforms 1
Platform Name NVIDIA CUDA
Platform Vendor NVIDIA Corporation
Platform Version OpenCL 1.2 CUDA 9.1.75
Platform Profile FULL_PROFILE
Platform Extensions cl_khr_global_int32_base_atomics cl_khr_global_int32_extended_atomics cl_khr_local_int32_base_atomics cl_khr_local_int32_extended_atomics cl_khr_fp64 cl_khr_byte_addressable_store cl_khr_icd cl_khr_gl_sharing cl_nv_compiler_options cl_nv_device_attribute_query cl_nv_pragma_unroll cl_nv_copy_opts cl_nv_create_buffer
Platform Extensions function suffix NV
Platform Name NVIDIA CUDA
Number of devices 1
Device Name GeForce 940M
Device Vendor NVIDIA Corporation
Device Vendor ID 0x10de
Device Version OpenCL 1.2 CUDA
Driver Version 387.22
Device OpenCL C Version OpenCL C 1.2
Device Type GPU
Device Available Yes
Device Profile FULL_PROFILE
Device Topology (NV) PCI-E, 04:00.0
Max compute units 3
Max clock frequency 980MHz
Compute Capability (NV) 5.0
Device Partition (core)
Max number of sub-devices 1
Supported partition types None
Max work item dimensions 3
Max work item sizes 1024x1024x64
Max work group size 1024
Compiler Available Yes
Linker Available Yes
Preferred work group size multiple 32
Warp size (NV) 32
Preferred / native vector sizes
char 1 / 1
short 1 / 1
int 1 / 1
long 1 / 1
half 0 / 0 (n/a)
float 1 / 1
double 1 / 1 (cl_khr_fp64)
Half-precision Floating-point support (n/a)
Single-precision Floating-point support (core)
Denormals Yes
Infinity and NANs Yes
Round to nearest Yes
Round to zero Yes
Round to infinity Yes
IEEE754-2008 fused multiply-add Yes
Support is emulated in software No
Correctly-rounded divide and sqrt operations Yes
Double-precision Floating-point support (cl_khr_fp64)
Denormals Yes
Infinity and NANs Yes
Round to nearest Yes
Round to zero Yes
Round to infinity Yes
IEEE754-2008 fused multiply-add Yes
Support is emulated in software No
Correctly-rounded divide and sqrt operations No
Address bits 64, Little-Endian
Global memory size 1029832704 (982.1MiB)
Error Correction support No
Max memory allocation 257458176 (245.5MiB)
Unified memory for Host and Device No
Integrated memory (NV) No
Minimum alignment for any data type 128 bytes
Alignment of base address 4096 bits (512 bytes)
Global Memory cache type Read/Write
Global Memory cache size 49152 (48KiB)
Global Memory cache line 128 bytes
Image support Yes
Max number of samplers per kernel 32
Max size for 1D images from buffer 134217728 pixels
Max 1D or 2D image array size 2048 images
Max 2D image size 16384x16384 pixels
Max 3D image size 4096x4096x4096 pixels
Max number of read image args 256
Max number of write image args 16
Local memory type Local
Local memory size 49152 (48KiB)
Registers per block (NV) 65536
Max constant buffer size 65536 (64KiB)
Max number of constant args 9
Max size of kernel argument 4352 (4.25KiB)
Queue properties
Out-of-order execution Yes
Profiling Yes
Prefer user sync for interop No
Profiling timer resolution 1000ns
Execution capabilities
Run OpenCL kernels Yes
Run native kernels No
Kernel execution timeout (NV) No
Concurrent copy and kernel execution (NV) Yes
Number of async copy engines 1
printf() buffer size 1048576 (1024KiB)
Built-in kernels
Device Extensions cl_khr_global_int32_base_atomics cl_khr_global_int32_extended_atomics cl_khr_local_int32_base_atomics cl_khr_local_int32_extended_atomics cl_khr_fp64 cl_khr_byte_addressable_store cl_khr_icd cl_khr_gl_sharing cl_nv_compiler_options cl_nv_device_attribute_query cl_nv_pragma_unroll cl_nv_copy_opts cl_nv_create_buffer
NULL platform behavior
clGetPlatformInfo(NULL, CL_PLATFORM_NAME, ...) NVIDIA CUDA
clGetDeviceIDs(NULL, CL_DEVICE_TYPE_ALL, ...) Success [NV]
clCreateContext(NULL, ...) [default] Success [NV]
clCreateContextFromType(NULL, CL_DEVICE_TYPE_CPU) No devices found in platform
clCreateContextFromType(NULL, CL_DEVICE_TYPE_GPU) No platform
clCreateContextFromType(NULL, CL_DEVICE_TYPE_ACCELERATOR) No devices found in platform
clCreateContextFromType(NULL, CL_DEVICE_TYPE_CUSTOM) No devices found in platform
clCreateContextFromType(NULL, CL_DEVICE_TYPE_ALL) No platform
ICD loader properties
ICD loader Name OpenCL ICD Loader
ICD loader Vendor OCL Icd free software
ICD loader Version 2.2.11
ICD loader Profile OpenCL 2.1
heaptrack stats:
allocations: 45018
leaked allocations: 136
temporary allocations: 601
Heaptrack finished! Now run the following to investigate the data:
heaptrack --analyze "/home/milian/heaptrack.clinfo.2262.gz"
@Giuseppe: If possible, please compile heaptrack from current git master and enable extended log output by setting s_debugVerbosity in libheaptrack.cpp to: constexpr const DebugVerbosity s_debugVerbosity = VeryVerboseOutput; I cannot figure out how your deadlock could arise. It does look like all threads except the main thread are blocked in free(), but it's unclear which thread is holding the lock :-/ It shouldn't be any of them, looking at the code... Thanks for the extensive tracking, Milian, I'll find sometime later today to try the latest git master of heaptrack. FWIW, I do have the Intel platform available, but I can reproduce the deadlock by limiting the available platforms to just the Mesa one (using ocl-icd for libOpenCL and setting OCL_ICD_VENDORS so that only Mesa is found), so I don't thin Intel's TBB would be at fault in my case. Maybe Mesa does its own alloc meddling? I'm using mesa 17.2.4-1+b1 packaged in Debian sid. still waiting for feedback Sorry for not getting back at you earlier. I just tried with the current git master, building on debian unstable with all dependencies, and I could not replicate the deadlock either, neither with nor without the very verbose debug option. On the other side, I now get the following: failed to parse line: t 7 Segmentation fault Looks like I'll have to investigate some more. Ok, so now what I find is that running clinfo under heaptrack causes a segfault. I can get some more information if I run `heaptrack -d clinfo`. Sadly, the segmentation fault happens inside the proprietary Intel OpenCL platform. I suspect that one of the LD preloads is interfering. The backtrace is:
#0 0x00007fffbb08abc1 in ?? () from /opt/intel/opencl-1.2-6.4.0.25/lib64/libintelocl.so
#1 0x00007fffbb0082fe in clGetPlatformInfo () from /opt/intel/opencl-1.2-6.4.0.25/lib64/libintelocl.so
#2 0x00007ffff79c26d4 in _malloc_clGetPlatformInfo (plt_info_ptr=plt_info_ptr@entry=0x7fffbb007ef0 <clGetPlatformInfo>, pid=0x555555ac0d80, cname=cname@entry=2308, sname=<optimized out>)
at ocl_icd_loader.c:298
#3 0x00007ffff79c2fc4 in _find_and_check_platforms (num_icds=<optimized out>) at ocl_icd_loader.c:498
#4 __initClIcd () at ocl_icd_loader.c:652
#5 _initClIcd_real () at ocl_icd_loader.c:702
#6 0x00007ffff79c36ab in _initClIcd () at ocl_icd_loader.c:724
#7 clGetPlatformIDs (num_entries=0, platforms=0x0, num_platforms=0x55555576ab58 <num_platforms>) at ocl_icd_loader.c:846
#8 0x0000555555561ffb in main (argc=1, argv=0x7fffffffe1b8) at src/clinfo.c:2851
I'm not sure if it's easy to reproduce, but it's probably going to need the Intel OpenCL ICD and the use of the open-source ocl-icd for libOpenCL.
ugh, that looks nasty. Can you paste the versions of these libs you are using, and the distro/platform you are running it all on? Maybe eventually I get time to investigate this in more depth. But, right now, I don't have the time for this I'm afraid to say :( I've double-checked against the other platforms, and this time the only one for which I can reproduce the issue is the proprietary Intel one (in contrast to the original report, for which I got the stall regardless). I'm using Debian unstable. The OpenCL ICD dispatcher is ocl-icd-libopencl1 version 2.2.12-1, from the repositories. The Intel OpenCL runtime is version 16.1.1 (aka 6.4.0.25, apparently they have two versioning schemes). I've just fixed some nasty bugs which may have been the reason for this bug too. can you please update to the latest git master and try again? thanks I'm afraid I'm still seeing the same segmentation fault with the Intel proprietary platform, and only that one.
heaptrack/build [master] $ bin/heaptrack clinfo
heaptrack output will be written to "/home/oblomov/src/heaptrack/build/heaptrack.clinfo.902.gz"
starting application, this might take some time...
Segmentation fault
heaptrack stats:
allocations: 22117
leaked allocations: 13372
temporary allocations: 7908
Heaptrack finished! Now run the following to investigate the data:
heaptrack --analyze "/home/oblomov/src/heaptrack/build/heaptrack.clinfo.902.gz"
Running with -d doesn't provide much useful information, because the segfault is inside the proprietary library:
Thread 1 "clinfo" received signal SIGSEGV, Segmentation fault.
0x00007ffff57ebbc1 in ?? () from /opt/intel/opencl-1.2-6.4.0.25/lib64/libintelocl.so
(gdb) bt
#0 0x00007ffff57ebbc1 in ?? () from /opt/intel/opencl-1.2-6.4.0.25/lib64/libintelocl.so
#1 0x00007ffff57692fe in clGetPlatformInfo () from /opt/intel/opencl-1.2-6.4.0.25/lib64/libintelocl.so
#2 0x00007ffff79c36d4 in _malloc_clGetPlatformInfo (plt_info_ptr=plt_info_ptr@entry=0x7ffff5768ef0 <clGetPlatformInfo>, pid=0x555555789f00, cname=cname@entry=2308, sname=<optimized out>)
at ocl_icd_loader.c:298
#3 0x00007ffff79c3fc4 in _find_and_check_platforms (num_icds=<optimized out>) at ocl_icd_loader.c:498
#4 __initClIcd () at ocl_icd_loader.c:652
#5 _initClIcd_real () at ocl_icd_loader.c:702
#6 0x00007ffff79c46ab in _initClIcd () at ocl_icd_loader.c:724
#7 clGetPlatformIDs (num_entries=0, platforms=0x0, num_platforms=0x7fffffffe030) at ocl_icd_loader.c:846
#8 0x00005555555640d5 in main (argc=1, argv=0x7fffffffe188) at src/clinfo.c:3190
|