Version 2.5.0, April 2024
Debugger manual written by: Eero Tamminen
See also: Hatari manual
Hatari on the WWW: http://hatari.tuxfamily.org/
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.
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.
When you save Hatari configuration, your current debugger settings are also saved to the Hatari configuration file.
Settings are following:
These are their defaults:
[Debugger] nNumberBase = 10 nSymbolLines = -1 nMemdumpLines = -1 nFindLines = -1 nDisasmLines = -1 nBacktraceLines = 0 nExceptionDebugMask = 515 nDisasmOptions = 15 bDisasmUAE = TRUE bSymbolsAutoLoad = TRUE bMatchAllSymbols = FALSE
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 have built debugger without readline support, as it is then unable to 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.
At the debugger prompt, type "help" to get a list of all the available commands and their shortcuts:
Generic commands:
cd ( ) : change directory
echo ( ) : output given string(s)
evaluate ( e) : evaluate an expression
help ( h) : print help
history (hi) : show last CPU and/or DSP PC values + 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
screenshot ( ) : save screenshot to given file
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
find ( ) : find given value sequence from memory
profile ( ) : profile CPU code
cpureg ( r) : dump register values or set register to value
memdump ( m) : dump memory
struct ( ) : structured memory output for breakpoints
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
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.
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/address/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 readline), result from the last "evaluate" command can be inserted by typing '$' and pressing TAB.
When debugging something, there can be so much output that you want to store emulator output for more detailed inspection later.
Hatari has 5 different kinds of outputs and their controls:
With 3 first options defaulting to "stderr".
If you want to catch all of them, it is better just to redirect all "stdout" and "stderr" output from Hatari to a file:
hatari --parse debugger.ini --trace os_base 2>&1 | tee out.log
("2>&1" redirects stderr to stdout for piping, and "tee" command both saves and shows the output, so that you can still see the saved output in more or less real-time.)
[1] E.g. VT52 console redirection to Hatari standard output is enabled with "os_base" and "os_all" trace settings and "--conout 2" option.
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 (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 program counter (PC) address every time you re-enter the debugger. If history is enabled and it includes addresses just before PC, disassembly will instead start from a slightly earlier address to give more context.
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").
One can also show contents of arbitrary program structs with the "struct" command. Parts of the structure can be skipped (with 's') and they can be shown in different number bases (e.g. 'wb' = word in binary):
> struct TOS 0xe00000 :s:2 version:wh:1 :s:20 os_date:lh os_conf:wb :s:14 :a:4 TOS: $e00000 + version : 0206 + os_date : 03172024 + os_conf : 0000000011111111 + $2c : ETOSBy saving such command to a file, it can be used with breakpoint ":file" option, to show contents of a given structure, whenever that breakpoint matches.
By using the "lock" command, you can ask Hatari to show specific information whenever you enter the debugger, e.g. due to 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).
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").
C++ (and other similar languages) store symbols in binaries in a "mangled" format used by tools like linkers, and symbol names need to be "demangled" (expanded) to a more readable / user-friendly format. This can be done using a tool coming with the C++ compiler (in "binutils-m68k-atari-mint" package). ScummVM example:
$ gst2ascii scummvm.ttp | m68k-atari-mint-c++filt > scummvm.sym
(When symbols are in a file named as "<prgname>.sym", Hatari debugger will load symbols from it, not from the program file.)
Note: many demangled C++ symbols contain special characters which prevent them from being given as arguments to breakpoints and other debugger commands. One should use (resolved) symbol address instead for those commands.
Addresses for symbols that match user specified substring, can be listed like this:
symbols name XMLParser::parse
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 invoked, and removed when that 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:
You can view the generated symbols (and convert them to debugger ASCII format) with tool installed with Hatari:
$ gst2ascii program.tos > program.sym
(By default "gst2ascii" filters out same symbols as Hatari debugger does.)
For C++ programs, pipe the that output through m68k-atari-mint-c++filt demangler (see above) before directing it to a file.
Symbols in a program can be overridden by providing similarly named ".sym" file in the same directory. If for example there is a file called "program.sym", debugger will try to load that instead of "program.prg" (when debugger is first invoked after that program started).
There are few reasons why one might want to do that:
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
If Hatari complains that your program doesn't have debug symbol table, or its symbols are in some unsupported format, 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).
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:
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.
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 a (space and) ':' character.
a $1234 :2
b pc > "pc" :once continue
Note: you can give multiple options for conditional breakpoints, but for address breakpoints you can give only one these options. "file" and "info" options are supported only for conditional breakpoints.
"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
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.
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:
b AesOpcode ! AesOpcode && AesOpcode < 0xffff :trace
b GemdosOpcode = 0x4B && OsCallParam = 0x0
b pc = TEXT :onceNote1: It is better to trigger this breakpoint only once, because if you would leave it on, during (re)boot you would get a warning for every instruction (until TOS sets a valid basepage).
m DATA m BSS
b HBL = "HBL+20"
b PConSymbol = 1
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
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:
# continue to "program.ini" on Pexec(0, ....) b GemdosOpcode = 0x4B && OsCallParam = 0x0 :trace :once :file program.ini
# continue to "trace.ini" when program execution starts b pc = TEXT :trace :once :file trace.ini
# load symbols, trace gemdos & program function calls symbols prg trace gemdos,cpu_symbols # continue to "disable.ini" after 4 VBLs b VBL = "VBL+4" :trace :once :file disable.ini
# stop tracing and remove breakpoints trace none b all
And then start Hatari with the first debugger input file:
hatari --parse pexec.ini /path/to/your/program.tos
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.
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:
"subreturn" differs from others by running until current subroutine ends, even if other subroutines are called before that. This is particularly useful for profiling more complex functions; set breakpoint on function start, enable profiling and run until that functions returns, to get its full profile. Example: "n subreturn", or "dn subreturn".
Notes:
(Hatari needs to be built with ENABLE_TRACING define set for tracing to work. By default it is.)
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 except 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 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.
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.)
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.
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 depends on Hatari emulation accuracy. Profile data accuracy from most to least accurate when Hatari's default emulation options are used is following:
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).
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:
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.
Saved profile data can be post-processed with (Python) script installed by Hatari, to:
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 etos1024k.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 -b -a -d program.prg > program.sym
(Options given to "gst2ascii" filter out symbols for other things than what are in the program code section.)
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 -b -a -d program.prg | grep -v -e useless1 -e useless2 > program.sym
For C++ programs, see earlier section(s) on how to best provide symbols for them.
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).
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 column are sums for costs accounted for all the adresses 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 symbols file does not contain addresses for all the relevant symbols, results from this can be misleading; instruction costs get assigned to whatever symbol's address happened to precede those instructions. And you do not see which caller is causing it from caller info or callgraphs either, as entry point for that time sink missing a symbol means calls to it had not been tracked by profiler...
The next two percentages (and cost counts) are total cost of calls to given subroutine, based on profiler runtime branch tracking (see caller information documented above). First value is ("exclusive") cost for just that subroutine (from its entry, until execution returns to where it was called from), without costs for branches to further subroutines. Latter value is ("inclusive") cost covering also costs for all the subroutines it calls.
Reasons why "between-symbols" costs, and subroutine call costs can differ, are following:
In the first case, you should check saved profile disassembly to find out whether there are missing symbols for executed function entry points. You can notice function entry points as address gaps and/or instructions retrieving arguments from stack. Exit points can be seen from RTS instructions.
Second case can also be seen from the profile disassembly. 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 optimizations based on profile information, you should always verify from profile disassembly where exactly the costs are in a function, to make sure your optimization efforts can actually have an impact on performance.
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:
$ dot -Tsvg program-profile-1.dot > program-profile-1.svg(problem with most PS/PDF and SVG viewers is that either they don't allow zooming large callgraphs enough or they use huge amounts of memory and get very slow)
Produced callgraph will look like this:
Interpreting the callgraph:
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
Here's a list of some common debugging tasks and how to do them with the Hatari debugger:
trace gemdos,io_allPlease see Tracing section for more information on tracing, what's possible with it and what are its limitations.
a $12345 :6
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).
b d1 = 5
b d1 ! d1
b d1 & 0xff ! d1 & 0xff
b d1 > 9 && d1 < 31
b ($ff820a).b & 2 = 2
b ($ff820a).b & 2 ! ($ff820a).b & 2
b ($ff820a).b & 2 ! ($ff820a).b & 2 :trace
find c 0xe00000 E T O SFind all potential (word aligned) RTS instructions from RAM:
find w 0x0 0x4e75
> e ($ff8802).b & 0x7 value at ($ff8802).b = $27 = %111 (bin), #7 (dec), $7 (hex)
info basepageTo see e.g. all Falcon Videl register values, use:
info videl
b VdiOpcode = $8 :quiet :info vdi
b VBL = 100 && HBL = 40 && LineCycles = 5
b d0 = "d0 + 10"
> 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)
history cpu c [breakpoint is hit and debugger entered] history 16
history on lock history 16 c
lock registers s [new register values] s [new register values] ...
m "a7-64"-a7
lock file stack.iniPlease see also Chaining breakpoints section for more examples on what you can do with the debugger input files.
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 addressesPlease see Profiling section for more info.
profile on c [after a while, use AltGr+Pause to get back to debugger] profile addressesPlease see Profiling section for more info.
address myfunction c [back in debugger at myfunction] profile on next subreturn [back in debugger when function returns]Please see Profiling section on and how to save and analyze profiling information after that, and Stepping section for some "next subreturn" command limitations.
profile on symbols prg b pc = _my_function :quiet :noinit :file showstack.iniI.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
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.
Hatari 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. Like many other programs (Bash etc), debugger uses libreadline to handle this.
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 "libreadline*-dev" packages). Otherwise the name completion and other features don't get enabled when you configure Hatari.
In addition to the normal line editing keys, libreadline supports several keyboard shortcuts ('^' indicates Control-key):
(Above shortcuts are inherited from Emacs text editor, and work also in all shells using readline. See "man readline" on how to configure them.)