Be Driven
  Device Drivers in the Be Os
     
    Debugging Drivers

Debugging Device Drivers

Welcome to the Cow...
Debugging Device Drivers
To date, the most enlightening How Toos are both written by Victor Tsou.
Copied Whole from Be Newsletter,Volume II, Issue 21; May 27, 1998
"
Question: Why is it that every time my device driver runs, my system hangs?

Fuuuunnnk daaaat!

Development behind the 2 GB iron curtain is often difficult, so the kernel provides several functions to help you track down bugs in your device driver or kernel add-on. You can follow along at home in the "Exported Kernel Functions" section of the "Device Drivers" chapter in the online Be Book.

The most primitive debugging function is dprintf(), which squirts formatted text through the serial port, much like the SERIAL_PRINT() macro of Support Kit fame. Unlike SERIAL_PRINT(), dprintf() is accessible from kernel space.

As always, serial communication occurs through /dev/serial1 on x86, /dev/serial4 on the BeBox, and /dev/modem on the Mac with data parameters 19200 N81.

No doubt you've been meaning to dust off your VT52 anyway.

If nothing comes out of the serial port, serial output is probably disabled. There are a few ways of turning it on, including:

  • Holding down the delete key on Macs or the F1 key on x86 or BeBox machines during bootup.

  • Calling set_dprintf_enabled(true), as detailed in the Be Book.

Once you've established a serial debugging connection, you may find yourself a frequent guest of the kernel debugger. The kernel debugger is typically triggered by an exception in kernel space.

You can also programmatically enter it with kernel_debugger(). The kernel debugger, for the most part, presents a read-only snapshot of the universe. This tool possesses limited poking abilities, but there is currently no way of modifying register values and breakpoints short of wading through stack frames and writing over code.

Typing "help" will give you a list of the debugger's capabilities. Don't bother to RTFM; that's all the M that's available for now (this will be rectified in the future).

The debugger understands symbols found in xMAP files, which is helpful in deciphering stack traces. Every aspiring kernel driver writer should copy the kernel's xMAP from the installation CD to /system. The kernel can be instructed to load your driver's symbols with load_driver_symbols(). This function searches for a specific xMAP in the drivers, file_systems, pnp, and cam subdirectories of the kernel add-ons directories.

In large functions, it's often difficult to identify the precise source line triggering the exception. Fortunately, the -g and -machinecodelist mwcc options working in tandem can provide you with an enlightening interleaved assembly and source view of your code. Its contents will let you locate the crash in no time at all.

Look for kernel debugger improvements in R4, including breakpoints, tracing, and improved register shadowing (how many times have you wanted to do 'dis eip' or 'esp += 8'?). These commands and more will help ease the
burden of locating bugs and can be used to avert impending crashes through judicious stack and pc manipulation.

In fine Hiroshi fashion, here are three insightful yet unrelated techniques for faster driver development:

ASSERT()

Although there is no predefined ASSERT() macro for kernel drivers, there's nothing to prevent you from selfishly cobbling one together for your personal use:

assert.h: 
#ifndef DEBUG #define ASSERT(c) 0 #else int _assert_(char *,int,char *); #define ASSERT(c) (!(c) ? _assert_(__FILE__,__LINE__,#c) : 0) #endif
assert.c: #ifdef DEBUG int _assert_(char *a, int b, char *c) { dprintf("tripped assertion in %s/%d (%s)\n", a, b, c); kernel_debugger("tripped assertion"); return 0; }
#endif


ioctl()

If the driver/add-on protocol includes an ioctl() facility, use it as a runtime debugging aid. For example, ioctls may be defined to print out important data structures or verify data integrity. Here's a short program you can modify to issue human-readable ioctl() commands to your driver.

#include <fcntl.h> 
#include <stdio.h> 
#include <stdlib.h> 
#include <string.h> 
#include <unistd.h> 
struct cmds { char *string; int code; } commands[] = {
/* replace with your ioctls */ { "dumpinfo", 10000 }, { "verifyintegrity", 10001 }, { "simulateerror", 10002 }, { "reset", 10003 }, { NULL, 0 } };
static void print_help()
{ int i; printf("usage: ioctl command files...\n"); printf("commands: %s", commands[0]); for (i=1;commands[i].string != NULL;i++) printf(", %s", commands[i]); printf("\n"); exit(-1); }
int main(int argc, char **argv)
{ int fd, i, code; if (argc < 3) print_help(); for (i=0;commands[i].string;i++) { if (!strcasecmp(commands[i].string, argv[1])) { code = commands[i].code; break; } }
if (commands[i].string == NULL) { for (i=0;argv[1][i];i++) if ((argv[1][i] < '0') || (argv[1][i] > '9')) break;
if (argv[1][i]) print_help();
code = atoi(argv[1]); } for (i=2;i<argc;i++) {
if ((fd = open(argv[i], O_RWMASK)) < 0) { printf("error opening %s (%s)\n", argv[i], strerror(fd)); continue; }
ioctl(fd, code); close(fd); }
return 0; }
add_debugger_command()

