SWV tracing for diagnosing hangs.

Patch provided by James Laird-Wah <james@laird-wah.net>

lib/SCSI2SD/software/SCSI2SD/src/main.c

@@ -24,6 +24,7 @@
 #include "disk.h"
 #include "led.h"
 #include "time.h"
+#include "trace.h"
 
 const char* Notice = "Copyright (C) 2014 Michael McMaster <michael@codesrc.com>";
 
@@ -33,6 +34,7 @@ int main()
 {
 	timeInit();
 	ledInit();
+	traceInit();
 
 	// Enable global interrupts.
 	// Needed for RST and ATN interrupt handlers.

lib/SCSI2SD/software/SCSI2SD/src/scsiPhy.c

@@ -21,6 +21,7 @@
 #include "scsi.h"
 #include "scsiPhy.h"
 #include "bits.h"
+#include "trace.h"
 
 #define scsiTarget_AUX_CTL (* (reg8 *) scsiTarget_datapath__DP_AUX_CTL_REG)
 
@@ -50,18 +51,21 @@ volatile uint8_t scsiTxDMAComplete;
 CY_ISR_PROTO(scsiRxCompleteISR);
 CY_ISR(scsiRxCompleteISR)
 {
+	traceIrq(trace_scsiRxCompleteISR);
 	scsiRxDMAComplete = 1;
 }
 
 CY_ISR_PROTO(scsiTxCompleteISR);
 CY_ISR(scsiTxCompleteISR)
 {
+	traceIrq(trace_scsiTxCompleteISR);
 	scsiTxDMAComplete = 1;
 }
 
 CY_ISR_PROTO(scsiResetISR);
 CY_ISR(scsiResetISR)
 {
+	traceIrq(trace_scsiResetISR);
 	scsiDev.resetFlag = 1;
 }
 
@@ -82,13 +86,16 @@ scsiReadDBxPins()
 uint8_t
 scsiReadByte(void)
 {
+	trace(trace_spinPhyTxFifo);
 	while (unlikely(scsiPhyTxFifoFull()) && likely(!scsiDev.resetFlag)) {}
 	scsiPhyTx(0);
 
+	trace(trace_spinPhyRxFifo);
 	while (scsiPhyRxFifoEmpty() && likely(!scsiDev.resetFlag)) {}
 	uint8_t val = scsiPhyRx();
 	scsiDev.parityError = scsiDev.parityError || SCSI_Parity_Error_Read();
 
+	trace(trace_spinTxComplete);
 	while (!(scsiPhyStatus() & SCSI_PHY_TX_COMPLETE) && likely(!scsiDev.resetFlag)) {}
 
 	return val;
@@ -124,6 +131,7 @@ doRxSingleDMA(uint8* data, uint32 count)
 {
 	// Prepare DMA transfer
 	dmaInProgress = 1;
+	trace(trace_doRxSingleDMA);
 
 	CyDmaTdSetConfiguration(
 		scsiDmaTxTd[0],
@@ -184,6 +192,7 @@ scsiReadDMAPoll()
 	{
 		// Wait until our scsi signals are consistent. This should only be
 		// a few cycles.
+		trace(trace_spinTxComplete);
 		while (!(scsiPhyStatus() & SCSI_PHY_TX_COMPLETE)) {}
 
 		if (likely(dmaSentCount == dmaTotalCount))
@@ -219,12 +228,13 @@ scsiRead(uint8_t* data, uint32_t count)
 	else
 	{
 		scsiReadDMA(data, count);
-		
+
 		// Wait for the next DMA interrupt (or the 1ms systick)
 		// It's beneficial to halt the processor to
 		// give the DMA controller more memory bandwidth to work with.
 		__WFI();
-		
+
+		trace(trace_spinReadDMAPoll);
 		while (!scsiReadDMAPoll() && likely(!scsiDev.resetFlag)) {};
 	}
 }
@@ -232,9 +242,11 @@ scsiRead(uint8_t* data, uint32_t count)
 void
 scsiWriteByte(uint8 value)
 {
+	trace(trace_spinPhyTxFifo);
 	while (unlikely(scsiPhyTxFifoFull()) && likely(!scsiDev.resetFlag)) {}
 	scsiPhyTx(value);
 
+	trace(trace_spinTxComplete);
 	while (!(scsiPhyStatus() & SCSI_PHY_TX_COMPLETE) && likely(!scsiDev.resetFlag)) {}
 	scsiPhyRxFifoClear();
 }
@@ -253,6 +265,7 @@ scsiWritePIO(const uint8_t* data, uint32_t count)
 		}
 	}
 
+	trace(trace_spinTxComplete);
 	while (!(scsiPhyStatus() & SCSI_PHY_TX_COMPLETE) && likely(!scsiDev.resetFlag)) {}
 	scsiPhyRxFifoClear();
 }
@@ -262,6 +275,7 @@ doTxSingleDMA(const uint8* data, uint32 count)
 {
 	// Prepare DMA transfer
 	dmaInProgress = 1;
+	trace(trace_doTxSingleDMA);
 
 	CyDmaTdSetConfiguration(
 		scsiDmaTxTd[0],
@@ -306,6 +320,7 @@ scsiWriteDMAPoll()
 	{
 		// Wait until our scsi signals are consistent. This should only be
 		// a few cycles.
+		trace(trace_spinTxComplete);
 		while (!(scsiPhyStatus() & SCSI_PHY_TX_COMPLETE)) {}
 
 		if (likely(dmaSentCount == dmaTotalCount))
@@ -341,12 +356,13 @@ scsiWrite(const uint8_t* data, uint32_t count)
 	else
 	{
 		scsiWriteDMA(data, count);
-		
+
 		// Wait for the next DMA interrupt (or the 1ms systick)
 		// It's beneficial to halt the processor to
 		// give the DMA controller more memory bandwidth to work with.
 		__WFI();
 
+		trace(trace_spinWriteDMAPoll);
 		while (!scsiWriteDMAPoll() && likely(!scsiDev.resetFlag)) {};
 	}
 }
@@ -370,6 +386,7 @@ void scsiEnterPhase(int phase)
 
 void scsiPhyReset()
 {
+	trace(trace_scsiPhyReset);
 	if (dmaInProgress)
 	{
 		dmaInProgress = 0;
@@ -378,6 +395,7 @@ void scsiPhyReset()
 		dmaTotalCount = 0;
 		CyDmaChSetRequest(scsiDmaTxChan, CY_DMA_CPU_TERM_CHAIN);
 		CyDmaChSetRequest(scsiDmaRxChan, CY_DMA_CPU_TERM_CHAIN);
+		trace(trace_spinDMAReset);
 		while (!(scsiTxDMAComplete && scsiRxDMAComplete)) {}
 
 		CyDmaChDisable(scsiDmaTxChan);

lib/SCSI2SD/software/SCSI2SD/src/sd.c

@@ -24,6 +24,7 @@
 #include "sd.h"
 #include "led.h"
 #include "time.h"
+#include "trace.h"
 
 #include "scsiPhy.h"
 
@@ -86,7 +87,9 @@ static uint8 sdCrc7(uint8* chr, uint8 cnt, uint8 crc)
 static uint8_t sdSpiByte(uint8_t value)
 {
 	SDCard_WriteTxData(value);
+	trace(trace_spinSpiByte);
 	while (!(SDCard_ReadRxStatus() & SDCard_STS_RX_FIFO_NOT_EMPTY)) {}
+	trace(trace_sdSpiByte);
 	return SDCard_ReadRxData();
 }
 
@@ -145,10 +148,12 @@ static uint16_t sdDoCommand(
 	// reads.
 	if (waitWhileBusy)
 	{
+		trace(trace_spinSDRxFIFO);
 		while (!(SDCard_ReadRxStatus() & SDCard_STS_RX_FIFO_NOT_EMPTY)) {}
 		int busy = SDCard_ReadRxData() != 0xFF;
 		if (unlikely(busy))
 		{
+			trace(trace_spinSDBusy);
 			while (sdSpiByte(0xFF) != 0xFF) {}
 		}
 	}
@@ -164,6 +169,7 @@ static uint16_t sdDoCommand(
 	CyDmaChEnable(sdDMARxChan, 1);
 	CyDmaChEnable(sdDMATxChan, 1);
 
+	trace(trace_spinSDDMA);
 	while (!(sdTxDMAComplete && sdRxDMAComplete)) { __WFI(); }
 
 	uint16_t response = discardBuffer;
@@ -177,6 +183,8 @@ static uint16_t sdDoCommand(
 	}
 
 	uint32_t start = getTime_ms();
+
+	trace(trace_spinSDBusy);
 	while ((response & 0x80) && likely(elapsedTime_ms(start) <= 200))
 	{
 		response = sdSpiByte(0xFF);
@@ -246,6 +254,7 @@ dmaReadSector(uint8_t* outputBuffer)
 	// Don't wait more than 200ms.  The standard recommends 100ms.
 	uint32_t start = getTime_ms();
 	uint8_t token = sdSpiByte(0xFF);
+	trace(trace_spinSDBusy);
 	while (token != 0xFE && likely(elapsedTime_ms(start) <= 200))
 	{
 		if (unlikely(token && ((token & 0xE0) == 0)))
@@ -367,6 +376,7 @@ void sdCompleteRead()
 		// Not much choice but to wait until we've completed the transfer.
 		// Cancelling the transfer can't be done as we have no way to reset
 		// the SD card.
+		trace(trace_spinSDCompleteRead);
 		while (!sdReadSectorDMAPoll()) { /* spin */ }
 	}
 	
@@ -536,6 +546,7 @@ void sdCompleteWrite()
 		// Not much choice but to wait until we've completed the transfer.
 		// Cancelling the transfer can't be done as we have no way to reset
 		// the SD card.
+		trace(trace_spinSDCompleteWrite);
 		while (!sdWriteSectorDMAPoll(1)) { /* spin */ }
 	}
 

lib/SCSI2SD/tools/trace2name.pl

@@ -0,0 +1,51 @@
+# Author James Laird-Wah <james@laird-wah.net>
+# This is free and unencumbered software released into the public domain.
+#
+# Anyone is free to copy, modify, publish, use, compile, sell, or
+# distribute this software, either in source code form or as a compiled
+# binary, for any purpose, commercial or non-commercial, and by any
+# means.
+#
+# In jurisdictions that recognize copyright laws, the author or authors
+# of this software dedicate any and all copyright interest in the
+# software to the public domain. We make this dedication for the benefit
+# of the public at large and to the detriment of our heirs and
+# successors. We intend this dedication to be an overt act of
+# relinquishment in perpetuity of all present and future rights to this
+# software under copyright law.
+#
+# THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
+# EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
+# MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT.
+# IN NO EVENT SHALL THE AUTHORS BE LIABLE FOR ANY CLAIM, DAMAGES OR
+# OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE,
+# ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR
+# OTHER DEALINGS IN THE SOFTWARE.
+
+# For more information, please refer to <http://unlicense.org/>
+open HDR, '<trace.h';
+$next = 0;
+$enum = 0;
+for (<HDR>) {
+    chomp;
+    /^enum trace_event/ || $enum or next;
+    $enum++;
+    /}/ && break;
+    /trace_(\S+)(\s*=\s*(\S+))?\s*,\s*$/ or next;
+    ($name, $valmatch, $val) = ($1, $2, $3);
+    $next = hex $val if defined $val;
+    $names{$next} = $name;
+    $next++;
+}
+    
+while (!eof STDIN) {
+    $ch = ord getc;
+    if ($ch==1 || $ch==9) {
+        $data = ord getc;
+        print "ISR: " if $ch==9;
+        $name = $names{$data} // sprintf "unk: 0x%X", $data;
+        print $names{$data}, "\n"
+    } else {
+        print "<dropped>\n";
+    }
+}