Elastic Agent with custom log integration

Hi,

Ran into issue which is quite puzzling. Referred to the official docs and some topics in this forum but it did not help.

I am trying to ingest custom logs via integration within elastic agent. Everything is working except that it does not go through the pipeline, no matter what I do.

Tried:

  1. Putting pipeline: db2logs into "custom configuration". But after doing this, logs does not get ingested at all.

  2. Updating the index via API using:

PUT .ds-logs-db2-default-2023.03.09-000001/_settings
{
  "index.default_pipeline": "dblogs"
}

But it has the same result as (1).

Here's some screenshots of my current configuration without (1) and (2).

As you can see, it is running the multiline parser correctly and ingesting the logs properly. But it just can't go through the pipeline. Tried running a simple pipeline doesn't help either.

Anyone has any idea on what should I look for or try? Appreciate any pointers here.

hi @eleong

Can you please show the exact entire pipeline....

This indicates that the pipeline running but causing a mapping issue. I'll explain that in a.bit and we can test that.

Can you just add your very simple pipeline using method 1 and check to see if the test field is added?.

Thanks for the speedy reply.

Here's the pipeline that I am using for my test:

[
  {
    "set": {
      "field": "test",
      "value": "success"
    }
  }
]

I can see that a field is added. Could you explain a bit more what do you mean by mapping?

Hi @eleong Ok you ready to dig in :slight_smile:

So I suspect you have a mapping / parsing issue which means you are trying to put a a value into field that has a conflicting type. This can be a bit hard to debug, but I have done it many times so I am going to ask you to go along and trust me and I will explain here is a short explanation of what is happening (there are other version of this bug but this is a very common one)

If I have to guess I suspect you are trying to write a field like host or agent or something like that where there is already a mapping defined.

You could actually log into the server where the agent is find the filebeat logs and the mapping exception would be there... but there is another way.

So debug this I need

  1. Your actual pipeline the real one...

GET _ingest/pipeline/db2logs

  1. I need a sample JSON document from Discover... like one of the ones above that has not gone through the full pipeline.

Then we I / will simulate and test the pipeline and actually try to write a doc, it will produce a very specific error which we can then address.

Get me those and we will solve this.

I've figured it out based on your guidance. Tried removing the pipeline and test it one processor at a time. There is indeed a conflicting field "@timestamp".

I was trying to extract out a date/time of the logs and then override it into "@timestamp". But this date/time was in keyword format. Hence, the conflicting field - and since "@timestamp" is in every document, no doc get parsed.

Now I am trying to figure out a way how to change the date/time extracted into "date" format. But that is another issue all together.

Thanks again for your guidance. Couldn't have figure it out without you even if you give me 1 week time :slight_smile:

Cool...

You probably want to use

Give us an example we can probably help

Sure. Here's the "new" pipeline that we are using. The one without overriding timestamp field:

[
  {
    "grok": {
      "field": "message",
      "patterns": [
        "(?<dblogs.date>(\\d\\d\\d\\d-\\d\\d-\\d\\d))-%{DATA:dblogs.time}.(?<dblogs.timemsec>(\\d)*)\\+%{GREEDYDATA:temp.dblogs1}LEVEL:%{SPACE}%{DATA:dblogs.log.level}\\nPID%{SPACE}:%{SPACE}%{DATA:dblogs.pid}%{SPACE}TID%{GREEDYDATA:temp.dblogs2}\\nINSTANCE:%{SPACE}%{DATA:dblogs.instance}%{SPACE}NODE(?<temp.dblogs3>(.|\\r|\\n)*)HOSTNAME:%{SPACE}(?<dblogs.hostname>(\\S)*)(?<temp.dblogs4>(.|\\r|\\n)*)FUNCTION:%{SPACE}%{GREEDYDATA:dblogs.function}\\n(?<dblogs.log.message>(.|\\r|\\n)*)"
      ]
    }
  },
  {
    "gsub": {
      "field": "dblogs.time",
      "pattern": "\\.",
      "replacement": ":"
    }
  },
  {
    "set": {
      "field": "dblogs.time",
      "value": "{{dblogs.time}}.{{dblogs.timemsec}}"
    }
  },
  {
    "set": {
      "field": "dblogs.datetime",
      "value": "{{dblogs.date}}T{{dblogs.time}}"
    }
  },
  {
    "fingerprint": {
      "fields": [
        "dblogs.datetime"
      ],
      "target_field": "fingerprint",
      "method": "SHA-512",
      "ignore_missing": true
    }
  },
  {
    "set": {
      "field": "_id",
      "copy_from": "fingerprint"
    }
  },
  {
    "date": {
      "field": "dblogs.datetime",
      "formats": [
        "ISO8601"
      ],
      "target_field": "dblogs.new_datetime",
      "timezone": "GMT+8"
    }
  },
  {
    "set": {
      "field": "test",
      "value": "success"
    }
  },
  {
    "remove": {
      "field": [
        "agent",
        "host"
      ]
    }
  }
]

