Hatari Debugger User's Manual

Index

The debugger

Hatari has a built-in debugging interface which can be used for analyzing code that runs in the emulated system.

On Unix (Linux / macOS) debugger uses Hatari's parent console window, so make sure you run Hatari from the command line when you want to use the debugger. On Windows you need to use "-W" option to get console window. You can add an icon to your desktop that does it. On Linux it should do something like this (replace "xterm" with your favorite terminal program):

xterm -T "Hatari debug window" -e hatari

To run debugger commands from a file at Hatari startup, one can use the "--parse <file>" command line option. This is useful e.g. for debugging TOS or some demo startup code, or if you always want to use some specific debugger setup (breakpoints etc).

Note that when debugger scripts are run, current directory is set to the currently running script's directory i.e. all file operations are relative to it. After script finishes, earlier current directory is restored. To set current directory from a setup script, e.g. for scripts run at breakpoints, you need to give '-f' option for the 'cd' command.

Invoking the debugger

You can invoke the debugger manually by pressing the AltGr + Pause key combination.

With the "-D" command line option, you can toggle whether m68k exceptions will also invoke the debugger. Which exceptions cause this, can be controlled with the "--debug-except" option.

Giving "-D" option at Hatari startup is not advised because TOS HW checks generate some exceptions at every TOS boot. It is better to toggle exception catching later from the debugger with the "setopt -D" command.

Alternatively, you can give "--debug-except" option "autostart" flag (e.g. "--debug-except all,autostart"). This will enable catching of (specified) exceptions after TOS boot, when Atari program given on Hatari command line is autostarted.

Debugger configuration options

When you save Hatari configuration, your current debugger settings are also saved to the Hatari configuration file. These are their defaults:

[Debugger]
nNumberBase = 10
nSymbolLines = -1
nMemdumpLines = -1
nDisasmLines = -1
nBacktraceLines = 0
nExceptionDebugMask = 515
nDisasmOptions = 15
bDisasmUAE = FALSE
bSymbolsAutoLoad = TRUE
bMatchAllSymbols = FALSE

Settings are following:

nNumberBase
Debugger number base. Set with the debugger "setopt [bin|dec|hex]" command
nSymbolLines
Number of lines to show when listing debug symbols
nMemdumpLines
Number of memory dump lines to show
nDisasmLines
Number of disassembly lines to show
nBacktraceLines
Number of items to show in stack/bactraces
nExceptionDebugMask
Mask of exceptions which invoke debugger when exceptions catching is enabled (-D). Set with the "--debug-except" option
nDisasmOptions
External disassembler output options, set with the "--disasm" option
bDisasmUAE
Whether disassembly uses CPU core internal disassembler ("uae"), or the external disassembler ("ext" one with output options). Set with the "--disasm" option
bSymbolsAutoLoad
Whether debug symbols are automatically loaded when debugger is invoked, and freed when program exits, for Atari programs run though GEMDOS HD. Set with the "symbols autoload [on|off]" command
bMatchAllSymbols
Whether symbol name TAB-completion matches just symbols from a relevant code section, or all of them. Toggled with the "symbols match" command

Settings on how many lines are shown can be changed only from the configuration file. You should need to change/set them only if you've built debugger without readline support, as it can't then determine terminal size ("-1" = use terminal height).

Note that "--debug-except" and "--disasm" options can be given either on Hatari command line or, like all other Hatari command line options, with the debugger "setopt" command.

General debugger use

At the debugger prompt, type "help" to get a list of all the available commands and their shortcuts:

Generic commands:
           cd (  ) : change directory
     evaluate ( e) : evaluate an expression
         help ( h) : print help
      history (hi) : show last CPU/DSP PC values & executed instructions
         info ( i) : show machine/OS information
         lock (  ) : specify information to show on entering the debugger
      logfile ( f) : open or close log file
        parse ( p) : get debugger commands from file
       rename (  ) : rename given file
        reset (  ) : reset emulation
       setopt ( o) : set Hatari command line and debugger options
    stateload (  ) : restore emulation state
    statesave (  ) : save emulation state
        trace ( t) : select Hatari tracing settings
    variables ( v) : List builtin symbols / variables
         quit ( q) : quit emulator

CPU commands:
      address ( a) : set CPU PC address breakpoints
   breakpoint ( b) : set/remove/list conditional CPU breakpoints
       disasm ( d) : disassemble from PC, or given address
      profile (  ) : profile CPU code
       cpureg ( r) : dump register values or set register to value
      memdump ( m) : dump memory
     memwrite ( w) : write bytes to memory
      loadbin ( l) : load a file into memory
      savebin (  ) : save memory to a file
      symbols (  ) : load CPU symbols & their addresses
         step ( s) : single-step CPU
         next ( n) : step CPU through subroutine calls / to given instruction type
         cont ( c) : continue emulation / CPU single-stepping

DSP commands:
   dspaddress (da) : set DSP PC address breakpoints
     dspbreak (db) : set/remove/list conditional DSP breakpoints
    dspdisasm (dd) : disassemble DSP code
   dspmemdump (dm) : dump DSP memory
   dspsymbols (  ) : load DSP symbols & their addresses
   dspprofile (dp) : profile DSP code
       dspreg (dr) : read/write DSP registers
      dspstep (ds) : single-step DSP
      dspnext (dn) : step DSP through subroutine calls / to given instruction type
      dspcont (dc) : continue emulation / DSP single-stepping

Entering arguments to debugger commands

After writing (with TAB completion) one of the above command names, pressing TAB will (for most commands) show all the available subcommands.

