Can’t parse haproxy logs #25827

manuelsaks · 2021-05-24T13:22:57Z

I created Grok pattern which works in Kibana Debug Grok devtool:
Sample data:

[May 22 02:22:22 server1 haproxy[5089]: -:22222 [22/May/2021:02:22:22.222] www-https~ myapp/node2 site.domain.com 0/0/0/18/18 200 200 - - ---- 222/222/2/0/0 0/0 \"OPTIONS /api/v2/app/ HTTP/1.1\"]

Grok pattern:

%{HAPROXY_LOG_DATE:haproxy.logdate} %{NOTSPACE:haproxy.host} %{NOTSPACE:process.name[pid]}[%{NUMBER:process.pid:long}] (%{IP:source.address}|-):%{POSINT:source} %{HAPROXY_DATE:haproxy.request_date} %{NOTSPACE:haproxy.frontend_name} %{NOTSPACE:haproxy.backend_name}/%{NOTSPACE:haproxy.server_name} %{NOTSPACE:haproxy.http.captured.request.headers} %{NUMBER:haproxy.http.request.time_wait_ms:long}/%{NUMBER:haproxy.total_waiting_time_ms:long}/%{NUMBER:haproxy.connection_wait_time_ms:long}/%{NUMBER:haproxy.http.request.time_wait_without_data_ms:long}/%{NUMBER:temp.duration:long} %{NUMBER:http.response.status_code:long} %{NUMBER:haproxy.bytes_read:long} %{NOTSPACE:haproxy.http.request.captured_cookie} %{NOTSPACE:haproxy.http.response.captured_cookie} %{NOTSPACE:haproxy.termination_state} %{NUMBER:haproxy.connections.active:long}/%{NUMBER:haproxy.connections.frontend:long}/%{NUMBER:haproxy.connections.backend:long}/%{NUMBER:haproxy.connections.server:long}/%{NUMBER:haproxy.connections.retries:long} %{NUMBER:haproxy.server_queue:long}/%{NUMBER:haproxy.backend_queue:long} \\\"%{NOTSPACE:haproxy.http.request.method} %{NOTSPACE:haproxy.http.request.captured_headers} %{NOTSPACE:haproxy.http.response.captured_headers}\\\"

Custom patterns:

HAPROXY_LOG_DATE %{MONTH} %{MONTHDAY} %{HOUR}:%{MINUTE}:%{SECOND}
HAPROXY_DATE \[%{MONTHDAY}[/-]%{MONTH}[/-]%{YEAR}:%{HOUR}:%{MINUTE}:%{SECOND}\]

Structured data:

{
  "process": {
    "name[pid]": "haproxy[5089]"
  },
  "temp": {
    "duration": 18
  },
  "haproxy": {
    "server_name": "node2",
    "total_waiting_time_ms": 0,
    "termination_state": "----",
    "connection_wait_time_ms": 0,
    "bytes_read": 200,
    "backend_queue": 0,
    "backend_name": "myapp",
    "logdate": "May 22 02:22:22",
    "host": "server1",
    "request_date": "[22/May/2021:02:22:22.222]",
    "http": {
      "request": {
        "captured_cookie": "-",
        "time_wait_without_data_ms": 18,
        "captured_headers": "/api/v2/app/",
        "method": "OPTIONS",
        "time_wait_ms": 0
      },
      "response": {
        "captured_cookie": "-",
        "captured_headers": "HTTP/1.1"
      },
      "captured": {
        "request": {
          "headers": "site.domain.com"
        }
      }
    },
    "frontend_name": "www-https~",
    "server_queue": 0,
    "connections": {
      "server": 0,
      "retries": 0,
      "active": 222,
      "backend": 2,
      "frontend": 222
    }
  },
  "http": {
    "response": {
      "status_code": 200
    }
  },
  "source": "22222"
}

First I thought that something else causes the problem: discuss.elastic.co

But the pattern is working, and I don't know why. but it doesn't work with Filebeat and Elastic.
I have an error in Elastic:

Provided Grok expressions do not match field value:
[May 22 02:22:22 server1 haproxy[5089]: -:22222 [22/May/2021:02:22:22.222] www-https~ myapp/node2 site.domain.com 0/0/0/18/18 200 200 - - ---- 222/222/2/0/0 0/0 \"OPTIONS /api/v2/app/ HTTP/1.1\"]

That's my current config file: gist.github.com

Version: Filebeat 7.6.1; Elastic&Kibana 7.7.1
Operating System: Debian Buster
Discuss Forum URL: discuss.elastic.co

The text was updated successfully, but these errors were encountered:

manuelsaks · 2021-05-25T09:15:00Z

I have the same error. I tried also to upgrade filebeat to 7.12.1 version and copy your pipline.json.
If you have some questions about my issue feel free to ask.

legoguy1000 · 2021-05-25T12:01:15Z

how did you test the changes? I would install the latest filebeat and then update that pipeline with the changes above. I added the sample log that you provided in the ticket. If there are other logs that don't work let me know.

legoguy1000 · 2021-05-27T01:38:08Z

I have the same error. I tried also to upgrade filebeat to 7.12.1 version and copy your pipline.json.
If you have some questions about my issue feel free to ask.

@maarsaks can you provide more details on what didn't work. I added ur sample log to the tests and it parsed properly.

manuelsaks · 2021-06-01T10:01:20Z

how did you test the changes? I would install the latest filebeat and then update that pipeline with the changes above. I added the sample log that you provided in the ticket. If there are other logs that don't work let me know.

I've tested on docker images with docker-compose using the latest, fresh version of filebeat.

I have the same error. I tried also to upgrade filebeat to 7.12.1 version and copy your pipline.json.
If you have some questions about my issue feel free to ask.

@maarsaks can you provide more details on what didn't work. I added ur sample log to the tests and it parsed properly.

I'm using Kibana to filter logs and there's is an error: 'Provided Grok expressions do not match field value'.
What details exactly do you need?

legoguy1000 · 2021-06-01T13:04:58Z

How did you update the pipeline? Is the log thats having the issue the same that I added to the sample data??

manuelsaks · 2021-06-01T19:21:19Z

How did you update the pipeline?

I updated pipeline by replacing default config with yours in a new, freshly installed filebeat under /usr/share/filebeat/module/haproxy/log/pipline.json.

Is the log thats having the issue the same that I added to the sample data??

Yes.

legoguy1000 · 2021-06-01T19:30:49Z

I updated pipeline by replacing default config with yours in a new, freshly installed filebeat under /usr/share/filebeat/module/haproxy/log/pipline.json.
Ok, and the pipeline loaded into Elasticsearch matches? I've never modified a pipeline that way. I would have done it through Kibana dev tools/API after it was loaded. Can you post the resulting event from ES?

manuelsaks · 2021-06-02T13:15:44Z

I updated pipeline by replacing default config with yours in a new, freshly installed filebeat under /usr/share/filebeat/module/haproxy/log/pipline.json.
Ok, and the pipeline loaded into Elasticsearch matches? I've never modified a pipeline that way. I would have done it through Kibana dev tools/API after it was loaded. Can you post the resulting event from ES?

Yup, it loaded and this is the message from ES:

Provided Grok expressions do not match field value:
[May 22 02:22:22 server1 haproxy[5089]: -:22222 [22/May/2021:02:22:22.222] www-https~ myapp/node2 site.domain.com 0/0/0/18/18 200 200 - - ---- 222/222/2/0/0 0/0 \"OPTIONS /api/v2/app/ HTTP/1.1\"]

legoguy1000 · 2021-06-02T13:33:20Z

Hmm, IDK. Here, https://github.com/elastic/beats/pull/25835/files#diff-8363329fdb5b538e99f1112198aaa68d0a353c161a49f26a1041f6f49ae47cfdR63, you can see that the sample log is the same as u provided and is being parsed properly.

manuelsaks · 2021-06-04T10:21:59Z

Hmm, IDK. Here, https://github.com/elastic/beats/pull/25835/files#diff-8363329fdb5b538e99f1112198aaa68d0a353c161a49f26a1041f6f49ae47cfdR63, you can see that the sample log is the same as u provided and is being parsed properly.

And that's the problem. Like I said in my first comment the pattern is working in Grok debugger, but it doesn't display correctly in Kibana.

manuelsaks · 2021-06-09T12:36:04Z

@legoguy1000

I've created the repo how to reproduce the error in ~5 minutes - make sure that you've made the all steps from README.md.
github.com/maarsaks/elk-docker-compose

legoguy1000 · 2021-06-15T14:27:47Z

@legoguy1000

I've created the repo how to reproduce the error in ~5 minutes - make sure that you've made the all steps from README.md.
github.com/maarsaks/elk-docker-compose

I'm looking at your pipeline file, you file doesn't have any of the changes that I made in the PR. What are you basing that file off of? This is the file you should copy, https://github.com/elastic/beats/blob/5582e6ccfddd152e4bcf4141361d6a0e0b1e4daa/filebeat/module/haproxy/log/ingest/pipeline.yml.

manuelsaks · 2021-06-17T06:36:14Z

Okay, I've updated the repo with the pipline.json that you provided and I have the same issue (from the repo that I've created for reproducing).

legoguy1000 · 2021-06-18T18:59:52Z

Okay, I've updated the repo with the pipline.json that you provided and I have the same issue (from the repo that I've created for reproducing).

So looking at the repo u created I found some issues.

/usr/share/filebeat/module/haproxy/log/ingest/pipline.json: you misspelled pipeline.
You have YAML in a json file
The file you want to overwrite is /usr/share/filebeat/module/haproxy/log/ingest/pipeline.yml

As such your test isn't actually loading the new pipeline. Please validate that the correct pipeline is loaded by going to the ingest pipelines page under stack management in Kibana and look at the HAProxy pipeline. The way I would test this change is load ES, Kibana, and Filebeat normally without any modifications. Manually update the pipeline using the API in dev tools, validate the changes using the API or ingest pipeline page and then ingest data.

legoguy1000 · 2021-06-22T11:40:24Z

@maarsaks we're u able to retest again? If we don't hear anything we're going to go ahead and merge the changes as they pass all the tests with the log samples you provided.

manuelsaks · 2021-06-22T12:10:57Z

Thank you.
Those logs that I provided are working.

But there's more :/
These aren't working for example:

Jun 22 10:13:15 node2 haproxy[23034]: [WARNING] 172/101315 (23551) : Server app/node3 is going DOWN for maintenance (entry removed from SRV record). 1 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
Jun 22 10:13:15 node2 haproxy[23034]: Server app/node3   is going DOWN for maintenance (entry removed from SRV record). 1 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
Jun 22 10:13:15 node2 haproxy[23034]: Server app/node3 is going DOWN for maintenance (entry removed from SRV record). 0 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
Jun 22 10:13:13 node2 haproxy[23034]: node/node3 changed its FQDN from (null) to my.domain.name by 'SRV record'
Jun 22 10:13:13 node2 haproxy[23034]: [WARNING] 122/111313 (22553) : app/node3 changed its IP from  to 192.122.0.22 by app/app.
Jun 22 10:13:13 node2 haproxy[23034]: [WARNING] 122/111313 (22553) : Server app/node3 ('node3.domain.eu.com') is UP/READY (resolves again).
Jun 22 10:13:13 node2 haproxy[23034]: Server app/node3 administratively READY thanks to valid DNS answer.
Jun 22 10:13:13 node2 haproxy[23034]: Server app/node4 ('node3.domain.eu.com') is UP/READY (resolves again).
Jun 22 12:02:53 node2 haproxy[23034]: -:47625 [22/Jun/2021:12:02:53.473] www-https~ app/app-node2 app.domain.com 0/0/1/17/18 302 291 - - ---- 1/1/0/0/0 0/0 "GET / HTTP/1.1"
Jun 22 12:03:01 node2 haproxy[23034]: -:47445 [22/Jun/2021:12:03:01.501] www-https~ app/node16 app.domain.com 0/0/1/55/56 200 3097 - - ---- 2/2/0/0/0 0/0 "GET /app/login/ HTTP/1.1"
Jun 22 12:03:01 node2 haproxy[23034]: -:43662 [22/Jun/2021:12:03:01.427] www-https~ app/node7 app.domain.com 0/0/1/30/31 200 1235 - - ---- 1/1/0/0/0 0/0 "GET /23rfsa/ HTTP/1.1"
Jun 22 12:02:59 node2 haproxy[23034]: -:47481 [22/Jun/2021:12:02:59.590] www-https~ app/node16 app.domain.com 0/0/3/32/35 403 142 - - ---- 1/1/0/0/0 0/0 "GET /app/event/ HTTP/1.1"
Jun 22 12:02:57 node2 haproxy[23034]: -:47642 [22/Jun/2021:12:02:55.202] www-https~ app/app-node2 app.domain.com 1/0/1/15/2606 200 325791 - - ---- 1/1/0/0/0 0/0 "GET /static/files/3rsdfas3.js HTTP/1.1"
Jun 22 12:03:08 node2 haproxy[23034]: -:11178 [22/Jun/2021:12:03:08.833] www-https~ app/node7 app.domain.com 0/0/1/29/30 404 448 - - ---- 3/3/0/0/0 0/0 "GET /favicon.ico HTTP/1.1"
Jun 22 12:03:04 node2 haproxy[23034]: -:21278 [22/Jun/2021:12:03:04.060] www-https~ app/node16 app.domain.com 0/0/2/39/41 200 1235 - - ---- 3/3/0/0/0 0/0 "GET /qfe32/ HTTP/1.1"
Jun 22 12:03:08 node3 haproxy[23034]: -:21978 [22/Jun/2021:12:03:08.339] www-https~ app/server app.domain.eu 0/0/2/45/47 404 448 - - ---- 3/3/0/0/0 0/0 "GET /dsffdssdf HTTP/1.1"

legoguy1000 · 2021-06-22T12:36:11Z

So the module isn't setup to parse the first half of those logs, the server/status messages. As for the 2nd half, they look like they're the same as what I just added so I can take a quick look.

legoguy1000 · 2021-06-23T00:23:55Z

Jun 22 12:02:53 node2 haproxy[23034]: -:47625 [22/Jun/2021:12:02:53.473] www-https~ app/app-node2 app.domain.com 0/0/1/17/18 302 291 - - ---- 1/1/0/0/0 0/0 "GET / HTTP/1.1"
Jun 22 12:03:01 node2 haproxy[23034]: -:47445 [22/Jun/2021:12:03:01.501] www-https~ app/node16 app.domain.com 0/0/1/55/56 200 3097 - - ---- 2/2/0/0/0 0/0 "GET /app/login/ HTTP/1.1"
Jun 22 12:03:01 node2 haproxy[23034]: -:43662 [22/Jun/2021:12:03:01.427] www-https~ app/node7 app.domain.com 0/0/1/30/31 200 1235 - - ---- 1/1/0/0/0 0/0 "GET /23rfsa/ HTTP/1.1"
Jun 22 12:02:59 node2 haproxy[23034]: -:47481 [22/Jun/2021:12:02:59.590] www-https~ app/node16 app.domain.com 0/0/3/32/35 403 142 - - ---- 1/1/0/0/0 0/0 "GET /app/event/ HTTP/1.1"
Jun 22 12:02:57 node2 haproxy[23034]: -:47642 [22/Jun/2021:12:02:55.202] www-https~ app/app-node2 app.domain.com 1/0/1/15/2606 200 325791 - - ---- 1/1/0/0/0 0/0 "GET /static/files/3rsdfas3.js HTTP/1.1"
Jun 22 12:03:08 node2 haproxy[23034]: -:11178 [22/Jun/2021:12:03:08.833] www-https~ app/node7 app.domain.com 0/0/1/29/30 404 448 - - ---- 3/3/0/0/0 0/0 "GET /favicon.ico HTTP/1.1"
Jun 22 12:03:04 node2 haproxy[23034]: -:21278 [22/Jun/2021:12:03:04.060] www-https~ app/node16 app.domain.com 0/0/2/39/41 200 1235 - - ---- 3/3/0/0/0 0/0 "GET /qfe32/ HTTP/1.1"
Jun 22 12:03:08 node3 haproxy[23034]: -:21978 [22/Jun/2021:12:03:08.339] www-https~ app/server app.domain.eu 0/0/2/45/47 404 448 - - ---- 3/3/0/0/0 0/0 "GET /dsffdssdf HTTP/1.1"

These logs parsed no problem. I think a separate discussion should be have for the other logs. I'm going to recommend that we merge the PR.

elasticmachine · 2021-06-23T13:21:33Z

Pinging @elastic/integrations (Team:Integrations)

* #25827: Update HA Proxy log grok patterns * update changelog * add more sample data

* #25827: Update HA Proxy log grok patterns * update changelog * add more sample data (cherry picked from commit a300f1b)

* #25827: Update HA Proxy log grok patterns * update changelog * add more sample data (cherry picked from commit a300f1b) Co-authored-by: Alex Resnick <[email protected]>

botelastic bot added the needs_team Indicates that the issue/PR needs a Team:* label label May 24, 2021

legoguy1000 mentioned this issue May 25, 2021

[Filebeat] Update HA Proxy log grok patterns #25835

Merged

6 tasks

legoguy1000 added a commit to legoguy1000/beats that referenced this issue Jun 23, 2021

elastic#25827: Update HA Proxy log grok patterns

d5bbb94

jsoriano added the Team:Integrations Label for the Integrations team label Jun 23, 2021

botelastic bot removed the needs_team Indicates that the issue/PR needs a Team:* label label Jun 23, 2021

P1llus closed this as completed in #25835 Jun 23, 2021

P1llus pushed a commit that referenced this issue Jun 23, 2021

[Filebeat] Update HA Proxy log grok patterns (#25835)

a300f1b

* #25827: Update HA Proxy log grok patterns * update changelog * add more sample data

mergify bot pushed a commit that referenced this issue Jun 23, 2021

[Filebeat] Update HA Proxy log grok patterns (#25835)

7626461

* #25827: Update HA Proxy log grok patterns * update changelog * add more sample data (cherry picked from commit a300f1b)

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Can’t parse haproxy logs #25827

Can’t parse haproxy logs #25827

manuelsaks commented May 24, 2021

manuelsaks commented May 25, 2021

legoguy1000 commented May 25, 2021

legoguy1000 commented May 27, 2021

manuelsaks commented Jun 1, 2021 •

edited

Loading

legoguy1000 commented Jun 1, 2021

manuelsaks commented Jun 1, 2021 •

edited

Loading

legoguy1000 commented Jun 1, 2021

manuelsaks commented Jun 2, 2021

legoguy1000 commented Jun 2, 2021

manuelsaks commented Jun 4, 2021

manuelsaks commented Jun 9, 2021 •

edited

Loading

legoguy1000 commented Jun 15, 2021

manuelsaks commented Jun 17, 2021

legoguy1000 commented Jun 18, 2021

legoguy1000 commented Jun 22, 2021

manuelsaks commented Jun 22, 2021 •

edited

Loading

legoguy1000 commented Jun 22, 2021

legoguy1000 commented Jun 23, 2021 •

edited

Loading

elasticmachine commented Jun 23, 2021

Can’t parse haproxy logs #25827

Can’t parse haproxy logs #25827

Comments

manuelsaks commented May 24, 2021

manuelsaks commented May 25, 2021

legoguy1000 commented May 25, 2021

legoguy1000 commented May 27, 2021

manuelsaks commented Jun 1, 2021 • edited Loading

legoguy1000 commented Jun 1, 2021

manuelsaks commented Jun 1, 2021 • edited Loading

legoguy1000 commented Jun 1, 2021

manuelsaks commented Jun 2, 2021

legoguy1000 commented Jun 2, 2021

manuelsaks commented Jun 4, 2021

manuelsaks commented Jun 9, 2021 • edited Loading

legoguy1000 commented Jun 15, 2021

manuelsaks commented Jun 17, 2021

legoguy1000 commented Jun 18, 2021

legoguy1000 commented Jun 22, 2021

manuelsaks commented Jun 22, 2021 • edited Loading

legoguy1000 commented Jun 22, 2021

legoguy1000 commented Jun 23, 2021 • edited Loading

elasticmachine commented Jun 23, 2021

manuelsaks commented Jun 1, 2021 •

edited

Loading

manuelsaks commented Jun 1, 2021 •

edited

Loading

manuelsaks commented Jun 9, 2021 •

edited

Loading

manuelsaks commented Jun 22, 2021 •

edited

Loading

legoguy1000 commented Jun 23, 2021 •

edited

Loading