Here's a sample log in JSON:

{
  "_index": ".ds-logs-db2-default-2023.03.10-000001",
  "_id": "1qUFyoYBloz8-T-8b66e",
  "_version": 1,
  "_score": 0,
  "_source": {
    "@timestamp": "2023-03-10T05:36:37.841Z",
    "message": "2022-10-29-22.52.30.073009+480 I8038702E535          LEVEL: Error\nPID     : 8173                 TID : 46999353157376  PROC : db2sysc 0\nINSTANCE: db2inst1             NODE : 000            DB   : ASSIST  \nHOSTNAME: pksdc2pdb01\nEDUID   : 60381                EDUNAME: db2hadrp.0.1 (ASSIST) 0\nFUNCTION: DB2 UDB, High Availability Disaster Recovery, hdrSendRedirectMsgToOneAddress, probe:31070\nMESSAGE : ZRC=0xFFFFFFFF=-1\nDATA #1 : <preformatted>\nThe HADR primary was not able to form a TCP connection with the standby: 10.20.7.11:51002.\n",
    "tags": [
      "db2logs"
    ],
    "input": {
      "type": "log"
    },
    "data_stream": {
      "type": "logs",
      "dataset": "db2",
      "namespace": "default"
    },
    "event": {
      "dataset": "db2"
    },
    "agent": {
      "id": "29f720ca-bb7b-4ca3-869e-04fcd0fa3af5",
      "version": "8.4.3",
      "ephemeral_id": "7cb3f7fe-19e7-406a-8977-48b1c39b84c3",
      "name": "ebc-backend",
      "type": "filebeat"
    },
    "host": {
      "containerized": false,
      "ip": [
        "10.2.0.4",
        "fe80::20c:29ff:fe5c:c10"
      ],
      "mac": [
        "00:0c:29:5c:0c:10"
      ],
      "name": "ebc-backend",
      "hostname": "ebc-backend",
      "architecture": "x86_64",
      "os": {
        "kernel": "5.15.0-52-generic",
        "codename": "jammy",
        "type": "linux",
        "platform": "ubuntu",
        "version": "22.04.1 LTS (Jammy Jellyfish)",
        "family": "debian",
        "name": "Ubuntu"
      },
      "id": "3e04fc4f15a14ae089934351b2811338"
    },
    "ecs": {
      "version": "8.0.0"
    },
    "log": {
      "flags": [
        "multiline"
      ],
      "offset": 8038702,
      "file": {
        "path": "/var/log/db2logs/test11.log"
      }
    },
    "elastic_agent": {
      "snapshot": false,
      "version": "8.4.3",
      "id": "29f720ca-bb7b-4ca3-869e-04fcd0fa3af5"
    }
  },
  "fields": {
    "elastic_agent.version": [
      "8.4.3"
    ],
    "host.hostname": [
      "ebc-backend"
    ],
    "host.mac": [
      "00:0c:29:5c:0c:10"
    ],
    "host.ip": [
      "10.2.0.4",
      "fe80::20c:29ff:fe5c:c10"
    ],
    "agent.type": [
      "filebeat"
    ],
    "host.os.version": [
      "22.04.1 LTS (Jammy Jellyfish)"
    ],
    "host.os.kernel": [
      "5.15.0-52-generic"
    ],
    "host.os.name": [
      "Ubuntu"
    ],
    "agent.name": [
      "ebc-backend"
    ],
    "host.name": [
      "ebc-backend"
    ],
    "elastic_agent.snapshot": [
      false
    ],
    "host.id": [
      "3e04fc4f15a14ae089934351b2811338"
    ],
    "host.os.type": [
      "linux"
    ],
    "elastic_agent.id": [
      "29f720ca-bb7b-4ca3-869e-04fcd0fa3af5"
    ],
    "data_stream.namespace": [
      "default"
    ],
    "host.os.codename": [
      "jammy"
    ],
    "input.type": [
      "log"
    ],
    "log.offset": [
      8038702
    ],
    "log.flags": [
      "multiline"
    ],
    "message": [
      "2022-10-29-22.52.30.073009+480 I8038702E535          LEVEL: Error\nPID     : 8173                 TID : 46999353157376  PROC : db2sysc 0\nINSTANCE: db2inst1             NODE : 000            DB   : INSTNAME1  \nHOSTNAME: db01\nEDUID   : 60381                EDUNAME: db2hadrp.0.1 (ASSIST) 0\nFUNCTION: DB2 UDB, High Availability Disaster Recovery, hdrSendRedirectMsgToOneAddress, probe:31070\nMESSAGE : ZRC=0xFFFFFFFF=-1\nDATA #1 : <preformatted>\nThe HADR primary was not able to form a TCP connection with the standby: 10.20.7.11:51002.\n"
    ],
    "data_stream.type": [
      "logs"
    ],
    "tags": [
      "db2logs"
    ],
    "host.architecture": [
      "x86_64"
    ],
    "@timestamp": [
      "2023-03-10T05:36:37.841Z"
    ],
    "agent.id": [
      "29f720ca-bb7b-4ca3-869e-04fcd0fa3af5"
    ],
    "host.containerized": [
      false
    ],
    "host.os.platform": [
      "ubuntu"
    ],
    "ecs.version": [
      "8.0.0"
    ],
    "data_stream.dataset": [
      "db2"
    ],
    "log.file.path": [
      "/var/log/db2logs/test11.log"
    ],
    "agent.ephemeral_id": [
      "7cb3f7fe-19e7-406a-8977-48b1c39b84c3"
    ],
    "agent.version": [
      "8.4.3"
    ],
    "host.os.family": [
      "debian"
    ],
    "event.dataset": [
      "db2"
    ]
  }
}

