Getting the most out of the UVM messages

Messages fill our log file with important information regarding test simulation results. Often this information is used to debug issues and/or report the status of some toggled functionality. Making sure the information added to the log is exact can greatly reduce debug time. I'd like to take a look at the uvm_info macro and suggest a method to receive the most possible information from each reported message.

Message Macro Format

`uvm_info(ID,MSG,VERBOSITY)

Verbosity

The verbosity selects importance of the message. A verbosity of UVM_NONE is an important message with the highest priority and should always be printed where UVM_DEBUG is the least important message with the lowest priority which should only be printed for deep debugging sessions. If a low priority verbosity is set for default messages, the following can occur:

• Users will run tests with a low verbosity priority causing many unwanted messages to be printed to the log. This setting can potentially make the log extremely hard to to review when debugging a failure. 
• Users will leave the verbosity at its higher priority level and many important messages won't be printed to the log. When a failure occurs it can be hard to debug since messages pointing to the failure have been obfuscated. 

So select wisely the verbosity settings for messages reported throughout your test relative to your default verbosity setting. 

MSG

This is the heart of your display message, here you insert the message you wish to display. Wrapping the message string in a $sformatf system call allows embedding variables into the message string so highly consider using this system task for all message strings created, even if you don't need to print a variable for a specific message. 

ID

This ID field is used to define the type of message printed. I've seen many examples where a simple string is inserted here such as "CFG" or "SEQ". These strings are obscure, misleading and often become irrelevant since messages are copy-pasted from one block to another. Many times the user doesn't update the string for a new block and this field looses its purpose. A much better approach for this field is to use the objects function get_type_name() defined in the uvm_object class. This function reports the object type in use, which becomes extremely useful with factory overrides.

Lets see an example of a log output with a sequence running natively and then with a factory overridden type:

Native sequence message:
UVM_INFO @ 200812.5ns: uvm_test_top.env.agnt.seqr@@seq [my_sequence] msg 1

Factory overridden message:
UVM_INFO @ 200812.5ns: uvm_test_top.env.agnt.seqr@@seq [my_inherited_sequence] msg2

In both cases the same pointer seq was run on the same agent sequencer but the factory override was reported in the log by the get_type_name()function call. Without any need for review, it is apparent which object type was executed and that the factory was successful in overriding the requested type. Since debugging factory issues can be somewhat hairy, there is an enormous amount of important information provided with this methodology. 

Other Messaging Macros

So what about the other messaging macros such as uvm_warning, uvm_error and uvm_fatal? These messages are a subset of the uvm_info with the verbosity set to UVM_NONE.
The ID and MSG fields are used in the same format with these macros as with the uvm_info allowing the same implementation as described above.