If you want to give numbers in other number bases than the default/selected one, they need to be prefixed with a character indicating this. For decimals this prefix is "#" (#15), for hexadecimals "$" ($F), and for binary values it is "%" (%1111).

By default debugger expects all numbers without a prefix to be decimals, but you can change the default number base with the "setopt" command, just give it the desired default number base (bin/dec/hex). When using the hexadecimal number base, remember still to prefix hexadecimal numbers with '$' if they could be confused with register names (a0-7, d0-7)! Otherwise results from expressions and conditional breakpoints can be unexpected.

Calculations and immediate evaluation

Instead of a number, you can also use an arithmetic expression, by surrounding it with quotes (""). An expression can contain calculations with CPU and DSP registers, symbols and Hatari variables in addition to numbers. For example to give a sum of A0 and D0 register values to a command, use "a0+d0".

Also within arithmetic expressions, parenthesis are used to indicate indirect addressing, not to change the order of precedence. Unlike with conditional breakpoint expressions (explained below), you cannot give size for the indirect addressing, a long value is always read from the RAM address given within parenthesis. For example to get a long value pointed by stack pointer + 2, use "(a7+2)".

Values of arithmetic expressions are always evaluated before being given to a command. Except for "evaluate" and "address" commands, they always need to be marked with quotes (""). Besides arithmetic, this can be used also to give symbol/register/variable values to commands that don't otherwise interpret them. If command complains that it didn't recognize e.g. a register name, just put it to quotes and it will be "evaluated" before being given to the command.

Virtual V0-V7 "registers" can be used to store intermediate results for calculations. For example, to get a sum of "_counter" symbol address contents one could use following in suitable breakpoint:

# store counter sum to V0 virtual register
r v0=(_counter)
# store count of how many values are added
r v1="v1+1"

And then later on, calculate the average:

# round the counter sum (add half count to sum)
r v2="v0 + v1/2"
# and calculate the rounded average (rounded sum / count)
e v2/v1

(Another virtual register was used for rounding here, in case one wants to continue summing the _counter values with the original value.)

With command argument completion (see build notes), result from the last "evaluate" command can be inserted by typing '$' and pressing TAB.

Inspecting emulation state

In the beginning, probably the most interesting commands are "m" and "d" for dumping and disassembling memory regions. You can use "dm" and "dd" commands to do the same for the DSP.

> help memdump
'memdump' or 'm' - dump memory
Usage:  m [b|w|l] [start address-[end address| count]]
	dump memory at address or continue dump from previous address.
	By default memory output is done as bytes, with 'w' or 'l'
	option, it will be done as words/longs instead.  Output amount
	can be given either as a count or an address range.
> help disasm
'disasm' or 'd' - disassemble from PC, or given address
Usage:  d [start address-[end address]]
        If no address is given, this command disassembles from the last
        position or from current PC if no last position is available.
> disasm pc
$00aa6e : 2f08                                 move.l    a0,-(sp)
$00aa70 : 0241 0fff                            andi.w    #$fff,d1
$00aa74 : 207c 00fe 78c0                       movea.l   #$fe78c0,a0
$00aa7a : 2070 1000                            movea.l   (a0,d1.w),a0
$00aa7e : 4ed0                                 jmp       (a0)

Both commands accept in addition to numeric addresses also register and symbol names, like in above example. If you don't specify an address, the commands continue showing from an address that comes after the previously shown data. "disasm" command default address will be reset to PC address every time you re-enter the debugger.

Use "setopt --disasm help" if you want to set options controlling the disassembly output.

You can use the "info" command to see state of specific sets of HW registers (e.g. "info videl") and Atari OS structures (e.g. "info gemdos").

Selecting what information is shown on entering the debugger

By using the "lock" command, you can ask Hatari to show specific information whenever you enter the debugger / hit a breakpoint. For example to see disassembly from current PC address, use "lock disasm".

With the "regaddr" subcommand, you see disassembly or memory dump of an address pointed by a given register ("lock regaddr disasm a0"). Of the DSP registers, only Rx ones are valid for this subcommand.

"file" subcommand can be used to get (arbitrary number of) commands parsed and executed from a given debugger input file whenever debugger is entered. With this you can output any information you need:

lock file debugger.ini

To disable showing of this extra information, use "lock default". Without arguments "lock" command will show the available options (like the "info" command does).

Debug symbols

You can load debugging symbols to the debugger with the "symbols" command (and with "dspsymbols" for DSP). These symbolic names can be used in arithmetic expressions and conditional breakpoint expressions. They also show up in the "disasm" command output and you can trace calls to them with "trace cpu_symbols" (and DSP symbols with "trace dsp_symbols").

For a program under GEMDOS HD emulation

If currently running program contains debug symbol table, and it is started from GEMDOS HD emulated drive, its symbol names / addresses are automatically loaded when debugger is entered, and removed when program terminates.

Above happens only if there are no symbols loaded when the program starts. If there are, you can load program symbol data manually with the following command, after program has been loaded to the memory by TOS (see setting breakpoint at program startup):

symbols prg

The options you need to add suitable symbol table to your programs, depend on which toolchain you use to build it:

Devpac:
"OPT D+,X+"
AHCC:
"-g" and "-l" options for linking
GCC:
"-g" for compilation, and no strip option for linking (with older Hatari versions that didn't support a.out format, also "-Wl,--traditional-format" option was needed for linking)
VBCC:
"-g" (can only be used at linking phase), when VBCC configuration file uses "-bataritos" option for the linker

You can view the generated symbols (and convert them to debugger ASCII format) with tool installed with Hatari:

$ gst2ascii -l -o program.tos > program.sym
(Options -l and -o are used to exclude useless symbols from the output.)

For a program on a (disk) image

If the program isn't run from a GEMDOS HD emulated drive, but from a cartridge, floppy or HD image, you need to have the corresponding program also as a normal host file which location you can give to the debugger:

symbols /path/to/the/program.tos

ASCII debug symbol files

If Hatari complains that your program doesn't have debug symbol table, or its symbols are in some unsupported format, and you cannot re-compile it to include a.out or GST/DRI symbols, you have two options:

NOTE: nm output for GCC generated a.out binaries includes labels also for loops, not just functions. While loop labels are fine for debugging, they should be removed before profiling. Besides causing misleading profile results, loop labels can seriously slow down profiling (call graph tracking is automatically enabled for profiling when debug symbols are loaded, and operations done on each matched symbol address cause huge overhead if that match is for something happening every few instructions).

ASCII symbols file format is following:

e01034 T random
e01076 T kbdvbase
e0107e T supexec

Where 'T' means text (code), 'D' means data and 'B' means BSS section type of address. The hexadecimal address, address type letter and the symbol name are separated by white space. Empty lines and lines starting with '#' (comments) are ignored.

Debugger will automatically "relocate" the symbol addresses when it loads them from a program binary, but with ASCII symbol files you need to give the relocation offset(s) separately, unless the symbol names are for fixed addresses (like is the case e.g. with EmuTOS):

symbols program.sym TEXT DATA BSS

If you're interested only about code symbols, you can leave DATA and BSS offsets out (the values of the above virtual debugger variables like TEXT come from the currently loaded program's basepage, they're set after the program is loaded by TOS, see "info basepage" output).

Debugging resident programs

When debugging resident (TSR) programs (terminated with a Ptermres() GEMDOS call), you'll probably have a 'trigger' program that invokes some functionality in the TSR you want to debug. Loading your 'trigger' program from a Hatari GEMDOS emulated drive will autoload its symbols, thus replacing the symbols of your TSR (which you are really interested in) you loaded previously.

Symbol replacement can be avoided in two ways:

Breakpoints

There are two ways to specify breakpoints for Hatari. First, there are the simple address breakpoints which trigger when the CPU (or DSP) program counter hits a given address. Use "a" (or "da" for the DSP) to create them, for example:

a $e01034
a some_symbol

Note that address breakpoints are just wrappers for conditional breakpoints so you need to use "b" command to remove or list them.

Then there are the conditional breakpoints which can handle much more complex break condition expressions; they can track changes to register and memory values with bitmasks, include multiple conditions for triggering a breakpoint and so on. Use "b" (or "db" for the DSP) to manage them.

Help explains the general syntax:

> help b
'breakpoint' or 'b' - set/remove/list conditional CPU breakpoints
Usage:  b <condition> [&& <condition> ...] [:<option>] | <index> | help | all

Set breakpoint with given <conditions>, remove breakpoint with
given <index>, remove all breakpoints with 'all' or output
breakpoint condition syntax with 'help'.  Without arguments,
lists currently active breakpoints.

Unless you give breakpoint one of the pre-defined subcommands ('all', 'help'), index for a breakpoint to remove or no arguments (to list breakpoints), the arguments are interpreted as a new breakpoint definition.

Each conditional breakpoint can have (currently up to 4) conditions which are separated by "&&". All of the breakpoint's conditions need to be true for a breakpoint to trigger.

Breakpoint options

Normally when a breakpoint is triggered, emulation is stopped and you get to the debugger. Breakpoint options can be used to affect what happens when a breakpoint is triggered. These options are given after the conditions and are prefixed with ':'.

<count>
Break only on every <count> hit. For example, to stop on every other time PC is at given address, use:
a $1234 :2
once
Delete the breakpoint when it is hit, i.e. trigger it only once. It may be useful if you just want to get a specific address. Or if you're on an instruction that jumps back to a start of the loop and you want to finish the loop, you could use:
b pc > "pc" :once
continue
trace
Continue emulation without stopping after printing the value that triggered the breakpoint and doing other possible option actions. This is most useful when investigating memory or register value changes (explained below).
lock
Show the same information on breakpoint hit as you see when entering the debugger (see the "lock" command in Inspecting emulation state above). This enables also trace option as you would anyway see this information if debugger would be entered.
file <file>
Execute debugger commands from given <file> when this breakpoint is hit. With this you have complete control over what information is show when the debugger is hit, you can even chain breakpoints (as explained in Chaining breakpoints later on) etc. Use this if "lock" option isn't enough or you want different information show on breakpoints and when entering the debugger.
noinit
Hitting breakpoint doesn't re-initialize debugger which would e.g. cause profiling data to be reset. This implies trace option as entering debugger would also re-initialize debugger state. This option is mainly intended for breakpoints that use :file option to show backtraces with "profile stack" command during profiling. See Usage examples section for an example.

Note: you can give multiple options for conditional breakpoints, but for address breakpoints you can give only one these options. And "file" option is supported only for conditional breakpoints.

Breakpoint conditions

"b help" explains very briefly the breakpoint condition syntax:

> b help
condition = <value>[.mode] [& <mask>] <comparison> <value>[.mode]

where:
        value = [(] <register/symbol/variable name | number> [)]
        number/mask = [#|$|%]<digits>
        comparison = '<' | '>' | '=' | '!'
        addressing mode (width) = 'b' | 'w' | 'l'
        addressing mode (space) = 'p' | 'x' | 'y'

For CPU breakpoints, mode is the address width; it can be byte ("b"), word ("w") or long ("l", default). For DSP breakpoints, mode specifies the address space: "P", "X" or "Y". Note that on DSP only R0-R7 registers can be used for memory addressing. For example;

db (r0).x = 1 && (r0).y = 2

If the value is in parenthesis like in '($ff820)' or '(a0)', then the used value will be read from the memory address pointed by it. Note that this conditional breakpoint expression value is checked at run-time whereas quoted arithmetic expressions (mentioned in Entering arguments to debugger commands above) are evaluated already when adding a breakpoint. For example, to break when a value in an address (later) pointed by A0 matches the value currently in D0, one would use:

b (a0) = "d0"

If you're interested only on certain bits in the value, you can use '&' and a numeric mask on either side of comparison operator to mask the corresponding value, like this:

b ($ff820).w & 3 = (a0)  &&  (a1) = d0 & %1100

Comparison operators should be familiar and obvious, except for '!' which indicates inequality ("is not") comparison. For example:

b d0 > $20  &&  d0 < $40  &&  d0 ! $30
Tracking breakpoint conditions

As a convenience, if the both sides of the comparison are exactly the same (i.e. condition is redundant as it is always either true or false), the right side of the comparison is replaced with its current value. This way you can give something like this:

b pc > "pc"

As:

b pc > pc

That in itself isn't so useful, but for inequality ('!') comparison, conditional breakpoint will additionally track and output all further changes for the given address/register expression. This can be used for example to find out all value changes in a given memory address, like this:

b ($ffff9202).w ! ($ffff9202).w :trace

Because tracking breakpoint conditions will print the evaluated value when it changes, they're typically used with the trace option to track changes e.g. to some I/O register.

Breakpoint condition notes

Breakpoint variables

In addition to loaded symbols, the debugger supports also setting conditional breakpoints on values of some "virtual" variables listed by "variables" (v) command. For example:

Hint: "info" command "aes", "bios", "gemdos", "vdi" and "xbios" subcommands can be used to list the corresponding OS-call opcodes. For example, to see the GEMDOS opcodes, use:

info gemdos 1

Chaining breakpoints and other actions

As the file pointed by the breakpoint ":file" option (see Breakpoint options) can contain any debugger commands, it can also be used to do automatic "chaining" of debugger and breakpoint actions so that after one breakpoint is hit, another one is set.

For example if you have these input files:

And then start Hatari with the first debugger input file:

hatari --parse pexec.ini /path/to/your/program.tos
  1. "pexec.ini" sets a breakpoint to parse debugger commands from "program.ini" when TOS starts loading the given program (it is first Pexec(0) after boot)
  2. "program.ini" sets a breakpoint to parse debugger commands from "trace.ini" when program code begins executing. These two steps are needed because TEXT variable isn't valid until TOS has booted
  3. "trace.ini" input file loads symbols for the run program, sets Hatari to trace several things (see Tracing section below) in the emulated system for few VBLs until breakpoint runs commands from the "disable.ini" file
  4. "disable.ini" input file will disable tracing and remove all (remaining) breakpoints

Note:

Hint: It is better to test each input file separately before testing the whole chain. Besides the ":file" breakpoint option, you can test these debugger input files also with the debugger "file" command, "file" option for the "lock" command, and with the Hatari "--parse" command line option.

Stepping through code

After analyzing the emulation state and/or setting new breakpoints, you can continue the emulation with the "c" command. You can continue for a given number of CPU instructions (or DSP instructions when "dc" is used), or you can continue forever (until a non-tracing breakpoint triggers) if you omit the instruction count.

If you want to continue just to the next instruction, use "s" (step) command to continue for exactly one instruction, or "n" (next), if you want to skip subroutine + exception calls and DBCC branching backwards (i.e. loops). "ds" and "dn" commands do the same for DSP (except that "dn" doesn't skip loops).

You can also continue with the "n" until instruction of certain type is encountered, by giving it the instruction type:

For example: "n branch", or "dn branch".

(Note: CHK, CHK2, FBCC, FDBCC, & FTRAPCC exception / branch CPU instructions aren't supported currently.)

Tracing

If you want e.g. to continue with real-time disassembling, you can enable it with "trace cpu_disasm" (or "trace dsp_disasm" for DSP) at the debugger prompt before continuing.

Disable tracing with "trace none" when you enter the debugger again. "trace help" (or TAB) can be used to list all the (over 40) supported traceable things, from HW events to OS functions.

At run-time you can enable and disable trace flags individually by starting the trace flags with -/+, like this:

trace gemdos,aes,vdi   # trace just these
trace +xbios,bios      # trace additionally these
trace -aes,-vdi        # remove tracing of these

('+' is optional for addition exept at start of the trace flags list.)

Notes:

If there isn't a trace option for something you would like to track, you may be able to use tracing breakpoints, explained above. For example, following tracks Line-A calls:

b  LineAOpcode ! LineAOpcode  &&  LineAOpcode < 0xffff  :trace

Profiling

Profiling tells where the emulated code spends most of its (emulated) time. It can be used to find out where a program is (apparently) stuck, or what are the largest performance bottlenecks for a program.

Collecting the profile data

Profiling is used by first enabling the profiler (use "dp" for DSP):

> profile on
Profiling enabled.

And profiling will start once you continue the emulation:

> c
Returning to emulation...
Allocated CPU profile buffer (27 MB).

When you get back to the debugger, the collected profiling information is processed and a summary of in which parts of memory the execution happened, and how long it took, is shown:

Allocated CPU profile address buffer (57 KB).
ROM TOS (0xE00000-0xE80000):
- active address range:
  0xe00030-0xe611a4
- active instruction addresses:
  14240 (100.00% of all)
- executed instructions:
  4589668 (100.00% of all)
- used cycles:
  56898472 (100.00% of all)
  = 7.09347s
Cartridge ROM (0xFA0000-0xFC0000):
  - no activity

= 7.09347s

(DSP RAM will be shown only as single area in profile information.)

Investigating the profile data

When you are back in debugger, you can inspect the collected profile data:

> h profile
'profile' - profile CPU code
Usage:  profile <subcommand> [parameter]

	Subcommands:
		- on
		- off
		- counts [count]
		- cycles [count]
		- i-misses [count]
		- d-hits [count]
		- symbols [count]
		- addresses [address]
		- callers
		- caches
		- stack
		- stats
		- save <file>
		- loops <file> [CPU limit] [DSP limit]

	'on' ¨ 'off' enable and disable profiling.  Data is collected
	until debugger is entered again at which point you get profiling
	statistics ('stats') summary.

	Then you can ask for list of the PC addresses, sorted either by
	execution 'counts', used 'cycles', i-cache misses or d-cache hits.
	First can be limited just to named addresses with 'symbols'.
	Optional count will limit how many items will be shown.

	'caches' shows histogram of CPU cache usage.

	'addresses' lists the profiled addresses in order, with the
	instructions (currently) residing at them.  By default this
	starts from the first executed instruction, or you can
	specify the starting address.

	'callers' shows (raw) caller information for addresses which
	had symbol(s) associated with them.  'stack' shows the current
	profile stack (this is useful only with :noinit breakpoints).

	Profile address and callers information can be saved with
	'save' command.

	Detailed (spin) looping information can be collected by
	specifying to which file it should be saved, with optional
	limit(s) on how many bytes first and last instruction
	address of the loop can differ (0 = no limit).

For example, to see which memory addresses were executed most and what instructions those have at the end of profiling, use:

> profile counts 8
addr:           count:
0xe06f10        12.11%  555724  move.l    $4ba,d1
0xe06f16        12.11%  555724  cmp.l     d1,d0
0xe06f18        12.11%  555724  bgt.s     $e06f06
0xe06f06        12.11%  555708  move.b    $fffffa01.w,d1
0xe06f0a        12.11%  555708  btst      #5,d1
0xe06f0e        12.11%  555708  beq.s     $e06f1e
0xe00ed8         1.66%  76001   subq.l    #1,d0
0xe00eda         1.66%  76001   bpl.s     $e00ed8
8 CPU addresses listed.

Then, to see what the executed code and its costs look like around top addresses:

> profile addresses 0xe06f04
# disassembly with profile data:
# <instructions percentage>% (<sum of instructions>, <sum of cycles>, <sum of i-cache misses>, <sum of d-cache hits>)

$e06f04 :             bra.s     $e06f10                    0.00% (48, 576, 0, 0)
$e06f06 :             move.b    $fffffa01.w,d1            12.11% (555708, 8902068, 0, 0)
$e06f0a :             btst      #5,d1                     12.11% (555708, 6685268, 0, 0)
$e06f0e :             beq.s     $e06f1e                   12.11% (555708, 4457312, 0, 0)
$e06f10 :             move.l    $4ba,d1                   12.11% (555724, 11125668, 0, 0)
$e06f16 :             cmp.l     d1,d0                     12.11% (555724, 4461708, 0, 0)
$e06f18 :             bgt.s     $e06f06                   12.11% (555724, 4455040, 0, 0)
$e06f1a :             moveq     #1,d0                      0.00% (16, 64, 0, 0)
Disassembled 8 (of active 14240) CPU addresses.

Unlike normal disassembly, "profile addresses" command shows only memory addresses which instructions were executed during profiling. You get instruction cache misses only when using cycle-accurate 030 emulation with a Hatari version configured to use WinUAE CPU core.

If you have loaded symbol information, symbol names are shown above the corresponding addresses. With the "profile symbols" command you get a list of how many times the code execution passed through the defined symbol addresses.

Profile data accuracy

Profile data accuracy depends on Hatari emulation accuracy. Profile data accuracy from most to least accurate when Hatari's default emulation options are used is following:

Caller information

If you have loaded symbols (see Debug symbols) before continuing emulation/profiling, additional caller information will be collected for all the code symbol addresses which are called as subroutines. This information includes callstack, call counts, calling instruction type (subroutine call, branch, return etc), and costs for those calls, both including costs for further subroutine calls and without them.

When debugger is re-entered, current callstack is output before profiling information:

> a _P_LineAttack
CPU condition breakpoint 1 with 1 condition(s) added:
        pc = $30f44
$030f44 : 48e7 3820                            movem.l   d2-d4/a2,-(sp)
> c
...
CPU breakpoint condition(s) matched 1 times.
        pc = $30f44
Finalizing costs for 12 non-returned functions:
- 0x32a3c: _P_GunShot (return = 0x32b7e)
- 0x32b18: _A_FireShotgun (return = 0x3229a)
- 0x3223a: _P_SetPsprite (return = 0x32e86)
- 0x32e4e: _P_MovePsprites (return = 0x38070)
- 0x37f44: _P_PlayerThink (return = 0x36ea0)
- 0x36e44: _P_Ticker (return = 0x260e0)
- 0x25dcc: _G_Ticker (return = 0x1e4c6)
- 0x1e29e: _TryRunTics (return = 0x239fa)
- 0x238e8: _D_DoomLoop (return = 0x2556a)
- 0x24d7a: _D_DoomMain (return = 0x44346)
...

("profile stack" command can be used in breakpoints with :noinit option to show backtraces during caller profiling.)

Note: rest of this subsection is about caller information format which is mainly of interest for people writing profiling post-processing tools. Come back here if you think there's some problem with callgraphs produced by those tools.

Other information collected during profiling is shown with following command:

> profile callers
# <callee>: <caller1> = <calls> <types>[ <inclusive/totals>[ <exclusive/totals>]], <caller2> ..., <callee name>
# types: s = subroutine call, r = return from subroutine, e = exception, x = return from exception,
#        b = branch/jump, n = PC moved to next instruction, u = unknown PC change
# totals: calls/instructions/cycles/misses
0xe00030: 0xffffff = 1 e, _main
0xe000fe: 0xe00a0c = 1 b, memdone
0xe0010a: 0xe04e34 = 1 s 1/5/72 1/5/72, _run_cartridge_applications
0xe00144: 0xe04dbe = 1 s 4/118/1512 1/27/444, _init_acia_vecs
0xe001ea: 0xe00ec6 = 1 b, _int_acia
0xe0038c: 0xe04c28 = 1 s 1/191/2052 1/191/2052, _init_exc_vec
0xe003a6: 0xe04c2e = 1 s 1/388/4656 1/388/4656, _init_user_vec
...

For example, if you don't know all the places from which a certain function is called, or in what context a certain interrupt handler can be called during the period you are profiling, profile caller information will tell you:

callee: caller: calls: calltype:
  |       |       |   /
0x379:  0x155 = 144 r, 0x283 = 112 b, 0x2ef = 112 b, 0x378 = 72 s
583236/359708265/1631189180 72/4419020/19123430, dsp_interrupt
           |                       |                 |
    inclusive costs         exclusive costs     callee name
  (of calls from 0x378)

Calltypes:
- b: jump/branch
- n: PC  just moved to next address
- r: subroutine return
- s: subroutine call

(Most "calls" to "dsp_interrupt" were subroutine call returns (=r) to it from address 0x155.)

With the execution counts in normal profiling data, caller information can actually be used to have complete picture of what exactly the code did during profiling. Main/overview work for this analysis is best done automatically, by the profiler data post-processor (documented below).

Caller data accuracy

Everything about profile data accuracy applies also to caller costs, but there are additional things to take into account, mainly because profiler cannot determine when exceptions are being handled:

Saving profile data to a file

It is useful to save the profile data to a file:

> profile save program-profile.txt

With the saved profile disassembly (and optional caller information) you can more easily investigate what your program did during profiling, search symbols & addresses in it, and compare the results to profiles you have saved from earlier versions of your code.

You may even create your own post-processing tools for investigating the profiling data more closely, e.g. to find CPU/DSP communication bottlenecks.

Profile data post-processing

Saved profile data can be post-processed with (Python) script installed by Hatari, to:

Providing symbols for the post-processor

When the data is post-processed, you should always provide the post-processor symbols for the profile code! Relying just on the symbol in the profile data can cause costs to be assigned to wrong symbol, if symbol's code wasn't called through symbol's own address, but by jumping inside its code.

If your code is in fixed location, you should tell post-processor to handle symbol addresses as absolute (-a):

$ hatari_profile.py -a etos512k.sym emutos-profile.txt

Normal programs are relocated and you should instead give the symbols as TEXT (code) section relative ones (-r):

$ hatari_profile.py -r program.sym program-profile.txt

If symbols are included to your binary, first they need to be extracted to the ASCII format understood by the post-processor:

$ gst2ascii -a -l -o program.prg > program.sym

If there are some extra symbols that you don't want to see separately in profiles, because they aren't real functions, but e.g. loop labels, you can either remove them manually from the ASCII *.sym file, or filter them out with grep:

$ gst2ascii -a -l -o program.prg | grep -v -e useless1 -e useless2 > program.sym

Post-processor provided statistics

Above post-processor examples just parse + verify the given data and produce output like this:

Hatari profile data processor

Parsing TEXT relative symbol address information from program.sym...
[...]
3237 lines with 1550 code symbols/addresses parsed, 0 unknown.

Parsing profile information from program-profile.txt...
[...]
9575 lines processed with 368 functions.

CPU profile information from 'program-profile.txt':
- Hatari v1.6.2+ (May  4 2013), WinUAE CPU core

To get statistics (-s) and list of top (-t) CPU users in profile, add "-st" option:

$ hatari_profile.py -st -r program.sym program-profile.txt
[...]
CPU profile information from 'program-profile.txt':
- Hatari v1.6.2+ (May  4 2013), WinUAE CPU core

Time spent in profile = 34.49539s.

Calls:
- max = 187738, in __toupper at 0x52b88, on line 8286
- 1585901 in total
Executed instructions:
- max = 1900544, in flat_remap_mips+14 at 0x47654, on line 7020
- 64499351 in total
Used cycles:
- max = 15224620, in flat_remap_mips+18 at 0x47658, on line 7022
- 553392132 in total
Instruction cache misses:
- max = 184308, in _BM_T_GetTicks at 0x43b90, on line 4772
- 4941307 in total

Calls:
  11.84%      187698  __toupper
  11.48%      182105  _BM_T_GetTicks
  11.48%      182019  _I_GetTime
[...]
Executed instructions:
  34.83%    22462729  flat_generate_mips
  14.08%     9080215  flat_remap_mips
   8.55%     5515945  render_patch_direct
   5.09%     3283328  _TryRunTics
[...]
Used cycles:
  23.62%   130702768  flat_generate_mips
  12.42%    68735832  flat_remap_mips
   9.77%    54041148  _TryRunTics
   5.80%    32111536  correct_element
[...]
Instruction cache misses:
  37.03%     1829764  _TryRunTics
  11.20%      553314  _BM_T_GetTicks
   9.44%      466319  _NetUpdate
   9.27%      457899  _HGetPacket
[...]

If you want to see also symbol addresses and what is per call cost, add -i option:

$ hatari_profile.py -st -i -r program.sym program-profile.txt
[...]
Executed instructions:
  34.83%    22462729  flat_generate_mips   (0x04778a, 774576 / call)
  14.08%     9080215  flat_remap_mips      (0x047646, 313110 / call)
   8.55%     5515945  render_patch_direct  (0x047382, 29977 / call)
   5.09%     3283328  _TryRunTics          (0x042356, 19660 / call)
[...]
Used cycles:
  23.62%   8.14728s  130702768  flat_generate_mips  (0x04778a, 0.28094s / call)
  12.42%   4.28461s   68735832  flat_remap_mips     (0x047646, 0.14775s / call)
   9.77%   3.36863s   54041148  _TryRunTics         (0x042356, 0.02017s / call)
   5.80%   2.00165s   32111536  correct_element     (0x04a658, 0.00001s / call)
[...]
Instruction cache misses:
  37.03%     1829764  _TryRunTics          (0x042356, 10956 / call)
  11.20%      553314  _BM_T_GetTicks       (0x043b90, 3 / call)
   9.44%      466319  _NetUpdate           (0x041bcc, 5 / call)
   9.27%      457899  _HGetPacket          (0x041754, 5 / call)
[...]

(For cycles the "per call" information is in seconds, not as a cost count.)

If your profile file contains caller information, you should add -p option to see it, as that will also help in detecting symbol issues (see Interpreting the numbers):

$ hatari_profile.py -st -p -r program.sym program-profile.txt
[...]
9575 lines processed with 368 functions.
[...]
Of all 1570498 switches, ignored 581 for type(s) ['r', 'u', 'x'].

CPU profile information from 'badmood-level-load-CPU.txt':
- Hatari v1.6.2+ (May  4 2013), WinUAE CPU core
[...]
Calls:
  11.84%  11.84%      187698    187698  __toupper
  11.48%  11.48%      182105    182105  _BM_T_GetTicks
  11.48%  22.95%      182019    364038  _I_GetTime
[...]
Executed instructions:
  34.83%  34.86%  34.86%    22462729  22484024  22484024  flat_generate_mips
  14.08%  14.10%  14.10%     9080215   9091270   9091676  flat_remap_mips
   8.55%                     5515945                      render_patch_direct
   5.09%   5.11%  94.96%     3283328   3294022  61247717  _TryRunTics
[...]
Used cycles:
  23.62%  23.69%  23.69%   130702768 131100604 131100604  flat_generate_mips
  12.42%  12.46%  12.46%    68735832  68928816  68930904  flat_remap_mips
   9.77%   9.80%  95.66%    54041148  54238744 529368824  _TryRunTics
   5.80%   5.82%   5.82%    32111536  32193664  32193664  correct_element
[...]
Instruction cache misses:
  37.03%  37.14%  98.57%     1829764   1835261   4870573  _TryRunTics
  11.20%  11.24%  11.24%      553314    555191    555191  _BM_T_GetTicks
   9.44%   9.49%  29.13%      466319    468782   1439340  _NetUpdate
   9.27%   9.29%   9.37%      457899    459197    463217  _HGetPacket
[...]

Now there's a message telling that some of the calls were ignored because according to their "call type", they were actually returns from exceptions, not real calls (this is mainly important for callgraph generation, discussed below).

Interpreting the results

In addition to accuracy issues mentioned in previous Profiling sections, function/symbol level costs have gotchas of their own.

The first cost percentage and count columns are sums for all the instructions that were in profile data file between the indicated symbol's address and the address of the next symbol (= "between-symbols" cost).

NOTE: If your symbol file doesn't contain addresses for all the relevant symbols, results from this can be misleading because instructions costs get assigned to whatever symbol's address happened to precede those instructions. And you don't see which caller is causing it from caller info or callgraph either, as entry point for that time sink lacking a symbol means profiler hadn't tracked calls to it...

The next two cost percentage and count columns are for subroutine calls costs, first one for exclusive and latter for inclusive cost i.e. including costs for further subroutine calls. Values are based on caller information documented above.

Reasons why between-symbol costs, and subroutine call costs can differ, are following:

In the first case, you should check the profile data to find out whether there are missing symbols for executed function entry points. You can notice function entry points as address gap and/or code retrieving arguments from stack. Exit points can be seen from RTS instructions.

Second case can also be seen from the profile data. Call count is same as count for how many times first instruction is executed (worst case: large loop on subroutine's first instruction).

While subroutine costs should be more accurate and relevant, due to code optimizations many of the functions are not called as subroutines (on m68k, using JSR/BSR), but just jumped or branched to. Because of this, it is useful to compare both subroutine and between-symbols costs. One should be able to see from the profile disassembly which of the above cases is cause for the discrepancy in the values.

NOTE: Before starting to do any serious source level optimizations, you should always verify from profile data (disassembly) where exactly the costs are in a function, to make sure your optimization efforts can actually help the performance.

Generating and viewing callgraphs

Callgraphs require that saved profile data contains caller function address information, i.e. symbols for the code should be loaded before starting profiling it (see loading symbol data).

Separate callgraphs will be created for each of the costs (0=calls, 1=instructions, 2=cycles) with the -g option:

$ hatari_profile.py -p -g -r program.sym program-profile.txt
[...]
Generating 'program-profile-0.dot' DOT callgraph file...

Generating 'program-profile-1.dot' DOT callgraph file...

Generating 'program-profile-2.dot' DOT callgraph file...
[...]

Callgraphs are saved in GraphViz "dot" format. Dot files can be viewed:

Produced callgraph will look like this:

Part of callgraph

Interpreting the callgraph:

Making large callgraphs readable

If profile is for larger and more varied amount of code (e.g. program startup), the resulting callgraph can be so huge that it not really readable anymore.

If your code has interrupt handlers, they can get called at any point, which can show in callgraph as "explicit" calls from the interrupted functions. To get rid of such incorrect calls, give interrupt handler names to --ignore-to option:

$ hatari_profile.py -p -g --ignore-to handler1,handler2 -r program.sym program-profile.txt

In large callgraph most of the functions aren't really interesting, because their contribution to the cost is insignificant. You can remove large number of them with --no-leafs and --no-intermediate options, those options act only on nodes which costs are below given threshold. Leaf nodes are ones which don't have any parents and/or children. Intermediate ones have only single parent and children (node calling itself is not taken into account).

Threshold for this is given with the --limit (-l) option. With that it typically makes also sense to change the node emphasis threshold with --emph-limit (-e) option:

$ hatari_profile.py -p -g -l 0.5 -e 2.0 -r program.sym program-profile.txt

If you are not interested in from how many different addresses a given function calls another function, use --compact option. If you still see multiple calls between two nodes with it, the reason is that they happened through different call paths which were removed from the callgraph after --compact option was applied:

$ hatari_profile.py -p -g -l 1.0 -e 2.0 --no-leafs --no-intermediate --compact -r program.sym program-profile.txt

If even this doesn't help, you can remove all nodes below the given cost threshold limit with --no-limited option, but this often doesn't leave much of a call hierarchy. Instead you may consider removing all nodes except for subroutine call ones, with the --only-subroutines option.

If you have trouble locating nodes you are specially interested about, you can either color them differently with the --mark option, or exclude everything else from the callgraph except those nodes and their immediate callers & callees, with the --only option:

$ hatari_profile.py -p -g --only func1,func2 -r program.sym program-profile.txt

Last option for reading the callgraph is using -k option to export the data for use in (Linux) Kcachegrind UI. Kcachegrind generates callgraphs on the fly, and just for the area around the function you selected, so navigating in callgraph may be easier. It also shows the related profile disassembly, which can make verifying matters easier:

$ hatari_profile.py -p -k -r program.sym program-profile.txt
[...]
Generating callgrind file 'program-profile.cg'...
[...]
$ kcachegrind program-profile.cg
Kcachegrind screenshot

Usage examples

Here's a list of some common debugging tasks and how to do them with the Hatari debugger:

Stopping on program startup and examining its data
Please see Breakpoint variables and Inspecting emulation state sections.
Tracing specific things in the system
To trace e.g. all GEMDOS calls and I/O operations, use:
trace  gemdos,io_all
Please see Tracing section for more information on tracing, what's possible with it and what are its limitations.
Stopping when certain PC address is passed Nth time
To stop e.g. after function/subroutine at $12345 is called for the 6th time:
a  $12345 :6
Stopping when specific exception happens
If one wants a specific breakpoint to trigger on a specific exception, one can check when its handler address is called by the CPU. At the start of memory is the CPU exception table for exception vectors. So, to stop e.g. at bus error with some extra information, one can use following:
history  on
b  pc=($8)
After bus error invokes debugger, 'history' command can then be used to see (executed memory addresses with their current) instructions leading to the error. The most interesting vector addresses are: $8 (Bus error), $C (Address error), $10 (Illegal instruction), $14 (Division by zero).
NOTE: Normally, to invoke debugger for larger set of exceptions, one would use Hatari's "--debug-except" option to specify on which exceptions debugger is invoked, and "setopt -D" to enable that on run-time.
Stopping when register has a specific value
To stop when e.g. D1 register contains value 5, set a breakpoint on:
b  d1 = 5
Stopping when a register value changes
To stop when e.g. D1 register value changes, set a breakpoint on:
b  d1 ! d1
Stopping when part of register value changes
To stop when e.g. D1 register lowest byte changes, set a breakpoint on masked lowest 8 bits:
b  d1 & 0xff ! d1 & 0xff
Stopping when register value is within some range
To stop when e.g. D1 register value is within range of 10-30, set a breakpoint on:
b  d1 > 9  &&  d1 < 31
Stopping when memory location has a specific value
To stop when e.g. bit 1 of the Video Shifter Sync Mode byte at I/O address $ff820a is set i.e. video frequency is 60Hz, set a breakpoint on:
b  ($ff820a).b & 2 = 2
Stopping when a memory value changes
To stop when above bit changes, set a breakpoint on its value being different from the current value ('!' compares for inequality):
b  ($ff820a).b & 2 ! ($ff820a).b & 2
Tracing all changes in specific memory location
To see the new values and continue without stopping, add the ":trace" breakpoint option:
b  ($ff820a).b & 2 ! ($ff820a).b & 2  :trace
Viewing OS structure and IO register values
To see e.g. basepage for currently running program:
info basepage
To see e.g. all Falcon Videl register values, use:
info videl
Stopping at specific screen position
To stop e.g. when VBL is 100, HBL is 40 and line cycles is 5, use the corresponding debugger variables:
b  VBL = 100  &&  HBL = 40  &&  FrameCycles = 5
Stopping after value increases/decreases by certain amount
To stop e.g. after D0 value has increased by 10, set breakpoint on:
b  d0 = "d0 + 10"
Examining specific system call return value
To check e.g. what's the Fopen() GEMDOS call return value, check with "info gemdos 1" its opcode, set a breakpoint for that and step to next (n) instruction from the trap call when breakpoint is hit. GEMDOS call return value is then in register D0:
> trace  gemdos
> b  GemdosOpcode = $3D
> c
[...continue until breakpoint...]
1. CPU breakpoint condition(s) matched 1 times.
        GemdosOpcode = $3D
> n
GEMDOS 0x3D Fopen("TEST.TXT", read-only)
> e  d0
= %1000000 (bin), #64 (dec), $40 (hex)
Seeing code leading to a breakpoint
To see CPU instructions executed before debugger was entered, you need to enable history tracking before it. Whenever debugger is entered, you can then request given number (here 16) of past instructions to be shown:
history  cpu
c
[breakpoint is hit and debugger entered]
history  16
Getting instruction execution history for every breakpoint
To see last 16 instructions for both CPU and DSP whenever (a normal or tracing) breakpoint is hit:
history  on
lock  history 16
c
Single stepping so that new register values are shown after each step
lock  registers
s
[new register values]
s
[new register values]
...
Showing current stack contents
To see first 64 bytes on top of the stack, use:
m  "a7-64"-a7
Seeing specific information each time debugger is entered
To see above information whenever some breakpoint is hit, you enter debugger manually etc, write that command to e.g. stack.ini file and then use:
lock  file stack.ini
Please see also Chaining breakpoints section for more examples on what you can do with the debugger input files.
Adding cycle information to disassembly
Profiling collects cycle usage information for all executed instructions:
profile  on
c
[after a while, use AltGr+Pause to get back to debugger]
d
[or if you want to see just the executed instructions]
profile addresses
Please see Profiling section for more info.
Finding where a program or the OS is stuck
Profiling tells from which addresses CPU is executing the instructions:
profile  on
c
[after a while, use AltGr+Pause to get back to debugger]
profile  counts
Please see Profiling section for more info.
Seeing program callstack when breakpoint is hit
Profiler caller data includes callstack information (with some limitations).
Seeing call backtraces whenever given function is called
Enable profiling, load symbols for the program and set breakpoint for the function you are interested about, in the following way:
profile on
symbols prg
b  pc = _my_function  :quiet :noinit :file showstack.ini
I.e. whenever 'my_function' address is called, quietly trigger a breakpoint without resetting profiling (callstack) information and run debugger command(s) from the 'showstack.ini' debugger script file, which contains following command:
profile stack
Seeing how program functions/symbols call each other
Profile data post-processing can provide execution callgraphs.

Hint: for most of the above commands, one just needs to prefix them with "d" (or "dsp" when using full command names) to do similar operation on the DSP.

Build notes

Lastly, the debugger is much nicer to use with the command line history, editing and especially the completion support for the command, command argument and symbol names.

If you are building Hatari yourself, please make sure that you have the GNU readline development files installed (on Debian / Ubuntu these come from the libreadline5-dev package). Otherwise the name completion and other features don't get enabled when you configure Hatari.

ENABLE_TRACING define needs to be set for tracing to work. By default it should be enabled.