In this chapter we'll look at a real example of using the mpatrol library to debug a program. All of the following building and debugging steps were performed on an Intel Linux machine so the details may differ slightly on your system, but the concepts should remain the same. However, on systems without virtual memory some of the steps may actually cause the machine to lock up or crash so be aware of this if you are running such a system — you may be safer just reading this tutorial rather than attempting it!
This tutorial will also make use of the option USEDEBUG which displays source-level file names and line numbers associated with symbols in call stack tracebacks, but only if the underlying object file access library supports reading line tables from object files and even then only if the object files were compiled with debugging information enabled. Alternatively, you may be able to use the mpsym command to obtain such information instead.
The program we are going to look at is a simple filter which processes its standard input and displays the processed information on its standard output. In this case the program converts all lowercase characters to uppercase and removes any blank lines. The source for the program is given below, but can also be found in tests/tutorial/test1.c.
23 /*
24 * Reads the standard input file stream, converts all lowercase
25 * characters to uppercase, and displays all non-empty lines to the
26 * standard output file stream.
27 */
30 #include <stdio.h>
31 #include <stdlib.h>
32 #include <string.h>
33 #include <ctype.h>
36 char *strtoupper(char *s)
37 {
38 char *t;
39 size_t i, l;
41 l = strlen(s);
42 t = (char *) malloc(l);
43 for (i = 0; i < l; i++)
44 t[i] = toupper(s[i]);
45 t[i] = '\0';
46 return t;
47 }
50 int main(void)
51 {
52 char *b, *s;
54 b = (char *) malloc(BUFSIZ);
55 while (gets(b))
56 {
57 s = strtoupper(b);
58 if (*s != '\0')
59 {
60 puts(s);
61 free(s);
62 }
63 }
64 free(b);
65 return EXIT_SUCCESS;
66 }
If you quickly skimmed over the above code then you might have noticed some rather obvious errors, but there are also some less obvious ones hidden there as well. After compiling and linking with the system C compiler and libraries it successfully runs, even when its source code is piped to it. So if it runs, why bother trying to debug it?
The short answer to that is that this program does in fact contain one rather major error that is likely to prevent it from running portably on other systems. However, for the purposes of this tutorial, we'll pretend that we've just been handed the source code for this program and have not worked on it before. So let's now try to compile and link it with the mpatrol library1.
First, add the inclusion of mpatrol.h to line 34 so that we can replace
calls to malloc() and free() with their mpatrol
equivalents2. Then, recompile the program and link it with the
mpatrol library. This time, running it with the CHECK=- option and
even the simplest of non-empty input lines should cause it to abort!
If you look at the mpatrol.log file produced, you should see something along the lines of the following at the end of the log file.
ERROR: [FRECOR]: free memory corruption at 0x08067FF6
0x08067FF6 00555555 55555555 5555 .UUUUUUUUU
This tells us that something has written a zero byte into free memory at location `0x08067FF6'. Unfortunately, the library only caught it at the next call to one of its functions so it had already happened somewhere in between the last call and the current call. Turning on the LOGALL option in the MPATROL_OPTIONS environment variable allows us to see the last successful function call to the mpatrol library.
ALLOC: malloc (56, 8192 bytes, 4 bytes) [main|test1.c|54]
0x0804960E main+34 at test1.c:54
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
returns 0x080F0B48
ALLOC: malloc (68, 2 bytes, 4 bytes) [strtoupper|test1.c|42]
0x08049592 strtoupper+50 at test1.c:42
0x08049631 main+69 at test1.c:57
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
returns 0x08067FF4
Unfortunately, this only tells us that the last successful mpatrol library
function call was malloc() called from strtoupper(). If we add
the option OFLOWSIZE=8 to the MPATROL_OPTIONS environment
variable then we get slightly more information about which memory allocation was
affected3.
ERROR: [ALLOVF]: allocation 0x08071E34 has a corrupted overflow buffer at
0x08071E36
0x08071E36 00AAAAAA AAAAAAAA ........
0x08071E34 (2 bytes) {malloc:68:0} [strtoupper|test1.c|42]
0x08049592 strtoupper+50 at test1.c:42
0x08049631 main+69 at test1.c:57
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
Now we can make a better guess about what is happening. Since the start of the upper overflow buffer of allocation 68 has been written to, we can assume that something has written one byte beyond the end of that memory allocation. You can probably see where that is happening now by looking at the code, but let's try to be even more sure that this is what is wrong.
The only foolproof way to do this is to add a watch point to keep an eye on the address that is being written to. This can normally only be done within a debugger, but on systems that support programmable software watch points, the OFLOWWATCH option can be used to do the same thing. For the sake of generality, we'll use the debugger watch point approach, in this case with gdb. In order for the following example to work correctly you'll need to add the ALLOCSTOP=68 option to the MPATROL_OPTIONS environment variable so that we can stop just after the last successful memory allocation.
(gdb) break main
Breakpoint 1 at 0x80495f2: file test1.c, line 54.
(gdb) run <test1.c
Starting program: a.out
Breakpoint 1, main() at test1.c:54
54 b = (char *) malloc(BUFSIZ);
(gdb) break __mp_trap
Breakpoint 2 at 0x804f083
(gdb) continue
Continuing.
Breakpoint 2, 0x804f083 in __mp_trap()
(gdb) backtrace
#0 0x804f083 in __mp_trap()
#1 0x804c81b in __mp_getmemory()
#2 0x8049a94 in __mp_alloc()
#3 0x8049592 in strtoupper(s=0x80f0be0 "/*") at test1.c:42
#4 0x8049631 in main() at test1.c:57
(gdb) step
Single stepping until exit from function __mp_trap,
which has no line number information.
0x804c81b in __mp_getmemory()
(gdb) step
Single stepping until exit from function __mp_getmemory,
which has no line number information.
0x8049a94 in __mp_alloc()
(gdb) step
Single stepping until exit from function __mp_alloc,
which has no line number information.
strtoupper(s=0x80f0be0 "/*") at test1.c:43
43 for (i = 0; i < l; i++)
(gdb) watch *0x8071e36
Hardware watchpoint 3: *134684214
(gdb) continue
Continuing.
Hardware watchpoint 3: *134684214
Old value = -1431655766
New value = -1431655936
strtoupper(s=0x80f0be0 "/*") at test1.c:46
46 return t;
(gdb) quit
The program is running. Exit anyway? (y or n) y
After loading the program into gdb, we need to break at main()
so that we can run to a point where all of the shared library symbols have been
loaded into memory4. We can then set another
breakpoint at __mp_trap() and continue until allocation 68 has been
reached.
Because the mpatrol library has not been built with debugging information in
this example we can quickly step back to the strtoupper() function since
gdb won't step through functions that have no debugging information.
We then set a watch point on address `0x8071e36', which is the address of
the memory location that has been causing the problems. After continuing, the
debugger stops at line 46, but this is more likely to be line 45 since that is
where a zero byte is being written to5.
So, we have located the problem, which is simply a case of not allocating
enough memory to contain the copied string and the terminating zero byte.
We can also improve the strtoupper() function by checking the pointer
returned by malloc() to see if it is `NULL', and if so simply exit
with an error. You can try running the program with the FAILFREQ
option to see how it would originally behave in a low memory situation.
The following listing shows the above modifications that we have made to our program. It can also be found in tests/tutorial/test2.c.
23 /*
24 * Reads the standard input file stream, converts all lowercase
25 * characters to uppercase, and displays all non-empty lines to the
26 * standard output file stream.
27 */
30 #include <stdio.h>
31 #include <stdlib.h>
32 #include <string.h>
33 #include <ctype.h>
34 #include "mpatrol.h"
37 char *strtoupper(char *s)
38 {
39 char *t;
40 size_t i, l;
42 l = strlen(s);
43 if ((t = (char *) malloc(l + 1)) == NULL)
44 {
45 fputs("strtoupper: out of memory\n", stderr);
46 exit(EXIT_FAILURE);
47 }
48 for (i = 0; i < l; i++)
49 t[i] = toupper(s[i]);
50 t[i] = '\0';
51 return t;
52 }
55 int main(void)
56 {
57 char *b, *s;
59 b = (char *) malloc(BUFSIZ);
60 while (gets(b))
61 {
62 s = strtoupper(b);
63 if (*s != '\0')
64 {
65 puts(s);
66 free(s);
67 }
68 }
69 free(b);
70 return EXIT_SUCCESS;
71 }
Leaving aside the obvious problem with gets() and the general
inefficiency of the algorithm, we could assume that our program works safely
now and we can release it to the outside world. However, a user soon reports
a problem with our program steadily using more and more memory during its
execution when processing very large files.
This is generally attributable to a memory leak and so we can use the SHOWUNFREED option to try to detect where the memory leak is coming from. Following is some example output from the mpatrol log file when our program is run and is given a relatively small text file as input.
unfreed allocations: 10 (185 bytes)
0x08062000 (176 bytes) {malloc:1:0} [-|-|-]
0x400B681B __new_fopen+27
0x0804F24E __mp_openlogfile+70
0x080497B5 __mp_init+109
0x08049973 __mp_alloc+31
0x0804962E main+34 at test2.c:59
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
0x08067FF4 (1 byte) {malloc:83:0} [strtoupper|test2.c|43]
0x08049593 strtoupper+51 at test2.c:43
0x08049651 main+69 at test2.c:62
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
0x08067FF8 (1 byte) {malloc:89:0} [strtoupper|test2.c|43]
0x08049593 strtoupper+51 at test2.c:43
0x08049651 main+69 at test2.c:62
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
0x08067FFC (1 byte) {malloc:90:0} [strtoupper|test2.c|43]
0x08049593 strtoupper+51 at test2.c:43
0x08049651 main+69 at test2.c:62
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
0x0808B304 (1 byte) {malloc:95:0} [strtoupper|test2.c|43]
0x08049593 strtoupper+51 at test2.c:43
0x08049651 main+69 at test2.c:62
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
0x0808B308 (1 byte) {malloc:96:0} [strtoupper|test2.c|43]
0x08049593 strtoupper+51 at test2.c:43
0x08049651 main+69 at test2.c:62
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
0x0808B30C (1 byte) {malloc:101:0} [strtoupper|test2.c|43]
0x08049593 strtoupper+51 at test2.c:43
0x08049651 main+69 at test2.c:62
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
0x0808B310 (1 byte) {malloc:113:0} [strtoupper|test2.c|43]
0x08049593 strtoupper+51 at test2.c:43
0x08049651 main+69 at test2.c:62
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
0x0808B314 (1 byte) {malloc:114:0} [strtoupper|test2.c|43]
0x08049593 strtoupper+51 at test2.c:43
0x08049651 main+69 at test2.c:62
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
0x0808B318 (1 byte) {malloc:118:0} [strtoupper|test2.c|43]
0x08049593 strtoupper+51 at test2.c:43
0x08049651 main+69 at test2.c:62
0x4007C9CB __libc_start_main+255
0x080494D1 _start+33
We can discount the first entry since that is obviously coming from when the
mpatrol library first initialises itself. However, all of the other entries
appear to be coming from line 43 within strtoupper() and appear to be
only 1 byte in length. At that point in the code, the only possible reason
for allocating 1 byte is when the string is empty and so that must mean that
we are not freeing memory that contains empty strings. Looking at line 66 we
can see that free() is only ever called for non-empty strings and
therefore if we move the call to free() outside the test for an empty
string we will fix the memory leak. The file tests/tutorial/test3.c
contains the source for the final program.
Note that we can come to the same conclusion as above in a much quicker manner by using the LEAKTABLE option. The following is written to the mpatrol log file when we use that option on the same program (note that the internal memory allocation has not automatically been added to the leak table):
top 1 unfreed memory entry in leak table:
bytes count location
-------- ------ --------
9 9 test2.c line 43
9 9 total
[1] On UNIX systems with dynamic linking it might also be possible to run the program under the mpatrol command with its --dynamic option without having to recompile or relink, but compiling and linking with the mpatrol library is a more generic solution across different platforms.
[2] This is not strictly necessary on UNIX and Windows platforms (and AmigaOS when using gcc), but it does give us more debugging information.
[3] Note that the start address of the allocation has changed slightly since we added padding around it with the OFLOWSIZE option.
[4] This is really only necessary when the mpatrol library has been built as a shared library.
[5] This is not necessarily the fault of the debugger or the debugging information generated by the compiler since on most platforms such watch points can only be caught after they occur, hence most debuggers show the next statement to be executed rather than the current one.