An example of debugging parallel program

In the past 2 weeks, I was tortured by a nasty bug, yes, a not-always-reproducible, use-third-party-code, parallel-program issue. Thank Goodness! The root cause was found on this Thursday, and I think the whole progress is a perfect experience and tutorial of how to debug parallel program. So I record it here and hope it can give you some tips when facing similar situation.

Background: I am leveraging FHEW to implement some complex calculations and experiments. Now the FHEW only works in single-thread environment, since many functions share the same global variables, like this:

......
double *in;
fftw_complex *out;
fftw_plan plan_fft_forw, plan_fft_back;

void FFTsetup() {
  in = (double*) fftw_malloc(sizeof(double) * 2*N);
  out = (fftw_complex*) fftw_malloc(sizeof(fftw_complex) * (N + 2));
  plan_fft_forw = fftw_plan_dft_r2c_1d(2*N, in, out,  FFTW_PATIENT);
  plan_fft_back = fftw_plan_dft_c2r_1d(2*N, out, in,  FFTW_PATIENT);
}

void FFTforward(Ring_FFT res, const Ring_ModQ val) {
  for (int k = 0; k < N; ++k)   {
    in[k] = (double) (val[k]);
    in[k+N] = 0.0;          
  }
  fftw_execute(plan_fft_forw); 
  for (int k = 0; k < N2; ++k) 
    res[k] = (double complex) out[2*k+1];               
}
.....

So to make it can be used in parallel, I first need to modify it to be used in multi-thread program. This work involves of allocating resources of every thread, adding lock of necessary global variables, etc. The multi-thread FHEW works always OK until I employed it to implement a complicated function. At most times the result was correct except some rare occasions. So I began the tough debugging work.

(1) Log. Undoubtedly, the log is the most effective one in all debugging tools. I tried to add as many traces as I can. An important attention you must pay is now that multiple threads are running simultaneously, you must identify the logs are from which thread. For example, if you use OpenMP, you can use following code to differentiate thread IDs:

......
printf("Thread(%d/%d) ......", omp_get_thread_num(), omp_get_num_threads(), ......);
......

After analyzing the log, a function was spotted, but it did noting but use 2 consecutive HomNAND to implement the AND operations (You should consider HomNAND is just a NAND gate in logical circuit, and use two NAND gates can realize AND gate.). According to AND gate truth-table, when two inputs are 0, the output should be 0 too, but in my program, the result is 1, which causes the final error.

(2) Simplify the program and try to find the reproducible condition. Since the bug was related to HomNAND and my original program was a little complicated, I needed to do some simple tests and try to find the reproducible condition. I designed 3 experiments:

a) Use original single-thread FHEW, and execute one HomNAND continuously:

for (;;) {
    ......
    HomNAND();
    ......
}

b) Use modified multi-thread FHEW, and spawn 8 threads. Every thread run one HomNAND in dead-loop:

#pragma omp parallel for
for (int loop = 0; loop < 8; loop++) {
    ......
    HomNAND();
    ......
}

c) Use modified multi-thread FHEW, and spawn 8 threads. Every thread run two HomNANDs to achieve AND function in dead-loop:

#pragma omp parallel for
for (int loop = 0; loop < 8; loop++) {
    ......
    HomNAND()
    HomNAND();
    ......
}

After testing, I found case a) and b) were always OK, while c) would generate wrong results after running 1 or 2 hours.

(3) Now the thing became intricate. Because I modified the FHEW, and FHEW also used FFTW, it was not an easy task to locate where the problem was. Additionally, the thread-safe usage of FFTW also involved many discussions (like this) and pitfalls (like this), so I resort the authors of FFTW to make sure my code is not wrong.

(4) Back to the experiments, I suddenly found that I have tested single-thread-single-HomNAND, multiple-thread-single-HomNAND, multiple-thread-two-HomNAND cases, but how about single-thread-two-HomNAND? If single-thread-two-HomNAND case can fail, it can prove the my modification code was innocent, and the problem should reside on the original FHEW code:

for (;;) {
    ......
    HomNAND();
    HomNAND();
    ......
}

Yeah, I was very lucky! After one hour, the error occurred. The murder was found, so the next step was to seek solution with the author.

