| Re: [hatari-devel] symbols not always loaded when entering debugger ? |
[ Thread Index |
Date Index
| More lists.tuxfamily.org/hatari-devel Archives
]
Hi,
On 11/15/2017 06:33 PM, Matthias Arndt wrote:
Am Wed, 15 Nov 2017 11:53:06 +0100
schrieb Nicolas Pomarède <npomarede@xxxxxxxxxxxx>:
[Lots of valid statements]
I fully agree to the statements given. If I have a binary with symbols
and I get a crash (bombs) that throuw me into the debugger, I as a
developer expect to be able to debug into my programs with symbols.
I would like to be able backtrack from exception frame to the location
where the problem occured. Only if it leads me into function x() I am
already happy.
If you enable profiling and your debug symbols are good,
you get backtrace when you drop to debugger. I used that
to get automatically backtraces to all places in BadMood
(Doom I/II) that process files during game play.
Profiler tracks all subroutine call instructions and their
returns, for addresses that have symbols for them. Back
traces are just a side benefit from that.
I've attached my script for doing all kinds of profiling
for BadMood, in case you're interested on an example.
If you want backtraces without profiling support...
Do you have example code that can reliably walk the stack and
produce correct backtrace addresses? On all 680x0 variants
(as they have different stack frames)?
- Eero
#!/bin/bash
#
# Use Hatari profiler to get BadMood startup and several
# frame rendering related profile data, both for DSP & CPU,
# and post-process them.
#
# Requires:
# - TOS v4, BadMood program and WAD for it in $dir
# - Processed BadMood CPU & DSP symbols in $dir
# - Hatari v1.7, preferably latest Hatari from Mercurial
# as some options don't work with v1.7
#
# Paths for these can be given in "profile.conf",
# see below.
#
# Profile data is saved to current directory, data
# post-processing results into $datadir subdirectory.
#
# TODO:
# - Option for specifying profile configuration file and
# data output directory.
# - Wrapper script that gives specified config files to
# this script and compares the profiling results against
# given baseline profile.
# script debugging
#set -x
# ------ User specific setup ------
if [ -f profile.conf ]; then
# shell script with same stuff as inside else part
. profile.conf
else
# directory where BM binary, symbols and TOS image are
dir=../../autoprofile
# old UAE CPU core
fpu="" # "--fpu-type 68882" for WinUAE
hatari="hatari"
# profile data postprocessor
profiler="hatari_profile.py"
# loop profile data postprocessor
looper="hatari_spinloop.py"
# directory for wad files
waddir="../../autoprofile"
# WAD file path/name
wadfile="$waddir/doom1.wad"
# BM command line options for above WAD
cmdline=""
fi
# ------- Script argument handling ---------
worst_ini="profile-worst.ini"
usage ()
{
cat << EOF
usage: ${0##*/} [options]
Options:
-p just re-post-process profile data
-g GEMDOS call tracing (from the beginning)
-l loop profiling for the game play
-s include resource load names & stack traces to hatari log
-w setup (interactive) worst frame profiling
By default profiling method is fully automated, it will start at
first shot fired, and end when player dies, at which point Hatari is
quit.
With "-w" option, user needs to start profiling at suitable moment
from the Hatari debugger with:
parse $worst_ini
"-w" option requires Hatari development version, newer than v1.7.
Default profiling is intended for BadMood builds where timedemos work
and worst frame (-w) profiling for BadMood builds that have more
aggressive / behavior changing engine optimizations enabled i.e. are
intended for normal play.
Because of this, script tries to run doom_t1.ttp for automated
profiling, and doom_t3.ttp for worst frame profiling. "t3" means
TIMEBASE_CONTROL level 3 (BadMood makefile option).
ERROR: $1
EOF
exit 1
}
no_run=0
do_loops=0
do_stack=0
do_worst=0
do_gemdos=0
doomtype="t4"
for arg in $*; do
if [ $arg = "-w" ]; then
do_worst=1
doomtype="t4"
elif [ $arg = "-s" ]; then
do_stack=1
elif [ $arg = "-p" ]; then
no_run=1
elif [ $arg = "-g" ]; then
do_gemdos=1
elif [ $arg = "-l" ]; then
do_loops=1
else
usage "unknown option '$1'"
fi
done
# --------- BadMood setup -----------
# BM binary to profile
bm="$dir/doom_${doomtype}.ttp"
# options file for BM
optfile="$dir/doom.def"
# BadMood CPU & DSP symbol information for Hatari
cpusym="$dir/doom_${doomtype}.sym"
dspsym="$dir/core.sym"
# name in BM dir to which given WAD file will be linked to
wadname="${wadfile##*/}"
# level play until this is taken to be level start,
# rest until death is normal play (where no loads
# should happen
#skipto="_P_LineAttack"
#skipto="_BM_A_Mux3x2"
skipto="_A_Chase"
# non-function labels that shouldn't be shown in the list
# because they're just confusing, and a comma separated list
# of BM interrupt entry point symbols
# (calls to them should be ignored in graphs & callcounts)
ignores="--ignore ascii_err_pwaddir --ignore-to _audio_mux_asm,framecounter,new_vbi,stabilizer_b,ikbd_handler,get_dx,get_dy"
# symbols for frame rendering start and end
render_start="r_begin"
render_end="r_end"
# check that files exist
if [ \! -f "$bm" ]; then
echo "ERROR: BM binary ($bm) missing!"
exit 1
fi
if [ \! -f "$cpusym" ]; then
echo "ERROR: BM CPU symbols ($cpusym) missing!"
exit 1
fi
if [ \! -f "$dspsym" ]; then
echo "ERROR: BM DSP symbols ($dspsym) missing!"
exit 1
fi
if [ \! -e "$wadfile" ]; then
echo "ERROR: configured WAD for BM ($wadfile) missing!"
exit 1
fi
ok="no"
cd $dir
# check all WAD file names recognized by Doom
for wad in doom2f.wad doom2.wad plutonia.wad tnt.wad doomu.wad doom.wad doom1.wad; do
if [ -h "$wad" ]; then
echo "Removing symlink to '$wad'"
rm "$wad"
fi
if [ "$wad" = "$wadname" ]; then
ok="yes"
elif [ -e "$wad" ]; then
echo "ERROR: remove '$dir/$wad', it may override symlink done by this script!"
exit 1
fi
done
if [ "$ok" = "no" ]; then
echo "ERROR: given '$wadname' WAD file name isn't one recognized by BM!"
exit 1
fi
if [ -f "$wadname" ]; then
echo "$wadname already exists, not changing it."
else
echo "symlinking $wadfile -> $wadname"
ln -s "$wadfile" "$wadname"
fi
cd -
# BM options
# (it's really annoying that it doesn't support "-iwad" option like PrBoom)
echo "$cmdline" > $optfile
echo "Using '$cmdline' options for '$wadname':"
ls -l $dir/$wadname
# --------- Hatari setup -----------
# debugging options
trace="--conout 2" # "--bios-intercept --trace xbios,gemdos"
if [ $do_gemdos -eq 1 ]; then
trace="$trace --trace gemdos"
fi
# need real TOS v4
tos="$dir/tos404.img"
# check that everything needed exist
if [ \! -f "$tos" ]; then
echo "ERROR: TOS v4 image ($tos) missing!"
exit 1
fi
if [ -z $(which "$hatari") ]; then
echo "ERROR: Hatari ($hatari) missing!"
exit 1
fi
if [ -z $(which "$profiler") ]; then
echo "ERROR: Hatari profiler ($profiler) missing!"
exit 1
fi
# --------- profiler automation chaining -----------
# where to store the results
datadir=data
# generated profile file prefixes
prof_start="badmood-startup"
prof_load="badmood-level-load"
prof_init="badmood-level-start"
prof_frames="badmood-all-frames"
prof_think="badmood-worst-think"
prof_render="badmood-worst-render"
# generated loop profile file names
prof_loop="badmood-loops.txt"
prof_think_loop="badmood-worst-think-loops.txt"
prof_render_loop="badmood-worst-render-loops.txt"
if [ $do_worst -eq 0 ]; then
prefixes="$prof_start $prof_load $prof_init $prof_frames"
loopers="$prof_loop"
else
prefixes="$prof_start $prof_think $prof_render"
loopers="$prof_think_loop $prof_render_loop"
fi
if [ $do_loops -eq 0 ]; then
loopers=""
fi
# -------- generic breakpoint handlers ----------
# show resource names for BM resource calls
echo "m a0" > profile-resource.ini
# show GEMDOS call stack & return value
# ----
cat > profile-gemdos.ini << EOF
profile stack
b pc="NextPC" :once :quiet :noinit :file profile-d0.ini
EOF
cat > profile-d0.ini << EOF
e d0
EOF
# ----
# quit Hatari
cat > profile-quit.ini << EOF
profile off
dspprofile off
quit
EOF
# -------- generic breakpoints setup --------------
# Breakpoint can be set at program startup only after TOS is up,
# catch Fopen() for *.INF file after TOS has initialized
profsetup="profile-setup.ini"
# ----
cat > $profsetup << EOF
b GemdosOpcode = 0x3D :once :trace :file profile-breakpoint.ini
EOF
# ----
# First breakpoint at program startup will do real setup
# ----
cat > profile-breakpoint.ini << EOF
b pc = text :once :trace :file profile-symbols.ini
EOF
# ----
# At program startup load CPU symbols and set breakpoint
# for when rendering starts (=initialization ends)
# ----
cat > profile-symbols.ini << EOF
symbols $cpusym text
profile on
b pc=r_begin :once :trace :file profile-startup.ini
EOF
# ----
# Save data for BM initialization, load DSP symbols
# and enable DSP profiling & history
# ----
cat > profile-startup.ini << EOF
profile save ${prof_start}-CPU.txt
dspsymbols $dspsym
dspprofile on
history on
EOF
# ----
# ---------- automated profiling ----------
# chain breakpoint for gathering data for startup until
# level start
if [ $do_worst -eq 0 ]; then
cat >> profile-startup.ini << EOF
b pc=_P_RunThinkers :once :trace :file profile-load.ini
EOF
else
# start worst frame profiling from same point as
# "all" frames profiling is started
cat >> profile-startup.ini << EOF
b pc=$skipto :once :trace :file $worst_ini
EOF
fi
# save data for level loading and set breakpoint for
# first interesting ($skipto) event
# ----
cat > profile-load.ini << EOF
profile save ${prof_load}-CPU.txt
dspprofile save ${prof_load}-DSP.txt
b pc=$skipto :once :trace :file profile-shot.ini
EOF
# ----
# start spinloop profiling and set breakpoint for
# gathering data until either:
# - player dies
# - game demo mode changes
# ----
cat > profile-shot.ini << EOF
profile save ${prof_init}-CPU.txt
dspprofile save ${prof_init}-DSP.txt
b pc=_P_DeathThink :once :trace :quiet :file profile-frames.ini
b pc=_D_AdvanceDemo :once :trace :quiet :file profile-frames.ini
b pc=_I_Quit :once :trace :quiet :file profile-frames.ini
b pc=_G_CheckDemoStatus :once :trace :quiet :file profile-frames.ini
b pc=_BM_E_PlayerDeath :once :trace :quiet :file profile-frames.ini
EOF
# ----
if [ $do_loops -eq 1 ]; then
echo "profile loops $prof_loop 0 0" >> profile-shot.ini
fi
if [ $do_stack -eq 1 ]; then
# output loaded resource names and Fread stack traces
cat >> profile-shot.ini << EOF
trace gemdos
b GemdosOpcode = 0x3F :quiet :noinit :file profile-gemdos.ini
b pc = read_resource :quiet :noinit :file profile-resource.ini
b pc = load_resource :quiet :noinit :file profile-resource.ini
EOF
fi
# Save data for collected frames, and quit
# ----
cat > profile-frames.ini << EOF
profile save ${prof_frames}-CPU.txt
dspprofile save ${prof_frames}-DSP.txt
parse profile-quit.ini
EOF
# ----
# --------- worst frame profiling ---------------
# get some data to initialize instruction counter,
# which amount should be less than in average frame
# (from previous RunThinkers breakpoint to r_begin)
cat > $worst_ini << EOF
b pc=r_begin :trace :once :quiet :file profile-worst-init.ini
EOF
# start spinloop profiling and set breakpoints for:
# - catching frames on which CpuInstr for thinking part and
# DspInstr for render part are larger than before
# - Clearing profile & CPU instructions counter on every frame
# thinking and rendering starts
# - Quit when player dies or demo mode changes
#
# Note: clearing breakpoints need to created after other
# breakpoints so that they get processed after them.
# Otherwise they would clear profile data you want to save,
# instead of reseting data counters for next frame.
# ----
cat > profile-worst-init.ini << EOF
b pc=r_begin && CpuInstr > CpuInstr :trace :file profile-worst-think.ini
b pc=r_end && DspInstr > DspInstr :trace :file profile-worst-render.ini
b pc=r_begin :trace :file profile-worst-clear.ini
b pc=r_end :trace :file profile-worst-clear.ini
b pc=_P_DeathThink :once :trace :quiet :file profile-quit.ini
b pc=_D_AdvanceDemo :once :trace :quiet :file profile-quit.ini
b pc=_I_Quit :once :trace :quiet :file profile-quit.ini
b pc=_G_CheckDemoStatus :once :trace :quiet :file profile-quit.ini
b pc=BM_E_PlayerDeath :once :trace :quiet :file profile-quit.ini
EOF
# ----
if [ $do_loops -eq 1 ]; then
echo "profile loops $prof_loop 0 0" >> profile-worst-init.ini
fi
if [ $do_stack -eq 1 ]; then
# output loaded resource names and Fread stack traces
cat >> profile-worst-init.ini << EOF
trace gemdos
b GemdosOpcode = 0x3F :quiet :noinit :file profile-gemdos.ini
b pc = read_resource :quiet :noinit :file profile-resource.ini
b pc = load_resource :quiet :noinit :file profile-resource.ini
EOF
fi
# just show instruction count for this frame
# (file breakpoint implicitly also clears data)
echo "e CpuInstr" > profile-worst-clear.ini
# save the worst frame for thinking and copy loop data
cat > profile-worst-think.ini << EOF
profile save ${prof_think}-CPU.txt
dspprofile save ${prof_think}-DSP.txt
EOF
# save the worst frame for rendering and copy loop data
cat > profile-worst-render.ini << EOF
profile save ${prof_render}-CPU.txt
dspprofile save ${prof_render}-DSP.txt
EOF
# put worst loop info aside
if [ $do_loops -eq 1 ]; then
echo "rename ${prof_loop} ${prof_think_loop}" >> profile-worst-think.ini
echo "rename ${prof_loop} ${prof_render_loop}" >> profile-worst-render.ini
fi
# --------- actual profiling -----------
if [ $no_run -eq 0 ]; then
# backup old files
for file in $loopers; do
mv $file $file.bak
done
for prefix in $prefixes; do
for core in CPU DSP; do
file=$prefix-$core.txt
if [ -f $file ]; then
mv $file $file.bak
fi
done
done
# BadMood needs 14MB of RAM and works fine with fast forwarding
hatari_start="$hatari -c hatari.conf --monitor vga --natfeats yes -s 14 $trace --parse $profsetup --fast-forward yes --machine falcon $fpu --tos $tos $bm"
hatari_log=hatari.log
echo "$hatari_start 2> $hatari_log"
echo "$hatari_start 2> $hatari_log" > $hatari_log
$hatari_start 2>> $hatari_log
fi
# remove options file
#rm $optfile
# --------- post-processing -----------
# create directory for processed data
mkdir -p $datadir
# file missing or parsing errors
errors=0
# callgraph options, and what to do for nodes below given limit
limits="--emph-limit 2.0 --limit 0.5 --compact"
compaction="--compact --no-leafs --no-intermediate" # --only-subroutines"
# run profile post-processor, save results to datadir, show summary & errors
profile_process ()
{
_prefix=$1
_profile=$_prefix.txt
_errors=$datadir/$_prefix-error.txt
_processed=$datadir/$_prefix-result.txt
if [ "$2" = "CPU" ]; then
# CPU symbols are TEXT relative, and interrupt ones need to be ignored
echo "$profiler -r $cpusym -p -g $ignores $limits $compaction -st $_profile > $_processed 2> $_errors"
$profiler -r $cpusym -p -g $ignores $limits $compaction -st $_profile > $_processed 2> $_errors
else
# DSP symbols are absolute
echo "$profiler -a $dspsym -p -g $limits -st $_profile > $_processed 2> $_errors"
$profiler -a $dspsym -p -g $limits -st $_profile > $_processed 2> $_errors
fi
if [ $? -ne 0 ]; then
errors=1
fi
mv $_prefix-*.dot $datadir/
# results
cat $_processed $_errors
}
# check that we actually got profile data & process it
profiled=""
for prefix in $prefixes; do
for core in CPU DSP; do
file=$prefix-$core.txt
if [ \! -f $file ]; then
echo "Note: no $core data for '$prefix' profile."
continue
fi
profiled="$profiled $file"
profile_process $prefix-$core $core
done
if [ "$errors" -gt 0 ]; then
echo "Errors detected, quitting..."
exit 1
fi
done
# process loop profiles
looped=""
for file in $loopers; do
if [ -f $file ]; then
# can take a while for large loop files...
echo "post-processing loop file '$file'..."
$looper $file > $datadir/$file
cat $datadir/$file
looped="$looped $file"
else
echo "Warning: loop profile '$file' missing!"
fi
done
echo "Hatari log:"
echo "- hatari.log ($(wc -l hatari.log) lines)"
echo "Profiling data:"
for i in $looped $profiled; do
echo "- $i"
done
echo "Earlier & new post-processing results in $datadir/:"
ls $datadir
echo "DONE!"