Microsoft.Extensions.Compliance.Redaction.NullRedactor doesn't seem to work #5691

Activity

1. erwinkramer

   added

   bugThis issue describes a behavior which is not expected - a bug.This issue describes a behavior which is not expected - a bug.

   untriaged

   on Nov 24, 2024
2. RussKie

   added

   area-compliance

   on Nov 26, 2024
3. RussKie commented on Nov 26, 2024

   

   RussKie

   on Nov 26, 2024

   Contributor

   More actions

   /cc: @dotnet/dotnet-extensions-compliance
4. amadeuszl

   self-assigned this

   on Nov 27, 2024
5. amadeuszl commented on Nov 27, 2024

   

   amadeuszl

   on Nov 27, 2024

   Contributor

   More actions

   Checking this one
6. amadeuszl commented on Nov 28, 2024

   

   amadeuszl

   on Nov 28, 2024

   Contributor

   More actions

   I can reproduce the issue. Seems like this problem is related to Aspire Dashboards as they do not show any properties marked with DataClassificationAttribute for structured logs at all. When you check how structured logs are looking with eg. JsonConsole they look as they should:

   {
       "EventId": 964789645,
       "LogLevel": "Information",
       "Category": "API logger",
       "Message": "Access received for user to teller data",
       "State": {
           "Message": "Microsoft.Extensions.Logging.ExtendedLogger\u002BModernTagJoiner",
           "{OriginalFormat}": "Access received for user to {dataType} data",
           "accessLog.AuthenticationType": "TEST", // no classification and only this one is visible in Aspire Dashboard
           "dataType": "teller",
           "accessLog.IShouldNotSeeIt": "", // restricted with ErasingRedactor
           "accessLog.TestField": "***", // tested with custom redactor for confidebtial
           "accessLog.UserId": "myId:accessLog.UserId" // unrestricted with NullRedactor
       }
   }

   How it looks in Aspire:
   

   Next, I'm going to check supported scenarios and what we can do for Aspire to make it work. We may need to create an issue on Aspire.
   @eerhardt can you take a look before we go to Aspire repo?

   👀React with 👀1Reacted by Erwin
7. amadeuszl

   removed

   untriaged

   on Nov 29, 2024
8. eerhardt commented on Nov 29, 2024

   

   eerhardt

   on Nov 29, 2024

   Member

   More actions

   The Aspire Dashboard displays the logs that get sent to it via OTLP (open telemetry logging protocol).

   It would be good to understand what is getting emitted out of the app through the OTLP exporter. Perhaps there is something in OpenTelemetry causing the problem.

   cc @JamesNK

   👍React with 👍1Reacted by Amadeusz Lechniak
9. JamesNK commented on Nov 30, 2024

   

   JamesNK

   on Nov 30, 2024

   Member

   More actions

   Aspire dashboard blindly displays what is sent to it. The problem must happen before the log is received by the dashboard.
10. amadeuszl commented on Jan 6, 2025

    

    amadeuszl

    on Jan 6, 2025

    Contributor

    More actions

    Sorry for late response I was OOO for most of the December.

    I was able to track down the issue. It's concurrency issue between ExtendedLogger and logic behind logging in OpenTelemetry.
    ExtendedLogger builds the logging state of type ModernTagJoiner, it has RedactedTagArray. RedactedTagArray which is KeyValuePair list has values of objects of JustInTimeRedactor.

    So now, ExtendedLogger will call LoggerLog() on all Loggers, one of them is OpenTelemetryLogger. It relies on BatchLogRecordExportProcessor, in the end it puts the attributes into buffer in BatchExportProcessor and runs exportTrigger.Set() to trigger execution on a different thread in ExporterProc. It causes the export to run on a different thread, while first thread with ExtendedLogger will continue execution, which ends up cleaning up the state by returning object to the pool thus cleaning up the redactors here.

    The result is the race condition, redactors are cleaned before OTLP exporter writes attributes, to be precise it results in NullReferenceException on Redactor object in JustInTimeRedactor.

    Potential solutions

    1. Not use batch exporter, but I believe it has to be used with OTLP Exporter
    2. Delay cleaning of the state and returning object to pool
    3. Change the pattern in which JIT Redactor is passed to inner Loggers.

    👍React with 👍1Reacted by Erwin
11. amadeuszl commented on Jan 6, 2025

    

    amadeuszl

    on Jan 6, 2025

    Last edited by amadeuszl

    Contributor

    More actions

    That issue was already reported #5080 and it's being investigated in OTEL open-telemetry/opentelemetry-dotnet#5276. I think we can keep this issue here open, to track efforts on our end.

    @erwinkramer suggested workaround from 5276 for now is:

    Edit: I got around this issue with a workaround, by using a Processor and intercepting the redacted attribute (we only have a handful), removing it from Attributes and re-adding it as a ToString() value. Hopefully the SDK can natively support this soon :)

    👍React with 👍1Reacted by Erwin