Based on this experience, I think analyzing log and simplifying test model are very important techniques during resolving parallel program bugs. Hope everyone can improve debugging ability, happy debugging!

Build FFTW supporting multi-thread

According to FFTW document:

Starting from FFTW-3.3.5, FFTW supports a new API to make the planner thread-safe:

void fftwmakeplannerthreadsafe(void);

This call installs a hook that wraps a lock around all planner calls.

To use fftw_make_planner_thread_safe() API, you need to add --enable-threads in configuration stage:

$ ./configure --enable-threads
$ make  
$ sudo make install

There will be two additional libraries (libfftw3_threads.a and libfftw3_threads.la) generated compared with no --enable-threads option:

$ cd /usr/local/lib/
$ ls -alt libfftw*
-rw-r--r-- 1 root root   44528 Jan 16 09:18 libfftw3_threads.a
-rwxr-xr-x 1 root root     946 Jan 16 09:18 libfftw3_threads.la
-rw-r--r-- 1 root root 2222828 Jan 16 09:18 libfftw3.a
-rwxr-xr-x 1 root root     886 Jan 16 09:18 libfftw3.la

BTW, although fftw_make_planner_thread_safe() API was introduced in FFTW-3.3.5, it didn’t really work until FFTW-3.3.6 who contains an important patch. Please refer the discussion and release note.

Generate carry in Carry-lookahead adder

Recently, I am implementing an 8-bit Carry-lookahead adder. But unfortunately, almost all materials in the Internet only provide the formula to get C1 toC4, so I write a simple python script to generate all carries:

#!/usr/bin/python3

import sys
num = 8

if len(sys.argv) != 1:
    num = int(sys.argv[1])

dict = {'C0': 'C0'}
for i in range(1, num + 1):
    dict['C' + str(i)] = 'G' + str(i - 1) + \
                        '+' + \
                        '+'.join([x + "*P" + str(i - 1) for x in dict['C' + str(i - 1)].split('+')])

for i in range(0, num + 1):
    key = 'C' + str(i)
    print(key, "=", dict[key])

By default, it will generate C1 to C8:

$ ./CarryFormulaInLookAheadAdder.py
C0 = C0
C1 = G0+C0*P0
C2 = G1+G0*P1+C0*P0*P1
C3 = G2+G1*P2+G0*P1*P2+C0*P0*P1*P2
C4 = G3+G2*P3+G1*P2*P3+G0*P1*P2*P3+C0*P0*P1*P2*P3
C5 = G4+G3*P4+G2*P3*P4+G1*P2*P3*P4+G0*P1*P2*P3*P4+C0*P0*P1*P2*P3*P4
C6 = G5+G4*P5+G3*P4*P5+G2*P3*P4*P5+G1*P2*P3*P4*P5+G0*P1*P2*P3*P4*P5+C0*P0*P1*P2*P3*P4*P5
C7 = G6+G5*P6+G4*P5*P6+G3*P4*P5*P6+G2*P3*P4*P5*P6+G1*P2*P3*P4*P5*P6+G0*P1*P2*P3*P4*P5*P6+C0*P0*P1*P2*P3*P4*P5*P6
C8 = G7+G6*P7+G5*P6*P7+G4*P5*P6*P7+G3*P4*P5*P6*P7+G2*P3*P4*P5*P6*P7+G1*P2*P3*P4*P5*P6*P7+G0*P1*P2*P3*P4*P5*P6*P7+C0*P0*P1*P2*P3*P4*P5*P6*P7

But you can pass a parameter to tell how many carries you want:

$ ./CarryFormulaInLookAheadAdder.py 6
C0 = C0
C1 = G0+C0*P0
C2 = G1+G0*P1+C0*P0*P1
C3 = G2+G1*P2+G0*P1*P2+C0*P0*P1*P2
C4 = G3+G2*P3+G1*P2*P3+G0*P1*P2*P3+C0*P0*P1*P2*P3
C5 = G4+G3*P4+G2*P3*P4+G1*P2*P3*P4+G0*P1*P2*P3*P4+C0*P0*P1*P2*P3*P4
C6 = G5+G4*P5+G3*P4*P5+G2*P3*P4*P5+G1*P2*P3*P4*P5+G0*P1*P2*P3*P4*P5+C0*P0*P1*P2*P3*P4*P5