ioctl() is nice and all, but you'll soon lust for some of that post-mortem loving.

Fortunately, the kernel debugger allows you to hook in new commands with add_debugger_command(). This function registers a callback with the kernel debugger that is called with main()-style argc/argv arguments.

When writing a kernel debugger command, remember that it may be called while the kernel is in an unpredictable state. This means malloc() and friends are off limits, as they may induce swapping. dprintf() is also a no-no; use the stripped down equivalent kprintf() instead.

Since added kernel debugger commands normally lie in the driver's memory space, the kernel debugger runs into problems involving accessing unallocated memory when the driver is unloaded. Drivers should therefore remove added commands with remove_debugger_command() (new for R3.1) when they are unloaded.

Want code?

int do_echo(int argc, char **argv) 
{ 
    int i; 
    if (argc == 1) { 
        kprintf("echo <args> - prints arguments\n"); 
        return 0; 
    } 
for (i=1;i<argc;i++) kprintf("%s\n", argv[i]);
return 0;
}
status_t init_driver() {
add_debugger_command("echo", do_echo,
"echo <args> - prints arguments" );
...
}
status_t uninit_driver()
{
remove_debugger_command("echo", do_echo);
...
}

"
More About The Same Sorta Stuff
Be Newsletter, Volume II, Issue 27; July 8, 1998

"
The debug server provides the default user-level debugger on the BeOS. The debugger can be called in a number of ways:

  • Following a program crash, the debugger will be brought up on the offending instruction.

  • The debugger() function, defined in , programmatically invokes the debugger on the calling thread.

  • The db command-line program can be used to either debug an existing thread or begin a debugging session on a new program. It takes the thread number or the name of the executable to debug as an argument.

The debugger is somewhat more capable than its kernel-level counterpart; for example, it allows you to set breakpoints and single-step. For a full list of available commands, type "help" at the debugger's command prompt.

While it only displays information at the assembly level, the debugger understands symbols in xMAP files. xMAPs for the system libraries are included in the /optional folder of the installation CD and should be copied to /system/lib. To generate xMAPs for your own images, pass the "-map" option to the linker followed by the name of the xMAP to generate (typically the application name followed by .xMAP). If you're using the BeIDE, you can achieve the same effect by checking the "Generate Link Map" linker option in the project settings dialog.

While debugging, you'll typically know the name of the function you're examining (by looking up the symbol associated with the current eip/pc) but not the precise source line. Again, for those who read the article concerning
debugging device drivers:

** Above ** Issue 21

the combination of the -g and -machinecodelist mwcc options will reward you with an interlaced source/assembly dump of your code, allowing you to quickly associate eip/pc values with source lines.

Along similar lines, the pedump (for x86) and pefdump (for PowerPC) programs disassemble and report import, export, and dependency information for executables, add-ons, and libraries. These tools are xMAP-aware and their output is more readable when the appropriate xMAPs are present. The import/export information is particularly useful and may be used to quickly check if a program was compiled correctly.

For example, if the Tracker refuses to load an add-on, a quick check with pedump/pefdump may reveal an improperly exported process_refs(). The dependency information can help identify the libraries an application
requires; no longer shall the "Not an executable" error message leave you scratching your head.

The /bin directory contains a variety of additional tools helpful for debugging while your application is running. Among these are several programs that display information about kernel constructs. A sampling of the available
programs and the information they reveal:

- ps: Display thread info

  • thread -- the thread id

  • name -- the name of the thread

  • state -- running (run), ready (rdy), suspended (sus), sleeping (zzz), in receive_data() (msg), or waiting on a semaphore (sem)

  • prio -- thread priority

  • user -- time, in milliseconds, the thread has spent executing user code

  • kernel -- time, in milliseconds, the thread has spent executing kernel code

  • semaphore -- semaphore the thread is waiting to acquire

