Logging/config recomendation

[gitblit]

I've got a small project setup with SLF4J & Logback and c3p0.

I've created a c3p0.properties file in the root of my app's classpath:

com.mchange.v2.log.MLog = slf4j
c3p0.maxPoolSize=30
c3p0.minPoolSize=10

I'm creating a pooled data source:

ds_unpooled = DataSources.unpooledDataSource(jdbcUrl, jdbcUsername, jdbcPassword);
ds_pooled = DataSources.pooledDataSource(ds_unpooled);

c3po is generating stacktrace noise which I believe is benign, but clutters my logs & console - especially during unit tests. Examples...

java.io.FileNotFoundException: Resource not found at path '/mchange-commons.properties'.
    at com.mchange.v2.cfg.BasicPropertiesConfigSource.propertiesFromSource(BasicPropertiesConfigSource.java:64) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.cfg.BasicMultiPropertiesConfig.firstInit(BasicMultiPropertiesConfig.java:185) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.cfg.BasicMultiPropertiesConfig.<init>(BasicMultiPropertiesConfig.java:110) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.cfg.ConfigUtils.read(ConfigUtils.java:63) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.cfg.ConfigUtils.readVmConfig(ConfigUtils.java:115) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.cfg.MLogConfigSource.readVmConfig(MLogConfigSource.java:46) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.log.MLogConfig.refresh(MLogConfig.java:59) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.log.MLog.refreshConfig(MLog.java:59) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.log.MLog.<clinit>(MLog.java:51) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.c3p0.DataSources.<clinit>(DataSources.java:72) ~[c3p0-0.9.5.jar:0.9.5]

java.io.FileNotFoundException: Resource not found at path '/mchange-log.properties'.
    at com.mchange.v2.cfg.BasicPropertiesConfigSource.propertiesFromSource(BasicPropertiesConfigSource.java:64) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.cfg.BasicMultiPropertiesConfig.firstInit(BasicMultiPropertiesConfig.java:185) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.cfg.BasicMultiPropertiesConfig.<init>(BasicMultiPropertiesConfig.java:110) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.cfg.ConfigUtils.read(ConfigUtils.java:63) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.cfg.MConfig$CSManager.recreateFromKey(MConfig.java:153) ~[mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v1.cachedstore.NoCleanupCachedStore.find(NoCleanupCachedStore.java:63) [mchange-commons-java-0.2.9.jar:0.2.9]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_31]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_31]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_31]
    at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_31]
    at com.mchange.v1.lang.Synchronizer$1.invoke(Synchronizer.java:58) [mchange-commons-java-0.2.9.jar:0.2.9]
    at com.sun.proxy.$Proxy2.find(Unknown Source) [na:na]
    at com.mchange.v2.cfg.MConfig.readVmConfig(MConfig.java:75) [mchange-commons-java-0.2.9.jar:0.2.9]
    at com.mchange.v2.c3p0.cfg.C3P0Config.findLibraryMultiPropertiesConfig(C3P0Config.java:157) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.c3p0.cfg.C3P0Config.<clinit>(C3P0Config.java:143) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.c3p0.impl.DriverManagerDataSourceBase.<init>(DriverManagerDataSourceBase.java:45) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.c3p0.DriverManagerDataSource.<init>(DriverManagerDataSource.java:90) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.c3p0.DriverManagerDataSource.<init>(DriverManagerDataSource.java:86) [c3p0-0.9.5.jar:0.9.5]
    at com.mchange.v2.c3p0.DataSources.unpooledDataSource(DataSources.java:138) [c3p0-0.9.5.jar:0.9.5]

These exceptions are repeated a couple times each. I could play with log levels and package filtering but I'm wondering if these exceptions are inadvertent or planned.

[swaldman]

Hi,

These stack traces are, alas, advertent. c3p0 (many com.mchange.*) libraries' logging style is to log a lot, to err on the side of verbosity, at DEBUG levels. For normal use, they are intended to be logged at INFO. You'll find c3p0 to be very verbose in general if you let it log at DEBUG.

c3p0 looks for config information is a series of standard places on initialization, the majority of which are never used in most installations. So, the config library encounters a bunch of FileNotFoundExceptions which are expected and harmless, but per the err verbosely philosophy, are logged at DEBUG. This is arguably an error even in erring verbose, you are not the only one to complain. Maybe those should be restricted only to a TRACE/FINEST level, or omitted entirely. But that's the deal for now, it's just extra information logged about what's going on at a DEBUG log level. Set the logging level for com.mchange.* to INFO (and maybe selectively set the threshold lower of there are com.mchange libraries you want verbosity from) and things will be much better.

[gitblit]

Ok, logback config to the rescue. Thanks for the help.