Moy Blog

If you ever find yourself with a deadlock in your application, you can use gdb to attach to the application, then sometimes you find one of the threads that is stuck trying to lock mutex x. Then you need to find out who is currently holding x and therefore deadlocking your thread (and equally important why the other thread is not releasing it).

At least on recent libc implementations in Linux, the mutex object seems to have a member named “__owner”. Let me show you what I recently saw when debugging a deadlocked application.

(gdb) f 4
#4  0x0805ab46 in ACE_OS::mutex_lock (m=0xa074248) at include/ace/OS.i:1406
1406      ACE_OSCALL_RETURN (ACE_ADAPT_RETVAL (pthread_mutex_lock (m), ace_result_),
(gdb) p *m
$8 = {__data = {__lock = 2, __count = 0, __owner = 17828, __kind = 0, __nusers = 1, {__spins = 0, __list = {__next = 0x0}}},
  __size = "\002\000\000\000\000\000\000\000�E\000\000\000\000\000\000\001\000\000\000\000\000\000", __align = 2}

We can see that the __owner is 17828. This number is the LWP (Light-weight process) id of the thread holding the lock. Now you can go to examine that thread stack and find out why that thread is also stuck.

This example also brings up a regular point of confusion for some Linux application developers. What is the difference between LWP and POSIX thread id ( the pthread_t type in pthread.h)?. The difference is that pthread_t is a user space concept, is simply an identifier for the thread library implementing POSIX threads to refer to the thread and its resources, state etc. However the LWP is an implementation detail of how the Linux kernel implements threads, which is done through the “thread group” concept and LWP’s, that are processes that share memory pages and other resources with the other processes in the same thread group.

From the Linux kernel point of view the pthread_t value doesn’t mean anything, the LWP id is how you identify threads in the kernel, and they share the same numbering as regular processes, since LWPs are just a special type of process. Knowing this is useful when using utilities like strace. When you want to trace a particular thread of a multi threaded application, you need to provide the LWP of the thread you want to trace, a common mistake is to provide the process id, which in a multithreaded application the process id is just the LWP of the first thread in the application (the one that started executing main()).

Here is how you get each identifier in a C program:

#include <stdio.h>
#include <syscall.h>
#include <pthread.h>
 
int main()
{
  pthread_t tid = pthread_self();
  int sid = syscall(SYS_gettid);
  printf("LWP id is %d\n", sid);
  printf("POSIX thread id is %d\n", tid);
  return 0;
}

It’s important to note that getting the POSIX thread id is much faster than the LWP, because pthread_self() is just a library call and libc most likely has this value cached somewhere in user space, no need to go down to the kernel. As you can see, getting the LWP requires a call to the syscall() function, which effectively executes the requested system call, this is expensive (well, compared with the time required to enter a simple user space function).

A couple of months ago I wrote a little application for Regulus Labs. The application is a simple daemon bridge between Sangoma E1 devices receving ISDN PRI calls and a TCP IP server. Everything received on the telephony side was simply bridged to the configured TCP IP server. The bridge supports PRI voice calls and V.110 data calls.

Even when the application is simple in nature, learning about V.110 to get it to work was interesting

Today I made the project public ( thanks to Tzury Bar Yochay from Regulus Labs) in google code:

http://code.google.com/p/sbridge/

Hopefully somebody else will find it useful.

Debugging information in Linux ELF binaries is usually stored in the binary itself. This had been really convenient to me, for example, I always compile my openr2 library with -ggdb3 -O0. I don’t care about optimizations nor the increase in size in the binary and users can always change those flags using CFLAGS when configuring openr2. Is convenient because if my users ever get a core dump, I was able to jump right in and get a useful backtrace and examine the stack. Alternatively they could get the stack trace themselves and send it to me without worrying about anything else than launching gdb with the right arguments.

However, when you ship non-open source software or you’re just concerned with the size of all the debugging information in lots of libraries, you want to separate the debugging information from the binary holding the program/library itself. In Windows this is the default behavior you get with the well known PDB (Program Data Base) files. For Linux though, you need some tricks to get the debugging information separate. This is of course what most distributions do, they include an extra package with debugging information, so when you install a package you get just the binary code, then, if you need to debug it you download the debugging package.

If you ever need this, you can follow the instructions in this web page to get it to work:

http://sources.redhat.com/gdb/current/onlinedocs/gdb_17.html#SEC166

The way I solved it for our internal build system is just to always compile with -ggdb3 and then:

1. Create a copy of the debugging symbols in a separate binary

objcopy --only-keep-debug somelibrary.so somelibrary.so.dbg

2. Remove the debugging information from the code binary.

objcopy --strip-debug somelibrary.so

3. Add a reference to the code binary so gdb knows where to look for the debugging information

objcopy --add-gnu-debuglink somelibrary.so.dbg somelibrary.so

This last step is simply putting a file name reference inside the ELF binary so GDB (or some other debugger) knows which file name will have the debugging information for this .so (or an executable if that’s what you’re building). In the red hat web page more advanced techniques are explained to make sure you don’t end up with a version mismatch between the debugging information and your library or executable.

It was the best of times, it was the worst of times, it was the age of wisdom, it was the age of foolishness, it was the age of bug-hunting!

Recently I fixed 2 bugs, yeah, I know I spent a lot of time fixing bugs but this 2 were quite interesting to me, not because of the bugs itself, but rather because of some stuff I learned in the process like the implementation of variadic functions and how the C++ compiler optimizes certain stuff unveiling odd bugs.

Bug 1

Let’s analyze the first one, it was a bug I had with some Unicall R2 installation in 64 bits. The problem was simple, as soon as I loaded chan_unicall.so Asterisk crashed

After running Asterisk with gdb I found the crash happened inside libc function strlen that was being called by uc_log(), the Unicall logging function. As most logging C functions, uc_log is a variadic function. uc_log does not do any complicated stuff, is mostly just a wrapper to vsnprintf and the variable arguments were just passed on to vsnprintf and there the crash was occurring, so, how can one see the arguments a variadic function receives using gdb? First, one must know how variadic functions are implemented by the compiler and platform you are working on.

Most common implementation of variadic functions in C is just to define va_list as an unsigned char* pointing to the last argument of the function and each call to va_arg() retrieves the next chunk of memory of the specified size and increment va_list to point to the start of the next argument, therefore, displaying arguments is just matter of printing the memory area after the last argument. However, AMD64 has a different implementation, va_list is an array of 1 structure with members:

.gp_offset
.fp_offset
.overflow_arg_area
.reg_save_area

gp_offset is how many bytes after reg_save_area the first argument is. To print the first variable argument that we know is an “int” we do:

(gdb) p *(int *)(((char *)arg_ptr[0].reg_save_area)+arg_ptr[0].gp_offset)

however, gp_offset will be only incremented after calling va_arg() macro, if you want to see more arguments you must increment reg_save_area by the number of bytes you know arguments take, in the case of uc_log, initial value of gp_offset is 24, probably because it receive 3 fixed arguments (8 bytes * 3). So, the first variable argument starts at .reg_save_area + 24, the second at .reg_save_area + 32 (we’re in a 64 bit machine).

So, what about .fp_offset and .overflow_arg_area?, well, it seems .reg_save_area is quite limited (possibly limited by the number of the processor registers) and you can never go beyond .gp_offset == 40, therefore that will only work for up to 6 arguments (including the fixed ones). .overflow_arg_area is used for any subsequent argument and .fp_offset is the pointer to the next argument on that memory area. Well, that’s enough, let’s get straight to the point, the crash was caused because unicall.h include the following prototype:

extern const char *uc_statet2str(int state);

That function returned the value passed to uc_log(…., uc_state2str()) … so what’s the issue? well, read once again the prototype and how uc_log used it. Is not a typo here in my blog, the prototype really is uc_statet2str, and the function call is uc_state2str, indeed there is a typo in the header file causing the compiler to default to the return value “int” and not const char* when compiling libmfcr2, for 64 bit platform there is 4 bytes of difference between char* and int causing a crash due to invalid memory read.

Bug 2

This one is easier to explain with a chunk of code, can you tell what’s wrong with it and what possible outputs will have when running it as “./test t”?

#include <stdio.h>
#include <string.h>

#define SIZE 100

int main(int argc, char *argv[])
{

        char *bufptr = NULL;
        if (argc == 2) {

                char inblock_buff[SIZE];
                bufptr = inblock_buff;
                strcpy(bufptr, "some buffer");
        }

        printf("buffer: %s\n", bufptr);
        if (argc == 2 && argv[1][0] == 't') {

                char otherbuff[SIZE];
                otherbuff[0] = 0;
        }

        printf("buffer: %s\n", bufptr);
        return 0;
}

Indeed, the output will depend on how you compile it and even probably will depend on the compiler implementation? The thing is, that if you compile this code in Linux with gcc 4.1.2 as gcc -O2 bug.c -o bug, and then run it as ./bug t

The output is:

buffer: some buffer
buffer: some buffer

But, compiling without optimizations gcc -O0 bug.c -o bug the output is:

buffer: some buffer
buffer:

When the second if() block is optimized-out the value of the block variable inblock_buff is not overwritten and therefore bufptr remains pointing to “some buffer” and the code seems to “work”, but when -O0 the second if() block is not optimized and the bug arise, bufptr will point to char 0 printing nothing. In my particular case this buffer was the input of the keyboard of a 5250 session, hence, in some cases the keyboard input was just ignored.