HAProxy captured response header Location not in Log

[Reamer]

Detailed Description of the Problem

I have a problem with the logging of captured response headers when a redirect is performed by HAProxy.

Actual log line

10.255.0.1:40272 [18/Mar/2024:16:18:22.794] example example/<NOSRV> - - 0/-1/-1/-1/-1/0 0/0/0/0 302 100 82 - - LR-- 1/1/0/0/0 0/0 {curl/7.81.0} {} "HEAD / HTTP/1.1"

Expected Behavior

Expected log line

10.255.0.1:40272 [18/Mar/2024:16:18:22.794] example example/<NOSRV> - - 0/-1/-1/-1/-1/0 0/0/0/0 302 100 82 - - LR-- 1/1/0/0/0 0/0 {curl/7.81.0} {https://www.fsf.org} "HEAD / HTTP/1.1"

Steps to Reproduce the Behavior

1. Place the attached HAProxy configuration in an empty folder.
2. Run docker run -d --name my-running-haproxy -v .:/usr/local/etc/haproxy:ro -p8080:80 --sysctl net.ipv4.ip_unprivileged_port_start=0 haproxy
3. Run curl -I localhost:8080
4. Check the log docker logs my-running-haproxy

Do you have any idea what may have caused this?

Unfortunately not.

Do you have an idea how to solve the issue?

No response

What is your configuration?

global
    log stdout format raw local0
defaults
    log global
    mode http
    log-format "%ci:%cp [%t] %ft %b/%s %sslv %sslc %TR/%Tw/%Tc/%Tr/%Td/%Ta %Th/%Ti/%Ta/%Tt %ST %B %U %CC %CS %tsc %ac/%fc/%bc/%sc/%rc %sq/%bq %hr %hs %{+Q}r"

frontend example
    bind *:80
    mode http
    
    capture request header user-agent len 100
    capture response header Location len 15

    
    acl is_android 	req.fhdr(user-agent) -i -m reg android\s(9|\d{2})[;|)]
    acl is_ios          req.fhdr(user-agent) -i -m reg (iphone|ipod|ipad).*os\s(1[4-9]|[2-9]\d)_
    
    http-request redirect code 302 location https://kernel.org if  is_ios
    http-request redirect code 302 location https://wikipedia.org if  is_android
    http-request redirect code 302 location https://www.fsf.org if !is_android !is_ios

Output of haproxy -vv

HAProxy version 2.9.6-9eafce5 2024/02/26 - https://haproxy.org/
Status: stable branch - will stop receiving fixes around Q1 2025.
Known bugs: http://www.haproxy.org/bugs/bugs-2.9.6.html
Running on: Linux 5.15.0-101-generic #111-Ubuntu SMP Tue Mar 5 20:16:58 UTC 2024 x86_64
Usage : haproxy [-f <cfgfile|cfgdir>]* [ -vdVD ] [ -n <maxconn> ] [ -N <maxpconn> ]

Last Outputs and Backtraces

No response

Additional Information

No response

[wtarreau]

It's expected, captures work very early, before any other rules, so that it's possible to take a copy of what is fed into haproxy before it's possible modified or deleted. In your case, the capture happens on the response from the server, before headers are rewritten, but you don't go that far with the redirect rule that interrupts request processing and forges a response without doing any response processing.

There is a trick you could use however. By adding an "http-after-response" rule, you can insert rules to be applied before the response is sent, that will take a capture of the header and copy it into a variable, that you will log:

   http-request redirect location /blah
   http-after-response set-var(txn.location) res.hdr(location)
   log-format "$HAPROXY_HTTP_LOG_FMT %[var(txn.location)]"

Testing it does indeed work for me, look at the end of the line:

$ curl 0:8001
<134>Apr  2 11:14:18 haproxy[368]: 127.0.0.1:21690 [02/Apr/2024:11:14:18.333] blah blah/<NOSRV> 0/-1/-1/-1/0 302 86 - - LR-- 1/1/0/0/0 0/0   "GET / HTTP/1.1" /blah

[Reamer]

Hello Willi,
Thank you very much for your quick reply. Unfortunately this makes logging very difficult as other requests rely on the capture response header Location len 15 statement.

[Reamer]

What do you think of the following solution?

global
    log stdout format raw local0
defaults
    log global
    mode http
    log-format "%ci:%cp [%t] %ft %b/%s %sslv %sslc %TR/%Tw/%Tc/%Tr/%Td/%Ta %Th/%Ti/%Ta/%Tt %ST %B %U %CC %CS %tsc %ac/%fc/%bc/%sc/%rc %sq/%bq %hr %hs %{+Q}r"

frontend example
    bind *:80
    mode http
    
    capture request header user-agent len 100

    use_backend web

    capture response header Location len 150
    capture response header Content-length len 9

backend web
    server s1 /tmp/webr.sock

frontend webrUnix
    bind unix@/tmp/webr.sock
    no log
    acl is_android 	req.fhdr(user-agent) -i -m reg android\s(9|\d{2})[;|)]
    acl is_ios          req.fhdr(user-agent) -i -m reg (iphone|ipod|ipad).*os\s(1[4-9]|[2-9]\d)_
    http-request redirect code 302 location https://kernel.org if  is_ios
    http-request redirect code 302 location https://wikipedia.org if  is_android
    http-request redirect code 302 location https://www.fsf.org if !is_android !is_ios

[capflam]

You can also use http-after-response capture action.

[Reamer]

Awesome.
Thanks that solution is working.

global
    log stdout format raw local0
defaults
    log global
    mode http
    log-format "%ci:%cp [%t] %ft %b/%s %sslv %sslc %TR/%Tw/%Tc/%Tr/%Td/%Ta %Th/%Ti/%Ta/%Tt %ST %B %U %CC %CS %tsc %ac/%fc/%bc/%sc/%rc %sq/%bq %hr %hs %{+Q}r"

frontend example
    bind *:80
    mode http
    
    capture request header user-agent len 100
    
    declare capture response len 20
    http-after-response capture res.hdr(Location) id 0
    
    declare capture response len 20
    http-after-response capture res.hdr(Content-length) id 1

    acl is_android      req.fhdr(user-agent) -i -m reg android\s(9|\d{2})[;|)]
    acl is_ios          req.fhdr(user-agent) -i -m reg (iphone|ipod|ipad).*os\s(1[4-9]|[2-9]\d)_
    http-request redirect code 302 location https://kernel.org if  is_ios
    http-request redirect code 302 location https://wikipedia.org if  is_android
    http-request redirect code 302 location https://www.fsf.org if !is_android !is_ios

[wtarreau]

I must confess I had totally forgotten about http-* capture actions! So I guess we can close now.