Debian: Exceptions flooding gunicorn.log

[Enzo Candotti]

Brief Description

There are lots of exceptions reported in gunicorn.log. Looks like logging of Horizon actions is broken.

Sample exception:

[2022-11-10 08:27:16 +0000] [77132] [INFO] Booting worker with pid: 77132
--- Logging error ---
Traceback (most recent call last):
  File "/usr/lib/python3.9/logging/handlers.py", line 959, in emit
    self.socket.sendto(msg, self.address)
OSError: [Errno 9] Bad file descriptor
Call stack:
  File "/usr/bin/gunicorn", line 33, in <module>
    sys.exit(load_entry_point('gunicorn==20.1.0', 'console_scripts', 'gunicorn')())
  File "/usr/lib/python3/dist-packages/gunicorn/app/wsgiapp.py", line 67, in run
    WSGIApplication("%(prog)s [OPTIONS] [APP_MODULE]").run()
  File "/usr/lib/python3/dist-packages/gunicorn/app/base.py", line 231, in run
    super().run()
  File "/usr/lib/python3/dist-packages/gunicorn/app/base.py", line 72, in run
    Arbiter(self).run()
  File "/usr/lib/python3/dist-packages/gunicorn/arbiter.py", line 202, in run
    self.manage_workers()
  File "/usr/lib/python3/dist-packages/gunicorn/arbiter.py", line 551, in manage_workers
    self.spawn_workers()
  File "/usr/lib/python3/dist-packages/gunicorn/arbiter.py", line 622, in spawn_workers
    self.spawn_worker()
  File "/usr/lib/python3/dist-packages/gunicorn/arbiter.py", line 587, in spawn_worker
    self.log.info("Booting worker with pid: %s", worker.pid)
  File "/usr/lib/python3/dist-packages/gunicorn/glogging.py", line 264, in info
    self.error_log.info(msg, *args, **kwargs)
Message: 'Booting worker with pid: %s'
Arguments: (77132,)

Severity

Minor - Horizon still works but debugging of events will be more difficult without seeing the logs of Horizon actions taken by customers

Steps to Reproduce

Seen on a running system, assumption is to just use/access Horizon

Expected Behavior

No exceptions should occur in /var/log/horizon/gunicorn.log

Actual Behavior

Exceptions occurring constantly in /var/log/horizon/gunicorn.log

Reproducibility

Reproducible

System Configuration

Any

Load info (eg: 2022-03-10_20-00-07)

BUILD_ID="2022-11-09_18-00-08"

Last Pass

No issue on CentOS; never passed on Debian

Timestamp/Logs

n/a

Alarms

n/a

Test Activity

Normal use via Horizon

Workaround

n/a

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/starlingx/root/+/873159
Committed: https://opendev.org/starlingx/root/commit/05a5b0ddad5e2c07fe1df9d4db2c871b8b40cc2b
Submitter: "Zuul (22348)"
Branch: master

commit 05a5b0ddad5e2c07fe1df9d4db2c871b8b40cc2b
Author: Enzo Candotti <email address hidden>
Date: Wed Feb 8 14:00:38 2023 -0300

    circular_dep.conf: add chain for python3.9

    New item for python3.9 is added into circular_dep.conf
    to resolve the build failure when building this package.

    Test Plan:
    PASS: build-pkgs -c -p python3.9

    Partial-Bug: 2006623

    Signed-off-by: Enzo Candotti <email address hidden>
    Change-Id: Ic39b04945c41b8fdbf187483b49acb34b8ce4483

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/starlingx/integ/+/871349
Committed: https://opendev.org/starlingx/integ/commit/2bd6d28ace1cc66fc73e90c4a03118404f500b34
Submitter: "Zuul (22348)"
Branch: master

commit 2bd6d28ace1cc66fc73e90c4a03118404f500b34
Author: Enzo Candotti <email address hidden>
Date: Fri Jan 20 15:39:25 2023 -0300

    Fix reconnection in logging.handlers.SysLogHandler

    There are lots of exceptions reported in gunicorn.log.
    That error was due to a bug present on SysLogHandler
    that was reported on cpython repo but was not fixed for python3.9.2.

    This change adds python3.9 package to the build system and patches
    it in order to update SysLogHandler to fix the reconnection bug.

    Test Plan:
    PASS: Build python3.9 package. Install
    libpython3.9-minimal_3.9.2-1.stx.1_amd64.deb and verify that the
    exceptions are no longer present.

    Depends-On: https://review.opendev.org/c/starlingx/root/+/873159
    Closes-bug: 2006623

    Signed-off-by: Enzo Candotti <email address hidden>
    Change-Id: I6eb44544da5c05e712bc89e69193548667c8ab28