| <chapter id="otherdebug"> |
| <title>Other debugging techniques</title> |
| <sect1 id="hardware-trace"> |
| <title>Doing A Hardware Trace</title> |
| |
| <para> |
| The primary reason to do this is to reverse engineer a |
| hardware device for which you don't have documentation, but |
| can get to work under Wine. |
| </para> |
| <para> |
| This lot is aimed at parallel port devices, and in particular |
| parallel port scanners which are now so cheap they are |
| virtually being given away. The problem is that few |
| manufactures will release any programming information which |
| prevents drivers being written for Sane, and the traditional |
| technique of using DOSemu to produce the traces does not work |
| as the scanners invariably only have drivers for Windows. |
| </para> |
| <para> |
| Presuming that you have compiled and installed wine the first |
| thing to do is is to enable direct hardware access to your |
| parallel port. To do this edit <filename>config</filename> |
| (usually in <filename>~/.wine/</filename>) and in the |
| ports section add the following two lines |
| </para> |
| <programlisting> |
| read=0x378,0x379,0x37a,0x37c,0x77a |
| write=0x378,x379,0x37a,0x37c,0x77a |
| </programlisting> |
| <para> |
| This adds the necessary access required for SPP/PS2/EPP/ECP |
| parallel port on LPT1. You will need to adjust these number |
| accordingly if your parallel port is on LPT2 or LPT0. |
| </para> |
| <para> |
| When starting wine use the following command line, where |
| <literal>XXXX</literal> is the program you need to run in |
| order to access your scanner, and <literal>YYYY</literal> is |
| the file your trace will be stored in: |
| </para> |
| <programlisting> |
| WINEDEBUG=+io wine XXXX 2> >(sed 's/^[^:]*:io:[^ ]* //' > YYYY) |
| </programlisting> |
| <para> |
| You will need large amounts of hard disk space (read hundreds |
| of megabytes if you do a full page scan), and for reasonable |
| performance a really fast processor and lots of RAM. |
| </para> |
| <para> |
| You will need to postprocess the output into a more manageable |
| format, using the <command>shrink</command> program. First |
| you need to compile the source (which is located at the end of |
| this section): |
| <programlisting> |
| cc shrink.c -o shrink |
| </programlisting> |
| </para> |
| <para> |
| Use the <command>shrink</command> program to reduce the |
| physical size of the raw log as follows: |
| </para> |
| <programlisting> |
| cat log | shrink > log2 |
| </programlisting> |
| <para> |
| The trace has the basic form of |
| </para> |
| <programlisting> |
| XXXX > YY @ ZZZZ:ZZZZ |
| </programlisting> |
| <para> |
| where <literal>XXXX</literal> is the port in hexadecimal being |
| accessed, <literal>YY</literal> is the data written (or read) |
| from the port, and <literal>ZZZZ:ZZZZ</literal> is the address |
| in memory of the instruction that accessed the port. The |
| direction of the arrow indicates whether the data was written |
| or read from the port. |
| </para> |
| <programlisting> |
| > data was written to the port |
| < data was read from the port |
| </programlisting> |
| <para> |
| My basic tip for interpreting these logs is to pay close |
| attention to the addresses of the IO instructions. Their |
| grouping and sometimes proximity should reveal the presence of |
| subroutines in the driver. By studying the different versions |
| you should be able to work them out. For example consider the |
| following section of trace from my UMAX Astra 600P |
| </para> |
| <programlisting> |
| 0x378 > 55 @ 0297:01ec |
| 0x37a > 05 @ 0297:01f5 |
| 0x379 < 8f @ 0297:01fa |
| 0x37a > 04 @ 0297:0211 |
| 0x378 > aa @ 0297:01ec |
| 0x37a > 05 @ 0297:01f5 |
| 0x379 < 8f @ 0297:01fa |
| 0x37a > 04 @ 0297:0211 |
| 0x378 > 00 @ 0297:01ec |
| 0x37a > 05 @ 0297:01f5 |
| 0x379 < 8f @ 0297:01fa |
| 0x37a > 04 @ 0297:0211 |
| 0x378 > 00 @ 0297:01ec |
| 0x37a > 05 @ 0297:01f5 |
| 0x379 < 8f @ 0297:01fa |
| 0x37a > 04 @ 0297:0211 |
| 0x378 > 00 @ 0297:01ec |
| 0x37a > 05 @ 0297:01f5 |
| 0x379 < 8f @ 0297:01fa |
| 0x37a > 04 @ 0297:0211 |
| 0x378 > 00 @ 0297:01ec |
| 0x37a > 05 @ 0297:01f5 |
| 0x379 < 8f @ 0297:01fa |
| 0x37a > 04 @ 0297:0211 |
| </programlisting> |
| <para> |
| As you can see there is a repeating structure starting at |
| address <literal>0297:01ec</literal> that consists of four io |
| accesses on the parallel port. Looking at it the first io |
| access writes a changing byte to the data port the second |
| always writes the byte <literal>0x05</literal> to the control |
| port, then a value which always seems to |
| <literal>0x8f</literal> is read from the status port at which |
| point a byte <literal>0x04</literal> is written to the control |
| port. By studying this and other sections of the trace we can |
| write a C routine that emulates this, shown below with some |
| macros to make reading/writing on the parallel port easier to |
| read. |
| </para> |
| <programlisting> |
| #define r_dtr(x) inb(x) |
| #define r_str(x) inb(x+1) |
| #define r_ctr(x) inb(x+2) |
| #define w_dtr(x,y) outb(y, x) |
| #define w_str(x,y) outb(y, x+1) |
| #define w_ctr(x,y) outb(y, x+2) |
| |
| /* Seems to be sending a command byte to the scanner */ |
| int udpp_put(int udpp_base, unsigned char command) |
| { |
| int loop, value; |
| |
| w_dtr(udpp_base, command); |
| w_ctr(udpp_base, 0x05); |
| |
| for (loop=0; loop < 10; loop++) |
| if ((value = r_str(udpp_base)) & 0x80) |
| { |
| w_ctr(udpp_base, 0x04); |
| return value & 0xf8; |
| } |
| |
| return (value & 0xf8) | 0x01; |
| } |
| </programlisting> |
| <para> |
| For the UMAX Astra 600P only seven such routines exist (well |
| 14 really, seven for SPP and seven for EPP). Whether you |
| choose to disassemble the driver at this point to verify the |
| routines is your own choice. If you do, the address from the |
| trace should help in locating them in the disassembly. |
| </para> |
| <para> |
| You will probably then find it useful to write a script/perl/C |
| program to analyse the logfile and decode them futher as this |
| can reveal higher level grouping of the low level routines. |
| For example from the logs from my UMAX Astra 600P when decoded |
| further reveal (this is a small snippet) |
| </para> |
| <programlisting> |
| start: |
| put: 55 8f |
| put: aa 8f |
| put: 00 8f |
| put: 00 8f |
| put: 00 8f |
| put: c2 8f |
| wait: ff |
| get: af,87 |
| wait: ff |
| get: af,87 |
| end: cc |
| start: |
| put: 55 8f |
| put: aa 8f |
| put: 00 8f |
| put: 03 8f |
| put: 05 8f |
| put: 84 8f |
| wait: ff |
| </programlisting> |
| <para> |
| From this it is easy to see that <varname>put</varname> |
| routine is often grouped together in five successive calls |
| sending information to the scanner. Once these are understood |
| it should be possible to process the logs further to show the |
| higher level routines in an easy to see format. Once the |
| highest level format that you can derive from this process is |
| understood, you then need to produce a series of scans varying |
| only one parameter between them, so you can discover how to |
| set the various parameters for the scanner. |
| </para> |
| |
| <para> |
| The following is the <filename>shrink.c</filename> program: |
| <programlisting> |
| /* Copyright David Campbell <campbell@torque.net> */ |
| #include <stdio.h> |
| #include <string.h> |
| |
| int main (void) |
| { |
| char buff[256], lastline[256] = ""; |
| int count = 0; |
| |
| while (!feof (stdin)) |
| { |
| fgets (buff, sizeof (buff), stdin); |
| if (strcmp (buff, lastline)) |
| { |
| if (count > 1) |
| printf ("# Last line repeated %i times #\n", count); |
| printf ("%s", buff); |
| strcpy (lastline, buff); |
| count = 1; |
| } |
| else count++; |
| } |
| return 0; |
| } |
| </programlisting> |
| </para> |
| </sect1> |
| |
| <sect1 id="undoc-func"> |
| <title>Understanding undocumented APIs</title> |
| |
| <para> |
| Some background: On the i386 class of machines, stack entries are |
| usually dword (4 bytes) in size, little-endian. The stack grows |
| downward in memory. The stack pointer, maintained in the |
| <literal>esp</literal> register, points to the last valid entry; |
| thus, the operation of pushing a value onto the stack involves |
| decrementing <literal>esp</literal> and then moving the value into |
| the memory pointed to by <literal>esp</literal> |
| (i.e., <literal>push p</literal> in assembly resembles |
| <literal>*(--esp) = p;</literal> in C). Removing (popping) |
| values off the stack is the reverse (i.e., <literal>pop p</literal> |
| corresponds to <literal>p = *(esp++);</literal> in C). |
| </para> |
| |
| <para> |
| In the <literal>stdcall</literal> calling convention, arguments are |
| pushed onto the stack right-to-left. For example, the C call |
| <function>myfunction(40, 20, 70, 30);</function> is expressed in |
| Intel assembly as: |
| <screen> |
| push 30 |
| push 70 |
| push 20 |
| push 40 |
| call myfunction |
| </screen> |
| The called function is responsible for removing the arguments |
| off the stack. Thus, before the call to myfunction, the |
| stack would look like: |
| <screen> |
| [local variable or temporary] |
| [local variable or temporary] |
| 30 |
| 70 |
| 20 |
| esp -> 40 |
| </screen> |
| After the call returns, it should look like: |
| <screen> |
| [local variable or temporary] |
| esp -> [local variable or temporary] |
| </screen> |
| </para> |
| |
| <para> |
| To restore the stack to this state, the called function must know how |
| many arguments to remove (which is the number of arguments it takes). |
| This is a problem if the function is undocumented. |
| </para> |
| |
| <para> |
| One way to attempt to document the number of arguments each function |
| takes is to create a wrapper around that function that detects the |
| stack offset. Essentially, each wrapper assumes that the function will |
| take a large number of arguments. The wrapper copies each of these |
| arguments into its stack, calls the actual function, and then calculates |
| the number of arguments by checking esp before and after the call. |
| </para> |
| |
| <para> |
| The main problem with this scheme is that the function must actually |
| be called from another program. Many of these functions are seldom |
| used. An attempt was made to aggressively query each function in a |
| given library (<filename>ntdll.dll</filename>) by passing 64 arguments, |
| all 0, to each function. Unfortunately, Windows NT quickly goes to a |
| blue screen of death, even if the program is run from a |
| non-administrator account. |
| </para> |
| |
| <para> |
| Another method that has been much more successful is to attempt to |
| figure out how many arguments each function is removing from the |
| stack. This instruction, <literal>ret hhll</literal> (where |
| <symbol>hhll</symbol> is the number of bytes to remove, i.e. the |
| number of arguments times 4), contains the bytes |
| <literal>0xc2 ll hh</literal> in memory. It is a reasonable |
| assumption that few, if any, functions take more than 16 arguments; |
| therefore, simply searching for |
| <literal>hh == 0 && ll < 0x40</literal> starting from the |
| address of a function yields the correct number of arguments most |
| of the time. |
| </para> |
| |
| <para> |
| Of course, this is not without errors. <literal>ret 00ll</literal> |
| is not the only instruction that can have the byte sequence |
| <literal>0xc2 ll 0x0</literal>; for example, |
| <literal>push 0x000040c2</literal> has the byte sequence |
| <literal>0x68 0xc2 0x40 0x0 0x0</literal>, which matches |
| the above. Properly, the utility should look for this sequence |
| only on an instruction boundary; unfortunately, finding |
| instruction boundaries on an i386 requires implementing a full |
| disassembler -- quite a daunting task. Besides, the probability |
| of having such a byte sequence that is not the actual return |
| instruction is fairly low. |
| </para> |
| |
| <para> |
| Much more troublesome is the non-linear flow of a function. For |
| example, consider the following two functions: |
| <screen> |
| somefunction1: |
| jmp somefunction1_impl |
| |
| somefunction2: |
| ret 0004 |
| |
| somefunction1_impl: |
| ret 0008 |
| </screen> |
| In this case, we would incorrectly detect both |
| <function>somefunction1</function> and |
| <function>somefunction2</function> as taking only a single |
| argument, whereas <function>somefunction1</function> really |
| takes two arguments. |
| </para> |
| |
| <para> |
| With these limitations in mind, it is possible to implement |
| more stubs |
| in Wine and, eventually, the functions themselves. |
| </para> |
| </sect1> |
| <sect1> |
| <title>How to do regression testing using CVS</title> |
| |
| <para> |
| A problem that can happen sometimes is 'it used to work |
| before, now it doesn't anymore...'. Here is a step by step |
| procedure to try to pinpoint when the problem occurred. This |
| is <emphasis>NOT</emphasis> for casual users. |
| </para> |
| |
| <orderedlist> |
| <listitem> |
| <para> |
| Get the <quote>full CVS</quote> archive from winehq. This |
| archive is the CVS tree but with the tags controlling the |
| versioning system. It's a big file (> 40 meg) with a name |
| like full-cvs-<last update date> (it's more than 100mb |
| when uncompressed, you can't very well do this with |
| small, old computers or slow Internet connections). |
| </para> |
| </listitem> |
| <listitem> |
| <para> |
| untar it into a repository directory: |
| <screen> |
| cd /home/gerard |
| tar -zxf full-cvs-2003-08-18.tar.gz |
| mv wine repository |
| </screen> |
| </para> |
| </listitem> |
| <listitem> |
| <para> |
| extract a new destination directory. This directory must |
| not be in a subdirectory of the repository else |
| <command>cvs</command> will think it's part of the |
| repository and deny you an extraction in the repository: |
| <screen> |
| cd /home/gerard |
| mv wine wine_current (-> this protects your current wine sandbox, if any) |
| export CVSROOT=/home/gerard/repository |
| cvs -d $CVSROOT checkout wine |
| </screen> |
| </para> |
| <para> |
| Note that it's not possible to do a checkout at a given |
| date; you always do the checkout for the last date where |
| the full-cvs-xxx snapshot was generated. |
| </para> |
| <para> |
| Note also that it is possible to do all this with a direct |
| CVS connection, of course. The full CVS file method is less |
| painful for the WineHQ CVS server and probably a bit faster |
| if you don't have a very good net connection. |
| </para> |
| </listitem> |
| <listitem> |
| <para> |
| you will have now in the <filename>~/wine</filename> |
| directory an image of the CVS tree, on the client side. |
| Now update this image to the date you want: |
| <screen> |
| cd /home/gerard/wine |
| cvs update -PAd -D "2004-08-23 CDT" |
| </screen> |
| </para> |
| <para> |
| The date format is <literal>YYYY-MM-DD HH:MM:SS</literal>. |
| Using the CST date format ensure that you will be able to |
| extract patches in a way that will be compatible with the |
| wine-cvs archive |
| <ulink url="http://www.winehq.org/hypermail/wine-cvs"> |
| http://www.winehq.org/hypermail/wine-cvs</ulink> |
| </para> |
| <para> |
| Many messages will inform you that more recent files have |
| been deleted to set back the client cvs tree to the date |
| you asked, for example: |
| <screen> |
| cvs update: tsx11/ts_xf86dga2.c is no longer in the repository |
| </screen> |
| </para> |
| <para> |
| <command>cvs update</command> is not limited to upgrade to |
| a <emphasis>newer</emphasis> version as I have believed for |
| far too long :-( |
| </para> |
| </listitem> |
| <listitem> |
| <para> |
| Now proceed as for a normal update: |
| </para> |
| <screen> |
| ./configure |
| make depend && make |
| </screen> |
| <para> |
| If any non-programmer reads this, the fastest method to |
| get at the point where the problem occurred is to use a |
| binary search, that is, if the problem occurred in 1999, |
| start at mid-year, then is the problem is already here, |
| back to 1st April, if not, to 1st October, and so on. |
| </para> |
| <para> |
| If you have lot of hard disk free space (a full compile |
| currently takes 400 Mb), copy the oldest known working |
| version before updating it, it will save time if you need |
| to go back. (it's better to <command>make |
| distclean</command> before going back in time, so you |
| have to make everything if you don't backup the older |
| version) |
| </para> |
| <para> |
| When you have found the day where the problem happened, |
| continue the search using the wine-cvs archive (sorted by |
| date) and a more precise cvs update including hour, |
| minute, second: |
| <screen> |
| cvs update -PAd -D "2004-08-23 15:17:25 CDT" |
| </screen> |
| This will allow you to find easily the exact patch that |
| did it. |
| </para> |
| </listitem> |
| <listitem> |
| <para> |
| If you find the patch that is the cause of the problem, |
| you have almost won; report about it to |
| <ulink url="http://bugs.winehq.org/">Wine Bugzilla</ulink> |
| or subscribe to wine-devel and post it there. There is a |
| chance that the author will jump in to suggest a fix; or |
| there is always the possibility to look hard at the patch |
| until it is coerced to reveal where is the bug :-) |
| </para> |
| </listitem> |
| </orderedlist> |
| </sect1> |
| <sect1> |
| <title>Which code has been tested?</title> |
| <para> |
| Deciding what code should be tested next can be a difficult |
| decision. And in any given project, there is always code that |
| isn't tested where bugs could be lurking. This section goes |
| over how to identify these sections using a tool called gcov. |
| </para> |
| <para> |
| To use gcov on wine, do the following: |
| </para> |
| <orderedlist> |
| <listitem> |
| <para> |
| In order to activate code coverage in the wine source code, |
| when running <command>make</command> set |
| <literal>CFLAGS</literal> like so <command>make |
| CFLAGS="-fprofile-arcs -ftest-coverage"</command>. Note that |
| this can be done at any directory level. Since compile |
| and run time are significantly increased by these flags, you |
| may want to only use these flags inside a given dll directory. |
| </para> |
| </listitem> |
| <listitem> |
| <para> |
| Run any application or test suite. |
| </para> |
| </listitem> |
| <listitem> |
| <para> |
| Run gcov on the file which you would like to know more |
| about code coverage. |
| </para> |
| </listitem> |
| </orderedlist> |
| <para> |
| The following is an example situation when using gcov to |
| determine the coverage of a file could be helpful. We'll use |
| the <filename>dlls/lzexpand/lzexpand_main.c.</filename> file. |
| At one time the code in this file was not fully tested (as it |
| may still be). For example at the time of this writing, the |
| function <function>LZOpenFileA</function> had the following |
| lines in it: |
| <screen> |
| if ((mode&~0x70)!=OF_READ) |
| return fd; |
| if (fd==HFILE_ERROR) |
| return HFILE_ERROR; |
| cfd=LZInit(fd); |
| if ((INT)cfd <= 0) return fd; |
| return cfd; |
| </screen> |
| Currently there are a few tests written to test this function; |
| however, these tests don't check that everything is correct. |
| For instance, <constant>HFILE_ERROR</constant> may be the wrong |
| error code to return. Using gcov and directed tests, we can |
| validate the correctness of this line of code. First, we see |
| what has been tested already by running gcov on the file. |
| To do this, do the following: |
| <screen> |
| cvs checkout wine |
| mkdir build |
| cd build |
| ../wine/configure |
| make depend && make CFLAGS="-fprofile-arcs -ftest-coverage" |
| cd dlls/lxexpand/tests |
| make test |
| cd .. |
| gcov ../../../wine/dlls/lzexpand/lzexpand_main.c |
| 0.00% of 3 lines executed in file ../../../wine/include/wine/unicode.h |
| Creating unicode.h.gcov. |
| 0.00% of 4 lines executed in file /usr/include/ctype.h |
| Creating ctype.h.gcov. |
| 0.00% of 6 lines executed in file /usr/include/bits/string2.h |
| Creating string2.h.gcov. |
| 100.00% of 3 lines executed in file ../../../wine/include/winbase.h |
| Creating winbase.h.gcov. |
| 50.83% of 240 lines executed in file ../../../wine/dlls/lzexpand/lzexpand_main.c |
| Creating lzexpand_main.c.gcov. |
| less lzexpand_main.c.gcov |
| </screen> |
| Note that there is more output, but only output of gcov is |
| shown. The output file |
| <filename>lzexpand_main.c.gcov</filename> looks like this. |
| <screen> |
| 9: 545: if ((mode&~0x70)!=OF_READ) |
| 6: 546: return fd; |
| 3: 547: if (fd==HFILE_ERROR) |
| #####: 548: return HFILE_ERROR; |
| 3: 549: cfd=LZInit(fd); |
| 3: 550: if ((INT)cfd <= 0) return fd; |
| 3: 551: return cfd; |
| </screen> |
| <command>gcov</command> output consists of three components: |
| the number of times a line was run, the line number, and the |
| actual text of the line. Note: If a line is optimized out by |
| the compiler, it will appear as if it was never run. The line |
| of code which returns <constant>HFILE_ERROR</constant> is |
| never executed (and it is highly unlikely that it is optimized |
| out), so we don't know if it is correct. In order to validate |
| this line, there are two parts of this process. First we must |
| write the test. Please see <xref linkend="testing"> to |
| learn more about writing tests. We insert the following lines |
| into a test case: |
| <screen> |
| INT file; |
| |
| /* Check for non-existent file. */ |
| file = LZOpenFile("badfilename_", &test, OF_READ); |
| ok(file == LZERROR_BADINHANDLE, |
| "LZOpenFile succeeded on nonexistent file\n"); |
| LZClose(file); |
| </screen> |
| Once we add in this test case, we now want to know if the line |
| in question is run by this test and works as expected. You |
| should be in the same directory as you left off in the previous |
| command example. The only difference is that we have to remove |
| the <filename>*.da</filename> files in order to start the |
| count over (if we leave the files than the number of times the |
| line is run is just added, e.g. line 545 below would be run 19 times) |
| and we remove the <filename>*.gcov</filename> files because |
| they are out of date and need to be recreated. |
| </para> |
| <screen> |
| rm *.da *.gcov |
| cd tests |
| make |
| make test |
| cd .. |
| gcov ../../../wine/dlls/lzexpand/lzexpand_main.c |
| 0.00% of 3 lines executed in file ../../../wine/include/wine/unicode.h |
| Creating unicode.h.gcov. |
| 0.00% of 4 lines executed in file /usr/include/ctype.h |
| Creating ctype.h.gcov. |
| 0.00% of 6 lines executed in file /usr/include/bits/string2.h |
| Creating string2.h.gcov. |
| 100.00% of 3 lines executed in file ../../../wine/include/winbase.h |
| Creating winbase.h.gcov. |
| 51.67% of 240 lines executed in file ../../../wine/dlls/lzexpand/lzexpand_main.c |
| Creating lzexpand_main.c.gcov. |
| less lzexpand_main.c.gcov |
| </screen> |
| <para> |
| Note that there is more output, but only output of gcov is |
| shown. The output file |
| <filename>lzexpand_main.c.gcov</filename> looks like this. |
| </para> |
| <screen> |
| 10: 545: if ((mode&~0x70)!=OF_READ) |
| 6: 546: return fd; |
| 4: 547: if (fd==HFILE_ERROR) |
| 1: 548: return HFILE_ERROR; |
| 3: 549: cfd=LZInit(fd); |
| 3: 550: if ((INT)cfd <= 0) return fd; |
| 3: 551: return cfd; |
| </screen> |
| <para> |
| Based on gcov, we now know that |
| <constant>HFILE_ERROR</constant> is returned once. And since |
| all of our other tests have remain unchanged, we can assume |
| that the one time it is returned is to satisfy the one case we |
| added where we check for it. Thus we have validated a line of |
| code. While this is a cursory example, it demostrates the |
| potential usefulness of this tool. |
| </para> |
| <para> |
| For a further in depth description of gcov, the official gcc |
| compiler suite page for gcov is <ulink |
| url="http://gcc.gnu.org/onlinedocs/gcc-3.2.3/gcc/Gcov.html"> |
| http://gcc.gnu.org/onlinedocs/gcc-3.2.3/gcc/Gcov.html</ulink>. |
| There is also an excellent article written by Steve Best for |
| Linux Magazine which describes and illustrates this process |
| very well at |
| <ulink url="http://www.linux-mag.com/2003-07/compile_01.html"> |
| http://www.linux-mag.com/2003-07/compile_01.html</ulink>. |
| </para> |
| </sect1> |
| |
| </chapter> |
| |
| <!-- Keep this comment at the end of the file |
| Local variables: |
| mode: sgml |
| sgml-parent-document:("wine-devel.sgml" "set" "book" "part" "chapter" "") |
| End: |
| --> |
