[logback-user] logback configuration variable substitution: Exception during parsing (NumberFormatException)

[Gerrit Hübbers]

In my environment, there are OS environment variables called
OPENSHIFT_DB_HOST and OPENSHIFT_DB_PORT. These variables can be used
to build the address pointing to a MySQL server. Both variables have
sensible values (e.g. OPENSHIFT_DB_HOST = 127.0.0.1 ....
OPENSHIFT_DB_PORT = 3306 )

In a logback XML configuration file, I'm configuring a DBAppender. I'm
using logback's variable substitution in the following line.

<url>jdbc:mysql://${OPENSHIFT_DB_HOST}:${OPENSHIFT_DB_PORT}/mydb?useUnicode=true&characterEncoding=UTF-8</url>

As you can see, I'm using both OS environment variables to build the
address, separated by a colon (":"). The resulting URL should
therefore look like
"jdbc:mysql://127.0.0.1:3306/mydb?useUnicode=true&characterEncoding=UTF-8"

When logback parses my logback XML configuration file, I get the
following exception:

~~~Begin: Exception stack trace~~~
18:44:06,288 |-INFO in ch.qos.logback.core.joran.action.AppenderAction
- About to instantiate appender of type
[ch.qos.logback.classic.db.DBAppender]
18:44:06,299 |-INFO in ch.qos.logback.core.joran.action.AppenderAction
- Naming appender as [db]
18:44:07,180 |-WARN in
ch.qos.logback.core.db.DataSourceConnectionSource at 12c662b - Could not
get a connection to discover the dialect to use.
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException:
Cannot load connection class because of underlying exceptio

                          n: 'java.lang.NumberFormatException: For
input string: "${OPENSHIFT_DB_PORT}"'.
        at com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException:
Cannot load connection class because of underlying exception:
'java.lang.NumberFormatException: For input string:
"${OPENSHIFT_DB_PORT}"'.
        at      at
sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at      at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
        at      at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at      at
java.lang.reflect.Constructor.newInstance(Constructor.java:525)
        at      at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
        at      at com.mysql.jdbc.Util.getInstance(Util.java:386)
        at      at
com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1014)
        at      at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:988)
        at      at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:974)
        at      at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:919)
        at      at
com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:343)
        at      at
com.mysql.jdbc.jdbc2.optional.MysqlDataSource.getConnection(MysqlDataSource.java:443)
        at      at
com.mysql.jdbc.jdbc2.optional.MysqlDataSource.getConnection(MysqlDataSource.java:141)
        at      at
com.mysql.jdbc.jdbc2.optional.MysqlDataSource.getConnection(MysqlDataSource.java:111)
        at      at
ch.qos.logback.core.db.DataSourceConnectionSource.getConnection(DataSourceConnectionSource.java:72)
        at      at
ch.qos.logback.core.db.DataSourceConnectionSource.start(DataSourceConnectionSource.java:46)
        at      at
ch.qos.logback.core.joran.action.NestedComplexPropertyIA.end(NestedComplexPropertyIA.java:167)
        at      at
ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:318)
        at      at
ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:197)
        at      at
ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:183)
        at      at
ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:157)
        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:143)
        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:106)
        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:56)
        at      at
ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
        at      at
ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:148)
        at      at
org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:84)
        at      at
org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:54)
        at      at org.slf4j.LoggerFactory.bind(LoggerFactory.java:128)
        at      at
org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:107)
        at      at
org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:295)
        at      at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:269)
        at      at org.eclipse.jetty.util.log.Slf4jLog.<init>(Slf4jLog.java:38)
        at      at org.eclipse.jetty.util.log.Slf4jLog.<init>(Slf4jLog.java:32)
        at      at
sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at      at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
        at      at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at      at
java.lang.reflect.Constructor.newInstance(Constructor.java:525)
        at      at java.lang.Class.newInstance0(Class.java:372)
        at      at java.lang.Class.newInstance(Class.java:325)
        at      at org.eclipse.jetty.util.log.Log.initialized(Log.java:161)
        at      at org.eclipse.jetty.util.log.Log.getLogger(Log.java:435)
        at      at org.eclipse.jetty.util.log.Log.getLogger(Log.java:425)
        at      at
org.eclipse.jetty.xml.XmlConfiguration.<clinit>(XmlConfiguration.java:72)
        at      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at      at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at      at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at      at java.lang.reflect.Method.invoke(Method.java:601)
        at      at org.eclipse.jetty.start.Main.invokeMain(Main.java:468)
        at      at org.eclipse.jetty.start.Main.start(Main.java:616)
        at      at org.eclipse.jetty.start.Main.main(Main.java:92)
Caused by: java.lang.NumberFormatException: For input string:
"${OPENSHIFT_DB_PORT}"
        at      at
java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)
        at      at java.lang.Integer.parseInt(Integer.java:481)
        at      at java.lang.Integer.parseInt(Integer.java:527)
        at      at
com.mysql.jdbc.NonRegisteringDriver.port(NonRegisteringDriver.java:866)
        at      at
com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:334)
        at      ... 41 common frames omitted
~~~End: Exception stack trace~~~

As you can see, logback seems to have not substituted the second
variable called ${OPENSHIFT_DB_PORT}, and instead took the raw string
"${OPENSHIFT_DB_PORT}" to pass it to the underlying URL parser.

Can it be that
* logback has problems substituting two (and more?) variables in a
single expression?
* logback has problems when two variables are separated by a colon?

Cheers