Add prefix for DEBUG_ERROR prints for data analysing purpose

[liqiqiii]

Description

Add prefix for DEBUG_ERROR prints for data analysing purpose
DEBUG_ERROR level prints are generally very important and worth analyzing. One blocking thing now is that we can't tell the difference between different debug level msgs because not all DEBUG_ERROR will have an "error:" as the prefix of the debug msg. This PR is to add a non-used keyword so we can easily track the DEBUG_ERRORs.

• Impacts functionality?
  • Functionality - Does the change ultimately impact how firmware functions?
  • Examples: Add a new library, publish a new PPI, update an algorithm, ...
• Impacts security?
  • Security - Does the change have a direct security impact on an application,
    flow, or firmware?
  • Examples: Crypto algorithm change, buffer overflow fix, parameter
    validation improvement, ...
• Breaking change?
  • Breaking change - Will anyone consuming this change experience a break
    in build or boot behavior?
  • Examples: Add a new library class, move a module to a different repo, call
    a function in a new library class in a pre-existing module, ...
• Includes tests?
  • Tests - Does the change include any explicit test code?
  • Examples: Unit tests, integration tests, robot tests, ...
• Includes documentation?
  • Documentation - Does the change contain explicit documentation additions
    outside direct code modifications (and comments)?
  • Examples: Update readme file, add feature readme file, link to documentation
    on an a separate Web page, ...

How This Was Tested

Tested with a platform that uses advancedlogger and can see [LOG_ERROR] in front of every debug_error msg.

Integration Instructions

N/A

[codecov-commenter]

Codecov Report

Attention: Patch coverage is 0% with 6 lines in your changes missing coverage. Please review.

Project coverage is 11.03%. Comparing base (005cfdd) to head (e1b873d).

Files	Patch %	Lines
...erPkg/Library/PeiDebugLibAdvancedLogger/DebugLib.c	0.00%	4 Missing ⚠️
...rPkg/Library/BaseDebugLibAdvancedLogger/DebugLib.c	0.00%	2 Missing ⚠️

Additional details and impacted files

@@                Coverage Diff                 @@
##           release/202311     #516      +/-   ##
==================================================
- Coverage           11.03%   11.03%   -0.01%     
==================================================
  Files                 144      144              
  Lines               22037    22042       +5     
  Branches             2356     2356              
==================================================
  Hits                 2432     2432              
- Misses              19573    19578       +5     
  Partials               32       32              

Flag	Coverage Δ
AdvLoggerPkg	3.63% <0.00%> (-0.01%)	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[os-d]

I don't think this adds value. DEBUG_ERROR gets used in a lot of places for things that aren't actual errors. Adding something like this will only cause spurious errors to get reported. At the end of the day, nothing will beat high quality print statements and actually analyzing a log.

[makubacki]

I don't think this adds value. DEBUG_ERROR gets used in a lot of places for things that aren't actual errors. Adding something like this will only cause spurious errors to get reported. At the end of the day, nothing will beat high quality print statements and actually analyzing a log.

That's my main concern. DEBUG_ERROR is often generically used as a "high level" for messages so they can appear in RELEASE builds and so on. I'm not going to defend that though; it is a bad design/pattern. Error should mean error and developers should and probably would pay more attention to those messages if that was the case.

I could maybe see this being controlled by a platform with something like PcdDebugPropertyMask (default off), but I think that extends the mess from DEBUG_ERROR by encoding it into a PCD rather than addressing the problem like just adding another level for "important" but not error messages. I also feel that if this were enabled (however that is done), the prefix of all levels (e.g. info:, warn:, etc.) should be printed for consistency.

[liqiqiii]

I don't think this adds value. DEBUG_ERROR gets used in a lot of places for things that aren't actual errors. Adding something like this will only cause spurious errors to get reported. At the end of the day, nothing will beat high quality print statements and actually analyzing a log.

That's my main concern. DEBUG_ERROR is often generically used as a "high level" for messages so they can appear in RELEASE builds and so on. I'm not going to defend that though; it is a bad design/pattern. Error should mean error and developers should and probably would pay more attention to those messages if that was the case.

I could maybe see this being controlled by a platform with something like PcdDebugPropertyMask (default off), but I think that extends the mess from DEBUG_ERROR by encoding it into a PCD rather than addressing the problem like just adding another level for "important" but not error messages. I also feel that if this were enabled (however that is done), the prefix of all levels (e.g. info:, warn:, etc.) should be printed for consistency.

Thanks Oliver and Michael, I think it's a good point that DEBUG_ERROR is often used in non error cases(kind of a routine), I was planning to do either cleaning up non-error debug errors + provide an ignore file that includes all non-error ones, so we can get really useful results, or I go and add error: into the real errors like some of them already have right now(non consistent format of print statements) and use error: as the keyword. Both will take time but I think if it's finished properly, it will really add values to our detailed uefi logs.

Now the uefi logs are gold that's hard to mine, Errors that don't block boot will be very hard to be found as no one notices in the tens of thousands of lines of log.

The pcd idea is sth worth a trial if everyone likes it.
I was thinking about adding prefix for all levels but was little bit worried about the extra space it would consume, adding the [LOG_ERROR] will increase binary size by around 50KB with several thousand DEBUG_ERRORs total; if we add it for all debug prints that would be a significant amount of size increase, and we don't really care about other level prefixes that much so I didn't add it. If we have plan to add it, I will also make some assessment and see if it really explodes the size or not.

[liqiqiii]

Hi @os-d @makubacki Oliver and Michael, I had an offline talk with Kun @kuqin12 and he mentioned a better way to use the existing debug_level in the metadata and in this way, we don't need to touch the firmware itself. I have tried with it and it's working perfectly fine, we got all the debug levels printed out.
22:36:22.840 : [MM_CORE] [DEBUG_INFO]AdvancedLoggerGetLoggerInfo: LoggerInfo=70F37000
22:36:22.857 : [MM_CORE] [DEBUG_ERROR]ERROR - The FV at 0xFFE60000 is invalid!

[makubacki]

Hi @os-d @makubacki Oliver and Michael, I had an offline talk with Kun @kuqin12 and he mentioned a better way to use the existing debug_level in the metadata and in this way, we don't need to touch the firmware itself. I have tried with it and it's working perfectly fine, we got all the debug levels printed out. 22:36:22.840 : [MM_CORE] [DEBUG_INFO]AdvancedLoggerGetLoggerInfo: LoggerInfo=70F37000 22:36:22.857 : [MM_CORE] [DEBUG_ERROR]ERROR - The FV at 0xFFE60000 is invalid!

Closing the PR.