Add log4j logging and bridge

[dr0i]

Enables logging.

See #383.

[fsteeg]

Tested with dist created with installDist, ran flux with log-object, got output 👍

[blackwinter]

Why are you introducing log4j, and also logback? We're already using slf4j.

[blackwinter]

Suggested change

	runtimeOnly 'org.apache.logging.log4j:log4j-core'
	implementation 'org.apache.logging.log4j:log4j-1.2-api:2.9.1'
	implementation 'ch.qos.logback:logback-classic:1.3.14'
	runtimeOnly "org.slf4j:slf4j-log4j12:${versions.slf4j}"

[fsteeg]

With this suggestion, I get no logging output, and the same Class path contains multiple SLF4J bindings. warning that I get without this PR.

[blackwinter]

That warning aside (different issue, IMO), you would have to increase the log level to DEBUG.

[fsteeg]

Same with DEBUG in log4j.xml: no logging output. As you wrote below, it must be using some other config?

[blackwinter]

That's not what I saw. Changing the log level (priority) in log4j.xml and then running ./gradlew installDist yields debug output with log-object.

[fsteeg]

Weird, I have <priority value="DEBUG" /> in metafix/src/main/resources/log4j.xml, only runtimeOnly "org.slf4j:slf4j-log4j12:${versions.slf4j}" added in metafix-runner/build.gradle: no logging output for log-object.

[blackwinter]

And you ran ./gradlew installDist afterwards? For me on master:

1. Copy log4j.xml from metafacture-core to metafix/src/main/resources/.
2. Change priority info to DEBUG in metafix/src/main/resources/log4j.xml.
3. Add runtimeOnly "org.slf4j:slf4j-log4j12:${versions.slf4j}" to metafix-runner/build.gradle.
4. Run ./gradlew installDist.
5. Change into metafix-runner/build/install/metafix-runner directory.
6. Run bin/metafix-runner /path/to/flux-with-log-object.
7. See "DEBUG [main] ..." output.

[dr0i]

@blackwinter your proposal is working for me

[fsteeg]

I just tried it on my home machine, and here it works. Maybe some cached dependency bringing in some other config file on my office machine? So that would be +1 for using only runtimeOnly "org.slf4j:slf4j-log4j12:${versions.slf4j}". However, it works here even without adding any dependency, just by switching INFO to DEBUG in metafix/src/main/resources/log4j.xml.

[blackwinter]

However, it works here even without adding any dependency

Indeed. Probably because it's pulled in by metafacture-runner. So let's just drop it altogether then.

[blackwinter]

Tested with dist created with installDist, ran flux with log-object, got output 👍

But not without increasing the log level first, right?

[fsteeg]

But not without increasing the log level first, right?

Oh, right, weird. I saw the original commit 47304f9 and thought it makes sense, but the current version is actually INFO, but I still get the DEBUG output, without any changes to log4j.xml.

[blackwinter]

but I still get the DEBUG output, without any changes to log4j.xml.

I see. Now that you mention it, the log format is also different than what is specified in the config. Could it be that logback ignores the config file?

[blackwinter]

That's another reason why I think we shouldn't introduce any new logging dependencies. metafacture-runner uses slf4j-log4j and so should metafix-runner.

[blackwinter]

Simplify changing the log level at runtime:

Suggested change

	<priority value="INFO" />
	<priority value="${env:METAFIX_LOG_LEVEL:-INFO}" />

[dr0i]

How is the variable set? export METAFIX_LOG_LEVEL=DEBUG; bin/metafix-runner $pathTo.flux didnt' work. Same for export METAFIX_LOG_LEVEL="DEBUG".

[dr0i]

hmpf, no this works , BUT it's always on DEBUG level regardless what I set .... oh , logging is so complicated ...

[blackwinter]

Oh, sorry, I overlooked that we're on Log4j 1.x which doesn't seem to support property substitution.

[blackwinter]

No, it doesn't work. It's effectively an invalid/empty log level.

[blackwinter]

Okay, apparently it does support property substitution, it's just not readily documented. However, I wasn't able to figure out how to supply a default value in the configuration file. So it gets a little more complicated:

<priority value="${org.metafacture.metafix.logLevel}" />

diff --git metafix-runner/build.gradle metafix-runner/build.gradle
index 1179b5c..ab71abb 100644
--- metafix-runner/build.gradle
+++ metafix-runner/build.gradle
@@ -39,11 +39,15 @@ dependencies {
 application {
   mainClass = 'org.metafacture.runner.Flux'
 
+  applicationDefaultJvmArgs = [
+    "-Dorg.metafacture.metafix.logLevel=INFO"
+  ]
+
   if (project.hasProperty('profile')) {
     def file = project.getProperty('profile') ?: project.name
     def depth = project.hasProperty('profile.depth') ? project.getProperty('profile.depth') : 8
 
-    applicationDefaultJvmArgs = [
+    applicationDefaultJvmArgs += [
       "-XX:FlightRecorderOptions=stackdepth=${depth}",
       "-XX:StartFlightRecording=dumponexit=true,filename=${file}.jfr,settings=profile"
     ]

Then run with JAVA_OPTS=-Dorg.metafacture.metafix.logLevel=DEBUG.

[blackwinter]

No additional dependencies required:

Suggested change

	runtimeOnly 'org.apache.logging.log4j:log4j-core'
	implementation 'org.apache.logging.log4j:log4j-1.2-api:2.9.1'
	implementation 'ch.qos.logback:logback-classic:1.3.14'

[blackwinter]

Allow changing the log level at runtime:

Suggested change

	<priority value="INFO" />
	<priority value="${org.metafacture.metafix.logLevel}" />

Specify default log level:

diff --git metafix-runner/build.gradle metafix-runner/build.gradle
index 1179b5c..ab71abb 100644
--- metafix-runner/build.gradle
+++ metafix-runner/build.gradle
@@ -39,11 +39,15 @@ dependencies {
 application {
   mainClass = 'org.metafacture.runner.Flux'
 
+  applicationDefaultJvmArgs = [
+    "-Dorg.metafacture.metafix.logLevel=INFO"
+  ]
+
   if (project.hasProperty('profile')) {
     def file = project.getProperty('profile') ?: project.name
     def depth = project.hasProperty('profile.depth') ? project.getProperty('profile.depth') : 8
 
-    applicationDefaultJvmArgs = [
+    applicationDefaultJvmArgs += [
       "-XX:FlightRecorderOptions=stackdepth=${depth}",
       "-XX:StartFlightRecording=dumponexit=true,filename=${file}.jfr,settings=profile"
     ]

Change log level at runtime with JAVA_OPTS=-Dorg.metafacture.metafix.logLevel=DEBUG.