Changed some stuffs in the "message" field, for obvious reasons - but it shouldn't affect your results.

So a little confused...do you want to write overwrite the @timestamp field with

  {
    "date": {
      "field": "dblogs.datetime",
      "formats": [
        "ISO8601"
      ],
      "target_field": "dblogs.new_datetime",
      "timezone": "GMT+8"
    }
  }

Yes, initially the target_field is for "@timestamp", but it made the whole thing unparsed. So, I've changed it to "dblogs.new_datetime" for testing purposes.

I don't mind creating a new field without overriding "@timestamp". However, overriding is the preferred choice.

Hmmm first pass working for me...

Below will show you how to test....

BTW interesting you are generating the _id from a fingerprint of a timestamp...... lots of potential pitfalls there ... not sure why you are doing that... it is a lot of overhead not sure for what... this looks like timeseries data... generally no need to do that... in short if you are hoping to update... probably not going to work with data streams... perhaps another thread on that.

Pipeline with target as @timestamp

PUT _ingest/pipeline/discuss-db2-logs
{
  "processors": [
    {
      "grok": {
        "field": "message",
        "patterns": [
          """(?<dblogs.date>(\d\d\d\d-\d\d-\d\d))-%{DATA:dblogs.time}.(?<dblogs.timemsec>(\d)*)\+%{GREEDYDATA:temp.dblogs1}LEVEL:%{SPACE}%{DATA:dblogs.log.level}\nPID%{SPACE}:%{SPACE}%{DATA:dblogs.pid}%{SPACE}TID%{GREEDYDATA:temp.dblogs2}\nINSTANCE:%{SPACE}%{DATA:dblogs.instance}%{SPACE}NODE(?<temp.dblogs3>(.|\r|\n)*)HOSTNAME:%{SPACE}(?<dblogs.hostname>(\S)*)(?<temp.dblogs4>(.|\r|\n)*)FUNCTION:%{SPACE}%{GREEDYDATA:dblogs.function}\n(?<dblogs.log.message>(.|\r|\n)*)"""
        ]
      }
    },
    {
      "gsub": {
        "field": "dblogs.time",
        "pattern": """\.""",
        "replacement": ":"
      }
    },
    {
      "set": {
        "field": "dblogs.time",
        "value": "{{dblogs.time}}.{{dblogs.timemsec}}"
      }
    },
    {
      "set": {
        "field": "dblogs.datetime",
        "value": "{{dblogs.date}}T{{dblogs.time}}"
      }
    },
    {
      "fingerprint": {
        "fields": [
          "dblogs.datetime"
        ],
        "target_field": "fingerprint",
        "method": "SHA-512",
        "ignore_missing": true
      }
    },
    {
      "set": {
        "field": "_id",
        "copy_from": "fingerprint"
      }
    },
    {
      "date": {
        "field": "dblogs.datetime",
        "formats": [
          "ISO8601"
        ],
        "timezone": "GMT+8"
      }
    },
    {
      "set": {
        "field": "test",
        "value": "success"
      }
    }
  ]
}

