Ingest pipeline not working correctly?

[iamtheliquor]

Hi everybody,

We have two pipelines, that are identical, one is for staging and one is for production logs;

    {
      "staging_pipeline" : {
        "description" : "Staging Pipeline",
        "processors" : [
          {
            "grok" : {
              "field" : "message",
              "patterns" : [
                "%{GREEDYDATA:log}"
              ],
              "on_failure" : [
                {
                  "set" : {
                    "field" : "error",
                    "value" : "{{ _ingest.on_failure_message }}"
                  }
                }
              ]
            }
          },
          {
            "json" : {
              "field" : "log",
              "on_failure" : [
                {
                  "set" : {
                    "field" : "error",
                    "value" : "{{ _ingest.on_failure_message }}"
                  }
                }
              ]
            }
          }
        ]
      }
    }

The difference is literally the word staging is production.

In the staging environment this does what we expect, and creates fields called log.whatever.is.in.the.json. However, in production, we get the following error;

Provided Grok expressions do not match field value:

Then the contents of the message, which is all in standard json format, and we can verify that in the actual message field.

I don't know why it's complaining about the grok expression in one but not the other, as the pipelines are identical, as are the logs coming in. We have tried completely deleting the production pipeline and recreating it, but the same thing happens.

Any thoughts would be much appreciated.

[spinscale (Alexander Reelsen)]

can you provide a fully reprodicible example with both pipelines and a simulate pipeline call for each of them showing the problem? That would help a lot!

Thanks!

[iamtheliquor]

Okay, so I think I am doing this correctly, here is the example log coming from the application;

{"message":"Notified event \"kernel.request\" to listener \"Symfony\\Component\\HttpKernel\\EventListener\\ValidateRequestListener::onKernelRequest\".","context":{"event":"kernel.request","listener":"Symfony\\Component\\HttpKernel\\EventListener\\ValidateRequestListener::onKernelRequest"},"level":100,"level_name":"DEBUG","channel":"event","datetime":{"date":"2020-10-27 10:19:40.978821","timezone_type":3,"timezone":"UTC"},"extra":[]}`

Here is me simulating it through the pipelines;

Staging;

POST /_ingest/pipeline/staging_pl/_simulate
{
  "docs": [
    {
        "_index": "index",
        "_id": "id",
        "_source": {"message":"Notified event \"kernel.request\" to listener \"Symfony\\Component\\HttpKernel\\EventListener\\ValidateRequestListener::onKernelRequest\".","context":{"event":"kernel.request","listener":"Symfony\\Component\\HttpKernel\\EventListener\\ValidateRequestListener::onKernelRequest"},"level":100,"level_name":"DEBUG","channel":"event","extra":[]}
    }
  ]
}

Response;

{
  "docs" : [
    {
      "doc" : {
        "_index" : "index",
        "_type" : "_doc",
        "_id" : "id",
        "_source" : {
          "level_name" : "DEBUG",
          "level" : 100,
          "log" : """Notified event "kernel.request" to listener "Symfony\Component\HttpKernel\EventListener\ValidateRequestListener::onKernelRequest".""",
          "extra" : [ ],
          "context" : {
            "listener" : """Symfony\Component\HttpKernel\EventListener\ValidateRequestListener::onKernelRequest""",
            "event" : "kernel.request"
          },
          "channel" : "event",
          "message" : """Notified event "kernel.request" to listener "Symfony\Component\HttpKernel\EventListener\ValidateRequestListener::onKernelRequest".""",
          "error" : """Unrecognized token 'Notified': was expecting 'null', 'true', 'false' or NaN\n at [Source: org.elasticsearch.common.bytes.BytesReference$MarkSupportingStreamInputWrapper@322f9cd2; line: 1, column: 10]"""
        },
        "_ingest" : {
          "timestamp" : "2020-10-27T10:22:01.769671Z"
        }
      }
    }
  ]
}

Production;

POST /_ingest/pipeline/production_pl/_simulate
{
  "docs": [
    {
      "_index": "index",
      "_id": "id",
      "_source": {"message":"Notified event \"kernel.request\" to listener \"Symfony\\Component\\HttpKernel\\EventListener\\ValidateRequestListener::onKernelRequest\".","context":{"event":"kernel.request","listener":"Symfony\\Component\\HttpKernel\\EventListener\\ValidateRequestListener::onKernelRequest"},"level":100,"level_name":"DEBUG","channel":"event","extra":[]}
    }
  ]
}

Response;

{
  "docs" : [
    {
      "doc" : {
        "_index" : "index",
        "_type" : "_doc",
        "_id" : "id",
        "_source" : {
          "level_name" : "DEBUG",
          "level" : 100,
          "log" : """Notified event "kernel.request" to listener "Symfony\Component\HttpKernel\EventListener\ValidateRequestListener::onKernelRequest".""",
          "extra" : [ ],
          "context" : {
            "listener" : """Symfony\Component\HttpKernel\EventListener\ValidateRequestListener::onKernelRequest""",
            "event" : "kernel.request"
          },
          "channel" : "event",
          "message" : """Notified event "kernel.request" to listener "Symfony\Component\HttpKernel\EventListener\ValidateRequestListener::onKernelRequest".""",
          "error" : """Unrecognized token 'Notified': was expecting 'null', 'true', 'false' or NaN\n at [Source: org.elasticsearch.common.bytes.BytesReference$MarkSupportingStreamInputWrapper@463937d9; line: 1, column: 10]"""
        },
        "_ingest" : {
          "timestamp" : "2020-10-27T10:31:58.385232Z"
        }
      }
    }
  ]
}

Both response look exactly the same to me. They are complaining about something;

"error" : """Unrecognized token 'Notified': was expecting 'null', 'true', 'false' or NaN\n at [Source: org.elasticsearch.common.bytes.BytesReference$MarkSupportingStreamInputWrapper@463937d9; line: 1, column: 10]""" },

But still, staging populates the fields correctly, but production does not.

Perhaps I am not doing something right here?