#45 Software Tracing with printf
HTML-код
- Опубликовано: 15 сен 2022
- This lesson explains "debugging by printf" as the most common software tracing technique. You'll learn how to implement printf on the TivaC LaunchPad board, as well as NUCLEO-L152. You'll also explore some shortcomings of this primitive technique.
Contents with Timestamps:
-------------------------
3:18 Adding printf tracing to the BSP code
4:25 Attempts to run and the hardcoded breakpoints
6:00 MicroLIB and the fputc() function
7:25 Instrumentation Trace Macrocell (ITM)
8:00 Demonstration of STM32 NUCLEO board
8:50 Sending output via ITM
9:40 Setting up ST-LINK for tracing with ITM
9:55 Opening view "Debug (printf) Viewer"
10:58 Universal Asynchronous Receiver and Transmitter (UART)
12:11 Code for sending printf output via UART in TivaC
14:19 Opening and connecting serial terminal (Termite)
16:25 Tracing macros (variadic macros and __VA_ARGS__)
19:42 Build Configurations
20:18 Creating the "spy" build configuration for software tracing
22:35 Costs and overheads of printf tracing
23:40 Impact of floating-point format specification
24:45 Impact of printf tracing on execution time
End Notes:
----------
Companion web-page to this video course
www.state-machine.com/video-c...
Project download for this lesson:
www.state-machine.com/course/...
GitHub repository for projects for this video course:
github.com/QuantumLeaps/moder...
Transcript of this lesson:
www.state-machine.com/course/...
References resources:
---------------------
Termite -- a simple RS232 terminal:
www.compuphase.com/software_t...
STM NUCLEO-L152RE board
Instrumentation Trace Macrocell
developer.arm.com/documentati...
Music credits:
--------------
The background music comes from:
www.bensound.com/royalty-free... 
Наука
Usually embedded designers use uart plus DMA to greatly reduce the cost of execution time.
However, the ASCII-printf style of software tracing simply carries too little information per byte.
Something way more cleaver, like QSpy, must be utilised.
Thx, Miro, always high quality video!
That's true that the DMA offloads the CPU for simple data movement. But using printf() with DMA (and actually, you must mean hear snprintf() that formats the output into a given buffer) is not trivial. This buffering is tricky if you really want to avoid busy-waiting for the DMA to finish transmitting a given buffer (so you need multiple buffers). For these reasons, I actually don't see that many really good implementations of printf-style software tracing with DMA. Perhaps you could point out some such implementation on GitHub or some other public repository? I'm sure people watching this video would be interested. --MMS
感谢,老师,讲的非常好, qp让我受益匪浅
受益了什么
给你的眼神, 自己体会@@weizhao4664
@@weizhao4664 新的开发方法。这还用问，你是sb
As usual, I learn something with every episode - Thank you so much for this body of work.
As someone who works with processes timed in nanoseconds and microseconds, printf is excessively costly in time to be useful for software tracing. Tracing stuff going on in interrupt handlers can also be problematic.
Since I have not had the luxury of debuggers like the one that you have shown, I have had to create logging functions on my own. What has worked for me is a singleton that accepts a string, prepends a unique ascending counter value to it, and adds it to an array that you dump to a text file when it gets full. Actually two arrays, since one has to be available for writing while the other is being written to a file, which is time consuming. Any other formatting I do it after the log file is complete. (The logging procedure must be protected from interruption, especially in a multi-threaded environment. A call to a singleton function seems to prevents this.) (This is much easier to implement in Ada than in C/C++, but it can be done.)
To create a call stack-like trace, each file gets a variable that contains the APP name and Module Name, and each named body of code gets a variable with its name. That allows strings like “App.Module.Procedure.Start” and “App.Module.Procedure.End” to be composed on the fly, which you add to the beginning and end of a body of code. As already shown, this technique can be used to trace state transitions if a log entry is made for each state Entry and Exit.
If you have a program that halts, add an integer variable called “last_line” to your code and add “last_line = ; before each executable statement. In any exception handling, dump the value of “last_line” to identify the last successfully run line of code. (This is very easy to do in Ada, and tougher in C/C++)
If the problem is identifying what happened up to a point, interleave problematic code with an exact copy of the code that follows it as the log entry rather than any other text. The trace output will then be a complete trace of the code that was run during a test. It will not solve the problem of code optimization reorganizing the code, but it will help if the code unexpectedly takes paths that programmer did not expect.
Lastly, give yourself a way to turn logging on and off while processing. I pass a Boolean flag called Trace to each call. When Trace is true, add logging, when Trace is false, do not log. Since Trace is passed to each function and procedure, turning on logging at a higher level of abstraction means every function or procedure below it will log without any other work. Once the questionable code has been identified, the logging can be tuned down to just the section that needs to be traced.
I have a feeling that all of this will be shown eloquently in the next lesson, which I am looking forward to.
Again, thanks for the lessons so far.
Thank you for sharing. Almost every experienced embedded developer has some sort of software tracing solution because this is critically important to the development, debugging, optimization, and diagnosing of embedded software. In the next upcoming lesson #46 I plan to present a mature software tracing system much more suitable for real-time embedded systems than "printf". I will talk about the main features, like buffering, the data protocol, filtering, etc. I hope this will be interesting both to novices and experienced developers. Stay tuned!
As you point out using printf to debug screws your real time performance. It also moves your code around in memory so there is a chance that it will run when debugging but give issues then they are removed. I liked it when I could use emulators for the processor and had far greater control. If I have spare io I will use them to go high when entering a subprocess and low again when leaving. This might only take up a few clock cycles so helps with timing as well. Nice video thanks.
The best way is to push messages into a buffer and print them only in the lowest priority task, so that it does not affect timing of the actual code.
@@DevendraGuptaProfile Most of my software testing was done on little snippits of code, as any form of debugging would affect the operation if not used in the final code. Used to hate the fact that a small few line code change could push the testing back a few month. Love working on my own MC code as no one cares if it falls over once a week. Know a project where the code went wrong in the first few lines with a buffer overrun but did not die until it had run for 6 months. That was a bugger to find.
@@DevendraGuptaProfile Yes, absolutely. As I just mentioned in my other comment, buffering of outgoing bytes must be part of the solution. But printf-style formatting to ASCII in the time-critical path through the code is not the smartest way of doing this and professional software tracing solutions are all based on binary data. I'll show an example in the next lesson. Stay tuned!
thanks for the video, is using DMA with UART will be a solution for the printf problem, because there are some cases when it is hard to use the debugger, for example, I was working the nrf52 and as soon as I stop the code the BLE stop working, also printf if useful when you try to collect a streaming set of data for further analysis
You're on the right track, but the use of DMA (Direct Memory Access) for the UART will not help, at least not without a complete re-design of the printf interface. The problem is *buffering* because you cannot start sending (through DMA or any other way) new bytes until you make sure that the old bytes went out. So, adding buffering will be part of the solution that I'll present in the next lesson. And I hear what you're saying about troubleshooting BLE. That's exactly why I present lessons about software tracing, but I mean the real thing that you can actually use in real-time systems. Stay tuned!
Better if you add flush, like this: #definition MY_PRINTF(format,...) printf(format_,##__VA_ARGS__); flush()
Important if you're looking for a line of code that crashes. Otherwise your message contained in printf not followed by flush may not appear if the next line of code crashes.
The call to flush() might be indeed useful *on the host* . In embedded targets it all depends on the implementation of the low-level fputc(). If there is no buffering (and typically there isn't) flush() does nothing and is superfluous. -MMS