The trace logs of app-insights in azure portal don't reflect the effective container logs (masked out sensitive data)

[bvahdat]

Expected behavior

The trace logs provided by app-insights should reflect the effective container logs of a given application.

Actual behavior

To have custom dimensions for our structured logging we make use of:

https://github.com/logfellow/logstash-logback-encoder

And we configure it to mask out sensitive data as per documentation here:

https://github.com/logfellow/logstash-logback-encoder#identifying-field-values-to-mask-by-value

And it actually works pretty well as because looking into the container logs we see that sensitive fields inside JSON are properly masked out, for example the container log entries look like:

{
  "@timestamp": "2022-07-21T12:15:41.181+02:00",
  "@version": "1",
  "message": "Processing of the event with cloudEventId: 6415d31r-b0o3-5cx8w-d934-d5320981278z and salesforceExternalId: 00525000008yPMSCC9 took 294 ms. which was successful.",
  "logger_name": "com.foo.bar.servicebus.salesforce.policy.MdcRoutePolicy",
  "thread_name": "main",
  "level": "INFO",
  "level_value": 20000,
  "forgerockEventBody": "{\n  \"data\": {\n    \"FrIndexedString1\": \"00525000008yPMSCC9\",\n    \"FrUnindexedString1\": \"George Michael\",\n    \"FrUnindexedString2\": \"en-GB\",\n    \"mail\": \"******\",\n    \"telephoneNumber\": \"******\"\n  },\n  \"datacontenttype\": \"application/json\",\n  \"dataschema\": \"foo:integration-hubs\",\n  \"id\": \"6415d31r-b0o3-5cx8w-d934-d5320981278z\",\n  \"source\": \"forgerock:idm\",\n  \"specversion\": \"1.0\",\n  \"time\": \"2018-04-05T17:31:00Z\",\n  \"type\": \"com.forgerock.user.migrated\"\n}\n",
  "trace_id": "00000000000000000000000000000000",
  "camel.contextId": "foo-ihub-connector-servicebus-salesforce",
  "salesforceMigrateAccountsSfResponseCode": "0",
  "span_id": "0000000000000000",
  "salesforceMigrateIndividualRequestBody": "{\"allOrNone\":true,\"compositeRequest\":[{\"body\":{\"FOO_Customer_Identity_External_ID__c\":\"00525000008yPMSCC9\",\"FirstName\":\"George Michael\",\"LastName\":\"Unknown\",\"REIDP_Email__c\": \"******\",\"REIDP_ForgeRock_Identity__c\":\"true\",\"REIDP_LanguageLocaleKey__c\":\"en-GB\",\"REIDP_Mobilephone__c\": \"******\"},\"method\":\"POST\",\"referenceId\":\"refIndividual\",\"url\":\"/services/data/v54.0/sobjects/Individual\"},{\"method\":\"GET\",\"referenceId\":\"refAccount\",\"url\":\"/services/data/v54.0/query/?q=SELECT+id+from+Account+where+FOO_Customer_Identity_External_ID__pc+=+%2700525000008yPMSCC9%27+AND+IsPersonAccount+=+TRUE\"}]}",
  "camel.routeId": "id-servicebus-to-salesforce",
  "cloudEventId": "6415d31r-b0o3-5cx8w-d934-d5320981278z",
  "salesforceMigrateIndividualResponseBody": "{\n  \"compositeResponse\": [\n    {\n      \"body\": {\n        \"id\": \"00525000008yPMSCC9\",\n        \"success\": true,\n        \"errors\": []\n      },\n      \"httpHeaders\": {\n        \"Location\": \"/services/data/v54.0/sobjects/Individual/0PK25000002zW7tGAE\"\n      },\n      \"httpStatusCode\": 201,\n      \"referenceId\": \"refIndividual\"\n    },\n    {\n      \"body\": {\n        \"totalSize\": 1,\n        \"done\": true,\n        \"records\": [\n          {\n            \"attributes\": {\n              \"type\": \"Account\",\n              \"url\": \"/services/data/v54.0/sobjects/Account/0012500001i9vb3AAA\"\n            },\n            \"Id\": \"0012500001i9vb3AAA\"\n          }\n        ]\n      },\n      \"httpHeaders\": {},\n      \"httpStatusCode\": 200,\n      \"referenceId\": \"refAccount\"\n    }\n  ]\n}",
  "camel.exchangeId": "F577AC290CF4B5D-0000000000000000",
  "salesforceExternalId": "00525000008yPMSCC9",
  "salesforceInvocationSucceeded": "true",
  "camel.messageId": "F577AC290CF4B5D-0000000000000000",
  "salesforceMigrateAccountsResponseBody": "{\"allOrNone\":true,\"compositeRequest\":[{\"body\":{\"FirstName\":\"George Michael\",\"LanguageLocaleKey__pc\":\"en-GB\",\"LastName\":\"Unknown\",\"PersonEmail\": \"******\",\"PersonIndividualId\":\"00525000008yPMSCC9\",\"PersonMobilePhone\": \"******\",\"REIDP_ForgeRock_Identity__pc\":\"true\"},\"method\":\"PATCH\",\"referenceId\":\"referenceId0012500001i9vb3AAA\",\"url\":\"/services/data/v54.0/sobjects/Account/0012500001i9vb3AAA\"}]}",
  "salesforceMigrateIndividualSfResponseCode": "201",
  "salesforceMigrateAccountsRequestBody": "{\"allOrNone\":true,\"compositeRequest\":[{\"body\":{\"FirstName\":\"George Michael\",\"LanguageLocaleKey__pc\":\"en-GB\",\"LastName\":\"Unknown\",\"PersonEmail\": \"******\",\"PersonIndividualId\":\"00525000008yPMSCC9\",\"PersonMobilePhone\": \"******\",\"REIDP_ForgeRock_Identity__pc\":\"true\"},\"method\":\"PATCH\",\"referenceId\":\"referenceId0012500001i9vb3AAA\",\"url\":\"/services/data/v54.0/sobjects/Account/0012500001i9vb3AAA\"}]}",
  "processingTimeInMillis": "294"
}