- listarea: Display area info

  • id -- area id

  • name -- area name

  • address -- address of the area in the address space of the team that created it

  • size -- in bytes of the area

  • allocated -- number of bytes currently in physical memory

  • #-cow -- copy on write count

  • #-in -- number of times any of the pages in the area have been swapped in

  • #-out -- number of times any of the pages in the area have been swapped out

- listport: Display port info

  • id -- port id

  • name -- port name

  • capacity -- length of port's message queue

  • queued -- number of messages currently in the queue

- listsem: Display semaphore info

  • id -- sem id

  • name -- semaphore name

  • count -- semaphore's current value  

"

Using SysLog, If you can understand it!

So you want to log to file ;-) Well, there is No Formal Documentation available from Be on this API, but the headers are there, and there was a newsletter written up on the subject matter (not so crash hot).

SysLog comes out of the unix land, and syslog_daemon is responsible for receiving the calls, and logging them to file for you. unlike the 'unix' functions, the logging IS multi-thread safe. syslog_daemon is a simple Be application that sits waiting for Be messages and conditionally writes them to a file, serial port, or the standard error stream.

SysLog is usable from applications, servers, and the kernel, making it quite versatile.

The syslog file is locate at : /boot/log/syslog

Currently the operating system uses syslog to document the Boot processes. So this service won't disapear anytime soon. ;-)

The Function Prototypes lacked the field names, and SHOULD have read as follows.

<syslog.h>
// The Original Unix Type Calls, Map to a Thread Level Arrangment.
//
void openlog ( char *ident, int logopt, int facility );
void closelog ( void ); void syslog ( int priority, char *message, ... ); int setlogmask ( int maskpri );
// Funcs specific for logging as a Team.
//
void openlog_team ( char *ident, int logopt, int facility );
void closelog_team ( void ); void log_team ( int priority, char *message, ... );
int setlogmask_team ( int maskpri );
// Funcs specific for logging at as Thread,
// Same as default unix calls.
//
void openlog_thread ( char *ident, int logopt, int facility );
void closelog_thread ( void );
void log_thread ( int priority, char *message, ... );
int setlogmask_thread ( int maskpri );

An attempt at a good explanation of the functions in Be Land is as follows.


void openlog ( char *ident, int logopt, int facility );


Opens the log with special overides.

char *ident:
In Be, the openlog, and openlog_thread provide a name (ident) for the active thread. openlog_team is used if you wish to have one output name (ident) for an entire application.

int logopt:
The logopt provides the following options that you can OR together. So to recieve process Id with each message and to log to the serial port, you pass the value ( LOG_PID | LOG_SERIAL ).

On BeOS the values are as follows : ( from the header file )

  • LOG_PID Log the process id with each message: useful for identify-
    ing instantiations of daemons.

  • LOG_THID Log Thread Id : maps to LOG_PID

  • LOG_TMID Log Team Id : maps to LOG_PID

  • LOG_CONS No Operation.

  • LOG_NDELAY No Operation.

  • LOG_ODELAY No Operation

  • LOG_SERIAL Log to the Serial Port

  • LOG_PERROR Write the message to standard error output as well to the
    system log.

int facility:

according to Mani Varadarajan:
[ "Facility" is a predetermined classification used by the syslog_daemon; facilities include the kernel, user programs, servers, the syslog_daemon itself, and so on. ]

I hope that makes more sense to you then it does to me.

At a guess I'd say, that at any point, the BeOs decides to report to more than one file, the following is used to indicate what 'File' to put it in.. I would just make sure you use LOG_USER for the most part., but for completness, here is the list.

  • LOG_AUTH The authorization system: su(1), getty(8), login(8),
    etc.

  • LOG_AUTHPRIV The same as LOG_AUTH, but logged to a file readable only by
    selected individuals.

  • LOG_CRON The clock daemon.

  • LOG_DAEMON System daemons, such as routed(8), that are not provided
    for explicitly by other facilities.

  • LOG_FTP The Internet File Transfer Protocol daemon.

  • LOG_KERN Messages generated by the kernel. These cannot be generat-
    ed by any user processes.

  • LOG_LPR The line printer spooling system: lpr(1), lpc(8), lpd(8),
    etc.

  • LOG_MAIL The mail system.

  • LOG_NEWS The network news system.

  • LOG_SYSLOG Messages generated internally by syslogd(8).

  • LOG_USER Messages generated by random user processes. This is the
    default facility identifier if none is specified.

  • LOG_UUCP The uucp system.

  • LOG_LOCAL0 Reserved for local use.

  • Similarly for LOG_LOCAL1 through LOG_LOCAL7.

