Serial debugging output mangled

Programming
1

I’m trying to debug something using the serial port interface, but it’s not working very well; the output I get seems to be overwriting part of the buffer. Here’s the code I have:

int Keyboard_::sendReportUnchecked(void) {
  Serial.flush();
  Serial.print("Sending normal report: ");
  Serial.flush();
  Serial.print(keyReport.modifiers, BIN);
  Serial.flush();
  for (byte i = 1; i < 12; ++i) {
    Serial.print(" ");
    Serial.print(keyReport.allkeys[i], BIN);
    Serial.flush();
  }
  Serial.println();
  Serial.flush();
  return HID().SendReport(HID_REPORTID_NKRO_KEYBOARD, &keyReport, sizeof(keyReport));
}


int Keyboard_::sendReport(void) {
  // ChromeOS 51-60 (at least) bug: if a modifier and a normal keycode are added in the
  // same report, in some cases the shift is not applied (e.g. `shift`+`[` doesn't yield
  // `{`). To compensate for this, check to see if the modifier byte has changed. If so,
  // copy the modifier byte to the previous key report, and resend it before proceeding.
  if (lastKeyReport.modifiers != keyReport.modifiers) {
    lastKeyReport.modifiers = keyReport.modifiers;
    Serial.print("Sending extra report: ");
    Serial.flush();
    Serial.print(lastKeyReport.modifiers, BIN);
    Serial.flush();
    for (byte i = 1; i < 12; ++i) {
      Serial.print(" ");
      Serial.print(lastKeyReport.allkeys[i], BIN);
      Serial.flush();
    }
    Serial.println();
    Serial.flush();
    HID().SendReport(HID_REPORTID_NKRO_KEYBOARD, &lastKeyReport, sizeof(lastKeyReport));
  }

  // If the last report is different than the current report, then we need to send a report.
  // We guard sendReport like this so that calling code doesn't end up spamming the host with empty reports
  // if sendReport is called in a tight loop.

  if (memcmp(lastKeyReport.allkeys, keyReport.allkeys, sizeof(keyReport))) {
    // if the two reports are different, send a report
    int returnCode = sendReportUnchecked();
    memcpy(lastKeyReport.allkeys, keyReport.allkeys, sizeof(keyReport));
    return returnCode;
  }
  return -1;
}

…and here’s the output from some testing:

Sending extra report: 10 0 0 0 0 0 0 0 0 0 0 0

Sending normal report: 10 0 0 0 0 0 10000000 0 0 0 0 0

Sending extra report: 0 0 0 0 0 0 10000000 0 0 0 0 0

Sending extra report: 10 0 0 0 0 0 0 0 0 0 0 0

 10000000 0 0 0 0 0

Sending extra report: 0 0 0 0 0 0 10000000 0 0 0 0 0

Sending extra report: 10 0 0 0 0 0 0 0 0 0 0 0

 0 10000000 0 0 0 0 0

Sending extra report: 0 0 0 0 0 0 10000000 0 0 0 0 0

Sending extra report: 10 0 0 0 0 0 0 0 0 0 0 0

 0 0 0 10000000 0 0 0 0 0

Sending extra report: 0 0 0 0 0 0 10000000 0 0 0 0 0

Sending extra report: 10 0 0 0 0 0 0 0 0 0 0 0

 0 0 0 10000000 0 0 0 0 0

Sending extra report: 0 0 0 0 0 0 10000000 0 0 0 0 0

Notice that some of the output lines are incomplete; the beginning has been dropped, and not always in the same place. Anybody know what might be happening here? It’s pretty hard to debug if you can’t trust your debugging tools…

2

I added lots of calls to Serial.flush() in the hope that it would fix the problem, but no such luck.

3

I think it was a timing issue. I added a call to delay(1); after the “extra report” was sent, and then I started to see the expected output. I’m still not really sure I trust it now, but I think it’s working as expected.

4

My suspicion would be that the OS polls the keyboard at a certain intervals, with a fixed buffer size, and if there’s too much data coming too fast, it discards some of it. Adding a delay allows the OS to poll more times, thus no buffers getting full.

This is just a suspicion, mind you.

1 Like
5

Your hypothesis does seem to fit the data, but that buffer must be quite small if it’s true. At least I have some idea of how to work around the limitation, even if its nature remains a mystery. Thanks!

6

Another culprit might be USB. If I remember correctly, USB raw HID has pretty small packet sizes (~64 bytes or so?), which is much closer to what you are seeing. But common sense says Serial should be operating with much bigger buffers.

7

Looking at HardwareSerial.h from Arduino:

#if !defined(SERIAL_TX_BUFFER_SIZE)
#if ((RAMEND - RAMSTART) < 1023)
#define SERIAL_TX_BUFFER_SIZE 16
#else
#define SERIAL_TX_BUFFER_SIZE 64
#endif

I don’t know if that’s actually applicable, but I would have thought all those calls to flush() would have done the trick, anyway, since none of the strings I sent were longer than 64 bytes.

For the moment, I’m just going to shrug my shoulders and move on to other things. Thanks again, @algernon!