Notice the masked out fields which are:

\"mail\": \"******\"
\"REIDP_Email__c\": \"******\"
\"PersonEmail\": \"******\"
\"telephoneNumber\": \"******\"
\"PersonMobilePhone\": \"******\"
\"REIDP_Mobilephone__c\": \"******\"

But when we look at the corresponding trace logs of AppInsights in portal they are not masked out and show the sensitive data we are actually trying to mask out!

The corresponding logback-spring.xml of the spring-boot application is as the following (the used spring-boot profile at runtime is the default profile and not local):

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <springProfile name="local">
        <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
        <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>
        <root level="INFO">
            <appender-ref ref="CONSOLE"/>
        </root>
    </springProfile>

    <springProfile name="!local">
        <appender name="JSON" class="ch.qos.logback.core.ConsoleAppender">
            <encoder class="net.logstash.logback.encoder.LogstashEncoder">
                <jsonGeneratorDecorator class="net.logstash.logback.mask.MaskingJsonGeneratorDecorator">
                    <valueMask>
                        <value>"mail"\s*:\s*"[^"]+"</value>
                        <mask>"mail":"******"</mask>
                    </valueMask>
                    <valueMask>
                        <value>"REIDP_Email__c"\s*:\s*"[^"]+"</value>
                        <mask>"REIDP_Email__c":"******"</mask>
                    </valueMask>
                    <valueMask>
                        <value>"PersonEmail"\s*:\s*"[^"]+"</value>
                        <mask>"PersonEmail":"******"</mask>
                    </valueMask>
                    <valueMask>
                        <value>"telephoneNumber"\s*:\s*"[^"]+"</value>
                        <mask>"telephoneNumber":"******"</mask>
                    </valueMask>
                    <valueMask>
                        <value>"REIDP_Mobilephone__c"\s*:\s*"[^"]+"</value>
                        <mask>"REIDP_Mobilephone__c":"******"</mask>
                    </valueMask>
                    <valueMask>
                        <value>"PersonMobilePhone"\s*:\s*"[^"]+"</value>
                        <mask>"PersonMobilePhone":"******"</mask>
                    </valueMask>
                </jsonGeneratorDecorator>
            </encoder>
        </appender>
        <root level="INFO">
            <appender-ref ref="JSON"/>
        </root>
    </springProfile>
</configuration>

So to says from a timeline perspective, app-insights seems to infer the written logs after the encoder tag by the configuration above but before the jsonGeneratorDecorator tag.

To Reproduce

Steps to reproduce the behavior:

Sample Application

If applicable, provide a sample application which reproduces the issue.

System information

Please provide the following information:

• SDK Version: Tried out 3.2.11, 3.3.0 and 3.3.1 having the same behaviour.
• OS type and version: Running in AKS using the azul/zulu-openjdk-alpine:11-jre-headless base image.
• Application Server type and version (if applicable):
• Using spring-boot? Yes, version 2.7.2
• Additional relevant libraries (with version, if applicable): Apache Camel 3.18.1

Logs

Turn on SDK logs and attach/paste them to the issue. If using an application server, also attach any relevant server logs.

The Turn on SDK logs link above doesn't work for me.

Screenshots

If applicable, add screenshots to help explain your problem.

[richorama]

@bvahdat was asking me if this has been resolved. I understand that #6541 addresses sanitization, and wondered if it resolves this issue?

[srferron]

Same problem here, the app-insights doesn´t take the mask logs. I can see they are mask on pod logs but unmasked on app-insights

Thanks