From fec99a7a541ea0d94f31dc769032a20a5e985df5 Mon Sep 17 00:00:00 2001
From: Anatoli Babenia <anatoli@rainforce.org>
Date: Tue, 17 Nov 2020 13:38:16 +0300
Subject: [PATCH] Properly setup Flask logging to stderr

Sometimes there is nothing, sometimes lines are duplicated.

Duplicated lines problem appears, because Python root logger
handler and Flask's `werkzeug` logger handler both write the
same message. `cheat.sh` is hit, because it sets this root
logging handler.

Normally `werkzeug` doesn't setup its own handler if it sees
that there are some handlers that process its messages. This
in case of `cheat.sh` resulted in no stderr logging at all.
No Exceptions either. Because `werkzeug` catches the
exceptions and logs them.

Hovewer, sometimes `werkzeug` starts too early, befora app
is imported (https://github.com/pallets/werkzeug/issues/1969)
and sets its logger anyway, before the app itself, resulting
in duplicating lines. In that case app root handler needs to
skip lines from `werkzeug`.

Kudos to @brandon-rhodes for `logging_tree` awesomeness
---
 bin/app.py | 22 ++++++++++++++++++++++
 1 file changed, 22 insertions(+)

diff --git a/bin/app.py b/bin/app.py
index bda993f..638bfbe 100644
--- a/bin/app.py
+++ b/bin/app.py
@@ -37,12 +37,34 @@ from options import parse_args
 
 from stateful_queries import save_query, last_query
 
+
 if not os.path.exists(os.path.dirname(CONFIG["path.log.main"])):
     os.makedirs(os.path.dirname(CONFIG["path.log.main"]))
 logging.basicConfig(
     filename=CONFIG["path.log.main"],
     level=logging.DEBUG,
     format='%(asctime)s %(message)s')
+# Fix Flask "exception and request logging" to `stderr`.
+#
+# When Flask's werkzeug detects that logging is already set, it
+# doesn't add its own logger that prints exceptions.
+stderr_handler = logging.StreamHandler()
+logging.getLogger().addHandler(stderr_handler)
+#
+# Alter log format to disting log lines from everything else
+stderr_handler.setFormatter(logging.Formatter('%(filename)s:%(lineno)s: %(message)s'))
+#
+# Sometimes werkzeug starts logging before an app is imported
+# (https://github.com/pallets/werkzeug/issues/1969)
+# resulting in duplicating lines. In that case we need root
+# stderr handler to skip lines from werkzeug.
+class SkipFlaskLogger(object):
+    def filter(self, record):
+        if record.name != 'werkzeug':
+            return True
+if logging.getLogger('werkzeug').handlers:
+    stderr_handler.addFilter(SkipFlaskLogger())
+
 
 app = Flask(__name__) # pylint: disable=invalid-name
 app.jinja_loader = jinja2.ChoiceLoader([