Other debugging techniques
Doing A Hardware Trace
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.
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.
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 config
(usually in ~/.wine/) and in the
ports section add the following two lines
read=0x378,0x379,0x37a,0x37c,0x77a
write=0x378,x379,0x37a,0x37c,0x77a
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.
When starting wine use the following command line, where
XXXX is the program you need to run in
order to access your scanner, and YYYY is
the file your trace will be stored in:
WINEDEBUG=+io wine XXXX 2> >(sed 's/^[^:]*:io:[^ ]* //' > YYYY)
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.
You will need to postprocess the output into a more manageable
format, using the shrink program. First
you need to compile the source (which is located at the end of
this section):
cc shrink.c -o shrink
Use the shrink program to reduce the
physical size of the raw log as follows:
cat log | shrink > log2
The trace has the basic form of
XXXX > YY @ ZZZZ:ZZZZ
where XXXX is the port in hexadecimal being
accessed, YY is the data written (or read)
from the port, and ZZZZ:ZZZZ 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.
> data was written to the port
< data was read from the port
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
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
As you can see there is a repeating structure starting at
address 0297:01ec 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 0x05 to the control
port, then a value which always seems to
0x8f is read from the status port at which
point a byte 0x04 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.
#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;
}
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.
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)
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
From this it is easy to see that put
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.
The following is the shrink.c program:
/* 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;
}
Understanding undocumented APIs
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
esp register, points to the last valid entry;
thus, the operation of pushing a value onto the stack involves
decrementing esp and then moving the value into
the memory pointed to by esp
(i.e., push p in assembly resembles
*(--esp) = p; in C). Removing (popping)
values off the stack is the reverse (i.e., pop p
corresponds to p = *(esp++); in C).
In the stdcall calling convention, arguments are
pushed onto the stack right-to-left. For example, the C call
myfunction(40, 20, 70, 30); is expressed in
Intel assembly as:
push 30
push 70
push 20
push 40
call myfunction
The called function is responsible for removing the arguments
off the stack. Thus, before the call to myfunction, the
stack would look like:
[local variable or temporary]
[local variable or temporary]
30
70
20
esp -> 40
After the call returns, it should look like:
[local variable or temporary]
esp -> [local variable or temporary]
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.
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.
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 (ntdll.dll) 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.
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, ret hhll (where
hhll is the number of bytes to remove, i.e. the
number of arguments times 4), contains the bytes
0xc2 ll hh in memory. It is a reasonable
assumption that few, if any, functions take more than 16 arguments;
therefore, simply searching for
hh == 0 && ll < 0x40 starting from the
address of a function yields the correct number of arguments most
of the time.
Of course, this is not without errors. ret 00ll
is not the only instruction that can have the byte sequence
0xc2 ll 0x0; for example,
push 0x000040c2 has the byte sequence
0x68 0xc2 0x40 0x0 0x0, 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.
Much more troublesome is the non-linear flow of a function. For
example, consider the following two functions:
somefunction1:
jmp somefunction1_impl
somefunction2:
ret 0004
somefunction1_impl:
ret 0008
In this case, we would incorrectly detect both
somefunction1 and
somefunction2 as taking only a single
argument, whereas somefunction1 really
takes two arguments.
With these limitations in mind, it is possible to implement
more stubs
in Wine and, eventually, the functions themselves.
How to do regression testing using CVS
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 NOT for casual users.
Get the full CVS
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).
untar it into a repository directory:
cd /home/gerard
tar -zxf full-cvs-2003-08-18.tar.gz
mv wine repository
extract a new destination directory. This directory must
not be in a subdirectory of the repository else
cvs will think it's part of the
repository and deny you an extraction in the repository:
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
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.
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.
you will have now in the ~/wine
directory an image of the CVS tree, on the client side.
Now update this image to the date you want:
cd /home/gerard/wine
cvs update -PAd -D "2004-08-23 CDT"
The date format is YYYY-MM-DD HH:MM:SS.
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
http://www.winehq.org/hypermail/wine-cvs
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:
cvs update: tsx11/ts_xf86dga2.c is no longer in the repository
cvs update is not limited to upgrade to
a newer version as I have believed for
far too long :-(
Now proceed as for a normal update:
./configure
make depend && make
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.
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 make
distclean before going back in time, so you
have to make everything if you don't backup the older
version)
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:
cvs update -PAd -D "2004-08-23 15:17:25 CDT"
This will allow you to find easily the exact patch that
did it.
If you find the patch that is the cause of the problem,
you have almost won; report about it to
Wine Bugzilla
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 :-)