musings of a systems conjurer

Ghost in the Instrument: Debugging Firmware Incompatibilities Between USBTMC And Test Hardware

I am currently building an internal C program designed to control test and measurement hardware over USB. So far so good until I hit an issue with our oscilloscope of choice, a Siglent SDS1202X-E digital oscilloscope.

The bug followed an incredibly frustrating pattern:

  1. I run the binary and it successfully queries with SCPI *IDN? which the scope responds with its vendor string.
  2. I run the binary a second time and complete dead silence.
  3. I check dmesg, and the Linux kernel is screaming about de-sync issues.

The only way to get a third run out of the machine was to physically walk over, power-cycle the scope, and re-plug the USB cable which also gets frustrating very fast.

Investigations

My first instinct was to check dmesg and what was actually happening on the kernel level of the USB subsystem. I got something similar to the following

[195234.417159] usbtmc 1-3:1.0: Device sent too small first packet: 4 < 12
[195253.358181] usbtmc 1-3:1.0: usb_control_msg returned -32
[195253.360845] usbtmc 1-3:1.0: Device sent reply with wrong bTag: 6 != 9

An error code -32 in Linux USB core translates directly to EPIPE (Broken Pipe/Stall). This means something was causing the scope's internal USB engine to lock up its endpoint and throw garbage back to the kernel and that something could be my own code, something in kernel (highly unlikely but still) or the scope itself.

I took a quick look at the device's node permissions to check if I was missing permissions or wasn't in the correct group and the output showed global read/write privileges:

> ls -la /dev/usbtmc1
crw-rw-rw- 1 root root 180, 1 Sep   3 13:43 /dev/usbtmc1

Permissions from the output were perfectly fine.

Since it wasn't a permissions issue, so my next point of investigation was my own code, specifically my device initialization code. The function calls a low-level hardware clear via ioctl(fd, USBTMC_IOCTL_CLEAR) to get rid of any stale data that might be clogging the pipeline and since the driver was returning EPIPE right at this call, I assumed the hardware was stuck and tried to force-inject the SCPI clear string *CLS inside the error handler. This actually made the problem significantly worse because now the sequence tags, bTag, drifted completely out of sync with every call.

[194075.948792] usbtmc 1-3:1.0: Device sent reply with wrong bTag: 4 != 6
[194077.670636] usbtmc 1-3:1.0: Device sent too small first packet: 4 < 12
[194078.788417] usbtmc 1-3:1.0: Device sent reply with wrong bTag: 6 != 10
[194079.938656] usbtmc 1-3:1.0: Device sent too small first packet: 4 < 12
[194080.816783] usbtmc 1-3:1.0: Device sent reply with wrong bTag: 8 != 14
[194082.042875] usbtmc 1-3:1.0: Device sent too small first packet: 4 < 12

The Root Cause(s)

Almost giving up here, I decided to look up the issue and a few things jumped up and made things clearer.

These two GitHub issues opened here and here shed some light on the issue. Many entry-to-mid tier instruments (particularly Siglent SDS1000X-E models; similar to ours) implement incomplete USBTMC firmware stacks and have buggy firmware. When the kernel driver triggered the ioctl() call, the scope's USB engine panics, sends a USB STALL packet and drops a corrupt 4-byte fragment instead of a valid 12-byte USBTMC header message. This is all my own hypothesis and is not guaranteed to be facts. A comment on one of the GitHub issues talks about something similar as well.

With a possible cause clear, this meant my core I/O framework was fundamentally flawed even though it looked sound. My assumption that sending a command with a single write() and then invoking a corresponding read() call would fetch all data.

// the old way
res = write(fd, cmd, sizeof(cmd));
// ... check res and more
n = read(fd, buf, sizeof(buf) - 1);

In Linux system programming, a single read() on a USBTMC device can fetch multiple physical USB packets and will automatically attempt to return the entire SCPI response text, provided the buffer is large enough. However, for large responses that exceed the buffer size or kernel transfer limits, the SCPI response may be split across multiple read() calls, meaning a complete transfer is only guaranteed by tracking the End-of-Message (EOM) status.

This meant that on the very first execution, the scope processed the command quickly enough to pack the whole string into a single read(). If the timing shifted however, no matter how slightly, my program exited early and closed the file descriptor leaving unread payload bytes sitting on the scope's USB FIFO queue. The next time the program is run, the leftover bytes spilled out immediately leaving the kernel with 4 bytes instead of the 12-byte header it expected. This likely triggered the 4 < 12 size validation errors in dmesg.

A Quick And Simple "Fix"

To fix this properly, I had to ensure the application layer assumes responsibility for the data synchronization instead of relying on the oscilloscope to do that. The most convenient way to do that was write a draining read loop which basically loops until it detects the standard SCPI newline terminator. This is however imperfect and won't work well for reading raw binary data since it would exit early if one of the bytes happens to be newline character (hex 0x0A) and as such the solution is limited to only reading ASCII string responses. Below is a genric and heavily stripped version of what I finally wrote (modify code and use with caution):

#define BUF_SIZE 4096

int query_device(int fd, const char *cmd, uint8_t *out_resp, size_t max_len) {
    char read_buf[BUF_SIZE];
    size_t total_bytes = 0;

    // send the SCPI command string (ensure caller included '\n' in cmd!)
    if (write(fd, cmd, strlen(cmd)) < 0) {
        return -1;
    }

    // loop until the instrument payload is completely drained
    while (1) {
        size_t space_left = sizeof(read_buf) - total_bytes - 1;
        
        // handle physical overflows safely.
        // on blocking file descriptors, trying to read() "trash" inside an error
        // handler will hang your thread indefinitely. exit immediately and let 
        // the top-level application reset the device connection.
        if (space_left == 0) {
            return -2; // buffer overflow error
        }

        ssize_t n = read(fd, &read_buf[total_bytes], space_left);
        if (n < 0) return -3; // read error
        if (n == 0) break;    // end of file / stream closed

        total_bytes += n;

        // break when we explicitly hit the SCPI newline terminator
        if (read_buf[total_bytes - 1] == '\n') {
            break;
        }
    }

    if (total_bytes >= max_len) {
        return -2; // destination buffer too small
    }

    memcpy(out_resp, read_buf, total_bytes);
    out_resp[total_bytes] = '\0';

    return 0;
}

Conclusions

If you are writing custom low-level tooling for bench instruments on Linux, keep these rules in mind:

#kernel #linux #systems #tooling #writing