Re: [hatari-devel] Most wanted debugger/profiler feature or convenience? (Blitter/LED)

[ Thread Index | Date Index | More lists.tuxfamily.org/hatari-devel Archives ]


Hi,

FYI: I commited the "info blitter" support.

On perjantai 12 huhtikuu 2013, Douglas Little wrote:
> On perjantai 12 huhtikuu 2013, Nicolas Pomarède wrote:
> > I'm not sure it's easy to choose what kind of blitter access should be
> > considered as "bug" or not and traced as such in Hatari.

Sure, that's why such debugging feature should be something that
user (developer) specifically enables, e.g. with "--trace blitter_bug".


I've now fixed tracking conditions in breakpoints so that you can use
them with other conditions (as long as tracking condition is first one):
http://hg.tuxfamily.org/mercurialroot/hatari/hatari/rev/40a67f5fa58b

....so that developer could in theory use something like this to check
for register changes while blitter is busy:
	b (0xff8a3d).b ! (0xff8a3d).b  &&  (0xff8a3c).b & 0x80 ! 0

However, because Blitter registers values are updated from Hatari
internal variables *only* when the emulated code reads those registers,
register values that Hatari changes internally (control, src & dst
address, words and lines), won't work properly in debugger breakpoints
or show up correctly in memdumps.

Even if blitter code would be fixed in this regard (at least to
update control register memory), there are a lot of registers to
track, so I think tracing "buggy" register accesses could be
useful.


> > As with the pacemaker example, we see they alter some registers while
> > blitter is on.

8 times at start, 12 times at end, dozens of times at exit,
but the PC address actually seems to be in TOS area, not in
pacemaker code.


Anyway, assuming that this kind of information is genuinely
valuable for developers, IMHO only possible concerns are:
* Do we have enough bits in trace variable for all these kind of notices?
* Does it slow down emulation so that anybody would notice?
* Is the additional code a maintenance burden?

My opinions on these in the blitter case:
* We have still 20 bits free, I don't think we're going to get so many
  new ("bug" or other) trace variables that this would be an issue.
* Blitter register writes aren't so frequent that there should be any
  noticeably performance impact on Hatari.
* Changes are not as small as I would like, but they're trivial, so
  I think it's acceptable.  See the attached patch.


> Of course - for emulation it's not helpful. But debugging code is a
> different scenario - it's not so much a case of deciding whether
> something is a bug or not - it's more a case of knowing when a class of
> thing is happening (in this case, a class of thing that is usually - but
> not always - accidental).
> 
> > IMO, using --trace blitter already allows to see when blitter
> > start/stop, and if some registers are accessed in between.
> 
> TBH this is may be enough as it is. Having it actually breakpoint/react
> is only needed if that helps find where it happened - but logging the
> address along with the event achieves the same (one of the benefits of
> non-intrusive emulation).

Current "--trace blitter" tracks *only* control register writes,
nothing else.  And with breakpoints there's the above mentioned issue,
mainly with control register.


> > If we want Hatari to report some possible coding bugs / bad practices,
> > I think it would be better to keep traces in Hatari as they are and
> > feed the output trace file to another program to do a higher level
> > analysis (as you do with the python profiler tools for example).

At least in case of Blitter, current traces seem inadequate
for that purpose.


> I think it is helpful to expose nasty state problems a programmer could
> find difficult to inspect directly - and let them do the rest of the work
> yes. :)


	- Eero
diff -r cd966a53283e src/debug/log.h
--- a/src/debug/log.h	Fri Apr 12 22:19:32 2013 +0300
+++ b/src/debug/log.h	Fri Apr 12 22:35:31 2013 +0300
@@ -126,6 +126,8 @@
 
 #define TRACE_NVRAM		 (1ll<<45)
 
+#define TRACE_BLITTER_BUG	 (1ll<<46)
+
 #define	TRACE_NONE		 (0)
 #define	TRACE_ALL		 (~0)
 
diff -r cd966a53283e src/debug/log.c
--- a/src/debug/log.c	Fri Apr 12 22:19:32 2013 +0300
+++ b/src/debug/log.c	Fri Apr 12 22:35:31 2013 +0300
@@ -75,6 +75,7 @@
 	{ TRACE_IKBD_ALL	 , "ikbd_all" } ,
 
 	{ TRACE_BLITTER 	 , "blitter" } ,
+	{ TRACE_BLITTER_BUG 	 , "blitter_bug" } ,
 
 	{ TRACE_OS_BIOS 	 , "bios" },
 	{ TRACE_OS_XBIOS	 , "xbios" },
diff -r cd966a53283e src/blitter.c
--- a/src/blitter.c	Fri Apr 12 22:19:32 2013 +0300
+++ b/src/blitter.c	Fri Apr 12 22:35:31 2013 +0300
@@ -725,6 +725,20 @@
 	IoMem_WriteByte(REG_SKEW, BlitterRegs.skew);
 }
 
+#if ENABLE_TRACING
+/*-----------------------------------------------------------------------*/
+/**
+ * Blitter "register write&change while active" warnings
+ */
+static void Blitter_RegWarning(const char *name, Uint32 oldval, Uint32 newval)
+{
+	if ((BlitterRegs.ctrl & 0x80) == 0 || oldval == newval) {
+		return;
+	}
+	LOG_TRACE_PRINT("WARNING: %s reg write (%x->%x) at pc=0x%x while blitter active\n" ,
+			name, oldval, newval, M68000_GetPC());
+}
+#endif
 
 /*-----------------------------------------------------------------------*/
 /**
@@ -732,6 +746,9 @@
  */
 static void Blitter_Halftone_WriteWord(int index)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("halftone", BlitterHalftone[index], IoMem_ReadWord(REG_HT_RAM + index + index));
