DAP_PACKET_SIZE > 128: random(?) zero bytes are inserted in DAP command stream

[rgrr]

Hello,

my side project is a debug probe (https://github.com/rgrr/yapicoprobe). Trying to optimize throughput via DAP_PACKET_SIZE/COUNT revealed some strange behavior of PyOCD: randomly(?) there are packets transmitted with only one zero byte. But only, if packet size > 128. OpenOCD does not do that.

I have now introduced some hack on probe side to fix this:

    while (bufsize != 0) {
        uint8_t tmp_buf[64];
        uint16_t n = MIN(bufsize, sizeof(tmp_buf));

        tud_vendor_read(tmp_buf, n);

        if (n == 1  &&  tmp_buf[0] == 0  &&  tool == E_DAPTOOL_PYOCD) {
            // this is a special pyocd hack (and of course openocd does not like it)
            //picoprobe_info("-----------pyocd hack\n");
        }
        else {
            xStreamBufferSend(dap_stream, tmp_buf, n, 0);
            send_event = true;
        }

        bufsize -= n;
    }

Nevertheless I'ld like to also fix this on PyOCD side. Any pointer where to dig?

PS: happended of course for CMSIS-DAP v2 and flashing PPS: TinyUSB is used, RP2350 is the probe hardware

[rgrr]

digged a little bit deeper... trace output shows the following packet with packet_size=256:

0002302 D [cmd:641] get_request_space(1, 05:w)[wc=0, rc=0, ba=1->1] -> (sz=1, free=62) [dap_access_cmsis_dap]
0002302 D [cmd:641] add(1, 05:w) -> [wc=1, rc=0, ba=1] [dap_access_cmsis_dap]
0002302 D trace: write_ap(addr=0x00002d04, data=0x10000020) [cmsis_dap_probe]
0002302 D trace: read_ap_multi(addr=0x00002d0c, count=56) -> ... [cmsis_dap_probe]
0002302 D [cmd:641] get_request_space(56, 0f:r)[wc=1, rc=0, ba=1->0] -> (sz=56, free=63, delta=-198) [dap_access_cmsis_dap]
0002302 D [cmd:641] add(56, 0f:r) -> [wc=1, rc=56, ba=0] [dap_access_cmsis_dap]
0002302 D flush: sending cmd:641; reading 0 outstanding [dap_access_cmsis_dap]
0002302 D [cmd:641] _send_packet: sending [dap_access_cmsis_dap]
0002302 D   USB OUT> (65) 05 00 39 05 20 00 00 10 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 00 [pyusb_v2_backend]

Checked length of the transfer which is 64, so the extra "00" at the end of the transfer is wrong.

A valid sequence of the above transfer is (with packet_size==128):

0000624 D [cmd:37] get_request_space(1, 05:w)[wc=0, rc=0, ba=1->1] -> (sz=1, free=30) [dap_access_cmsis_dap]
0000624 D [cmd:37] add(1, 05:w) -> [wc=1, rc=0, ba=1] [dap_access_cmsis_dap]
0000624 D trace: write_ap(addr=0x00002d04, data=0xe00fffd0) [cmsis_dap_probe]
0000624 D trace: read_ap_multi(addr=0x00002d0c, count=12) -> ... [cmsis_dap_probe]
0000624 D [cmd:37] get_request_space(12, 0f:r)[wc=1, rc=0, ba=1->0] -> (sz=12, free=31, delta=-242) [dap_access_cmsis_dap]
0000624 D [cmd:37] add(12, 0f:r) -> [wc=1, rc=12, ba=0] [dap_access_cmsis_dap]
0000624 D flush: sending cmd:37; reading 0 outstanding [dap_access_cmsis_dap]
0000624 D [cmd:37] _send_packet: sending [dap_access_cmsis_dap]
0000625 D   USB OUT> (20) 05 00 0d 05 d0 ff 0f e0 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f 0f [pyusb_v2_backend]

[rgrr]

Haha... it is happening here:

    def write(self, data):
        """@brief Write data on the OUT endpoint."""

        if self.ep_out:
            TRACE.debug("aaaaa %d %d %d", len(data), self.packet_size, self.ep_out.wMaxPacketSize)
            if (len(data) > 0) and (len(data) < self.packet_size) and (len(data) % self.ep_out.wMaxPacketSize == 0):
                data.append(0)

        if TRACE.isEnabledFor(logging.DEBUG):
            TRACE.debug("  USB OUT> (%d) %s", len(data), ' '.join([f'{i:02x}' for i in data]))

        self.read_sem.release()

        self.ep_out.write(data, timeout=self.DEFAULT_USB_TIMEOUT_MS)

Output above is aaaaa 64 256 64 [pyusb_v2_backend]. Corresponding commit is ~6 years old: https://github.com/flit/pyOCD/commit/6e5f413e57e8b80efa4e06e029fac8f0d6ecfe29.

I'm wondering what the actual reasoning for this appended zero is. Perhaps a former buggy USB interface?

Of course it is working without the "data.append(0)".

[MiloradCvjetkovic]

Hi @rgrr,

the reason for this additional 1 dummy byte is termination of the bulk transfer.

The USB Specification 2.0 specifies transfer completion as on the screenshot below:

it means that if the transfer length is multiple of wMaxPacketSize and not exactly same as DAP packet size the transfer has to be terminated with a short packet or a zero-length packet (ZLP), otherwise the other side would continue waiting for further expected data.

Short packet or ZLP signals to the other side that the transfer is completed.

Adding 1 dummy byte to the transfer in this case forces a short packet to terminate the transfer.

[rgrr]

Hi @MiloradCvjetkovic

if you'ld ask me, there is a difference between a zero-length packet (ZLP) and a packet containing a zero. Data stream also looses transparency if intermittent zeroes are transmitted.

With pyocd running on Linux and a TinyUSB counterpart, everything works fine without the append(0).

To append a ZLP TMO best way would be to make a self.ep_out.write() with no data (if it is not already handled there).

[rgrr]

Hi @MiloradCvjetkovic

checked your #1882 and it still works for me (Debian testing). Commit before emitted those zeroes in the data stream, with your PR it does no longer.

Closed this issue.

[MiloradCvjetkovic]

Hi @rgrr ,

thank you for your detailed issue description and for feedback also.