Memory burst writes with abstractauto can fail due to missing BUSY checks

[nadime15]

When abstractauto (for dataX) is enabled, writing to a data register automatically triggers an abstract command. However, if a previous command is still executing (BUSY=1), the new command cannot start. Currently, openocd continues writing to data registers without checking BUSY, which results in ignored commands and lost updates.

For example, we enable abstractauto and issue a single abstract command (Access Register). Once it completes, writing to data0 triggers execution of that command again (CMD1). If we write to data0 again while this command (CMD1) is still executing, cmderr.BUSY is set, so the write is ignored. Once CMD1 finishes, BUSY is cleared (success), and execution continues.

See the logs showing continuous writes to data0 and data1.

Debug: 29678 1856715 batch.c:264 log_batch(): 41b w 02010413 @05 -> ?; 0i
Debug: 29679 1856715 batch.c:199 log_dmi_decoded(): write:
Debug: 29680 1856715 batch.c:264 log_batch(): 41b w 00813823 @04 -> ?; 169i
Debug: 29681 1856715 batch.c:199 log_dmi_decoded(): write:
Debug: 29682 1856715 batch.c:264 log_batch(): 41b w feb43023 @05 -> ?; 0i
Debug: 29683 1856715 batch.c:199 log_dmi_decoded(): write:
Debug: 29684 1856715 batch.c:264 log_batch(): 41b w fea43423 @04 -> ?; 169i
Debug: 29685 1856715 batch.c:199 log_dmi_decoded(): write:
Debug: 29686 1856715 batch.c:264 log_batch(): 41b w fe043783 @05 -> ?; 0i
Debug: 29687 1856715 batch.c:199 log_dmi_decoded(): write:
Debug: 29688 1856715 batch.c:264 log_batch(): 41b w fe843703 @04 -> ?; 169i
Debug: 29689 1856715 batch.c:199 log_dmi_decoded(): write:
Debug: 29690 1856715 batch.c:264 log_batch(): 41b w 00078513 @05 -> ?; 0i
Debug: 29691 1856715 batch.c:199 log_dmi_decoded(): write:
Debug: 29692 1856715 batch.c:264 log_batch(): 41b w 00f707b3 @04 -> ?; 169i
Debug: 29693 1856715 batch.c:199 log_dmi_decoded(): write:
Debug: 29694 1856715 batch.c:264 log_batch(): 41b w 01013403 @05 -> ?; 0i
Debug: 29695 1856715 batch.c:199 log_dmi_decoded(): write:
Debug: 29696 1856715 batch.c:264 log_batch(): 41b w 01813083 @04 -> ?; 169i

Half of the data is lost because writes to data0 and data1 are ignored while a previous abstract command is still executing.

In my opinion, this is caused by openocd not checking whether the hart is currently busy (BUSY=1) before writing to a data register. On real hardware, this may be a rare case since the core likely executes abstract commands faster than the jtag accesses, so it’s mainly a timing issue. However, openocd seems to assume that abstract commands complete faster than the writes to dataX (just an assumption from my end).

But I might miss something!

This is related to issue #587 and is unfortunately still relevant today.

[en-sc]

Thanks for the report!

The idea behind this wierd behavior is to bunch up the operations and reduce the number of round-trips in the OpenOCD -- JTAG adapter communication that results in a significant speed-up.

This is allowed since both busy statuses (DMI and Abstract Commands) are sticky, meaning the next operation is ignored if the bus is busy.

The idea is to opportunistically assume the delay in-between the scans is big enough and to run a whole bunch of operations.
If the delay was too low -- we will get a busy response and some operations will fail. Nevertheless, all failing operations will follow successful operations, so by side effects of an operation we will be able to observe which operation was the last successful one and we will re-run the failing ones.

The busy status (both DMI and abstractcs) is checked when writing memory via program buffer:

riscv-openocd/src/target/riscv/riscv-013.c

Lines 4955 to 4972 in eb01c63

	const bool dmi_busy_encountered = riscv_batch_was_batch_busy(batch);
	if (cmderr == CMDERR_NONE && !dmi_busy_encountered) {
	LOG_TARGET_DEBUG(target, "Successfully written memory block M[0x%" TARGET_PRIxADDR
	".. 0x%" TARGET_PRIxADDR ")", *address_p, end_address);
	*address_p = end_address;
	return ERROR_OK;
	} else if (cmderr == CMDERR_BUSY || dmi_busy_encountered) {
	if (cmderr == CMDERR_BUSY)
	LOG_TARGET_DEBUG(target, "Encountered abstract command busy response while writing block M[0x%"
	TARGET_PRIxADDR ".. 0x%" TARGET_PRIxADDR ")", *address_p, end_address);
	if (dmi_busy_encountered)
	LOG_TARGET_DEBUG(target, "Encountered DMI busy response while writing block M[0x%"
	TARGET_PRIxADDR ".. 0x%" TARGET_PRIxADDR ")", *address_p, end_address);
	/* TODO: If dmi busy is encountered, the address of the last
	* successful write can be deduced by analysing the batch.
	*/
	return write_memory_progbuf_handle_busy(target, address_p, size, buffer);
	}

