javaandroidlogginglog4j

Android log4j logging from compiled dependency not working


I am building a java class which will include various logging statements, and wish to compile this into a dependency which will be used by an Android application (and separately in standalone java/desktop applications)

The class looks like this:

package com.example.shared;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class ExampleClass {

    public static Logger logger = LogManager.getLogger(ExampleClass.class);
    
    public ExampleClass(){}
    
    public void printMessages(){
        logger.error("This is an error message from ExampleClass!");
        logger.warn("This is a warn message from ExampleClass!");
        logger.info("This is an info message from ExampleClass!");
        logger.debug("This is a debug message from ExampleClass!");
        logger.trace("This is a trace message from ExampleClass!");
    }
}

The dependency will be compiled with maven, with pom.xml as follows:

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <groupId>com.example</groupId>
    <artifactId>shared</artifactId>
    <version>1.0.0</version>
    <name>Shared</name>
    
    <properties>
        <maven.compiler.source>1.8</maven.compiler.source>
        <maven.compiler.target>1.8</maven.compiler.target>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
        <java.version>1.8</java.version>
    </properties>

    <dependencies>
        <dependency>
          <groupId>org.apache.logging.log4j</groupId>
          <artifactId>log4j-api</artifactId>
          <version>2.20.0</version>
        </dependency>
        <dependency>
          <groupId>org.apache.logging.log4j</groupId>
          <artifactId>log4j-core</artifactId>
          <version>2.20.0</version>
        </dependency>
  </dependencies>
</project>

To use this in my android project, I have enabled local maven repositories and imported the artefact along with log4j api/core and an android runtime implementation:

app/build.gradle

plugins {
    id 'com.android.application'
}

android {
    compileSdk 34
    buildToolsVersion "30.0.3"

    defaultConfig {
        applicationId "com.example.android"
        minSdk 26
        targetSdk 34
        versionCode 1
        versionName "1.0"

        testInstrumentationRunner "androidx.test.runner.AndroidJUnitRunner"
    }

    buildTypes {
        release {
            minifyEnabled false
            proguardFiles getDefaultProguardFile('proguard-android-optimize.txt'), 'proguard-rules.pro'
        }
    }
    compileOptions {
        sourceCompatibility JavaVersion.VERSION_1_8
        targetCompatibility JavaVersion.VERSION_1_8
    }

    packagingOptions {
        resources.excludes.add("META-INF/*")
        resources.excludes.add("serviceAccountKey*.json")
    }
}

dependencies {

    implementation 'androidx.appcompat:appcompat:1.6.1'
    implementation 'com.google.android.material:material:1.12.0'
    implementation 'androidx.constraintlayout:constraintlayout:2.1.4'

    implementation 'com.example:shared:1.0.0'

    implementation 'org.apache.logging.log4j:log4j-api:2.20.0'
    implementation 'org.apache.logging.log4j:log4j-core:2.20.0'
    runtimeOnly 'com.celeral:log4j2-android:1.0.0'
}

The log4j configuration I am trying to use (which should only print INFO lines) is provided in app/src/main/assets/log4j2.xml:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="INFO">
    <Appenders>
        <Console name="console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n" />
        </Console>
    </Appenders>

    <Loggers>
        <Root level="INFO">
            <AppenderRef ref="console" />
        </Root>
    </Loggers>
</Configuration>

My android application main activity is setup as below:

package com.example.android;

import androidx.appcompat.app.AppCompatActivity;

import android.os.Bundle;

import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.LogManager;

import com.example.shared.ExampleClass;

public class MainActivity extends AppCompatActivity {

    public static Logger logger = LogManager.getLogger(MainActivity.class);

    @Override
    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.activity_main);

        //Test logging from dependency
        ExampleClass ec = new ExampleClass();
        ec.printMessages();
    }
}

However, when I attempt to run my application and test the logging statements, the configuration is ignored and all logging levels are printed:

E/ExampleClass: This is an error message from ExampleClass!
W/ExampleClass: This is a warn message from ExampleClass!
I/ExampleClass: This is an info message from ExampleClass!
D/ExampleClass: This is a debug message from ExampleClass!
V/ExampleClass: This is a trace message from ExampleClass!

But if I remove runtimeOnly 'com.celeral:log4j2-android:1.0.0' from app/build.gradle, I am met with the error below:

W/System.err: ERROR StatusLogger Unable to load services for service class org.apache.logging.log4j.spi.Provider
W/System.err:  java.lang.NoSuchMethodError: No static method metafactory(Ljava/lang/invoke/MethodHandles$Lookup;Ljava/lang/String;Ljava/lang/invoke/MethodType;Ljava/lang/invoke/MethodType;Ljava/lang/invoke/MethodHandle;Ljava/lang/invoke/MethodType;)Ljava/lang/invoke/CallSite; in class Ljava/lang/invoke/LambdaMetafactory; or its super classes (declaration of 'java.lang.invoke.LambdaMetafactory' appears in /apex/com.android.art/javalib/core-oj.jar)
W/System.err:     at org.apache.logging.log4j.util.ServiceLoaderUtil.callServiceLoader(ServiceLoaderUtil.java:110)
W/System.err:     at org.apache.logging.log4j.util.ServiceLoaderUtil$ServiceLoaderSpliterator.<init>(ServiceLoaderUtil.java:146)
W/System.err:     at org.apache.logging.log4j.util.ServiceLoaderUtil.loadClassloaderServices(ServiceLoaderUtil.java:101)
W/System.err:     at org.apache.logging.log4j.util.ServiceLoaderUtil.loadServices(ServiceLoaderUtil.java:83)
W/System.err:     at org.apache.logging.log4j.util.ServiceLoaderUtil.loadServices(ServiceLoaderUtil.java:77)
W/System.err:     at org.apache.logging.log4j.util.ProviderUtil.<init>(ProviderUtil.java:67)
W/System.err:     at org.apache.logging.log4j.util.ProviderUtil.lazyInit(ProviderUtil.java:145)
W/System.err:     at org.apache.logging.log4j.util.ProviderUtil.hasProviders(ProviderUtil.java:129)
W/System.err:     at org.apache.logging.log4j.LogManager.<clinit>(LogManager.java:90)
W/System.err:     at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:598)
W/System.err:     at com.example.android.MainActivity.<clinit>(MainActivity.java:14)
W/System.err:     at java.lang.Class.newInstance(Native Method)
W/System.err:     at android.app.AppComponentFactory.instantiateActivity(AppComponentFactory.java:95)
W/System.err:     at androidx.core.app.CoreComponentFactory.instantiateActivity(CoreComponentFactory.java:44)
W/System.err:     at android.app.Instrumentation.newActivity(Instrumentation.java:1253)
W/System.err:     at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:3353)
W/System.err:     at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:3601)
W/System.err:     at android.app.servertransaction.LaunchActivityItem.execute(LaunchActivityItem.java:85)
W/System.err:     at android.app.servertransaction.TransactionExecutor.executeCallbacks(TransactionExecutor.java:135)
W/System.err:     at android.app.servertransaction.TransactionExecutor.execute(TransactionExecutor.java:95)
W/System.err:     at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2066)
W/System.err:     at android.os.Handler.dispatchMessage(Handler.java:106)
W/System.err:     at android.os.Looper.loop(Looper.java:223)
W/System.err:     at android.app.ActivityThread.main(ActivityThread.java:7656)
W/System.err:     at java.lang.reflect.Method.invoke(Native Method)
W/System.err:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:592)
W/System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:947)

Although I do get the error line printed:

W/System.err: ERROR ExampleClass This is an error message from ExampleClass!

Why does this not work as required?

Update 1: Someone has voted to close this as "Needs more focus". There is only one problem requiring an answer - I have amended the last statement to reflect this,

Final edit:

After the update to log4j v2.24.1 (and the removal of celeral log4j2-android runtime dependency) it is clearer now what has been happening.

Log4j has been unable to find/resolve the configuration provided in the assets directory, and thus no loggers are defined. By default, the loggers I attempt to use are set to Level.ERROR, hence why the single error line:

W/System.err: ERROR ExampleClass This is an error message from ExampleClass!

was still being logged. The previous log4j-android, when in use, would simply forward everything to android Log class, which logs all levels in the console (not what I wanted).

The issue I am left trying to resolve is why the configuration won't load


Solution

  • TL;DR Upgrade to version 2.24.0 of the Log4j API.

    Log4j API struggles to maintain compatibility with a lot of runtimes:

    The cause of your failure is the lack of a standard JDK 8 method in Android. The method call was introduces to fix a problem with our SecurityManager and JPMS support around version 2.18.0.

    It was removed in version 2.24.0, which should solve your problem.