So a simple example would be..

openlog( "MyThread", LOG_PID | LOG_SERIAL, LOG_USER);

 


void closelog ( void );


Closes the log.

void syslog ( int priority, char *message, ... );

Syslog is the actual output function. You do not need to call openlog for default behaviour.

There are 8 standard priority levels, giving you the choice of the following.

0 LOG_EMERG

A panic condition. This is normally broadcast to all users.

1 LOG_ALERT

A condition that should be corrected immediately, such as a
corrupted system database.

2 LOG_CRIT

Critical conditions, e.g., hard device errors.

3 LOG_ERR

Errors.

4 LOG_WARNING

Warning messages.

5 LOG_NOTICE

Conditions that are not error conditions, but should possibly be handled specially.

6 LOG_INFO

Informational messages.

7 LOG_DEBUG

Messages that contain information normally of use only when debugging a program.

The message field follows the well none printf() rule.


int setlogmask ( int maskpri );


The setlogmask() function sets the log priority mask to maskpri and re-turns the previous mask. Calls to syslog() with a priority not set in maskpri are rejected.

Now, looking at Be headers, i can't make head or tails of it.

I could not find LOG_UPTO(), nor LOG_MASK() macros.

Try experimenting with values, and see what you get ;-)

Other SysLog Documentation

The Only other Documentation Currently Available on the Be Functions.
From the Be Newsletters..
"
DR9 of the BeOS will include a "syslog_daemon," which provides the
facility to log messages of all sorts -- from applications, servers, and the kernel -- to a file. By default each message gets a time stamp; the daemon can also log the caller's thread ID and an identifier string. Furthermore, each message can be given a priority.

For example, simple, informational debugging messages should be given the priority LOG_DEBUG; more critical messages, such as severe errors or application panics, should be given a higher priority, such as LOG_ALERT or LOG_PANIC.

Developers can then set a preference for which priority messages they want to log. If you're interested only in severe errors, for example, you wouldn't want to be bothered by ordinary debugging messages.

As the name suggests, the syslog_daemon is inspired by a similar service in the UNIX world. syslog_daemon is a simple Be application that sits waiting for Be messages and conditionally writes them to a file, serial port, or the standard error stream.

The API for using syslog_daemon is identical to its UNIX counterpart, except for multithreaded extensions. Here's an outline of the routines:

openlog_team and openlog_thread set up default logging behavior. They take the arguments: (ident, options, facility).

log_thread, log_team, and syslog take printf()-style specifiers and fire a message off to the syslog_daemon. They take the arguments: (options, format string, ...).

setlogmask_team and setlogmask_thread set which messages to mask on a priority basis. They take the argument: (prioritymask).

closelog_team and closelog_thread end a logging session.
logger is a command-line routine to use in shell scripts.

The routines are grouped by team or thread, because it's sometimes desirable to report messages on a per-team basis rather than on a per-thread basis. The bare routines openlog(), syslog(), setlogmask(), and closelog() default to the per-thread functions.

The openlog calls are optional; if the program doesn't call openlog itself, the first call to the logging routine will implicitly call it. Openlog just allows the programmer to set up default options (such as thread ID logging, serial port output, and so on) and an identifier string for all logged messages from the thread or team. "Facility" is a predetermined classification used by the syslog_daemon; facilities include the kernel, user programs, servers, the syslog_daemon itself, and so on.

The log_thread, log_team, and syslog() functions are the moral equivalents of printf() and accept all the same specifiers.

The messages are logged as follows:

Feb 13 13:14:49 'ftpd'[145]: received 1000 bytes
Feb 13 13:15:01 'thread1'[200]: got here! yeah!
Feb 13 13:15:05 'thread1'[200]: Waiting on semaphore foobar
Feb 13 13:15:07 'thread2'[201]: Waiting on semaphore foobar

Currently, all messages are logged in a single system-wide file. Ideally, I'd like to set up the ability for each application to optionally specify a different log file, but it's unlikely that I'll have that finished for DR9. I'm also planning a reasonably nice Log Viewer (a la Event Viewer on Windows NT), which will allow users to view and sort messages according to various criteria.
"
Be Newsletter, Issue 61, February 19, 1997
Tools to Help with Extermination
By Mani Varadarajan

Setting Up A Debugging Environment : Hardware

Anybody Got Any Experience with this?


The Communal Be Documentation Site
1999 - bedriven.miffy.org