JDBC Appender log4j2 error

Question

I am trying to log error into PostgreSQL database using log4j2. Though I am able to do that, I have a doubt.

(Case:0) If I try to run the code shown as it is, it doesn't give any error.

(Case:1) But if I uncomment the line 'System.out.println(Utils.hello);' it shows null pointer exception. I think this is mostly because the logger is null in Utils Class. I am initializing it but don't know why this is happening.

I tried debugging this (in case:1) and found out that the logger variable is getting initialized and whenever the control reaches the 'System.out.println(Utils.hello)', it becomes null. I just want to know whats happening here (not solution for how to log to DB). Whats actually happening inside for the above 2 cases and why 'case:1' is giving error. Thanks in advance. :-)

Main function:

public class Main {
public static void main(String[] args)
        throws InstantiationException, IllegalAccessException, ClassNotFoundException, IOException {
    System.out.println("aa");
    System.out.println(Utils.class);
    //System.out.println(Utils.hello);
    if (args.length == 0) {
        ...
    } else {
        Processing procObj = new Processing();      
    }
}

Utils Class:

public class Utils {

public static Properties prop;
static InputStream input;
public static org.apache.logging.log4j.Logger logger= LogManager.getLogger(Utils.class);
public static int hello = 10;

public static void initProperties() {
    System.out.println(logger);
    logger.traceEntry();
    prop = new Properties();
    input = null;
    try {
        input = new FileInputStream(prop.getClass().getResource("/config.properties").getPath());
        prop.load(input);
        logger.info("Successully completed initialization process.");
    } catch (IOException e) {
        logger.error("{} Error initializing from properties file. <{}>",Utils.prop.getProperty("utility"), e);
    } catch (Exception e) {
        logger.error("{} Error initializing from properties file. <{}>",Utils.prop.getProperty("utility"), e);
    }
}
}

ConnectionFactory Class:

  public class ConnectionFactory  implements ConnectionSource{
 private static interface Singleton {
  final ConnectionFactory INSTANCE = new ConnectionFactory();
 }

 private final DataSource dataSource;

 public ConnectionFactory() {
     Utils.initProperties();
  Properties properties = new Properties();
  properties.setProperty("user", "user");
  properties.setProperty("password", "password");

  GenericObjectPool pool = new GenericObjectPool();

  DriverManagerConnectionFactory connectionFactory = new DriverManagerConnectionFactory(
   "url", properties);
  new PoolableConnectionFactory(connectionFactory, pool, null,
    "SELECT 1", 3, false, false,
    Connection.TRANSACTION_READ_COMMITTED);

  this.dataSource = new PoolingDataSource(pool);
 }

 public static Connection getDatabaseConnection() throws SQLException {
  return Singleton.INSTANCE.dataSource.getConnection();
 }

@Override
public Connection getConnection() throws SQLException {
    return Singleton.INSTANCE.dataSource.getConnection();
}
}

Processing Class:

public class Processing {
    String query;
    private static org.apache.logging.log4j.Logger logger = LogManager.getLogger(Processing.class);

    public Processing() {
        Utils.initProperties();
        ....
    }
    .....
    .....
    }

The error is:

  2017-06-09 16:38:32,318 main ERROR JdbcDatabaseManager JdbcManager{name=databaseAppender, bufferSize=0, tableName=error, columnConfigs=[{ name=key, layout=null, literal=-100, timestamp=false }, { name=create_date, layout=null, literal=null, timestamp=true }, { name=create_user, layout=%logger, literal=null, timestamp=false }, { name=error_message, layout=%msg, literal=null, timestamp=false }], columnMappings=[]} Could not perform database startup operations: java.sql.SQLException: Failed to obtain connection from factory method. java.sql.SQLException: Failed to obtain connection from factory method.
    at org.apache.logging.log4j.core.appender.db.jdbc.FactoryMethodConnectionSource$1.getConnection(FactoryMethodConnectionSource.java:108)
    at org.apache.logging.log4j.core.appender.db.jdbc.FactoryMethodConnectionSource.getConnection(FactoryMethodConnectionSource.java:54)
    at org.apache.logging.log4j.core.appender.db.jdbc.JdbcDatabaseManager.startupInternal(JdbcDatabaseManager.java:74)
    at org.apache.logging.log4j.core.appender.db.AbstractDatabaseManager.startup(AbstractDatabaseManager.java:65)
    at org.apache.logging.log4j.core.appender.db.AbstractDatabaseAppender.start(AbstractDatabaseAppender.java:89)
    at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:260)
    at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:545)
    at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:617)
    at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:634)
    at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:229)
    at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:152)
    at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:45)
    at org.apache.logging.log4j.LogManager.getContext(LogManager.java:194)
    at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:551)
    at mypackage.Utils.<clinit>(Utils.java:19)
    at java.lang.Class.forName0(Native Method)
    at java.lang.Class.forName(Class.java:348)
    at mypackage.Main.main(Main.java:18)
Caused by: java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.logging.log4j.core.appender.db.jdbc.FactoryMethodConnectionSource$1.getConnection(FactoryMethodConnectionSource.java:106)
    ... 17 more
Caused by: java.lang.ExceptionInInitializerError
    at mypackage.ConnectionFactory.getDatabaseConnection(ConnectionFactory.java:40)
    ... 22 more
Caused by: java.lang.NullPointerException
    at mypackage.Utils.initProperties(Utils.java:45)
    at mypackage.ConnectionFactory.<init>(ConnectionFactory.java:23)
    at mypackage.ConnectionFactory$Singleton.<clinit>(ConnectionFactory.java:17)
    ... 23 more

Vikas Sachdeva Vikas Sachdeva · Accepted Answer · 2017-06-10T15:34:01

Your code is using very complex logic and probably wrong logic for initializing Logger and due this this logic, you are getting such error.

Following things are happening behind the scene when you uncomment System.out.println(Utils.hello); line -

main() method execution starts.
Now, when execution come to System.out.println(Utils.hello); line, Java class loader tries to load Utils class for accessing hello static variable.
During the loading of Utils class, all static variables are initialized including logger variable.
Now, since, you are using JDBC appender for log4j2 configuration, LogManager tries to get database connection by calling ConnectionFactory.getDatabaseConnection() method.
In your ConnectionFactory.getDatabaseConnection() method call, constructor of this singleton class is called.
In constructor body, you are calling Utils.initProperties() method.
In Utils.initProperties() method, you are using logger static variable but, in actual, your logger static variable is still not initialized and due to this, you got NullPointerException when you use logger in this method.

Now, to solve this issue, you should change your logic to break this chain. One solution is not to use Logger in Utils class. However, still, you need check other possible cases.

JDBC Appender log4j2 error

1 Answers