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).
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