Today, I was able to actually test and debug rsyslog Not just looking at code and how it may work. No, real interaction and real crashes.
Things went well, but then I got stuck. Somehow, the segfault didn’t make much sense. I found something that is related to the segfault user’s are seeing. But is it really the actual segfault or just a side-effect of instrumentation?
With mudflap active, rsyslog crashes when freeing the message structure in the worker thread. The structure was allocated (malloc) in another thread, actually the “main” thread, that is the one rsyslog starts up in. Of course, I’ve first assumed I have messed up with the structure. But further analysis showed that I have not. So a bad feeling creeped in … that there may be some thread safety issues with malloc/free. On the other hand, rsyslog is far from being my first multi-threaded program (but on a modern flavor of linux, I have to admit). I’ve used dynamic memory alloc in multithreaded apps for years now and without any problems. After all, dynamic memory is often a trouble-safer with multithreading.
Then, I have written a minimalistic program to check out threading functionality. Here it is:
#include <stdlib.h>
#include <pthread.h>
static char *pthrd;
static char *pmain;
static void *singleWorker1()
{
pthrd = malloc(32);
printf("alloc p in thread: %8.8xn", pthrd);
pthread_exit(0);
}
static void *singleWorker2()
{
printf("freeing p from thread: %8.8xn", pthrd);
free(pthrd);
printf("free done!n");
printf("freeing p from main thread: %8.8xn", pmain);
free(pmain);
printf("free done!n");
pthread_exit(0);
}
void main()
{
int i;
pthread_t thrdWorker;
i = pthread_create(&thrdWorker, NULL, singleWorker1, NULL);
pthread_join(thrdWorker, NULL);
pmain = malloc(32);
printf("alloc p in main thread: %8.8xn", pmain);
i = pthread_create(&thrdWorker, NULL, singleWorker2, NULL);
pthread_join(thrdWorker, NULL);
printf("main thread exitingn");
}
Note: the code did originally contain sleep(1) in stead of the pthread_join()s now found in it. I was initially too lazy to do it right in this tester. I’ve been told this is bad, so I fixed it. The result, however, is unchanged.
… and now look at the output:
cc -O1 -fmudflapth threadtest.c -lpthread -lmudflapth
threadtest.c: In function ‘main’:
threadtest.c:27: warning: return type of ‘main’ is not ‘int’
[root@localhost rsyslog]# ./a.out
malloc: using debugging hooks
alloc p in thread: 095586d0
alloc p in main thread: 095587f8
freeing p from thread: 095586d0
free done!
freeing p from main thread: 095587f8
*** glibc detected *** ./a.out: free(): invalid pointer: 0x095587f8 ***
free done!
main thread exiting
*******
mudflap stats:
calls to __mf_check: 0
__mf_register: 5179 [524294B, 32B, 20981024B, 0B, 2365B]
__mf_unregister: 0 [0B]
__mf_violation: [0, 0, 0, 0, 0]
calls with reentrancy: 5132
lock contention: 0
lookup cache slots used: 0 unused: 1024 peak-reuse: 0
number of live objects: 5179
zombie objects: 0
As you can see, the free that is done on the memory malloc’ed in the thread I created manually works fine. But the freeing the memory malloc’ed in the main thread fails miserably (I’ve set MALLOC_CHECK_=1, for the records).
I am both stunned and puzzled. If that is really a problem, it is clear why rsyslog aborts.
… but can that really be? I have to admit I now suspect a problem with mudflap — when it is compiled without it, everything works. But this applies only to the test program. Rsyslog doesn’t as quickly abort compiled without mudflap, but it aborts in any case. So can there really be a problem in the way dynamic memory management is done and in which threads?
If you can contribute to the solution, please do. I really need any helping hand, this is probably one of the most strange situations I’ve ever seen [and, of course, all will clear up once I see where I have failed – as always ;)].
Feedback appreciated!