Discussion:
[Heaptrack] [Bug 386923] New: heaptrack stalls forever in
(too old to reply)
Giuseppe Bilotta
2017-11-14 21:40:31 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

Bug ID: 386923
Summary: heaptrack stalls forever in LineReader::getLine
Product: Heaptrack
Version: unspecified
Platform: Debian unstable
OS: Linux
Status: UNCONFIRMED
Severity: normal
Priority: NOR
Component: general
Assignee: ***@milianw.de
Reporter: ***@gmail.com
Target Milestone: ---

I tried running clinfo under heaptrack, and noticed that it stalls forever.

A backtrace on a stalled case gives:

#0 0x00007faa3bbf76c0 in __read_nocancel () at
../sysdeps/unix/syscall-template.S:84
#1 0x00007faa3c4855b7 in std::__basic_file<char>::xsgetn(char*, long) () from
/usr/lib/x86_64-linux-gnu/libstdc++.so.6
#2 0x00007faa3c4bed50 in std::basic_filebuf<char, std::char_traits<char>
::underflow() () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#3 0x00007faa3c47d049 in std::basic_istream<char, std::char_traits<char> >&
std::getline<char, std::char_traits<char>, std::allocator<char>
(std::basic_istream<char, std::char_traits<char> >&,
std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char>
&, char) () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#4 0x000055aa3a1be937 in std::getline<char, std::char_traits<char>,
std::allocator<char> > (__str="R 5017", __is=...) at
/usr/include/c++/6/bits/basic_string.h:5382
#5 LineReader::getLine (in=..., this=0x7ffe0e404470) at
./src/util/linereader.h:45
#6 main () at ./src/interpret/heaptrack_interpret.cpp:360


With some experimenting, it seems that this happens if (and only if?) the Mesa
OpenCL ICD is available. Possible steps to reproduce, on Debian unstable:

* apt-get install ocl-icd-libopencl1 mesa-opencl-icd clinfo
* run heaptrack clinfo

This can be done also in a virtual machine, since it's not necessary for the
Mesa OpenCL ICD to actually expose any OpenCL devices (on my machine it has 0
devices, for example).
--
You are receiving this mail because:
You are watching all bug changes.
Giuseppe Bilotta
2017-11-14 21:48:04 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

--- Comment #1 from Giuseppe Bilotta <***@gmail.com> ---
Created attachment 108868
--> https://bugs.kde.org/attachment.cgi?id=108868&action=edit
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.
--
You are receiving this mail because:
You are watching all bug changes.
Milian Wolff
2017-11-15 11:22:55 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

Milian Wolff <***@milianw.de> changed:

What |Removed |Added
----------------------------------------------------------------------------
Status|UNCONFIRMED |CONFIRMED
Ever confirmed|0 |1

--- Comment #2 from Milian Wolff <***@milianw.de> ---
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
--
You are receiving this mail because:
You are watching all bug changes.
Milian Wolff
2017-11-16 23:21:31 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

--- Comment #3 from Milian Wolff <***@milianw.de> ---
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"
--
You are receiving this mail because:
You are watching all bug changes.
Milian Wolff
2017-11-16 23:29:02 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

--- Comment #4 from Milian Wolff <***@milianw.de> ---
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"
--
You are receiving this mail because:
You are watching all bug changes.
Milian Wolff
2017-11-16 23:38:09 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

--- Comment #5 from Milian Wolff <***@milianw.de> ---
@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...
--
You are receiving this mail because:
You are watching all bug changes.
Giuseppe Bilotta
2017-11-17 07:54:48 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

--- Comment #6 from Giuseppe Bilotta <***@gmail.com> ---
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.
--
You are receiving this mail because:
You are watching all bug changes.
Milian Wolff
2018-03-08 20:47:44 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

Milian Wolff <***@milianw.de> changed:

What |Removed |Added
----------------------------------------------------------------------------
Status|CONFIRMED |NEEDSINFO
Resolution|--- |WAITINGFORINFO

--- Comment #7 from Milian Wolff <***@milianw.de> ---
still waiting for feedback
--
You are receiving this mail because:
You are watching all bug changes.
Giuseppe Bilotta
2018-03-09 07:10:52 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

--- Comment #8 from Giuseppe Bilotta <***@gmail.com> ---
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.
--
You are receiving this mail because:
You are watching all bug changes.
Giuseppe Bilotta
2018-03-13 20:02:49 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

--- Comment #9 from Giuseppe Bilotta <***@gmail.com> ---
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=***@entry=0x7fffbb007ef0 <clGetPlatformInfo>,
pid=0x555555ac0d80, 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.
--
You are receiving this mail because:
You are watching all bug changes.
Milian Wolff
2018-03-14 08:05:15 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

Milian Wolff <***@milianw.de> changed:

What |Removed |Added
----------------------------------------------------------------------------
Resolution|WAITINGFORINFO |---
Status|NEEDSINFO |CONFIRMED

--- Comment #10 from Milian Wolff <***@milianw.de> ---
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 :(
--
You are receiving this mail because:
You are watching all bug changes.
Giuseppe Bilotta
2018-03-14 09:04:42 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

--- Comment #11 from Giuseppe Bilotta <***@gmail.com> ---
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).
--
You are receiving this mail because:
You are watching all bug changes.
Milian Wolff
2018-04-27 11:22:02 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

--- Comment #12 from Milian Wolff <***@milianw.de> ---
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
--
You are receiving this mail because:
You are watching all bug changes.
Giuseppe Bilotta
2018-04-27 18:22:42 UTC
Permalink
Raw Message
https://bugs.kde.org/show_bug.cgi?id=386923

--- Comment #13 from Giuseppe Bilotta <***@gmail.com> ---
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=***@entry=0x7ffff5768ef0 <clGetPlatformInfo>,
pid=0x555555789f00, 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
--
You are receiving this mail because:
You are watching all bug changes.
Loading...