Posting a document

POST filebeat-8.6.2/_doc?pipeline=discuss-db2-logs
{
  "@timestamp": "2023-03-10T05:36:37.841Z",
  "message": "2022-10-29-22.52.30.073009+480 I8038702E535          LEVEL: Error\nPID     : 8173                 TID : 46999353157376  PROC : db2sysc 0\nINSTANCE: db2inst1             NODE : 000            DB   : ASSIST  \nHOSTNAME: pksdc2pdb01\nEDUID   : 60381                EDUNAME: db2hadrp.0.1 (ASSIST) 0\nFUNCTION: DB2 UDB, High Availability Disaster Recovery, hdrSendRedirectMsgToOneAddress, probe:31070\nMESSAGE : ZRC=0xFFFFFFFF=-1\nDATA #1 : <preformatted>\nThe HADR primary was not able to form a TCP connection with the standby: 10.20.7.11:51002.\n",
  "tags": [
    "db2logs"
    ],
    "input": {
      "type": "log"
    }
}

# Results
{
  "_index": ".ds-filebeat-8.6.2-2023.03.10-000002",
  "_id": "PBTBOzjBaGXNsEMZbIxJknMjG5J47c0Btr30J0GpYfJQRhZLVcQOyyBkSz2Jp6e4LKQRFDHqcgpsOAoRUiNCWQ==",
  "_version": 4,
  "result": "created",
  "_shards": {
    "total": 2,
    "successful": 1,
    "failed": 0
  },
  "_seq_no": 3,
  "_primary_term": 1
}

Search show correct timestamp in _source and fields

GET .ds-filebeat-8.6.2-2023.03.10-000002/_search
{
  "fields": [
    "*"
  ]
}

# Results note the _source @timestamp and the fields @timestamp dates are always stored in UTC

