BMFlash: erase failed

[ALTracer]

Hello again.
BMFlash is unusable (without tweaks) against blackpill-f411ce platform and AT32F403A target.

Problem 1. vFlashErase throws an "Flash erase failed" error before even proceeding to vFlashWrite.

Black-Magic-Probe-Book/source/bmp-support.c

Lines 920 to 924 in 6010ef3

	sprintf(cmd, "vFlashErase:%x,%x", (unsigned)rgn->address, (unsigned)(flashsectors * rgn->blocksize));
	gdbrsp_xmit(cmd, -1);
	size_t rcvd = gdbrsp_recv(cmd, pktsize, 500);
	if (!testreply(cmd, rcvd, "OK")) {
	notice(BMPERR_FLASHERASE, "Flash erase failed");

I enabled -Ddebug_output=true and adjusted DEBUG_TARGET to get complete in-probe diagnostic logging. Per grabserial a page erase took 38ms on average -- 2048 byte pages, 512+512 KiB in two banks. I wrote a test project in AT32IDE and experimented with .rodata blob sizes to iterate quickly (this is also a flash readback test I used to validate some of my upstream AT32F4 PRs), and around 60 KiB is the bug trigger threshold.
Basically BMFlash issues a RSP packet of vFlashErase:8000000:5800 then times out waiting 500ms for a response, despite the probe being actively busy polling on FPEC registers. Judging by ttyBmpTarg output it completes erasing all requested pages, so that target layer engine works -- but the target stays erased (and halted), with BMP awaiting further instructions. I measured ~10 seconds during a per-page erase (effectively mass erase, but that'd be a different command), which is 20 times more than this timeout.
Consider either increasing this erase timeout, which postpones the problem, or write a loop to issue vFlashErase commands per single page, these will likely complete fast enough.

Problem 2.
I was using highest frequency in SWD mode that is available in-tree, around 6-8 MHz, but it's only relevant for write and readback phases, if any. Of course, after writing a big project (ELF file with 512 KiB of loadable content), then BMFlash throws another error right at the end of verification pass, but I wanted to measure timings.

Black-Magic-Probe-Book/source/bmp-support.c

Lines 1015 to 1023 in 6010ef3

	/* request CRC from Black Magic Probe */
	char cmd[100];
	sprintf(cmd, "qCRC:%lx,%lx", saddr, ssize);
	gdbrsp_xmit(cmd, -1);
	size_t rcvd = gdbrsp_recv(cmd, sizearray(cmd), 3000);
	cmd[rcvd] = '\0';
	unsigned crc_tgt = (rcvd >= 2 && cmd[0] == 'C') ? strtoul(cmd + 1, NULL, 16) : 0;
	if (crc_tgt != crc_src) {
	notice(BMPERR_FLASHCRC, "Segment %d data mismatch", segment);

At the best read speed (bmd_crc32 in-probe reporting) of 125-150 KiB/s it takes about 4 seconds per bank to verify, which is slightly more than 3000ms. Please bump timeout.

Problem 3. There is a stray clock() remaining in bmflash.c whereas everything else was migrated to custom timestamp().

Black-Magic-Probe-Book/source/bmflash.c

Lines 1924 to 1925 in 6010ef3

	clock_t tstamp_stop = clock();
	sprintf(msg, "Completed in %.1f seconds\n", (tstamp_stop - state->tstamp_start) / 1000.0);

At minimum, please replace to timestamp(), I tried it and this works. At maximum, consider also refactoring timestamp() from gettimeofday() to clock_gettime(CLOCK_MONOTONIC, ) because otherwise timestamp could jump during daylight savings time switch and from NTP adjtime corrections.

Problem 4. Blackpill-f4 in default in-tree configuration does not support qRcmd,tpwr monitor commands, and per RSP returns a Nak with 0 length payload, this triggers an assert somewhere, I had to #if 0 out this block. There is an optional shield with enables this command, so behaviour is not universal.

bmp-bmflash.log

Success screenshot

Worktree differences

diff --git a/source/Makefile.linux b/source/Makefile.linux
index e06972e..8642602 100644
--- a/source/Makefile.linux
+++ b/source/Makefile.linux
@@ -52,11 +52,11 @@ LFLAGS    := $(GLFW_LIB)
 
 ifdef NDEBUG
     # retail version
-    CFLAGS += -DNDEBUG
+    CFLAGS += -DNDEBUG -O2
     LFLAGS += -s
 else
     # development version
-    CFLAGS += -g
+    CFLAGS += -g -Og
     LFLAGS += -g
 endif
 
diff --git a/source/bmflash.c b/source/bmflash.c
index 6101d61..bd322bb 100644
--- a/source/bmflash.c
+++ b/source/bmflash.c
@@ -1284,6 +1284,7 @@ static bool probe_set_options(APPSTATE *state)
         ok = false;
       }
     }
+#if 0
     strcpy(cmd, "tpwr ");
     strlcat(cmd, state->tpwr ? "enable" : "disable", sizearray(cmd));
     if (bmp_monitor(cmd)) {
@@ -1297,6 +1298,7 @@ static bool probe_set_options(APPSTATE *state)
       bmp_callback(BMPERR_MONITORCMD, "Power to target failed");
       ok = false;
     }
+#endif
     state->set_probe_options = false;
   }
   return ok;
@@ -1924,7 +1926,7 @@ static bool handle_stateaction(APPSTATE *state, enum nk_collapse_states tab_stat
       SETSTATE(*state, STATE_IDLE);
     if (state->download_success && state->print_time) {
       char msg[100];
-      clock_t tstamp_stop = clock();
+      unsigned long tstamp_stop = timestamp();
       sprintf(msg, "Completed in %.1f seconds\n", (tstamp_stop - state->tstamp_start) / 1000.0);
       log_addstring(msg);
     }
diff --git a/source/bmp-support.c b/source/bmp-support.c
index f299776..5115d0b 100644
--- a/source/bmp-support.c
+++ b/source/bmp-support.c
@@ -919,7 +919,7 @@ bool bmp_download(void)
            (unsigned)rgn->address, (unsigned)(flashsectors * rgn->blocksize));
     sprintf(cmd, "vFlashErase:%x,%x", (unsigned)rgn->address, (unsigned)(flashsectors * rgn->blocksize));
     gdbrsp_xmit(cmd, -1);
-    size_t rcvd = gdbrsp_recv(cmd, pktsize, 500);
+    size_t rcvd = gdbrsp_recv(cmd, pktsize, 15000);
     if (!testreply(cmd, rcvd, "OK")) {
       notice(BMPERR_FLASHERASE, "Flash erase failed");
       free(cmd);
@@ -1016,7 +1016,7 @@ bool bmp_verify(void)
     char cmd[100];
     sprintf(cmd, "qCRC:%lx,%lx", saddr, ssize);
     gdbrsp_xmit(cmd, -1);
-    size_t rcvd = gdbrsp_recv(cmd, sizearray(cmd), 3000);
+    size_t rcvd = gdbrsp_recv(cmd, sizearray(cmd), 9000);
     cmd[rcvd] = '\0';
     unsigned crc_tgt = (rcvd >= 2 && cmd[0] == 'C') ? strtoul(cmd + 1, NULL, 16) : 0;
     if (crc_tgt != crc_src) {

[compuphase]

Thank you for the detailed analysis. The last two commits (95cb88c and 6797c3e) address these issues.