I think that instrumentation-based profiling is a second-best choice compared to profiling unmodified code, and source code instrumentation is even worse than binary instrumentation. If you have all the code location info, per-address instruction and clock cycle counts, _and_ even jump/call information, it should be possible to reconstruct everything without instrumenting anything.
Sandy Brand wrote:
Do you have any performance issues using larger TCL sctips, btw? I found that, while my approach sort of worked, such a heavy use of TCL scripting and writing data to output ports had a tendency to lock-up the emulator.
That shouldn't happen. Can you give a concrete example, so we can reproduce and investigate that?
My latest script which logs VDP accesses. Each read and write to the registers or vram is recorded. Each log entry includes the PC when the VDP was modified so it can be matched to an instruction/subroutine in the diassembly. VRAM accesses include the VDP address and value being written/read. VRAM accesses are further decoded based on the current value of the registers to indicate which table is being written to in VRAM. Certain values, such as patterns and colors are shown in human readable format. I'm hoping to use this to more quickly make sense of the VDP manipulation routines in the Bold demo disassembly.
namespace eval vdp_log {
set_help_text vdp_log \
{Log VDP reads and writes.}
variable log_file
variable reg_lsb
variable vdp_reg_read_wp
variable vdp_reg_write_wp
variable vdp_ram_read_wp
variable vdp_ram_write_wp
proc vdp_color_name {color} {
return [lindex {transparent black medium_green light_green dark_blue light_blue dark_red cyan medium_red light_red dark_yellow light_yellow dark_green magenta gray white} $color]
}
proc vdp_bitpattern {value} {
set pattern ""
for {set i 0} {$i < 8} {incr i} {
if {$value & (1 << $i)} {
set pattern [format "*%s" $pattern]
} else {
set pattern [format ".%s" $pattern]
}
}
return $pattern
}
proc vdp_log_vram {rw} {
variable log_file
set addr [expr {[debug read "VRAM pointer" 1] << 8 | [debug read "VRAM pointer" 0]}]
if {$rw == "read"} {
set value [debug read VRAM $addr]
} else {
set value $::wp_last_value
}
set mode [get_screen_mode_number]
# calculate starting address of tables
set nameaddr [expr {[vdpreg 2] * 0x400}]
if {$mode == 2} {
# graphics II mode color and pattern address based on MSB only
if {[vdpreg 3] & 0x80} {
set coloraddr 0x2000
} else {
set coloraddr 0
}
if {[vdpreg 4] & 0x40} {
set patternaddr 0x2000
} else {
set patternaddr 0
}
} else {
set coloraddr [expr {[vdpreg 3] * 0x40}]
set patternaddr [expr {[vdpreg 4] * 0x800}]
}
set spriteattraddr [expr {[vdpreg 5] * 0x80}]
set spritepttnaddr [expr {[vdpreg 6] * 0x800}]
# default table lengths
set namelen 768
set colorlen -1
set patternlen 2048
set spriteattrlen 128
set spritepttnlen 2048
# override table lengths based on mode
if {$mode == 0} {
# text mode
set namelen 960
set spriteattrlen -1
set spritepttnlen -1
} elseif {$mode == 1} {
# graphics I mode
set colorlen 32
} elseif {$mode == 2} {
# graphics II mode
set colorlen 6144
set patternlen 6144
}
# identify addressed entity
if {$addr >= $nameaddr && $addr < $nameaddr + $namelen} {
set entry [expr {$addr - $nameaddr}]
if {$mode == 0} {
set x [expr {$entry % 40}]
set y [expr {$entry / 40}]
if {$value >= 0x20 && $value <= 126} {
set desc [format "name %x | %d , %d %c" $entry $x $y $value]
} else {
set desc [format "name %x | %d , %d" $entry $x $y]
}
} elseif {$mode == 1} {
set x [expr {$entry % 32}]
set y [expr {$entry / 32}]
set desc [format "name %x | %d , %d" $entry $x $y]
} else {
set desc [format "name %x" $entry]
}
} elseif {$addr >= $coloraddr && $addr < $coloraddr + $colorlen} {
set entry [expr {$addr - $coloraddr}]
set fg [vdp_color_name [expr {$value >> 4}]]
set bg [vdp_color_name [expr {$value & 0xF}]]
set desc [format "color %x | fg %s bg %s" $entry $fg $bg]
} elseif {$addr >= $patternaddr && $addr < $patternaddr + $patternlen} {
set entry [expr {$addr - $patternaddr}]
set pattern [vdp_bitpattern $value]
set desc [format "pattern %x | %s" $entry $pattern]
} elseif {$addr >= $spriteattraddr && $addr < $spriteattraddr + $spriteattrlen} {
set entry [expr {$addr - $spriteattraddr}]
set sprite [expr {$entry / 4}]
set field [expr {$entry % 4}]
if {$field == 0} {
set desc [format "spriteattr %x | sprite %d y %d" $entry $sprite $value]
} elseif {$field == 1} {
set desc [format "spriteattr %x | sprite %d x %d" $entry $sprite $value]
} elseif {$field == 2} {
set desc [format "spriteattr %x | sprite %d name %d" $entry $sprite $value]
} else {
if {$value & 0x80} {
set early 1
} else {
set early 0
}
set color [vdp_color_name [expr {$value & 0xF}]]
set desc [format "spriteattr %x | sprite %d early %d color %s" $entry $sprite $early $color]
}
} elseif {$addr >= $spritepttnaddr && $addr < $spritepttnaddr + $spritepttnlen} {
set entry [expr {$addr - $spritepttnaddr}]
set pattern [vdp_bitpattern $value]
set desc [format "spritepttn %x | %s" $entry $pattern]
} else {
set desc "unmapped"
}
puts $log_file [format "%04x: %s vram %04x %02x \[ %s \]" [reg PC] $rw $addr $value $desc]
}
proc vdp_ram_write {} {
variable reg_lsb
# clear register lsb
set reg_lsb -1
# log vram write
vdp_log_vram "write"
}
proc vdp_ram_read {} {
variable reg_lsb
# clear register lsb
set reg_lsb -1
# log vram read
vdp_log_vram "read"
}
proc vdp_reg_write {} {
variable log_file
variable reg_lsb
set pc [reg PC]
# check if lsb is already set
if {$reg_lsb == -1} {
# if not, set it now and return
set reg_lsb $::wp_last_value
} else {
# if so, get msb
set reg_msb $::wp_last_value
# check whether msb indicates a register write
if {$reg_msb & 0x80} {
# if so, log register number and value
set reg_msb [expr {$reg_msb & 0x7}]
puts $log_file [format "%04x: write reg %02x %02x" $pc $reg_msb $reg_lsb]
} else {
# if not, must be setting vram address; check whether for read or write?
if {$reg_msb & 0x40} {
set rw "write"
} else {
set rw "read"
}
# log vram address setting
set addr [expr {(($reg_msb & 0x3F) << 8) | $reg_lsb}]
puts $log_file [format "%04x: set vram %s addr %04x" $pc $rw $addr]
}
set reg_lsb -1
}
}
proc vdp_reg_read {} {
variable log_file
variable reg_lsb
# clear register lsb
set reg_lsb -1
# log status read
puts $log_file [format "%04x: read status %02x" [reg PC] [debug read "VDP status regs" 0]]
}
proc vdp_log_stop {} {
variable vdp_reg_read_wp
variable vdp_reg_write_wp
variable vdp_ram_read_wp
variable vdp_ram_write_wp
# remove watch points
catch {debug remove_watchpoint $vdp_ram_write_wp}
catch {debug remove_watchpoint $vdp_ram_read_wp}
catch {debug remove_watchpoint $vdp_reg_write_wp}
catch {debug remove_watchpoint $vdp_reg_read_wp}
return ""
}
proc vdp_log_start {filename} {
variable log_file
variable reg_lsb
variable vdp_reg_read_wp
variable vdp_reg_write_wp
variable vdp_ram_read_wp
variable vdp_ram_write_wp
# clear lsb
set reg_lsb -1
# open log
set log_file [open $filename {WRONLY TRUNC CREAT}]
# set up watch points
set vdp_ram_write_wp [debug set_watchpoint write_io 0x98 1 {vdp_log::vdp_ram_write}]
set vdp_ram_read_wp [debug set_watchpoint read_io 0x98 1 {vdp_log::vdp_ram_read}]
set vdp_reg_write_wp [debug set_watchpoint write_io 0x99 1 {vdp_log::vdp_reg_write}]
set vdp_reg_read_wp [debug set_watchpoint read_io 0x99 1 {vdp_log::vdp_reg_read}]
return ""
}
namespace export vdp_log_start
namespace export vdp_log_stop
} ;# namespace call_log
namespace import vdp_log::* Example output...
Text mode name table writes, which decode X, Y coordinates and the ASCII character being output:
0bee: write vram 00aa 76 [ name aa | 10 , 4 v ] 07e8: set vram write addr 00ab 0bee: write vram 00ab 65 [ name ab | 11 , 4 e ] 07e8: set vram write addr 00ac 0bee: write vram 00ac 72 [ name ac | 12 , 4 r ] 07e8: set vram write addr 00ad 0bee: write vram 00ad 73 [ name ad | 13 , 4 s ] 07e8: set vram write addr 00ae 0bee: write vram 00ae 69 [ name ae | 14 , 4 i ] 07e8: set vram write addr 00af 0bee: write vram 00af 6f [ name af | 15 , 4 o ] 07e8: set vram write addr 00b0 0bee: write vram 00b0 6e [ name b0 | 16 , 4 n ] 07e8: set vram write addr 00b1 0bee: write vram 00b1 20 [ name b1 | 17 , 4 ] 07e8: set vram write addr 00b2 0bee: write vram 00b2 31 [ name b2 | 18 , 4 1 ] 07e8: set vram write addr 00b3 0c4d: read status 9f 0bee: write vram 00b3 2e [ name b3 | 19 , 4 . ] 07e8: set vram write addr 00b4 0bee: write vram 00b4 31 [ name b4 | 20 , 4 1 ] 07e8: set vram write addr 00b5 0bee: write vram 00b5 31 [ name b5 | 21 , 4 1 ] 0c4d: read status 9f 07e8: set vram write addr 00f2 0bee: write vram 00f2 41 [ name f2 | 2 , 6 A ] 07e8: set vram write addr 00f3 0bee: write vram 00f3 3e [ name f3 | 3 , 6 > ]
Pattern table writes:
0170: write vram 0000 00 [ pattern 0 | ........ ] 0170: write vram 0001 00 [ pattern 1 | ........ ] 0170: write vram 0002 00 [ pattern 2 | ........ ] 0170: write vram 0003 00 [ pattern 3 | ........ ] 0170: write vram 0004 00 [ pattern 4 | ........ ] 0170: write vram 0005 00 [ pattern 5 | ........ ] 0170: write vram 0006 00 [ pattern 6 | ........ ] 0170: write vram 0007 00 [ pattern 7 | ........ ] 0170: write vram 0008 80 [ pattern 8 | *....... ] 0170: write vram 0009 98 [ pattern 9 | *..**... ] 0170: write vram 000a a4 [ pattern a | *.*..*.. ] 0170: write vram 000b a4 [ pattern b | *.*..*.. ] 0170: write vram 000c 98 [ pattern c | *..**... ] 0170: write vram 000d 00 [ pattern d | ........ ] 0170: write vram 000e 00 [ pattern e | ........ ] 0170: write vram 000f 00 [ pattern f | ........ ] 0170: write vram 0010 00 [ pattern 10 | ........ ] 0170: write vram 0011 38 [ pattern 11 | ..***... ] 0170: write vram 0012 48 [ pattern 12 | .*..*... ] 0170: write vram 0013 48 [ pattern 13 | .*..*... ] 0170: write vram 0014 38 [ pattern 14 | ..***... ] 0170: write vram 0015 00 [ pattern 15 | ........ ] 0170: write vram 0016 00 [ pattern 16 | ........ ] 0170: write vram 0017 00 [ pattern 17 | ........ ] 0170: write vram 0018 14 [ pattern 18 | ...*.*.. ] 0170: write vram 0019 70 [ pattern 19 | .***.... ] 0170: write vram 001a 94 [ pattern 1a | *..*.*.. ] 0170: write vram 001b 94 [ pattern 1b | *..*.*.. ] 0170: write vram 001c 74 [ pattern 1c | .***.*.. ] 0170: write vram 001d 00 [ pattern 1d | ........ ] 0170: write vram 001e 00 [ pattern 1e | ........ ] 0170: write vram 001f 00 [ pattern 1f | ........ ] 0170: write vram 0020 00 [ pattern 20 | ........ ] 0170: write vram 0021 70 [ pattern 21 | .***.... ] 0170: write vram 0022 48 [ pattern 22 | .*..*... ] 0170: write vram 0023 48 [ pattern 23 | .*..*... ] 0170: write vram 0024 48 [ pattern 24 | .*..*... ] 0170: write vram 0025 00 [ pattern 25 | ........ ] 0170: write vram 0026 00 [ pattern 26 | ........ ] 0170: write vram 0027 00 [ pattern 27 | ........ ] 0170: write vram 0028 00 [ pattern 28 | ........ ] 0170: write vram 0029 70 [ pattern 29 | .***.... ] 0170: write vram 002a 90 [ pattern 2a | *..*.... ] 0170: write vram 002b 90 [ pattern 2b | *..*.... ] 0170: write vram 002c 74 [ pattern 2c | .***.*.. ] 0170: write vram 002d 10 [ pattern 2d | ...*.... ] 0170: write vram 002e 60 [ pattern 2e | .**..... ] 0170: write vram 002f 00 [ pattern 2f | ........ ] 0170: write vram 0030 00 [ pattern 30 | ........ ] 0170: write vram 0031 00 [ pattern 31 | ........ ] 0170: write vram 0032 00 [ pattern 32 | ........ ] 0170: write vram 0033 00 [ pattern 33 | ........ ] 0170: write vram 0034 50 [ pattern 34 | .*.*.... ] 0170: write vram 0035 00 [ pattern 35 | ........ ] 0170: write vram 0036 00 [ pattern 36 | ........ ] 0170: write vram 0037 00 [ pattern 37 | ........ ]
Sprite attribute table write:
3abd: write vram 1b00 27 [ spriteattr 0 | sprite 0 y 39 ] 3ac4: write vram 1b01 51 [ spriteattr 1 | sprite 0 x 81 ] 3ac8: write vram 1b02 80 [ spriteattr 2 | sprite 0 name 128 ] 3acc: write vram 1b03 07 [ spriteattr 3 | sprite 0 early 0 color cyan ] 3ad0: write vram 1b04 27 [ spriteattr 4 | sprite 1 y 39 ] 3ad7: write vram 1b05 53 [ spriteattr 5 | sprite 1 x 83 ] 3adb: write vram 1b06 84 [ spriteattr 6 | sprite 1 name 132 ] 3adf: write vram 1b07 05 [ spriteattr 7 | sprite 1 early 0 color light_blue ] 3ae3: write vram 1b08 27 [ spriteattr 8 | sprite 2 y 39 ] 3aea: write vram 1b09 55 [ spriteattr 9 | sprite 2 x 85 ] 3aee: write vram 1b0a 88 [ spriteattr a | sprite 2 name 136 ] 3af2: write vram 1b0b 04 [ spriteattr b | sprite 2 early 0 color dark_blue ] 3af6: write vram 1b0c 27 [ spriteattr c | sprite 3 y 39 ] 3afd: write vram 1b0d 57 [ spriteattr d | sprite 3 x 87 ] 3b01: write vram 1b0e 10 [ spriteattr e | sprite 3 name 16 ] 3b05: write vram 1b0f 01 [ spriteattr f | sprite 3 early 0 color black ] 3b09: write vram 1b10 d0 [ spriteattr 10 | sprite 4 y 208 ]
Войдите или зарегистрируйтесь, чтобы получить возможность отправлять комментарии
