Testbench debug logging content and formatting
Testbench logging is front end of debug. Debug log content refers to information used for understanding scenario created by test and insights into testbench operation for…
Testbench logging is front end of debug. Debug log content refers to information used for understanding scenario created by test and insights into testbench operation for the purpose of debugging failures.
Good log formatting is not just eye pleasing. Beauty is necessary but its definition is not always eye pleasing. Bottom line is logging should adapt seamlessly to it’s use case model. Beauty of logging is in the eyes of it’s use cases.
Some of verification environments do pretty ASCII art based logging. Where log file messages are formatted to look easy on eyes using multiple lines, spacing and some special characters. While this is good for certain type of information, it does not suit all for all logging requirements. Logging should be aligned to requirements of logging objectives.
Some of the logs contain transactions formatted in pretty ASCII table format. It’s not much of value to format the transactions in ASCII table format. It’s almost useless to format any information in bulk quantity to look pretty. This type of information is typically not read. It’s more likely to be analyzed to reduce the scope to arrive at the subset of the transactions which are suspects causing the failure. So bulk information such as transactions or execution traces should be formatted for ease of analysis over looking pretty.
Does it mean our engineers with ASCII art skills are out of job?
No, not really. Randomized structural and functional configurations, which are typically programmed once during the beginning of the test, are one of the candidates for the ASCII table format.
Another candidate is test statistics about various transactions and events printed at the end of the test. This type of information is typically read more than analyzed, so it makes sense to print them in ASCII table format to be easy on eyes.
How to format bulk logging information such as transactions?
Bulk information logged should be analysis friendly over looking pretty. It should be made friendly with the analysis tools available on the platform used for the development.
Any serious development these days is using unix or linux variant of some type as platform for development. In shell some of great and quick analysis tools are search, filter and sort functionality related shell commands. Ultimately ability to extract the useful information with the simple shell commands scores over making it look pretty in the log file. If you can do both, then go ahead.
How to choose between multiline logging to vs. single line logging?
Multi Line messages are tricky to operate using the popular search related shell commands such as grep and awk. For logging information such as transactions, which are large in number, there is not much of value in logging them in multiple lines. One may argue it has large number of fields, so single line will look too long. It’s fine, don’t worry too much about how it looks. When you have large number of transactions they are not read transaction by transaction anyway. What matters is ability to find answers to questions of debug using the tools of platform.
For example if all the USBx transfers printed had term “TRANSFER” in them, one can simply do
> grep TRANSFER usb_test_run.log
Let’s say you want to find all transfers targeting an interrupt endpoint.
> grep TRANSFER usb_test_run.log | grep “EP: INTR”
Concatenation of simple commands can easily extract information for most complex query if they are single line messages.
If the TRANSFER was multiline message and number of lines printed varied, it becomes difficult to quickly extract information.
It’s not impossible. Of course you can write some scripts to do the job but then it limits ability to do things quickly to adapt to changing requirements, which is required while exploring the log files for different types of debugs.