+	}
 	BlitterHalftone[index] = IoMem_ReadWord(REG_HT_RAM + index + index);
 }
 
@@ -758,6 +775,9 @@
  */
 void Blitter_SourceXInc_WriteWord(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("src X inc", BlitterRegs.src_x_incr, IoMem_ReadWord(REG_SRC_X_INC));
+	}
 	BlitterRegs.src_x_incr = (short)(IoMem_ReadWord(REG_SRC_X_INC) & 0xFFFE);
 }
 
@@ -767,6 +787,9 @@
  */
 void Blitter_SourceYInc_WriteWord(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("src Y inc", BlitterRegs.src_y_incr, IoMem_ReadWord(REG_SRC_Y_INC));
+	}
 	BlitterRegs.src_y_incr = (short)(IoMem_ReadWord(REG_SRC_Y_INC) & 0xFFFE);
 }
 
@@ -776,6 +799,9 @@
  */
 void Blitter_SourceAddr_WriteLong(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("src addr", BlitterRegs.src_addr, IoMem_ReadLong(REG_SRC_ADDR));
+	}
 	BlitterRegs.src_addr = IoMem_ReadLong(REG_SRC_ADDR) & 0xFFFFFE;
 }
 
@@ -785,6 +811,9 @@
  */
 void Blitter_Endmask1_WriteWord(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("end mask 1", BlitterRegs.end_mask_1, IoMem_ReadWord(REG_END_MASK1));
+	}
 	BlitterRegs.end_mask_1 = IoMem_ReadWord(REG_END_MASK1);
 }
 
@@ -794,6 +823,9 @@
  */
 void Blitter_Endmask2_WriteWord(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("end mask 2", BlitterRegs.end_mask_2, IoMem_ReadWord(REG_END_MASK2));
+	}
 	BlitterRegs.end_mask_2 = IoMem_ReadWord(REG_END_MASK2);
 }
 
@@ -803,6 +835,9 @@
  */
 void Blitter_Endmask3_WriteWord(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("end mask 3", BlitterRegs.end_mask_3, IoMem_ReadWord(REG_END_MASK3));
+	}
 	BlitterRegs.end_mask_3 = IoMem_ReadWord(REG_END_MASK3);
 }
 
@@ -812,6 +847,9 @@
  */
 void Blitter_DestXInc_WriteWord(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("dst X inc", BlitterRegs.dst_x_incr, IoMem_ReadWord(REG_DST_X_INC));
+	}
 	BlitterRegs.dst_x_incr = (short)(IoMem_ReadWord(REG_DST_X_INC) & 0xFFFE);
 }
 
@@ -821,6 +859,9 @@
  */
 void Blitter_DestYInc_WriteWord(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("dst Y inc", BlitterRegs.dst_y_incr, IoMem_ReadWord(REG_DST_Y_INC));
+	}
 	BlitterRegs.dst_y_incr = (short)(IoMem_ReadWord(REG_DST_Y_INC) & 0xFFFE);
 }
 
@@ -830,6 +871,9 @@
  */
 void Blitter_DestAddr_WriteLong(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("dst addr", BlitterRegs.dst_addr, IoMem_ReadLong(REG_DST_ADDR));
+	}
 	BlitterRegs.dst_addr = IoMem_ReadLong(REG_DST_ADDR) & 0xFFFFFE;
 }
 
@@ -844,6 +888,9 @@
 	if (words == 0)
 		words = 65536;
 
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("words", BlitterRegs.words, words);
+	}
 	BlitterRegs.words = words;
 	BlitterVars.dst_words_reset = words;
 }
@@ -859,6 +906,9 @@
 	if (lines == 0)
 		lines = 65536;
 
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("lines", BlitterRegs.lines, lines);
+	}
 	BlitterRegs.lines = lines;
 }
 
@@ -868,6 +918,9 @@
  */
 void Blitter_HalftoneOp_WriteByte(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("HOP", BlitterRegs.hop, IoMem_ReadByte(REG_BLIT_HOP));
+	}
 	/* h/ware reg masks out the top 6 bits! */
 	BlitterRegs.hop = IoMem_ReadByte(REG_BLIT_HOP) & 3;
 }
@@ -878,6 +931,9 @@
  */
 void Blitter_LogOp_WriteByte(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("LOP", BlitterRegs.lop, IoMem_ReadByte(REG_BLIT_LOP));
+	}
 	/* h/ware reg masks out the top 4 bits! */
 	BlitterRegs.lop = IoMem_ReadByte(REG_BLIT_LOP) & 0xF;
 }
@@ -947,6 +1001,9 @@
  */
 void Blitter_Skew_WriteByte(void)
 {
+	if (LOG_TRACE_LEVEL(TRACE_BLITTER_BUG)) {
+		Blitter_RegWarning("skew", BlitterRegs.skew, IoMem_ReadByte(REG_SKEW));
+	}
 	BlitterRegs.skew = IoMem_ReadByte(REG_SKEW);
 	BlitterVars.fxsr = (BlitterRegs.skew & 0x80)?1:0;
 	BlitterVars.nfsr = (BlitterRegs.skew & 0x40)?1:0;


Mail converted by MHonArc 2.6.19+ http://listengine.tuxfamily.org/