Figure out why Azure platformlogs tests fail

[zmoog]

If I walk into the Azure Logs package sources:

cd ~/code/projects/elastic/integrations/

git checkout main. # commit 12a95e8b8779423a5be585f999044b3d76821f6a

cd packages/azure

elastic-package build && elastic-package stack up -d -v --version 8.7.1

And run the pipeline tests I get an error:

$ elastic-package test pipeline -v
2023/09/26 08:36:23 DEBUG Enable verbose logging
2023/09/26 08:36:23 DEBUG latest version (cached): &{v0.87.1 https://github.com/elastic/elastic-package/releases/tag/v0.87.1 2023-09-26 08:18:48.308297 +0200 CEST}
Run pipeline tests for the package
2023/09/26 08:36:23 DEBUG GET https://127.0.0.1:5601/api/status
--- Test results for package: azure - START ---
FAILURE DETAILS:
azure/platformlogs test-platformlogs-invalid-raw.log:
--- want
+++ got
@@ -5,25 +5,7 @@
             "azure": {
                 "platformlogs": {
                     "category": "ApplicationGatewayAccessLog",
-                    "event_category": "Administrative",
-                    "operation_name": "ApplicationGatewayAccess",
-                    "properties": {
-                        "clientIP": "172.105.13.165",
-                        "clientPort": 18234,
-                        "host": "IP",
-                        "httpMethod": "GET",
-                        "httpStatus": 502,
-                        "httpVersion": "HTTP/1.1",
-                        "instanceId": "ApplicationGatewayRole_IN_1",
-                        "originalHost": "IP",
-                        "receivedBytes": 108,
-                        "requestQuery": "X-AzureApplicationGateway-CACHE-HIT=0",
-                        "requestUri": "/nmaplowercheck1602448229",
-                        "sentBytes": 1636,
-                        "sslEnabled": "off",
-                        "timeTaken": 78,
-                        "userAgent": "Mozilla/5.0"
-                    }
+                    "event_category": "Administrative"
                 },
                 "resource": {
                     "id": "/SUBSCRIPTIONS/SUBSCRIPTION/RESOURCEGROUPS/ET-AZURE-INTEGRATION-TESTING/PROVIDERS/MICROSOFT.NETWORK/APPLICATIONGATEWAYS/LANGERGATEWAY",
@@ -36,12 +18,15 @@
             "ecs": {
                 "version": "8.0.0"
             },
+            "error": {
+                "message": "Received invalid json from the Azure Cloud platform. Unable to parse the source log message"
+            },
             "event": {
-                "action": "ApplicationGatewayAccess",
                 "kind": "event",
                 "original": "{ \"resourceId\": \"/SUBSCRIPTIONS/SUBSCRIPTION/RESOURCEGROUPS/ET-AZURE-INTEGRATION-TESTING/PROVIDERS/MICROSOFT.NETWORK/APPLICATIONGATEWAYS/LANGERGATEWAY\", \"operationName\": \"ApplicationGatewayAccess\", \"time\": \"2020-10-11T20:30:59Z\", \"category\": \"ApplicationGatewayAccessLog\", \"properties\": {\"instanceId\":\"ApplicationGatewayRole_IN_1\",\"clientIP\":\"172.105.13.165\",\"clientPort\":18234,\"httpMethod\":\"GET\",\"requestUri\":\"/nmaplowercheck1602448229\",\"requestQuery\":\"X-AzureApplicationGateway-CACHE-HIT=0\",\"userAgent\":\"Mozilla/5.0\",\"httpStatus\":502,\"httpVersion\":\"HTTP/1.1\",\"receivedBytes\":108,\"sentBytes\":1636,\"timeTaken\":78,\"sslEnabled\":\"off\",\"host\":\"IP\",\"originalHost\":\"IP\"}},{ \"resourceId\": \"/SUBSCRIPTIONS/SUBSCRIPTION/RESOURCEGROUPS/ET-AZURE-INTEGRATION-TESTING/PROVIDERS/MICROSOFT.NETWORK/APPLICATIONGATEWAYS/LANGERGATEWAY\", \"operationName\": \"ApplicationGatewayAccess\", \"time\": \"2020-10-11T20:30:59Z\", \"category\": \"ApplicationGatewayAccessLog\", \"properties\": {\"instanceId\":\"ApplicationGatewayRole_IN_1\",\"clientIP\":\"172.105.13.165\",\"clientPort\":18706,\"httpMethod\":\"GET\",\"requestUri\":\"/evox/about\",\"requestQuery\":\"X-AzureApplicationGateway-CACHE-HIT=0\",\"userAgent\":\"Mozilla/5.0\",\"httpStatus\":502,\"httpVersion\":\"HTTP/1.1\",\"receivedBytes\":94,\"sentBytes\":1636,\"timeTaken\":62,\"sslEnabled\":\"off\",\"host\":\"IP\",\"originalHost\":\"IP\"}}]}"
             },
             "tags": [
+                "preserve_original_event",
                 "preserve_original_event"
             ]
         },

╭─────────┬─────────────────────┬───────────┬──────────────────────────────────────────────┬─────────────────────────────────────────────────────────────────────────┬──────────────╮
│ PACKAGE │ DATA STREAM         │ TEST TYPE │ TEST NAME                                    │ RESULT                                                                  │ TIME ELAPSED │
├─────────┼─────────────────────┼───────────┼──────────────────────────────────────────────┼─────────────────────────────────────────────────────────────────────────┼──────────────┤
│ azure   │ activitylogs        │ pipeline  │ test-activitylogs-edgecases.log              │ PASS                                                                    │ 121.455667ms │
│ azure   │ activitylogs        │ pipeline  │ test-activitylogs-identity.log               │ PASS                                                                    │   6.087875ms │
│ azure   │ activitylogs        │ pipeline  │ test-activitylogs-raw.log                    │ PASS                                                                    │   9.067542ms │
│ azure   │ application_gateway │ pipeline  │ test-application-gateway-raw.log             │ PASS                                                                    │     18.199ms │
│ azure   │ auditlogs           │ pipeline  │ test-audit-logs-edgecases.log                │ PASS                                                                    │   7.400958ms │
│ azure   │ auditlogs           │ pipeline  │ test-audit-logs-sample.log                   │ PASS                                                                    │   5.754875ms │
│ azure   │ auditlogs           │ pipeline  │ test-auditlogs-raw.log                       │ PASS                                                                    │   2.963083ms │
│ azure   │ eventhub            │ pipeline  │ test-eventhub-raw.log                        │ PASS                                                                    │    2.64775ms │
│ azure   │ firewall_logs       │ pipeline  │ test-applicationrules-raw.log                │ PASS                                                                    │   11.56775ms │
│ azure   │ firewall_logs       │ pipeline  │ test-dnsproxyrules-raw.log                   │ PASS                                                                    │   4.442209ms │
│ azure   │ firewall_logs       │ pipeline  │ test-networkrules-raw.log                    │ PASS                                                                    │  10.508208ms │
│ azure   │ firewall_logs       │ pipeline  │ test-sdh3075-raw.log                         │ PASS                                                                    │   3.631666ms │
│ azure   │ identity_protection │ pipeline  │ test-rickyusers-raw.log                      │ PASS                                                                    │   5.566083ms │
│ azure   │ identity_protection │ pipeline  │ test-userriskevents-raw.log                  │ PASS                                                                    │   3.524083ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-edgecases.log              │ PASS                                                                    │   4.572042ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-identity-raw.log           │ PASS                                                                    │   3.076583ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-invalid-raw.log            │ FAIL: test case failed: Expected results are different from actual ones │   5.457375ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-kube.log                   │ PASS                                                                    │   2.910791ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-raw.log                    │ PASS                                                                    │   2.976167ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-remote-raw.log             │ PASS                                                                    │   2.610167ms │
│ azure   │ provisioning        │ pipeline  │ test-provisioninglogs-raw.log                │ PASS                                                                    │   3.741166ms │
│ azure   │ signinlogs          │ pipeline  │ test-managed-identity-sample.log             │ PASS                                                                    │  29.278375ms │
│ azure   │ signinlogs          │ pipeline  │ test-managed-identity.log                    │ PASS                                                                    │   4.029875ms │
│ azure   │ signinlogs          │ pipeline  │ test-non-interactive-user-sample.log         │ PASS                                                                    │  12.714125ms │
│ azure   │ signinlogs          │ pipeline  │ test-non-interactive-user-signin.log         │ PASS                                                                    │  10.548916ms │
│ azure   │ signinlogs          │ pipeline  │ test-non-interactive-user.log                │ PASS                                                                    │   5.445208ms │
│ azure   │ signinlogs          │ pipeline  │ test-service-principal-signinlogs-sample.log │ PASS                                                                    │   5.609458ms │
│ azure   │ signinlogs          │ pipeline  │ test-service-principal.log                   │ PASS                                                                    │   3.243417ms │
│ azure   │ signinlogs          │ pipeline  │ test-signinlogs-raw.log                      │ PASS                                                                    │   3.794084ms │
│ azure   │ signinlogs          │ pipeline  │ test-signinlogs-sample.log                   │ PASS                                                                    │   5.592792ms │
│ azure   │ springcloudlogs     │ pipeline  │ test-springcloudlogs-edgecases.log           │ PASS                                                                    │   3.609459ms │
│ azure   │ springcloudlogs     │ pipeline  │ test-springcloudlogs-raw.log                 │ PASS                                                                    │   2.617208ms │
╰─────────┴─────────────────────┴───────────┴──────────────────────────────────────────────┴─────────────────────────────────────────────────────────────────────────┴──────────────╯
--- Test results for package: azure - END   ---
Done
Error: one or more test cases failed

[zmoog]

On CI, the tests runs successfully.

The latest execution was using stack 8.6.0. probably because it's the minimum version in the manifest.yml file.

[zmoog]

If I run the pipeline test on 8.6.0 it succedes:

elastic-package build && elastic-package stack up -d -v --version 8.6.0

$ elastic-package test pipeline -v
2023/09/26 08:42:09 DEBUG Enable verbose logging
2023/09/26 08:42:09 DEBUG latest version (cached): &{v0.87.1 https://github.com/elastic/elastic-package/releases/tag/v0.87.1 2023-09-26 08:18:48.308297 +0200 CEST}
Run pipeline tests for the package
2023/09/26 08:42:09 DEBUG GET https://127.0.0.1:5601/api/status
--- Test results for package: azure - START ---
╭─────────┬─────────────────────┬───────────┬──────────────────────────────────────────────┬────────┬──────────────╮
│ PACKAGE │ DATA STREAM         │ TEST TYPE │ TEST NAME                                    │ RESULT │ TIME ELAPSED │
├─────────┼─────────────────────┼───────────┼──────────────────────────────────────────────┼────────┼──────────────┤
│ azure   │ activitylogs        │ pipeline  │ test-activitylogs-edgecases.log              │ PASS   │  42.943916ms │
│ azure   │ activitylogs        │ pipeline  │ test-activitylogs-identity.log               │ PASS   │   5.074458ms │
│ azure   │ activitylogs        │ pipeline  │ test-activitylogs-raw.log                    │ PASS   │   8.545917ms │
│ azure   │ application_gateway │ pipeline  │ test-application-gateway-raw.log             │ PASS   │   13.72725ms │
│ azure   │ auditlogs           │ pipeline  │ test-audit-logs-edgecases.log                │ PASS   │  14.202416ms │
│ azure   │ auditlogs           │ pipeline  │ test-audit-logs-sample.log                   │ PASS   │    6.52625ms │
│ azure   │ auditlogs           │ pipeline  │ test-auditlogs-raw.log                       │ PASS   │   3.444667ms │
│ azure   │ eventhub            │ pipeline  │ test-eventhub-raw.log                        │ PASS   │   2.444792ms │
│ azure   │ firewall_logs       │ pipeline  │ test-applicationrules-raw.log                │ PASS   │  18.128667ms │
│ azure   │ firewall_logs       │ pipeline  │ test-dnsproxyrules-raw.log                   │ PASS   │   6.014417ms │
│ azure   │ firewall_logs       │ pipeline  │ test-networkrules-raw.log                    │ PASS   │  12.155334ms │
│ azure   │ firewall_logs       │ pipeline  │ test-sdh3075-raw.log                         │ PASS   │   3.763208ms │
│ azure   │ identity_protection │ pipeline  │ test-rickyusers-raw.log                      │ PASS   │   5.685959ms │
│ azure   │ identity_protection │ pipeline  │ test-userriskevents-raw.log                  │ PASS   │   3.838292ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-edgecases.log              │ PASS   │   5.014542ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-identity-raw.log           │ PASS   │   3.183083ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-invalid-raw.log            │ PASS   │   5.379334ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-kube.log                   │ PASS   │   3.198375ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-raw.log                    │ PASS   │   3.303666ms │
│ azure   │ platformlogs        │ pipeline  │ test-platformlogs-remote-raw.log             │ PASS   │   3.062667ms │
│ azure   │ provisioning        │ pipeline  │ test-provisioninglogs-raw.log                │ PASS   │   3.927583ms │
│ azure   │ signinlogs          │ pipeline  │ test-managed-identity-sample.log             │ PASS   │  37.253708ms │
│ azure   │ signinlogs          │ pipeline  │ test-managed-identity.log                    │ PASS   │   3.430375ms │
│ azure   │ signinlogs          │ pipeline  │ test-non-interactive-user-sample.log         │ PASS   │  18.194167ms │
│ azure   │ signinlogs          │ pipeline  │ test-non-interactive-user-signin.log         │ PASS   │   8.793541ms │
│ azure   │ signinlogs          │ pipeline  │ test-non-interactive-user.log                │ PASS   │   5.195834ms │
│ azure   │ signinlogs          │ pipeline  │ test-service-principal-signinlogs-sample.log │ PASS   │    6.70975ms │
│ azure   │ signinlogs          │ pipeline  │ test-service-principal.log                   │ PASS   │   3.260042ms │
│ azure   │ signinlogs          │ pipeline  │ test-signinlogs-raw.log                      │ PASS   │     5.1635ms │
│ azure   │ signinlogs          │ pipeline  │ test-signinlogs-sample.log                   │ PASS   │    6.71425ms │
│ azure   │ springcloudlogs     │ pipeline  │ test-springcloudlogs-edgecases.log           │ PASS   │   4.247792ms │
│ azure   │ springcloudlogs     │ pipeline  │ test-springcloudlogs-raw.log                 │ PASS   │   3.130875ms │
╰─────────┴─────────────────────┴───────────┴──────────────────────────────────────────────┴────────┴──────────────╯
--- Test results for package: azure - END   ---
Done

[zmoog]

Trying to test this using the Dev Tools.

On 8.6.0

Single document in the message

#
# request
#

POST _ingest/pipeline/logs-azure.platformlogs-1.6.0/_simulate
{
  "docs": [
    {
      "_source": {
        "tags": [
          "parse_message"
        ],
        "@timestamp": "2022-10-04T13:05:22.643+1300",
        "message": """{"id": 1}"""
      }
    }
  ]
}

#
# Response
#

{
  "docs": [
    {
      "doc": {
        "_index": "_index",
        "_id": "_id",
        "_version": "-3",
        "_source": {
          "cloud": {
            "provider": "azure"
          },
          "@timestamp": "2022-10-04T13:05:22.643+1300",
          "ecs": {
            "version": "8.0.0"
          },
          "event": {
            "kind": "event"
          },
          "tags": [
            "parse_message"
          ],
          "azure": {
            "platformlogs": {
              "id": 1,
              "event_category": "Administrative"
            }
          }
        },
        "_ingest": {
          "timestamp": "2023-09-26T06:53:26.342706008Z"
        }
      }
    }
  ]
}

Multiple documents in the message

#
# request
#

POST _ingest/pipeline/logs-azure.platformlogs-1.6.0/_simulate
{
  "docs": [
    {
      "_source": {
        "tags": [
          "parse_message"
        ],
        "@timestamp": "2022-10-04T13:05:22.643+1300",
        "message": """{"id": 1}, {"id": 2}"""
      }
    }
  ]
}

#
# Response
#

{
  "docs": [
    {
      "doc": {
        "_index": "_index",
        "_id": "_id",
        "_version": "-3",
        "_source": {
          "cloud": {
            "provider": "azure"
          },
          "@timestamp": "2022-10-04T13:05:22.643+1300",
          "ecs": {
            "version": "8.0.0"
          },
          "event": {
            "kind": "event"
          },
          "tags": [
            "parse_message"
          ],
          "azure": {
            "platformlogs": {
              "id": 1,
              "event_category": "Administrative"
            }
          }
        },
        "_ingest": {
          "timestamp": "2023-09-26T06:56:33.128092219Z"
        }
      }
    }
  ]
}

Multiple documents in the message with malformed JSON

POST _ingest/pipeline/logs-azure.platformlogs-1.6.0/_simulate
{
  "docs": [
    {
      "_source": {
        "tags": [
          "parse_message"
        ],
        "@timestamp": "2022-10-04T13:05:22.643+1300",
        "message": """{"id": 1}, {'I am broken!': yeah} """
      }
    }
  ]
}

{
  "docs": [
    {
      "doc": {
        "_index": "_index",
        "_id": "_id",
        "_version": "-3",
        "_source": {
          "cloud": {
            "provider": "azure"
          },
          "@timestamp": "2022-10-04T13:05:22.643+1300",
          "ecs": {
            "version": "8.0.0"
          },
          "event": {
            "kind": "event"
          },
          "tags": [
            "parse_message"
          ],
          "azure": {
            "platformlogs": {
              "id": 1,
              "event_category": "Administrative"
            }
          }
        },
        "_ingest": {
          "timestamp": "2023-09-26T06:58:11.716927667Z"
        }
      }
    }
  ]
}

[zmoog]

On 8.7.1

On this version the behaviour is different:

#
# Request
#

POST _ingest/pipeline/logs-azure.platformlogs-1.6.0/_simulate
{
  "docs": [
    {
      "_source": {
        "tags": [
          "parse_message"
        ],
        "@timestamp": "2022-10-04T13:05:22.643+1300",
        "message": """{"id": 1}{'I am broken!': yeah} """
      }
    }
  ]
}

#
# Response
#

{
  "docs": [
    {
      "doc": {
        "_index": "_index",
        "_id": "_id",
        "_version": "-3",
        "_source": {
          "@timestamp": "2022-10-04T13:05:22.643+1300",
          "ecs": {
            "version": "8.0.0"
          },
          "event": {
            "original": """{"id": 1}{'I am broken!': yeah} """,
            "kind": "pipeline_error"
          },
          "error": {
            "message": [
              "Received invalid json from the Azure Cloud platform. Unable to parse the source log message",
              "cannot access method/field [platformlogs] from a null def reference"
            ]
          },
          "tags": [
            "parse_message",
            "preserve_original_event"
          ]
        },
        "_ingest": {
          "timestamp": "2023-09-26T07:07:47.178085503Z"
        }
      }
    }
  ]
}

[zmoog]

On 8.7, the json processor added a strict_json_parsing setting that defaults to true.

[zmoog]

Final check.

If I set [^1] strict_json_parsing: false on 8.7, I get the 8.6 behaviour:

POST _ingest/pipeline/logs-azure.platformlogs-1.7.0/_simulate
{
  "docs": [
    {
      "_source": {
        "tags": [
          "parse_message"
        ],
        "@timestamp": "2022-10-04T13:05:22.643+1300",
        "message": """{"id": 1}{'I am broken!': yeah} """
      }
    }
  ]
}

{
  "docs": [
    {
      "doc": {
        "_index": "_index",
        "_id": "_id",
        "_version": "-3",
        "_source": {
          "cloud": {
            "provider": "azure"
          },
          "@timestamp": "2022-10-04T13:05:22.643+1300",
          "ecs": {
            "version": "8.0.0"
          },
          "event": {
            "kind": "event"
          },
          "tags": [
            "parse_message"
          ],
          "azure": {
            "platformlogs": {
              "id": 1,
              "event_category": "Administrative"
            }
          }
        },
        "_ingest": {
          "timestamp": "2023-09-26T07:53:53.337915339Z"
        }
      }
    }
  ]
}

[^1]: I had to update the pipeline source code, couldn't find an option in the UI for doing this in Kibana.