P.S., the full code isĀ here.

The core dump file in Arch Linux

Arch Linux uses systemd, and the core dump files will be stored in /var/lib/systemd/coredump directory by default.

Let’s look at the following simple program:

int main(void) {
        int *p = 0;
        *p = 1;
}

Compile and run it:

$ gcc -g -o test test.c
$ ./test
Segmentation fault (core dumped)

Definitely, the program crashes! Check the core dump files:

$ coredumpctl list
TIME                            PID   UID   GID SIG COREFILE EXE
......
Mon 2017-01-09 16:13:44 SGT    7307  1014  1014  11 present  /home/xiaonan/test
$ ls -alt /var/lib/systemd/coredump/core.test*
-rw-r-----+ 1 root root     22821 Jan  9 16:13 /var/lib/systemd/coredump/core.test.1014.183b4c57ccad464abd2eba2c104a47a8.7307.1483949624000000000000.lz4

According to the file name and time, we can find the program’s corresponding core dump binary. To debug it, we can use “coredumpctl gdb PID” command:

$ coredumpctl gdb 7307
       PID: 7307 (test)
       UID: 1014 (xiaonan)
       GID: 1014 (xiaonan)
    Signal: 11 (SEGV)
 Timestamp: Mon 2017-01-09 16:13:44 SGT (6min ago)
Command Line: ./test
Executable: /home/xiaonan/test
 Control Group: /user.slice/user-1014.slice/session-c4.scope
          Unit: session-c4.scope
         Slice: user-1014.slice
       Session: c4
     Owner UID: 1014 (xiaonan)
       Boot ID: 183b4c57ccad464abd2eba2c104a47a8
    Machine ID: 25671e5feadb4ae4bbe2c9ee6de97d66
      Hostname: supermicro-sys-1028gq-trt
       Storage: /var/lib/systemd/coredump/core.test.1014.183b4c57ccad464abd2eba2c104a47a8.7307.1483949624000000000000.lz4
       Message: Process 7307 (test) of user 1014 dumped core.

            Stack trace of thread 7307:
            #0  0x00000000004004b6 main (test)
            #1  0x00007f67ba722291 __libc_start_main (libc.so.6)
            #2  0x00000000004003da _start (test)

GNU gdb (GDB) 7.12
Copyright (C) 2016 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-pc-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /home/xiaonan/test...done.
[New LWP 7307]
Core was generated by `./test'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00000000004004b6 in main () at test.c:3
3               *p = 1;
(gdb) bt
#0  0x00000000004004b6 in main () at test.c:3

BTW, if you omit PID, “coredumpctl gdb” will launch the newest core dump file.

Attention should be paid. The core dump size is limited to 2GiB, so if it is too large, it will be truncated, and generate the warning like this (Please refer this bug):

......
BFD: Warning: /var/tmp/coredump-ZrhAM4 is truncated: expected core file size >= 2591764480, found: 2147483648.
......

References:
GDB and trouble with core dumps;
Core dump.

Build googlemock library

When enabling ENABLE_TESTS option to build tfhe project, the googlemock library is needed, otherwise the following errors will be generated:

[ 54%] Linking CXX executable unittests-fftw
/usr/bin/ld: cannot find -lgmock
collect2: error: ld returned 1 exit status
make[2]: *** [test/CMakeFiles/unittests-fftw.dir/build.make:229: test/unittests-fftw] Error 1
make[1]: *** [CMakeFiles/Makefile2:1290: test/CMakeFiles/unittests-fftw.dir/all] Error 2
make: *** [Makefile:95: all] Error 2

To build googlemock, you can follow this guide:

(1) Download googletest:

$ git clone https://github.com/google/googletest.git

(2) Execute autoreconf command:

$ cd googletest/googlemock
$ autoreconf -fvi

(3) Create libgmock:

$ cd make
$ make
$ ar -rv libgmock.a gtest-all.o gmock-all.o

(4) Copy libgmock.a into /usr/local/lib:

$ cp libgmock.a /usr/local/lib/

Then you can use libgmock.a now.