Update txt logger mode to 'a'

[antklein]

Python logging to a file with mode='w' can cause log loss when logging happens after the logger has already been cleaned up.
See issue: python/cpython#86544

The fix for Python was to have special cases for files opened in mode='w'. Currently we use mode='w+', so the checked in fix does not solve our problem.

I've implemented moving the file_logger to mode='a' and an explicit deletion of the logging file before opening the FileHandler.

[antklein]

@makubacki looks like the Ubuntu Python 3.10 and 3.11 builds are complaining because of the below error. Who could help look into that?

Test Stuart PR for Policy 5 library inf changed                       | FAIL |
'' does not contain 'MdeModulePkg'

[Javagedes]

@makubacki looks like the Ubuntu Python 3.10 and 3.11 builds are complaining because of the below error. Who could help look into that?

Test Stuart PR for Policy 5 library inf changed                       | FAIL |
'' does not contain 'MdeModulePkg'

@antklein Do not worry about this error. I added a new policy check that still need to be integrated into EDK2. This will continue to fail while I work through the mailing list and EDK2 PR process.

[Javagedes]

@antklein This change looks good, but could you please specify the situation where this is an issue? The only way I see this being an issue is if you setup the same txt logger twice, which does not happen in an invocable.

Thanks!
Joey

[antklein]

@antklein This change looks good, but could you please specify the situation where this is an issue? The only way I see this being an issue is if you setup the same txt logger twice, which does not happen in an invocable.

Thanks! Joey

Hi Joey,
For us this exact issue was happening. python/cpython#86544 (comment)

That's because in our platform level PlatformPostBuild function we spin off sub-threads which make use of the RunPythonScript from edk2toollib.utility_functions. If the main thread closes, closing the logging FileHandle, the sub-threads then return causing the RunPtyhonScript to log additional information clearing the original BUILDLOG output.

[Javagedes]

@antklein This change looks good, but could you please specify the situation where this is an issue? The only way I see this being an issue is if you setup the same txt logger twice, which does not happen in an invocable.
Thanks! Joey

Hi Joey, For us this exact issue was happening. python/cpython#86544 (comment)

That's because in our platform level PlatformPostBuild function we spin off sub-threads which make use of the RunPythonScript from edk2toollib.utility_functions. If the main thread closes, closing the logging FileHandle, the sub-threads then return causing the RunPtyhonScript to log additional information clearing the original BUILDLOG output.

Understood. That scenario makes sense. Thanks!

[codecov]

Codecov Report

Merging #584 (3f4dce4) into master (e0625a4) will increase coverage by 0.00%.
The diff coverage is 100.00%.

Additional details and impacted files

@@           Coverage Diff           @@
##           master     #584   +/-   ##
=======================================
  Coverage   78.99%   78.99%           
=======================================
  Files          47       47           
  Lines        4774     4776    +2     
=======================================
+ Hits         3771     3773    +2     
  Misses       1003     1003           

Impacted Files	Coverage Δ
edk2toolext/edk2_logging.py	88.20% <100.00%> (+0.13%)	⬆️