{
  "took": 36,
  "timed_out": false,
  "_shards": {
    "total": 1,
    "successful": 1,
    "skipped": 0,
    "failed": 0
  },
  "hits": {
    "total": {
      "value": 1,
      "relation": "eq"
    },
    "max_score": 1,
    "hits": [
      {
        "_index": ".ds-filebeat-8.6.2-2023.03.10-000002",
        "_id": "PBTBOzjBaGXNsEMZbIxJknMjG5J47c0Btr30J0GpYfJQRhZLVcQOyyBkSz2Jp6e4LKQRFDHqcgpsOAoRUiNCWQ==",
        "_score": 1,
        "_source": {
          "input": {
            "type": "log"
          },
          "dblogs": {
            "date": "2022-10-29",
            "hostname": "pksdc2pdb01",
            "datetime": "2022-10-29T22:52:30.073009",
            "instance": "db2inst1",
            "log": {
              "level": "Error",
              "message": """MESSAGE : ZRC=0xFFFFFFFF=-1
DATA #1 : <preformatted>
The HADR primary was not able to form a TCP connection with the standby: 10.20.7.11:51002.
"""
            },
            "function": "DB2 UDB, High Availability Disaster Recovery, hdrSendRedirectMsgToOneAddress, probe:31070",
            "timemsec": "073009",
            "pid": "8173",
            "time": "22:52:30.073009"
          },
          "temp": {
            "dblogs1": "480 I8038702E535          ",
            "dblogs2": " : 46999353157376  PROC : db2sysc 0",
            "dblogs3": """ : 000            DB   : ASSIST  
""",
            "dblogs4": """
EDUID   : 60381                EDUNAME: db2hadrp.0.1 (ASSIST) 0
"""
          },
          "@timestamp": "2022-10-29T22:52:30.073+08:00",
          "test": "success",
          "fingerprint": "PBTBOzjBaGXNsEMZbIxJknMjG5J47c0Btr30J0GpYfJQRhZLVcQOyyBkSz2Jp6e4LKQRFDHqcgpsOAoRUiNCWQ==",
          "message": """2022-10-29-22.52.30.073009+480 I8038702E535          LEVEL: Error
PID     : 8173                 TID : 46999353157376  PROC : db2sysc 0
INSTANCE: db2inst1             NODE : 000            DB   : ASSIST  
HOSTNAME: pksdc2pdb01
EDUID   : 60381                EDUNAME: db2hadrp.0.1 (ASSIST) 0
FUNCTION: DB2 UDB, High Availability Disaster Recovery, hdrSendRedirectMsgToOneAddress, probe:31070
MESSAGE : ZRC=0xFFFFFFFF=-1
DATA #1 : <preformatted>
The HADR primary was not able to form a TCP connection with the standby: 10.20.7.11:51002.
""",
          "tags": [
            "db2logs"
          ]
        },
        "fields": {
          "dblogs.timemsec": [
            "073009"
          ],
          "test": [
            "success"
          ],
          "dblogs.date": [
            "2022-10-29"
          ],
          "dblogs.pid": [
            "8173"
          ],
          "input.type": [
            "log"
          ],
          "message": [
            """2022-10-29-22.52.30.073009+480 I8038702E535          LEVEL: Error
PID     : 8173                 TID : 46999353157376  PROC : db2sysc 0
INSTANCE: db2inst1             NODE : 000            DB   : ASSIST  
HOSTNAME: pksdc2pdb01
EDUID   : 60381                EDUNAME: db2hadrp.0.1 (ASSIST) 0
FUNCTION: DB2 UDB, High Availability Disaster Recovery, hdrSendRedirectMsgToOneAddress, probe:31070
MESSAGE : ZRC=0xFFFFFFFF=-1
DATA #1 : <preformatted>
The HADR primary was not able to form a TCP connection with the standby: 10.20.7.11:51002.
"""
          ],
          "dblogs.log.message": [
            """MESSAGE : ZRC=0xFFFFFFFF=-1
DATA #1 : <preformatted>
The HADR primary was not able to form a TCP connection with the standby: 10.20.7.11:51002.
"""
          ],
          "dblogs.hostname": [
            "pksdc2pdb01"
          ],
          "tags": [
            "db2logs"
          ],
          "@timestamp": [
            "2022-10-29T14:52:30.073Z"
          ],
          "temp.dblogs4": [
            """
EDUID   : 60381                EDUNAME: db2hadrp.0.1 (ASSIST) 0
"""
          ],
          "fingerprint": [
            "PBTBOzjBaGXNsEMZbIxJknMjG5J47c0Btr30J0GpYfJQRhZLVcQOyyBkSz2Jp6e4LKQRFDHqcgpsOAoRUiNCWQ=="
          ],
          "dblogs.instance": [
            "db2inst1"
          ],
          "temp.dblogs3": [
            """ : 000            DB   : ASSIST  
"""
          ],
          "dblogs.time": [
            "22:52:30.073009"
          ],
          "dblogs.datetime": [
            "2022-10-29T22:52:30.073009"
          ],
          "temp.dblogs2": [
            " : 46999353157376  PROC : db2sysc 0"
          ],
          "dblogs.function": [
            "DB2 UDB, High Availability Disaster Recovery, hdrSendRedirectMsgToOneAddress, probe:31070"
          ],
          "temp.dblogs1": [
            "480 I8038702E535          "
          ],
          "dblogs.log.level": [
            "Error"
          ]
        }
      }
    ]
  }
}

Alright. Let me test it further later today. It's Friday and I would buy you a beer if you are in Malaysia :slight_smile:

As for the _id, the idea is that we might be ingesting duplicated logs. Hence, instead of creating several documents which is the same, it will "update" the documents instead since the _id are the same. We are using "datetime" as the hash, thinking to use other fields as hash but did not go deep into that yet.

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.