Serial port interrupt timings

[JayKominek]

There were some concerns a few weeks back with at least one person convinced that the serial card's UART had a "slow" interrupt. I finally got around to taking measurements, so I'm presenting them here to lay that to rest, and explain what the actual issues are.

Here's a logic analyzer capture of a 16550 in the X16 receiving a byte:

x16 serial receive interrupt timing 921600.png (217.36 KiB) Viewed 1113 times

The stop bit begins at 14.315720ms, and INTR goes up at 14.316208ms, which is 488 nanoseconds later. VPB goes low 1168 nanoseconds later (at 14.317376ms). So it takes rather longer for the 65C02 to start grabbing the interrupt handler's address than it does for the '550 to signal the interrupt.

We can zoom out further and catch the processor reading from the UART:

x16 serial receive interrupt timing 921600 zoomed out.png (230.4 KiB) Viewed 1113 times

This particular interrupt handler needs 8680ns to get to reading from the UART after VPB goes low. (FWIW It's the miditest code from https://github.com/X16-community-experimental/miditest - thanks to m00dawg for that, saved me a bunch of time.)

So, then, why would anyone think the interrupt handler was slow / how would you lose bytes when you've got the FIFO turned on?

Here's a capture when running ROMTERM, and pressing/transmitting "Z":

x16 serial transmit character.png (119.17 KiB) Viewed 1113 times

ROMTERM polls the UART for bytes, with a normal gap of 63.272us. When the default KERNAL interrupt handler runs, the gap blows up to 648.4us. So the handler is taking 585.128us. If you're running 8N1, with a 16 byte FIFO, you can have 160 bit periods in that 585us before you exceed the FIFO capacity. That's 3.65us per bit, or ~273kbit/second. If you want to receive data faster than that, you've got to do something fancier than using the default interrupt handler.

The above testing was done with an original National Semiconductor PC16550DN on a serial card of my design, so the interrupt circuit actually works, unlike the currently available TexElec serial card. But timing may vary, very slightly, between that part and the TL16C2550 present on the TexElec card.

If anyone has any questions or spots any errors, I'd be happy to try and address them.

(I'll be release the schematic for my card very soon now, the same as I released the schematic for my cartridge design.)

[voidstar]

Can you try across each of the EXT slots to ensure this is consistent across each of those? (it should be, just I've seen some inconsistent behavior across EXT slots and across certain boards - meaning EXT3 might be fine on one board, but "iffy" on a different board).

Also, try to examine maybe about a dozen tx/rx of lower-case o (as in just holding it down). For some reason that signal has seemed to be the most problematic for me.

I couldn't fathom any of that having any impact to the interrupt mechanism (but yet, not all my little "o"'s are making it across in every slot).

[JayKominek]

Hm, so, all of the lines are being measured physically on my serial card, except for PHI2 and VPB. VPB is generated in the CPU, after it sees IRQB go low, and variations will be dominated by what instruction is being executed when the IRQ hits. Since PHI2 is being measured at the CPU, and everything else on the card, we would see some phase differences depending on the slot, but I'm not sure that moving the card between slots and repeating this particular experiment would be very interesting. I've also got different decode logic from the TexElec product (I'm using discrete, though hole 74xx parts, whereas it uses some CPLD), so anything with the logic propagation delay in it won't tell us anything about the TexElec product's behavior.

However! I've sketched out a little breakout card that exposes all of the interesting bus signals on convenient headers. My plan is to get 4 of those made, plug them into all of the slots, and then I can watch a single signal move along the four slots on my oscilloscope, or watch a whole bunch of signals on the logic analyzer. (I've got one that can do 32 channels @ 250MHz which ought to suffice.)

I'm up for sending a bunch of 'o's back and forth and capturing them on the analyzer, though. I sent a few screenfuls of data through during testing and didn't notice any corruption, but I wasn't aiming to catch it, either, so it's worth a go.

[JayKominek]

Hrm, wrote another reply which I probably failed to hit 'submit' on.

I hooked up my serial card (which, again, is not the TexElec card, but one of my own design using an original 16550, which does not support auto RTS/CTS) to a Linux system via null modem cable. I then had a small program send a screenful of lines which consisted of "a", a bunch of "o"s and then a "z". This was done at 921.6k baud, but I only sent 1000 characters per second. So a bit more than could be handled by 9600 baud if it were maxed out. What ROMTERM showed me, almost every time, was something that looked like:

IMG_3238.jpg (3.89 MiB) Viewed 910 times

One or two messed up lines, followed by generally being okay. Over a lot of runs, I never had any blanks, corrupted characters, etc. I think this is completely different from voidstar's issue, and is actually a bug in ROMTERM. If we look at the system under the logic analyzer, we see:

x16 romterm stops reading.png (133.11 KiB) Viewed 910 times

At the trigger point, marked "data start", the bytes begin coming in. But ROMTERM which was regularly reading from the UART (we can see the /CS line triggering over and over, except when interrupted slightly by the interrupt handler), all of a sudden stops reading, and just snags 4 characters over the next 150ms. Then it starts up again. Very weird behavior, doesn't make much sense to me. Probably ROMTERM can get away with that because it's mostly being used with a TL16C2550 which does have auto-RTS/CTS, so it's just turning off the other end, and then sitting and twiddling its thumbs for 150ms, and then starting to read the FIFO again.

I didn't work out the timing exactly, but I bet the 3 other gaps we see in the /CS line's toggling are new lines, when ROMTERM has got to scroll the screen. That's understandable, but, uh, really quite long. Probably about 15ms?

I hooked up some more lines to the logic analyzer and did a more complete analysis of where the time is going during the standard interrupt handler:

interrupt stuff without key press.png (223.68 KiB) Viewed 910 times

Reading I2C takes 115us in this case, reading the SNES controllers takes 169us. Total time in the handler was estimated to be 394us. Those two things account for ~72% of the handler's time, even when there's no input. Gets a bit worse if there is keyboard input.