Neutron haproxy logs are not being collected

Bug #1744359 reported by Daniel Alvarez on 2018-01-19
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
devstack
Undecided
Unassigned
neutron
High
Brian Haley
tripleo
High
Unassigned

Bug Description

In Neutron, we use haproxy to proxy metadata requests from instances to Nova Metadata service.
By default, haproxy logs to /dev/log but in Ubuntu, those requests get redirected by rsyslog to
/var/log/haproxy.log which is not being collected.

ubuntu@devstack:~$ cat /etc/rsyslog.d/49-haproxy.conf
# Create an additional socket in haproxy's chroot in order to allow logging via
# /dev/log to chroot'ed HAProxy processes
$AddUnixListenSocket /var/lib/haproxy/dev/log

# Send HAProxy messages to a dedicated logfile
if $programname startswith 'haproxy' then /var/log/haproxy.log
&~

Another possibility would be to change the haproxy.cfg file to include the log-tag option so that haproxy uses a different tag [0] and then it'd be dumped into syslog instead but this would break backwards compatibility.

[0] https://cbonte.github.io/haproxy-dconv/configuration-1.5.html#3.1-log-tag

tags: added: l3-ipam-dhcp
Brian Haley (brian-haley) wrote :

So I tested using log-tag in the haproxy conf file, and it does help differentiating things in /var/log/haproxy.log since all the haproxies will log there.

A typical line went from this:

Jan 15 16:57:45 localhost haproxy[14095]: 10.0.0.6:34898 [15/Jan/2018:16:57:45.650] listener listener/metadata 2/0/1/17/20 200 157 - - ---- 1/1/0/1/0 0/0 "GET /2009-04-04/meta-data/hostname HTTP/1.1"

to this:

Jan 19 14:49:34 localhost haproxy-metadata-proxy-c891c6a2-07b3-4cdf-86c7-6164cdac7dd1[7418]: 10.0.0.7:52947 [19/Jan/2018:14:49:34.097] listener listener/metadata 7/0/0/368/375 200 157 - - ---- 1/1/0/0/0 0/0 "GET /2009-04-04/meta-data/hostname HTTP/1.1"

Which doesn't look too backwards incompatible, just a change in what proxy logged it.

Brian Haley (brian-haley) wrote :

So I think these are logged, they're just not where we expect them to be. I noticed that when running journalctl in devstack:

    'sudo journalctl --unit <email address hidden>'

I was seeing haproxy lines, most likely since it's using systemd and haproxy is started as a child.

I also noticed it in other jobs as well:

http://logs.openstack.org/88/535488/1/check/barbican-simple-crypto-devstack-tempest/4a4b91a/logs/screen-q-l3.txt.gz#_Jan_18_22_10_24_019350

That doesn't mean there isn't work to do in TripleO to capture them as well.

Fix proposed to branch: master
Review: https://review.openstack.org/535948

Changed in neutron:
assignee: nobody → Brian Haley (brian-haley)
status: New → In Progress

I guess having haproxy prefix is backwards compatible enough to allow it to slip like that.

Changed in tripleo:
status: New → Triaged
importance: Undecided → High
milestone: none → queens-3

Reviewed: https://review.openstack.org/535948
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=703ff85b8262997f209e7666396c5d430d3baa34
Submitter: Zuul
Branch: master

commit 703ff85b8262997f209e7666396c5d430d3baa34
Author: Brian Haley <email address hidden>
Date: Fri Jan 19 15:53:38 2018 -0500

    Add log-tag to haproxy config file

    By adding a log-tag line to the haproxy config file that contains
    the network or router id, we will be able to differentiate which
    proxy is logging what. This should help with debugging.

    Change-Id: I5bb57b7682c00645e20cce69847dbb3b72165aa8
    Partial-bug: #1744359

Changed in tripleo:
milestone: queens-3 → queens-rc1

Reviewed: https://review.openstack.org/536919
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=f74b39c57dbb306dd3bb9a68cc44491d54b7988a
Submitter: Zuul
Branch: stable/pike

commit f74b39c57dbb306dd3bb9a68cc44491d54b7988a
Author: Brian Haley <email address hidden>
Date: Fri Jan 19 15:53:38 2018 -0500

    Add log-tag to haproxy config file

    By adding a log-tag line to the haproxy config file that contains
    the network or router id, we will be able to differentiate which
    proxy is logging what. This should help with debugging.

    Change-Id: I5bb57b7682c00645e20cce69847dbb3b72165aa8
    Partial-bug: #1744359
    (cherry picked from commit 703ff85b8262997f209e7666396c5d430d3baa34)

tags: added: in-stable-pike
Akihiro Motoki (amotoki) wrote :

Brian, is there anything remaining in neutron? You used "Partial-Bug" for a neutron fix.

Changed in neutron:
importance: Undecided → High
Brian Haley (brian-haley) wrote :

Akihiro - yes, I don't think there is more in neutron, I thought there was at the time or I would have used closes-bug instead. We should now have slightly better logging in this area.

Miguel Lavalle (minsel) on 2018-02-01
Changed in neutron:
status: In Progress → Fix Committed
Changed in tripleo:
milestone: queens-rc1 → rocky-1
Changed in neutron:
status: Fix Committed → Fix Released
Dr. Jens Harbott (j-harbott) wrote :

Seems like this has been an issue in Neutron, please reopen if there is still some issue with devstack.

Changed in devstack:
status: New → Invalid
Changed in tripleo:
milestone: rocky-1 → rocky-2
Changed in tripleo:
milestone: rocky-2 → rocky-3
Changed in tripleo:
milestone: rocky-3 → rocky-rc1
Changed in tripleo:
milestone: rocky-rc1 → stein-1
Changed in tripleo:
milestone: stein-1 → stein-2
Changed in tripleo:
milestone: stein-2 → stein-3
Changed in tripleo:
milestone: stein-3 → stein-rc1
Changed in tripleo:
milestone: stein-rc1 → train-1
Changed in tripleo:
milestone: train-1 → train-2
Changed in tripleo:
milestone: train-2 → train-3
Changed in tripleo:
milestone: train-3 → ussuri-1
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers