I liked the QNX approach, where the kernel sends log messages to another process, loaded on boot. When you build a boot image, you provide a logger process to read those messages. There's no expectation in embedded that there's a console available. If your system is a pump or an auto dashboard, you need to send the messages somewhere other than a "console". There might not even be a file system. In QNX, messaging is a primitive on top of which file systems and networking are built.
When I had to do logging in real time, each process used a library which did "logprintf" calls. Those went into a circular buffer which was written to a log file from another thread. If the circular buffer filled, "..." would appear in the log, and log messages would be lost, but the real-time thread would not block.
Interaction between real-time and non-real-time is always tough. It comes up a lot in networked game development.
[1] https://www.kernel.org/doc/html/latest/admin-guide/serial-co...
Actual kernel debugging is rarely needed except on strange or broken hardware. If you have to do that, you use a JTAG debugger.
Further startup is handled by a startup process in the boot image. It's running in user space, and loads more drivers, file systems, networking, etc. Anything it needs to log it sends to a user space logger process that was also part of the boot image. What that does depends on the target hardware. Often, there's no console or display in embedded. It might send on a network. Or write to a circular buffer that can be read out later.
This immediately signifies some level of "does not understand how this stuff works". Latency sensitive (audio or other) tasks need to be in the SCHED_RR or SCHED_FIFO scheduling class, which nice(1) has no effect on.
Conversely, using nice(1) on a SCHED_OTHER task is also unlikely to work, given that nice only impacts scheduling decisions and cannot provide RT-like behavior.
serial8250: too much work for irq4
The first result for "8250 too much work for irq4" is this: https://unix.stackexchange.com/questions/387600/understandin... (2017)
The problem is that the UART hardware that is emulated by various brands of virtual machine behaves impossibly, sending characters at an impossibly fast line speed. To the kernel, this is indistinguishable from faulty real UART hardware that is continually raising an interrupt for an empty output buffer/full input buffer. (Such faulty real hardwares exist, and you will find embedded Linux people also discussing this problem here and there.) The kernel pushes the data out/pulls the data in, and the UART is immediately raising an interrupt saying that it is ready for more.
So, is this seven year old problem still a problem, or is the virtual serial port driver actually unable to keep up with the stream of text?
If you're running in a VM, how do you know the difference between a virtual interrupt and a actual interrupt? Either way, you're handling an interrupt.
If I understand the issue, it's not that the virtual serial port is swamped really. It seems like the issue is that the virtual serial port is firing its empty/ready interrupt so often (probably after every byte written to the port?) that the driver thinks the interrupt is broken, so then it falls back to polling for readiness. The driver polling rate seems like it's not high enough to keep up with the logging, so then logging blocks.
Probably, it'd be better for the virtual serial port to limit the number of irqs it will send. Limiting the number of interrupts is a key benefit of the 16550 over earlier UART chips; it does this by having a 16 byte buffer and sending interrupts only when the buffer is empty/below a threshold (for outgoing) or full/above a threshold (for incoming). Getting an interrupt for each outbound byte is too many interrupts if you're logging a lot of junk on the serial console (which I'm guessing happens; modern software is full of junky logs IMHO).
Probably the right thing to do would be for virtual machine hosts to over virtio consoles as well as virtual serial ports, and for virtual machine guests to prefer to use a virtualio console rather than a serial port for logging. But it's probably possible to adjust the serial driver options as well. Virtio console could be much more efficient, as it allows transfers larger than a single byte at a time.
You'd just have your logs backing up because you're writing more than 115kbaud, and then things that write logs become blocking. You'd need to figure that out by seeing what processes are blocked on what, rather than getting a hint because the irq behavior is weird.
In terms of how it causes the issue, I think it's more that the serial driver will monopolise the (virtual) CPU for as long as it is receiving or sending text. If there's a large buffer being dumped all at once (a common default for non-interactive streams), it could stall for long enough to cause an underrun, which doesn't need to be very long, even if the average data rate isn't very high. Consider that the virtual 8250 serial port interface isn't exactly the most efficient interface to begin with, since it's at most copying 16 bytes from host to guest at a time
You shouldn’t have to try to reproduce this in a test environment - your infrastructure should allow profiling in live for cases like this. And it should be solved with profiling, not guesswork and bisecting
That's not how you live in AI age. Move fast and break things; YOLO; K8S all the things; etc..
(/s in case it's not clear)
Buffer overruns feels very 1996-cd-burner-ish. Ope, burned a coaster, let's try this hellaciously real-time-bound thing again with inadequate buffering and I/O devices that have unpredictable latency.
What am I missing?
If you can manage with large latency, then sure, buffer the hell out of everything and your chances of losing data will be close to zero.
If you need low latency, you cannot buffer the hell out of everything, and anything that interferes with the data flow runs the risk of causing an underrun.
The solution in the CD burner case was easy: massive latency is fine, so buffer the hell out of it, and it just works.
The solution for low-latency audio anything is not so easy: you can't buffer the hell out of it, which means you're susceptible to hardware and software issues that disrupt timing and end up causing underruns/overruns.
So you make your buffer larger. But the thing consuming the data is still slower than the thing producing the data, so that buffer will eventually overrun, too. The graceful way to fail is not to block, but to quickly drop the excess data. However, you're now losing data, and doing so very unexpectedly overall, because apparently this transcription service was supposed to be well able to keep up with the audio stream. (If I understood this whole thing right, it's a bit vague.)
So really, unless the root cause is taken care of, you either block or lose data, without good reason in this case.
> Buffer overruns feels very 1996-cd-burner-ish.
That was a buffer underrun, the opposite. The CD burner, moving at a fixed speed, ran out of data because the producer (the rest of the PC, effectively) was not able to replenish the buffer quickly enough. The fix, besides faster PCs, was to have very large buffers, that were able to pick up the slack for longer than the duration of a "dropout" on the PC side. But between those "dropouts", the PC was probably well able to produce the data to the CD burner at a higher rate than necessary, so the large buffer stayed filled on average.
Both buffer overruns and underruns are still very much a concern. They exist anywhere where producers and consumers operate at a mismatched rate for more than just a short time, in a real-time setting.
(Now, why does it produce a pop as opposed to silence/hiccup/stretched sound? probably because it was easiest to code)
> (Now, why does it produce a pop as opposed to silence/hiccup/stretched sound? probably because it was easiest to code)
Sudden "silence" pretty much is a pop, and so is the silence suddenly ending. The sharp transition at least theoretically contains energy in all frequencies (or rather the full bandwidth of this bandwidth-limited signal), which we perceive as a pop.
Bang a steel bar against a hard table, and you get a whole range of frequencies as well, also very pop-like. Do the same with a tuning fork, and after the initial bang you get a nice, clean, single tone, because the tuning fork effectively filters out all the other frequencies through its impulse response.
If running PREEMPT_RT, which anything handling realtime audio should really do, this should be handled.
After a major migration, we faced a strange audio issue that led us on a deep dive through our infrastructure.
The culprit? Not the audio code—but a hidden interaction with AWS’s virtual serial ports.
We wrote about our journey discovering the artifacts and finding a clean fix!