1.1.5: Remove #error { line from fatal logs

[dmosorast]

Description of change

The current pattern of logging is showing a dangling #error { line when the FATAL log lines are parsed out of projects that use this library (e.g., taps' top-level error handler and Stitch's failure message). This provide no value, and is just clutter in the message, causing confusion.

The lines that follow this are the stack trace and are definitely not an error summary, so this PR makes those non-fatal level to keep them out of the exit reason.

Due to slf4j being a hard requirement of a lot of Java libraries (specifically, apache/avro for our purposes), those taps do not have a FATAL level, since that's not present in slf4j (at least not from clojure.tools.logging). This PR takes advantage of the dynamic binding of *logger-factory* provided by clojure.tools.logging to explicitly use log4j as has been the case for our Clojure taps up until this slf4j dependency was forced upon us.

This allows the clojure-level to use the logger that we have been using, while allowing libraries to use their own. The downside is that log4j is now an explicit dependency requirement for users of this library, but it was before, it'll just now check through the delay binding in log.clj.

Manual QA steps

• Running this through a local tap with a forced exception to confirm that the levels are correct in that context
• Added unit tests to check for the specific change.

Risks

• Low, it's only logging, as long as integration tests pass on upgrading, this should not be considered "breaking"

Rollback steps

• revert this branch, release new patch version

[dmosorast]

If log4j is not found (aka (is (nil? (log-impl/log4j-factory))``), this exception is thrown from the first usage of fatalthrough the use of adelay`:

ERROR in (log-fatal-trims-error-from-wrapped-exinfo) (log.clj:19)
Uncaught exception, not in assertion.
expected: nil
  actual: java.lang.Exception: [log4j not found] - In order to use singer-clojure fatal-level logging, log4j is required.
 at singer_clojure.log$eval681$fn__682.invoke (log.clj:19)
    clojure.lang.Delay.deref (Delay.java:42)
    clojure.core$deref.invokeStatic (core.clj:2312)

In usage where slf4j is present:
Before:

$ lein run --repl
WARNING: error-handler already refers to: #'clojure.core/error-handler in namespace: com.stitchdata.target-stitch-avro.flush-pipeline, being replaced by: #'com.stitchdata.target-stitch-avro.flush-pipeline/error-handler
2021-07-23 15:05:15,668 INFO  [main] tap-hp-mysql.main - Started nrepl server at /127.0.0.1:39949
FATAL 2021-07-23 15:05:15,668 [main] tap-hp-mysql.main - Fatal Error Occured - BOOOOOOOM
FATAL 2021-07-23 15:05:15,683 [main] #error {
 :cause BOOOOOOOM
 :via
 [{:type java.lang.Exception
   :message BOOOOOOOM
   :at [tap_hp_mysql.main$main_impl invokeStatic main.clj 95]}]

After:

$ lein run --repl
WARNING: error-handler already refers to: #'clojure.core/error-handler in namespace: com.stitchdata.target-stitch-avro.flush-pipeline, being replaced by: #'com.stitchdata.target-stitch-avro.flush-pipeline/error-handler
INFO 2021-07-23 16:20:51,107 [main] Started nrepl server at /127.0.0.1:46325
FATAL 2021-07-23 16:20:51,113 [main] tap-hp-mysql.main - Fatal Error Occured - BOOOOOOOM
ERROR 2021-07-23 16:20:51,124 [main] #error {
 :cause BOOOOOOOM
 :via
 [{:type java.lang.Exception
   :message BOOOOOOOM
   :at [tap_hp_mysql.main$main_impl invokeStatic main.clj 95]}]

[dmosorast]

Having trouble with the unit test not rebinding err and capturing the output when run from the CLI (it works in the REPL), so I'm considering just relying on manual integration testing here. After some review, this is a more simplified form of the output with info fixed to include the namespace.

vagrant@vagrant:/opt/code/tap-hp-mysql$ lein run --repl
WARNING: error-handler already refers to: #'clojure.core/error-handler in namespace: com.stitchdata.target-stitch-avro.flush-pipeline, being replaced by: #'com.stitchdata.target-stitch-avro.flush-pipeline/error-handler
INFO  [main] tap-hp-mysql.main - Started nrepl server at /127.0.0.1:43557
FATAL [main] tap-hp-mysql.main - Fatal Error Occured - BOOOOOOOM
ERROR [main] #error {
 :cause BOOOOOOOM
 :via
 [{:type java.lang.Exception
   :message BOOOOOOOM
   :at [tap_hp_mysql.main$main_impl invokeStatic main.clj 95]}]

[dmosorast]

This is the final version. Will run it through and confirm that the code as-is matches my most recent comment. There was a strange issue with capture stderr in the unit tests where the re-binding worked in the repl, but not on the command line.

Given that log testing (unit form) is slightly brittle and explicit, I decided they were providing negative value and removed them.

[dmosorast]

Here's the final version, with a debug level that's not getting logged (since there's no debug logger defined in log4j) and all the visible log levels.

$ lein run
WARNING: error-handler already refers to: #'clojure.core/error-handler in namespace: com.stitchdata.target-stitch-avro.flush-pipeline, being replaced by: #'com.stitchdata.target-stitch-avro.flush-pipeline/error-handler
INFO  [main] tap-hp-mysql.main - Started nrepl server at /127.0.0.1:39991
WARN  [main] tap-hp-mysql.main - This is a warning! DO NOT BE ALARMED
FATAL [main] tap-hp-mysql.main - Fatal Error Occured - BOOOOOOOM
ERROR [main] #error {
 :cause BOOOOOOOM
 :via
 [{:type java.lang.Exception
   :message BOOOOOOOM
   :at [tap_hp_mysql.main$main_impl invokeStatic main.clj 98]}]