Dynamically naming log4j log file - Works, but not without exception from setFile()

Question

I have a program that runs for individual customers. Each customer has an account code (we call it a start code). The account code is communicated to the program via a commandline parameter. I'm getting the following exception thrown back at me, which by the way, doesn't cause a program crash, it goes happily on its way. I want to separate the logging by customer account, which seems to be working. My log file will get created to "Balancer_990004.log" and log messages certainly build up to the point of Balancer_990004.log.7 being created, BUT, not without this exception. Scratching my head on this one. I've included log4j.properties bits and bits of code.

log4j:ERROR setFile(null,true) call failed.
java.io.FileNotFoundException:  (A file or directory in the path name does not exist.)
 at java.io.FileOutputStream.openAppend(Native Method)
 at java.io.FileOutputStream.<init>(FileOutputStream.java:203)
 at java.io.FileOutputStream.<init>(FileOutputStream.java:127)
 at org.apache.log4j.FileAppender.setFile(FileAppender.java:294)
 at org.apache.log4j.RollingFileAppender.setFile(RollingFileAppender.java:207)
 at org.apache.log4j.FileAppender.activateOptions(FileAppender.java:165)
 at org.apache.log4j.config.PropertySetter.activate(PropertySetter.java:307)
 at org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:172)
 at org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:104)
 at org.apache.log4j.PropertyConfigurator.parseAppender(PropertyConfigurator.java:809)
 at org.apache.log4j.PropertyConfigurator.parseCategory(PropertyConfigurator.java:735)
 at org.apache.log4j.PropertyConfigurator.parseCatsAndRenderers(PropertyConfigurator.java:639)
 at org.apache.log4j.PropertyConfigurator.doConfigure(PropertyConfigurator.java:504)
 at org.apache.log4j.PropertyConfigurator.doConfigure(PropertyConfigurator.java:547)
 at org.apache.log4j.helpers.OptionConverter.selectAndConfigure(OptionConverter.java:483)
 at org.apache.log4j.LogManager.<clinit>(LogManager.java:127)
 at java.lang.J9VMInternals.initializeImpl(Native Method)
 at java.lang.J9VMInternals.initialize(J9VMInternals.java:200)
 at org.apache.log4j.Logger.getLogger(Logger.java:117)
 at Balancer.<init>(Balancer.java:292)
 at Balancer.main(Balancer.java:2370)

*** Sample bit from log4j.properties.  The name of the Java program in question is "Balancer" ***

log4j.rootLogger=debug, devnull        
log4j.logger.Balancer=info, BalancerLog

log4j.appender.BalancerLog=org.apache.log4j.RollingFileAppender
log4j.appender.BalancerLog.File=${balancer.log}                
log4j.appender.BalancerLog.MaxFileSize=10000KB                                
log4j.appender.BalancerLog.MaxBackupIndex=10                                  
log4j.appender.BalancerLog.layout=org.apache.log4j.PatternLayout              
log4j.appender.BalancerLog.layout.ConversionPattern=%5p %d [%t] (%F:%L) - %m%n

*** How I'm building my log filename and initializing the Logger ***

public class Balancer {
    static Logger log = null;
    ....

// In constructor...

StringBuilder logName = new StringBuilder("Balancer_");
logName.append(startCode.toString());
logName.append(".log");

// Hopefully in log4j.properties our appender section contains this line:
// log4j.appender.BalancerLog.File=${balancer.log}.  This ${} bit means to get a system property to set the log file
// name.  We set that system property here, then initialize the Logger object.
System.setProperty("balancer.log", logName.toString()); 

// This is line 292 in the exception trace.
log = Logger.getLogger(Balancer.class);

Answer 1

It looks like you're trying to access the log before the environment variable is set.

This code will fail without making a single log call:

class Whatever {
    private static Logger log = Logger.getLogger(Whatever.class)
    public Whatever() {
        System.setProperty("balancer.log","C:\\log.txt")
    }
}

So do this:

class Whatever {
    private static Logger log = null
    public Whatever() {
        System.setProperty("balancer.log","C:\\log.txt")
        log = Logger.getLogger(Whatever.class)
    }
}

The basic idea is not to do anything at all with the logging system before the environment variables are set correctly.

Answer 2

I found out why I was getting the exception from setFile(). Maybe this isn't supported in the .properties log4j configuration and I have to use the XML method, but if I set a ".File" property with the recommended syntax for using a system property, I get the error (even though it goes ahead and works anyway). For instance:

log4j.appender.BalancerLog=org.apache.log4j.RollingFileAppender
log4j.appender.BalancerLog.File=${balancer.log}
log4j.appender.BalancerLog.MaxFileSize=10000KB
log4j.appender.BalancerLog.MaxBackupIndex=10
log4j.appender.BalancerLog.layout=org.apache.log4j.PatternLayout
log4j.appender.BalancerLog.layout.ConversionPattern=%5p %d [%t] (%F:%L) - %m%n

Gives me the error. Go back to the standard:

log4j.appender.BalancerLog=org.apache.log4j.RollingFileAppender
log4j.appender.BalancerLog.File=Balancer.log
log4j.appender.BalancerLog.MaxFileSize=10000KB
log4j.appender.BalancerLog.MaxBackupIndex=10
log4j.appender.BalancerLog.layout=org.apache.log4j.PatternLayout
log4j.appender.BalancerLog.layout.ConversionPattern=%5p %d [%t] (%F:%L) - %m%n

and "alle ist klar herr kommissar". So, I am using this code block for the moment until I work out a better solution. For the moment the configuration will rely on the appender name for this program being "BalancerLog".

// We are dynamically building the name of our log file, if the log4j.properties file is set correctly.
// Should look like "Balancer_997232.log" or any other startcode.  Log file will be created in whatever the current
// IFS directory is when the job gets kicked off.
StringBuilder logName = new StringBuilder("Balancer_");
logName.append(startCode.toString());
logName.append(".log");

// This isn't perfect I guess and am sure it will see revisions in the future.
// What I'm doing here is asking the log object if it has an appender called BalancerLog. Look in 
// the log4j.properties file.  You should see a line similiar to :
// log4j.logger.Balancer=info, BalancerLog
// We're getting the the appender object and setting it's file name to be what was built above.
// We don't want to use the default log file name.  You'll see it in the log4j.properties file like:
// log4j.appender.BalancerLog.File=Balancer.log
try {
    Appender appender = log.getAppender("BalancerLog");
    if (appender != null && appender instanceof org.apache.log4j.FileAppender) {
        FileAppender roll = (FileAppender) appender;
        roll.setFile(logName.toString());
        roll.activateOptions();
    }
}
catch (Exception e) {
    System.out.println(e);
}

Feel free to pick this apart and make any suggestions. BTW, using log4j 1.2 here.

Answer 3

If you can switch to logback, I suggest you use SiftingAppender instead. This kind of tweaking with log4j is unnatural.