There is a bug with this approach that is fixed in #1304. Perhaps the issue you are having is somewhat related?

This approach has it's flaws though, e.g. the it takes a long time to learn the necessary delays and riscv/riscv-debug-spec#1104.

[nadime15]

I am still getting familiar with the code, so my observation is based only on the openocd logs and my (mis)understanding of the debug spec. But it looks to me like the success check happens after the block has already been written.

If the delay was too low -- we will get a busy response and some operations will fail.

This gets tricky, because as shown in my example, if an abstract command is still being executed (triggered by a read/write to dataX with abstractauto enabled) and you access dataX again before the previous command has completed, the corresponding dataX won’t be updated, leading to data loss and preventing a new abstract command from being issued.

See:

Attempts to write them (dataX registers ) while busy is set does not change their value.

and from the cmderr field:

Gets set if an abstract command fails. The bits in this field remain set until they are cleared by writing 1 to them. No
abstract command is started until the value is reset to 0.

Once the first abstract command comes back it will set cmderr to 0. So if you unlucky (like me) the whole sequence will finish wlth cmderr 0 even though errors have occurred in between.

Correct me if am wrong but the c code only seems to work if busy is 1 at the end of the sequence.

• TODO: If dmi busy is encountered, the address of the last
• successful write can be deduced by analysing the batch.
  */

I was expecting a similar apprach by checking after each write whether busy was set to 1, but that would slow things down. My case is probably extremely rare anyway, since the JTAG module was about 100× faster than the RISC-V model I am working on. I have adjusted it now, and with the core running 4× faster than the JTAG module, which seems to resolve the problem.

[en-sc]

Once the first abstract command comes back it will set cmderr to 0. So if you unlucky (like me) the whole sequence will finish wlth cmderr 0 even though errors have occurred in between.

This is not the case. See [3.14.6. Abstract Control and Status (abstractcs, at 0x16)], cmderr field description:

1 (busy): An abstract command was executing while command, abstractcs, or abstractauto was written, or when one of the data or progbuf registers was read or written. This status is only written if cmderr contains 0.

Therefore cmderr will not become 0 if a dataX register is written while a command is running.

Correct me if am wrong but the c code only seems to work if busy is 1 at the end of the sequence.

Since the busy status is sticky and is not being reset in the batch any scan returning busy results in the last scan returning busy.

[nadime15]

Therefore cmderr will not become 0 if a dataX register is written while a command is running.

Thats not what I mean, what I mean is, cmderr becomes 1 (busy) if you write dataX while an abstract command is executed. But once the current abstract commands terminates it will set cmderr to 0.

Since the busy status is sticky and is not being reset in the batch any scan returning busy results in the last scan returning busy.

This is actually a good point, and it does confuse me. The cmderr field is defined as R/W1C, so in my interpretation, the “sticky” behavior only applies to (external) writes to cmderr via abstractcs.

That does not necessarily mean that cmderr cant be overwritten internally, unless this is explicitly stated somewhere.

The issue I think I am seeing is that cmderr could be set to 1 and then cleared to 0 internally.

That being said, allowing internal overwrites of cmderr does seem like it could lead to unexpected behavior.

[en-sc]

Thats not what I mean, what I mean is, cmderr becomes 1 (busy) if you write dataX while an abstract command is executed. But once the current abstract commands terminates it will set cmderr to 0.

This is not the case. Any non-zero cmderr is sticky, so once it becomes 1 it can only change it's value if the debugger resets it by a write.

[en-sc]

The cmderr field is defined as R/W1C, so in my interpretation, the “sticky” behavior only applies to (external) writes to cmderr via abstractcs.

I don't get it. How can a field be sticky wrt external writes when it is W1C? Any non-zero write clears some of it's bits.

That does not necessarily mean that cmderr cant be overwritten internally, unless this is explicitly stated somewhere.

I believe this:

Gets set if an abstract command fails. The bits in this field remain set until they are cleared by writing 1 to them.

explicitly states that cmderr can not be reset to 0 internally.

[nadime15]

Yeah I think you are right, I was so much focused on the external access. At least a caught a few bugs by running into this issue!

Since the busy status is sticky and is not being reset in the batch any scan returning busy results in the last scan returning busy.

One final question, something is still unclear to me. Let’s say busy gets set in the middle of writing a block. How do you know where to resume? Do you start reading the memory to figure out up to which address the correct data was written?

[en-sc]

Do you start reading the memory to figure out up to which address the correct data was written?

There is a program in the program buffer being executed (thanks to command.postexec).
This program accesses memory (read/write) (address is taken from a register) and then increments the register containing the address.
For the case of abstractcs.cmderr == busy (and for DMI busy in case of memory writes), we are reading the register. It contains the address of the first element to be accessed on the follow-up run.
The logic is straight-forward:

• If an access fails (any reason, e.g. memory access fault), the address in the register will not be incremented.
• If access succeeds, the address in the register gets incremented (increment can not fail).

Therefore, the register contains the address of the next element to be accessed.