Beats: Grok for new haproxy module in filebeat fail

[RemiDesgrange]

I have haproxy from debian repo, version 1.5.8. Log conf is:

global
    log /dev/log    local0
    log /dev/log    local1 notice

Filebeat haproxy module is configured as follow:

- module: haproxy
  http:
    enabled: true
    var.input: "file"
    var.paths: ["/var/log/haproxy.log"]

a typical log line (heartbeat from a monitoring tool):

Sep 13 10:43:45 serv haproxy[666]: 1.1.1.1 - - [13/Sep/2018:08:43:45 +0000] "HEAD / HTTP/1.0" 301 93 \"\" \"\" 10976 \828 "https" "https" "<NOSRV>" \0 -1 -1 -1 0 LR-- 1 1 \0 0 0 0 0 "" "" \

a real line that fetch real data from a backend server

Sep 13 10:43:21 serv haproxy[666]: 52.XX.53.XX - - [13/Sep/2018:08:43:21 +0000] "GET /this/is/a/path HTTP/1.1" 401 248 \"\" \"\" 31006 \709 "https~" "vm-myvm" "<NOSRV>" \-1 -1 -1 -1 194 PR-- 1 1 \0 0 3 0 0 "" "" \

This produce a grok error in elasticsearch. Since I'm using "default" logging in haproxy, I found weird that I got error from Grok.

• Version: from master@0a20f580519dc86232b7f854f7acb88220034a7c
• Operating System: Linux
• Discuss Forum URL: https://discuss.elastic.co/t/haproxy-module-with-master-version/148094
• Steps to Reproduce: setup filebeat from master (go get, cd and make)

[jsoriano]

Hi @RemiDesgrange,

Thanks for reporting this!

It is weird because your format doesn't look like any of the default haproxy log formats according to its documentation. The "default" one, used when no other log option is set is discouraged and marked as deprecated, but it still looks different to yours.
For http option httplog is recommended, and in principle this is the format supported by current module, could you try to use this option?

In any case if it works for you with option httplog we can still leave this open to support your current format, probably more people are using it. And we sould also check support for "default" and option tcplog log formats, and check that the module documentation mentions the supported log formats.

[ph]

@RemiDesgrange If this work for you we should consider on our side to update the documentation with mention that setting.

[RemiDesgrange]

Ok @jsoriano I already have this option in default:

defaults
    log global
    mode    http
    option  httplog
    option  dontlognull

Maybe I should make it global. But I don't modify anything in frontend/backend about logs. Is there any other config file beside /etc/haproxy/haproxy.conf ?

[jsoriano]

Having this option in defaults should be enough, yes :thinking: We will have to investigate it further.

I don't know of any other config file that could be affecting this.

[jsoriano]

I have been doing some quick tests in a clean debian jessie with haproxy 1.5.8-3+deb8u2 and logs look like the ones in the documentation.

I have added this config to the haproxy config provided by the package:

listen mysvc :82
        mode http
        capture request header Host len 64
        capture response header Content-Type len 64
        capture response header Content-Length len 64
        server myserver01 127.0.0.1:80 check

frontend mynginx
        bind :81
        mode http
        capture request header Host len 64
        default_backend myservers

backend myservers
        mode http
        capture response header Content-Type len 64
        capture response header Content-Length len 64
        server myserver01 127.0.0.1:80 check

And doing requests with curl to ports 81 and 82 I see logs like:

Sep 13 15:36:18 debian8-haproxy haproxy[5988]: 127.0.0.1:41284 [13/Sep/2018:15:36:18.772] mysvc mysvc/myserver01 0/0/0/0/0 200 1104 - - ---- 1/1/0/1/0 0/0 {example.com} {text/html|867} "GET / HTTP/1.1"
Sep 13 15:36:21 debian8-haproxy haproxy[5988]: 127.0.0.1:54556 [13/Sep/2018:15:36:21.135] mynginx myservers/myserver01 0/0/0/0/0 200 1104 - - ---- 1/1/0/1/0 0/0 {example.com} "GET / HTTP/1.1"

The only variable parts are the ones between curly brackets, they are captured headers, I think that current patterns are expecting them and they don't need to be present, we will have to handle this.
We will also need to add a pattern for availability messages:

Sep 13 15:51:16 debian8-haproxy haproxy[5988]: Server mysvc/myserver01 is DOWN, reason: Layer4 connection problem, info: "Connection refused", check duration: 0ms. 0 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.

And a catch it all pattern for this kind of messages:

Sep 13 15:51:15 debian8-haproxy haproxy[5988]: backend myservers has no server available!

I am checking the logs in /var/log/haproxy.log as collected by rsyslog, I don't know if it is possible that the syslog daemon could be modifying the log line, I'd find this really strange.

[jsoriano]

@RemiDesgrange could you double-check that you don't have any log-format directive in your haproxy config?

[RemiDesgrange]

Oh god... yes in the frontend part... This is so dumb... I'm sorry. Ok closing.

[jsoriano]

@RemiDesgrange good to read that an explanation has been found :slightly_smiling_face:
It has been useful in any case to discuss this, I have collected some action items in #8311 after the investigations for this issue.
Thanks!

[SETI]

We're running into the same issue. We don't have a log-format option in our haproxy.cfg file.

Any advice would be great!

[jsoriano]

Hi @SETI,
I am sorry to read that you are having problems with haproxy module.
Could you check if you could be affected by any of the pending issues mentioned in #8311? For example #9463 can be the cause if you are not capturing headers.
A log line reproducing the issue could be helpful too for further diagnostics.

[SETI]

thanks. checking the capture hearders - I know I'm not capturing them currently.

Here is an message from ELK:

Provided Grok expressions do not match field value: [Jan 9 10:06:46 haproxy3 haproxy[14466]: 46.229.168.132:35508 [09/Jan/2019:10:06:46.638] http_in bigpicturescience_backend_farm/bps1 0/0/0/73/74 200 52952 - - ---- 1/1/0/0/0 0/0 \"GET /episodes?order=title&page=4&sort=asc&tag=behavior&view=tag HTTP/1.1\"]

[jsoriano]

@SETI ok, then this is #9463. I have pushed a fix today for this (#9958), this will be available on next release.