manual killbill installation problem

[Алексей Васильев]

Hi everybody,

I tries to install killbill manually on ubuntu 16.04.

Java 1.8, jruby 1.7.24

Killbill installed with kpm as per http://docs.killbill.io/0.16/getting_started.html#installation

Mysql server installed, databases for killbill/kaui created

http://docs.killbill.io/0.18/ddl.sql

https://raw.github.com/killbill/killbill-admin-ui/master/db/ddl.sql

imported.

catalina.properties configured:

# Kill Bill properties

org.killbill.dao.url=jdbc:mysql://127.0.0.1:3306/killbill

org.killbill.dao.user=root

org.killbill.dao.password=XXXXXX

org.killbill.billing.osgi.dao.url=jdbc:mysql://127.0.0.1:3306/killbill

org.killbill.billing.osgi.dao.user=root

org.killbill.billing.osgi.dao.password=XXXXXXX

# Kaui properties

kaui.db.adapter=jdbcmysql

kaui.db.url=jdbc:mysql://localhost/kaui

kaui.db.username=root

kaui.db.password=XXXXXXX

tomcat launched, trying to open

http://54.91.110.81:8080/kaui/

ok, asked for login and pass.

admin/password entered.

after ~3-4 min of waiting I got "We're sorry, but something went wrong."

Logs:

root@ip-172-31-52-220:~/killbill# ./bin/catalina.sh run

Using CATALINA_BASE:   /home/ubuntu/killbill

Using CATALINA_HOME:   /home/ubuntu/killbill

Using CATALINA_TMPDIR: /home/ubuntu/killbill/temp

Using JRE_HOME:        /usr

Using CLASSPATH:       /home/ubuntu/killbill/bin/bootstrap.jar:/home/ubuntu/killbill/bin/tomcat-juli.jar

OpenJDK 64-Bit Server VM warning: ignoring option PermSize=512m; support was removed in 8.0

OpenJDK 64-Bit Server VM warning: ignoring option MaxPermSize=1G; support was removed in 8.0

Dec 08, 2016 10:45:54 AM org.apache.catalina.core.AprLifecycleListener init

INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib

Dec 08, 2016 10:45:54 AM org.apache.coyote.AbstractProtocol init

INFO: Initializing ProtocolHandler ["http-bio-8080"]

Dec 08, 2016 10:45:54 AM org.apache.coyote.AbstractProtocol init

INFO: Initializing ProtocolHandler ["ajp-bio-8009"]

Dec 08, 2016 10:45:54 AM org.apache.catalina.startup.Catalina load

INFO: Initialization processed in 374 ms

Dec 08, 2016 10:45:54 AM org.apache.catalina.core.StandardService startInternal

INFO: Starting service Catalina

Dec 08, 2016 10:45:54 AM org.apache.catalina.core.StandardEngine startInternal

INFO: Starting Servlet Engine: Apache Tomcat/7.0.42

Dec 08, 2016 10:45:54 AM org.apache.catalina.startup.HostConfig deployDescriptor

INFO: Deploying configuration descriptor /home/ubuntu/killbill/conf/Catalina/localhost/ROOT.xml

2016-12-08T10:45:57,226+0000 lvl='INFO', log='DefaultKillbillConfigSource', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Overwrite of user.timezone system property with Etc/UTC may break database serialization of date. Kill Bill will overwrite to GMT

2016-12-08T10:45:57,231+0000 lvl='WARN', log='DefaultKillbillConfigSource', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', System property java.security.egd has not been set, this may cause some requests to hang because of a lack of entropy. You should probably set it to 'file:/dev/./urandom'

2016-12-08T10:45:57,245+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.server.http.gzip] on [org.killbill.billing.server.config.KillbillServerConfig#isConfiguredToReturnGZIPResponses()]

2016-12-08T10:45:57,248+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [true] for [org.killbill.server.multitenant] on [org.killbill.billing.server.config.KillbillServerConfig#isMultiTenancyEnabled()]

2016-12-08T10:45:57,249+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [http://127.0.0.1:8080] for [org.killbill.server.baseUrl] on [org.killbill.billing.server.config.KillbillServerConfig#getBaseUrl()]

2016-12-08T10:45:57,250+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.server.test.mode] on [org.killbill.billing.server.config.KillbillServerConfig#isTestModeEnabled()]

2016-12-08T10:45:57,309+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.metrics.graphite] on [org.killbill.billing.server.config.MetricsGraphiteConfig#isGraphiteReportingEnabled()]

2016-12-08T10:45:57,310+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [30] for [org.killbill.metrics.graphite.interval] on [org.killbill.billing.server.config.MetricsGraphiteConfig#getInterval()]

2016-12-08T10:45:57,310+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [killbill] for [org.killbill.metrics.graphite.prefix] on [org.killbill.billing.server.config.MetricsGraphiteConfig#getPrefix()]

2016-12-08T10:45:57,311+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [localhost] for [org.killbill.metrics.graphite.host] on [org.killbill.billing.server.config.MetricsGraphiteConfig#getHostname()]

2016-12-08T10:45:57,312+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [2003] for [org.killbill.metrics.graphite.port] on [org.killbill.billing.server.config.MetricsGraphiteConfig#getPort()]

2016-12-08T10:45:57,711+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [1] for [org.killbill.dao.minIdle] on [org.killbill.commons.jdbi.guice.DaoConfig#getMinIdle()]

2016-12-08T10:45:57,712+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [60m] for [org.killbill.dao.idleMaxAge] on [org.killbill.commons.jdbi.guice.DaoConfig#getIdleMaxAge()]

2016-12-08T10:45:57,713+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [0m] for [org.killbill.dao.maxConnectionAge] on [org.killbill.commons.jdbi.guice.DaoConfig#getMaxConnectionAge()]

2016-12-08T10:45:57,713+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [5m] for [org.killbill.dao.idleConnectionTestPeriod] on [org.killbill.commons.jdbi.guice.DaoConfig#getIdleConnectionTestPeriod()]

2016-12-08T10:45:57,724+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.dao.connectionInitSql] on [org.killbill.commons.jdbi.guice.DaoConfig#getConnectionInitSql()]

2016-12-08T10:45:57,726+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [500] for [org.killbill.dao.prepStmtCacheSize] on [org.killbill.commons.jdbi.guice.DaoConfig#getPreparedStatementsCacheSize()]

2016-12-08T10:45:57,727+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [2048] for [org.killbill.dao.prepStmtCacheSqlLimit] on [org.killbill.commons.jdbi.guice.DaoConfig#getPreparedStatementsCacheSqlLimit()]

2016-12-08T10:45:57,728+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [true] for [org.killbill.dao.cachePrepStmts] on [org.killbill.commons.jdbi.guice.DaoConfig#isPreparedStatementsCacheEnabled()]

2016-12-08T10:45:57,728+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [true] for [org.killbill.dao.useServerPrepStmts] on [org.killbill.commons.jdbi.guice.DaoConfig#isServerSidePreparedStatementsEnabled()]

2016-12-08T10:45:57,729+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.dao.dataSourceClassName] on [org.killbill.commons.jdbi.guice.DaoConfig#getDataSourceClassName()]

2016-12-08T10:45:57,729+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.dao.driverClassName] on [org.killbill.commons.jdbi.guice.DaoConfig#getDriverClassName()]

2016-12-08T10:45:57,729+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [4.0] for [org.killbill.dao.mysqlServerVersion] on [org.killbill.commons.jdbi.guice.DaoConfig#getMySQLServerVersion()]

2016-12-08T10:45:57,730+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [DEBUG] for [org.killbill.dao.logLevel] on [org.killbill.commons.jdbi.guice.DaoConfig#getLogLevel()]

2016-12-08T10:45:57,730+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [HIKARICP] for [org.killbill.dao.poolingType] on [org.killbill.commons.jdbi.guice.DaoConfig#getConnectionPoolingType()]

2016-12-08T10:45:57,731+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [10s] for [org.killbill.dao.healthCheckConnectionTimeout] on [org.killbill.commons.jdbi.guice.DaoConfig#getHealthCheckConnectionTimeout()]

2016-12-08T10:45:57,731+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [50ms] for [org.killbill.dao.healthCheckExpected99thPercentile] on [org.killbill.commons.jdbi.guice.DaoConfig#getHealthCheckExpected99thPercentile()]

2016-12-08T10:45:57,732+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning value [jdbc:mysql://127.0.0.1:3306/killbill] for [org.killbill.dao.url] on [org.killbill.commons.jdbi.guice.DaoConfig#getJdbcUrl()]

2016-12-08T10:45:57,732+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning value [root] for [org.killbill.dao.user] on [org.killbill.commons.jdbi.guice.DaoConfig#getUsername()]

2016-12-08T10:45:57,733+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [10s] for [org.killbill.dao.connectionTimeout] on [org.killbill.commons.jdbi.guice.DaoConfig#getConnectionTimeout()]

2016-12-08T10:45:57,733+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [100] for [org.killbill.dao.maxActive] on [org.killbill.commons.jdbi.guice.DaoConfig#getMaxActive()]

2016-12-08T10:45:57,733+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning value [********] for [org.killbill.dao.password] on [org.killbill.commons.jdbi.guice.DaoConfig#getPassword()]

2016-12-08T10:45:57,782+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.persistent.bus.${instanceName}.off] on [org.killbill.bus.api.PersistentBusConfig#isProcessingOff()]

2016-12-08T10:45:57,782+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [30] for [org.killbill.persistent.bus.${instanceName}.nbThreads] on [org.killbill.bus.api.PersistentBusConfig#geMaxDispatchThreads()]

2016-12-08T10:45:57,783+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [30000] for [org.killbill.persistent.bus.${instanceName}.queue.capacity] on [org.killbill.bus.api.PersistentBusConfig#getEventQueueCapacity()]

2016-12-08T10:45:57,783+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [bus_events] for [org.killbill.persistent.bus.${instanceName}.tableName] on [org.killbill.bus.api.PersistentBusConfig#getTableName()]

2016-12-08T10:45:57,784+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [bus_events_history] for [org.killbill.persistent.bus.${instanceName}.historyTableName] on [org.killbill.bus.api.PersistentBusConfig#getHistoryTableName()]

2016-12-08T10:45:57,784+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.persistent.bus.${instanceName}.inMemory] on [org.killbill.bus.api.PersistentBusConfig#isInMemory()]

2016-12-08T10:45:57,785+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [5m] for [org.killbill.persistent.bus.${instanceName}.claim.time] on [org.killbill.bus.api.PersistentBusConfig#getClaimedTime()]

2016-12-08T10:45:57,785+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [3000] for [org.killbill.persistent.bus.${instanceName}.sleep] on [org.killbill.bus.api.PersistentBusConfig#getPollingSleepTimeMs()]

2016-12-08T10:45:57,786+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [3] for [org.killbill.persistent.bus.${instanceName}.max.failure.retry] on [org.killbill.bus.api.PersistentBusConfig#getMaxFailureRetries()]

2016-12-08T10:45:57,786+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [10] for [org.killbill.persistent.bus.${instanceName}.claimed] on [org.killbill.bus.api.PersistentBusConfig#getMaxEntriesClaimed()]

2016-12-08T10:45:57,791+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [STICKY_EVENTS] for [org.killbill.persistent.bus.${instanceName}.queue.mode] on [org.killbill.bus.api.PersistentBusConfig#getPersistentQueueMode()]

2016-12-08T10:45:57,798+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.persistent.bus.${instanceName}.off] on [org.killbill.bus.api.PersistentBusConfig#isProcessingOff()]

2016-12-08T10:45:57,798+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [30] for [org.killbill.persistent.bus.${instanceName}.nbThreads] on [org.killbill.bus.api.PersistentBusConfig#geMaxDispatchThreads()]

2016-12-08T10:45:57,799+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [30000] for [org.killbill.persistent.bus.${instanceName}.queue.capacity] on [org.killbill.bus.api.PersistentBusConfig#getEventQueueCapacity()]

2016-12-08T10:45:57,799+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning value [bus_ext_events] for [org.killbill.persistent.bus.external.tableName] on [org.killbill.bus.api.PersistentBusConfig#getTableName()]

2016-12-08T10:45:57,800+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning value [bus_ext_events_history] for [org.killbill.persistent.bus.external.historyTableName] on [org.killbill.bus.api.PersistentBusConfig#getHistoryTableName()]

2016-12-08T10:45:57,800+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.persistent.bus.${instanceName}.inMemory] on [org.killbill.bus.api.PersistentBusConfig#isInMemory()]

2016-12-08T10:45:57,800+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [5m] for [org.killbill.persistent.bus.${instanceName}.claim.time] on [org.killbill.bus.api.PersistentBusConfig#getClaimedTime()]

2016-12-08T10:45:57,801+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [3000] for [org.killbill.persistent.bus.${instanceName}.sleep] on [org.killbill.bus.api.PersistentBusConfig#getPollingSleepTimeMs()]

2016-12-08T10:45:57,801+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [3] for [org.killbill.persistent.bus.${instanceName}.max.failure.retry] on [org.killbill.bus.api.PersistentBusConfig#getMaxFailureRetries()]

2016-12-08T10:45:57,801+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [10] for [org.killbill.persistent.bus.${instanceName}.claimed] on [org.killbill.bus.api.PersistentBusConfig#getMaxEntriesClaimed()]

2016-12-08T10:45:57,802+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [STICKY_EVENTS] for [org.killbill.persistent.bus.${instanceName}.queue.mode] on [org.killbill.bus.api.PersistentBusConfig#getPersistentQueueMode()]

2016-12-08T10:45:57,805+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.notificationq.${instanceName}.notification.off] on [org.killbill.notificationq.api.NotificationQueueConfig#isProcessingOff()]

2016-12-08T10:45:57,805+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [10] for [org.killbill.notificationq.${instanceName}.notification.nbThreads] on [org.killbill.notificationq.api.NotificationQueueConfig#geMaxDispatchThreads()]

2016-12-08T10:45:57,806+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [100] for [org.killbill.notificationq.${instanceName}.queue.capacity] on [org.killbill.notificationq.api.NotificationQueueConfig#getEventQueueCapacity()]

2016-12-08T10:45:57,806+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [notifications] for [org.killbill.notificationq.${instanceName}.tableName] on [org.killbill.notificationq.api.NotificationQueueConfig#getTableName()]

2016-12-08T10:45:57,807+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [notifications_history] for [org.killbill.notificationq.${instanceName}.historyTableName] on [org.killbill.notificationq.api.NotificationQueueConfig#getHistoryTableName()]

2016-12-08T10:45:57,807+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.notificationq.${instanceName}.inMemory] on [org.killbill.notificationq.api.NotificationQueueConfig#isInMemory()]

2016-12-08T10:45:57,808+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [5m] for [org.killbill.notificationq.${instanceName}.claim.time] on [org.killbill.notificationq.api.NotificationQueueConfig#getClaimedTime()]

2016-12-08T10:45:57,808+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [3000] for [org.killbill.notificationq.${instanceName}.sleep] on [org.killbill.notificationq.api.NotificationQueueConfig#getPollingSleepTimeMs()]

2016-12-08T10:45:57,809+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [3] for [org.killbill.notificationq.${instanceName}.max.failure.retry] on [org.killbill.notificationq.api.NotificationQueueConfig#getMaxFailureRetries()]

2016-12-08T10:45:57,809+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [10] for [org.killbill.notificationq.${instanceName}.claimed] on [org.killbill.notificationq.api.NotificationQueueConfig#getMaxEntriesClaimed()]

2016-12-08T10:45:57,810+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [STICKY_POLLING] for [org.killbill.notificationq.${instanceName}.queue.mode] on [org.killbill.notificationq.api.NotificationQueueConfig#getPersistentQueueMode()]

2016-12-08T10:45:57,814+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [] for [org.killbill.osgi.system.bundle.export.packages.extra] on [org.killbill.billing.osgi.config.OSGIConfig#getSystemBundleExportPackagesExtra()]

2016-12-08T10:45:57,815+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [osgi-cache] for [org.killbill.osgi.bundle.cache.name] on [org.killbill.billing.osgi.config.OSGIConfig#getOSGIBundleCacheName()]

2016-12-08T10:45:57,815+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [/var/tmp/bundles] for [org.killbill.osgi.bundle.install.dir] on [org.killbill.billing.osgi.config.OSGIConfig#getRootInstallationDir()]

2016-12-08T10:45:57,816+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [killbill.properties] for [org.killbill.osgi.bundle.property.name] on [org.killbill.billing.osgi.config.OSGIConfig#getOSGIKillbillPropertyName()]

2016-12-08T10:45:57,816+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [org.killbill.billing.account.api,org.killbill.billing.analytics.api.sanity,org.killbill.billing.analytics.api.user,org.killbill.billing.beatrix.bus.api,org.killbill.billing.catalog.api,org.killbill.billing.catalog.api.rules,org.killbill.billing.invoice.plugin.api,org.killbill.billing.invoice.api,org.killbill.billing.invoice.api.formatters,org.killbill.billing.entitlement.api,org.killbill.billing,org.killbill.clock,org.killbill.billing.notification.api,org.killbill.billing.notification.plugin.api,org.killbill.billing.notification.plugin,org.killbill.billing.osgi.api,org.killbill.billing.osgi.api.config,org.killbill.billing.overdue,org.killbill.billing.payment.api,org.killbill.billing.payment.plugin.api,org.killbill.billing.control.plugin.api,org.killbill.billing.tenant.api,org.killbill.billing.usage.api,org.killbill.billing.util.api,org.killbill.billing.util.nodes,org.killbill.billing.util.audit,org.killbill.billing.util.callcontext,org.killbill.billing.util.customfield,org.killbill.billing.util.email,org.killbill.billing.util.entity,org.killbill.billing.util.tag,org.killbill.billing.util.template,org.killbill.billing.util.template.translation,org.killbill.billing.currency.plugin.api,org.killbill.billing.catalog.plugin.api,org.killbill.billing.entitlement.plugin.api,org.killbill.billing.currency.api,org.killbill.billing.security.api,org.killbill.billing.osgi.libs.killbill,org.joda.time;org.joda.time.format;version=2.3,org.slf4j;version=1.7.2,org.osgi.service.log;version=1.3,org.osgi.service.http;version=1.2.0,org.osgi.service.deploymentadmin;version=1.1.0,org.osgi.service.event;version=1.2.0] for [org.killbill.osgi.system.bundle.export.packages.api] on [org.killbill.billing.osgi.config.OSGIConfig#getSystemBundleExportPackagesApi()]

2016-12-08T10:45:57,817+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [com.sun.xml.internal.ws,com.sun.xml.internal.ws.addressing,com.sun.xml.internal.ws.addressing.model,com.sun.xml.internal.ws.addressing.policy,com.sun.xml.internal.ws.addressing.v200408,com.sun.xml.internal.ws.api,com.sun.xml.internal.ws.api.addressing,com.sun.xml.internal.ws.api.client,com.sun.xml.internal.ws.api.config.management,com.sun.xml.internal.ws.api.config.management.policy,com.sun.xml.internal.ws.api.fastinfoset,com.sun.xml.internal.ws.api.ha,com.sun.xml.internal.ws.api.handler,com.sun.xml.internal.ws.api.message,com.sun.xml.internal.ws.api.message.stream,com.sun.xml.internal.ws.api.model,com.sun.xml.internal.ws.api.model.soap,com.sun.xml.internal.ws.api.model.wsdl,com.sun.xml.internal.ws.api.pipe,com.sun.xml.internal.ws.api.pipe.helper,com.sun.xml.internal.ws.api.policy,com.sun.xml.internal.ws.api.server,com.sun.xml.internal.ws.api.streaming,com.sun.xml.internal.ws.api.wsdl.parser,com.sun.xml.internal.ws.api.wsdl.writer,com.sun.xml.internal.ws.binding,com.sun.xml.internal.ws.client,com.sun.xml.internal.ws.client.dispatch,com.sun.xml.internal.ws.client.sei,com.sun.xml.internal.ws.config.management.policy,com.sun.xml.internal.ws.developer,com.sun.xml.internal.ws.encoding,com.sun.xml.internal.ws.encoding.fastinfoset,com.sun.xml.internal.ws.encoding.policy,com.sun.xml.internal.ws.encoding.soap,com.sun.xml.internal.ws.encoding.soap.streaming,com.sun.xml.internal.ws.encoding.xml,com.sun.xml.internal.ws.fault,com.sun.xml.internal.ws.handler,com.sun.xml.internal.ws.message,com.sun.xml.internal.ws.message.jaxb,com.sun.xml.internal.ws.message.saaj,com.sun.xml.internal.ws.message.source,com.sun.xml.internal.ws.message.stream,com.sun.xml.internal.ws.model,com.sun.xml.internal.ws.model.soap,com.sun.xml.internal.ws.model.wsdl,com.sun.xml.internal.ws.org.objectweb.asm,com.sun.xml.internal.ws.policy,com.sun.xml.internal.ws.policy.jaxws,com.sun.xml.internal.ws.policy.jaxws.spi,com.sun.xml.internal.ws.policy.privateutil,com.sun.xml.internal.ws.policy.sourcemodel,com.sun.xml.internal.ws.policy.sourcemodel.attach,com.sun.xml.internal.ws.policy.sourcemodel.wspolicy,com.sun.xml.internal.ws.policy.spi,com.sun.xml.internal.ws.policy.subject,com.sun.xml.internal.ws.protocol.soap,com.sun.xml.internal.ws.protocol.xml,com.sun.xml.internal.ws.resources,com.sun.xml.internal.ws.server,com.sun.xml.internal.ws.server.provider,com.sun.xml.internal.ws.server.sei,com.sun.xml.internal.ws.spi,com.sun.xml.internal.ws.streaming,com.sun.xml.internal.ws.transport,com.sun.xml.internal.ws.transport.http,com.sun.xml.internal.ws.transport.http.client,com.sun.xml.internal.ws.transport.http.server,com.sun.xml.internal.ws.util,com.sun.xml.internal.ws.util.exception,com.sun.xml.internal.ws.util.localization,com.sun.xml.internal.ws.util.pipe,com.sun.xml.internal.ws.util.xml,com.sun.xml.internal.ws.wsdl,com.sun.xml.internal.ws.wsdl.parser,com.sun.xml.internal.ws.wsdl.writer,com.sun.xml.internal.ws.wsdl.writer.document,com.sun.xml.internal.ws.wsdl.writer.document.http,com.sun.xml.internal.ws.wsdl.writer.document.soap,com.sun.xml.internal.ws.wsdl.writer.document.soap12,com.sun.xml.internal.ws.wsdl.writer.document.xsd,javax.annotation,javax.management,javax.naming,javax.naming.ldap,javax.net,javax.net.ssl,javax.crypto,javax.crypto.spec,javax.sql,javax.sql.rowset,javax.sql.rowset.serial,javax.transaction,javax.transaction.xa,javax.xml,javax.xml.bind,javax.xml.validation,javax.xml.namespace,javax.xml.parsers,javax.xml.validation,javax.xml.stream,javax.xml.stream.events,javax.xml.stream.util,javax.xml.transform,javax.xml.transform.dom,javax.xml.transform.sax,javax.xml.transform.stax,javax.xml.transform.stream,javax.xml.xpath,javax.jws.soap,com.sun.org,com.sun.org.apache,com.sun.org.apache.xml,com.sun.org.apache.xml.internal,com.sun.org.apache.xml.internal.utils,com.sun.org.apache.xpath,com.sun.org.apache.xpath.internal,com.sun.org.apache.xpath.internal.jaxp,com.sun.org.apache.xpath.internal.objects,org.w3c.dom,org.w3c.dom.bootstrap,org.w3c.dom.events,org.w3c.dom.ls,org.w3c.dom.css,org.w3c.dom.html,org.w3c.dom.ranges,org.w3c.dom.stylesheets,org.w3c.dom.traversal,org.w3c.dom.views,org.xml.sax,org.xml.sax.ext,org.xml.sax.helpers,sun.misc,sun.misc.unsafe,sun.security,sun.security.util,javax.servlet;version=3.1,javax.servlet.http;version=3.1] for [org.killbill.osgi.system.bundle.export.packages.java] on [org.killbill.billing.osgi.config.OSGIConfig#getSystemBundleExportPackagesJava()]

2016-12-08T10:45:57,820+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [/var/tmp/felix] for [org.killbill.osgi.root.dir] on [org.killbill.billing.osgi.config.OSGIConfig#getOSGIBundleRootDir()]

2016-12-08T10:45:57,825+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [1] for [org.killbill.billing.osgi.dao.minIdle] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getMinIdle()]

2016-12-08T10:45:57,825+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [60m] for [org.killbill.billing.osgi.dao.idleMaxAge] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getIdleMaxAge()]

2016-12-08T10:45:57,825+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [0m] for [org.killbill.billing.osgi.dao.maxConnectionAge] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getMaxConnectionAge()]

2016-12-08T10:45:57,826+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [5m] for [org.killbill.billing.osgi.dao.idleConnectionTestPeriod] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getIdleConnectionTestPeriod()]

2016-12-08T10:45:57,826+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [500] for [org.killbill.billing.osgi.dao.prepStmtCacheSize] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getPreparedStatementsCacheSize()]

2016-12-08T10:45:57,826+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [2048] for [org.killbill.billing.osgi.dao.prepStmtCacheSqlLimit] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getPreparedStatementsCacheSqlLimit()]

2016-12-08T10:45:57,827+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [true] for [org.killbill.billing.osgi.dao.cachePrepStmts] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#isPreparedStatementsCacheEnabled()]

2016-12-08T10:45:57,827+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [true] for [org.killbill.billing.osgi.dao.useServerPrepStmts] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#isServerSidePreparedStatementsEnabled()]

2016-12-08T10:45:57,827+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.billing.osgi.dao.dataSourceClassName] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getDataSourceClassName()]

2016-12-08T10:45:57,828+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.billing.osgi.dao.driverClassName] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getDriverClassName()]

2016-12-08T10:45:57,828+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [4.0] for [org.killbill.billing.osgi.dao.mysqlServerVersion] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getMySQLServerVersion()]

2016-12-08T10:45:57,828+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [DEBUG] for [org.killbill.billing.osgi.dao.logLevel] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getLogLevel()]

2016-12-08T10:45:57,829+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [HIKARICP] for [org.killbill.billing.osgi.dao.poolingType] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getConnectionPoolingType()]

2016-12-08T10:45:57,829+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning value [jdbc:mysql://127.0.0.1:3306/killbill] for [org.killbill.billing.osgi.dao.url] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getJdbcUrl()]

2016-12-08T10:45:57,829+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning value [root] for [org.killbill.billing.osgi.dao.user] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getUsername()]

2016-12-08T10:45:57,829+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [10s] for [org.killbill.billing.osgi.dao.connectionTimeout] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getConnectionTimeout()]

2016-12-08T10:45:57,830+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [100] for [org.killbill.billing.osgi.dao.maxActive] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getMaxActive()]

2016-12-08T10:45:57,830+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning value [********] for [org.killbill.billing.osgi.dao.password] on [org.killbill.billing.osgi.glue.OSGIDataSourceConfig#getPassword()]

2016-12-08T10:45:57,830+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.dao.connectionInitSql] on [org.killbill.commons.jdbi.guice.DaoConfig#getConnectionInitSql()]

2016-12-08T10:45:57,831+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [10s] for [org.killbill.dao.healthCheckConnectionTimeout] on [org.killbill.commons.jdbi.guice.DaoConfig#getHealthCheckConnectionTimeout()]

2016-12-08T10:45:57,831+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [50ms] for [org.killbill.dao.healthCheckExpected99thPercentile] on [org.killbill.commons.jdbi.guice.DaoConfig#getHealthCheckExpected99thPercentile()]

2016-12-08T10:45:57,853+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [5s] for [org.killbill.billing.util.broadcast.rate] on [org.killbill.billing.util.config.definition.BroadcastConfig#getBroadcastServiceRunningRate()]

2016-12-08T10:45:57,859+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [ehcache.xml] for [org.killbill.cache.config.location] on [org.killbill.billing.util.config.definition.EhCacheConfig#getCacheConfigLocation()]

2016-12-08T10:45:57,870+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [SpyCarBasic.xml] for [org.killbill.catalog.uri] on [org.killbill.billing.util.config.definition.CatalogConfig#getCatalogURI()]

2016-12-08T10:45:57,878+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [killbill-currency-plugin] for [org.killbill.currency.provider.default] on [org.killbill.billing.util.config.definition.CurrencyConfig#getDefaultCurrencyProvider()]

2016-12-08T10:45:57,899+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [2] for [org.killbill.invoice.readMaxRawUsagePreviousPeriod] on [org.killbill.billing.util.config.definition.InvoiceConfig#getMaxRawUsagePreviousPeriod()]

2016-12-08T10:45:57,899+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [36] for [org.killbill.invoice.maxNumberOfMonthsInFuture] on [org.killbill.billing.util.config.definition.InvoiceConfig#getNumberOfMonthsInFuture()]

2016-12-08T10:45:57,900+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [50] for [org.killbill.invoice.globalLock.retries] on [org.killbill.billing.util.config.definition.InvoiceConfig#getMaxGlobalLockRetries()]

2016-12-08T10:45:57,900+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.invoice.emailNotificationsEnabled] on [org.killbill.billing.util.config.definition.InvoiceConfig#isEmailNotificationsEnabled()]

2016-12-08T10:45:57,900+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [15] for [org.killbill.invoice.maxDailyNumberOfItemsSafetyBound] on [org.killbill.billing.util.config.definition.InvoiceConfig#getMaxDailyNumberOfItemsSafetyBound()]

2016-12-08T10:45:57,901+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [0s] for [org.killbill.invoice.dryRunNotificationSchedule] on [org.killbill.billing.util.config.definition.InvoiceConfig#getDryRunNotificationSchedule()]

2016-12-08T10:45:57,908+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [org.killbill.billing.invoice.template.formatters.DefaultInvoiceFormatterFactory] for [org.killbill.template.invoiceFormatterFactoryClass] on [org.killbill.billing.util.template.translation.TranslatorConfig#getInvoiceFormatterFactoryClass()]

2016-12-08T10:45:57,909+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [en_US] for [org.killbill.default.locale] on [org.killbill.billing.util.template.translation.TranslatorConfig#getDefaultLocale()]

2016-12-08T10:45:57,910+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [org/killbill/billing/util/template/translation/CatalogTranslation] for [org.killbill.catalog.bundlePath] on [org.killbill.billing.util.template.translation.TranslatorConfig#getCatalogBundlePath()]

2016-12-08T10:45:57,910+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [org/killbill/billing/util/template/translation/InvoiceTranslation] for [org.killbill.template.bundlePath] on [org.killbill.billing.util.template.translation.TranslatorConfig#getInvoiceTemplateBundlePath()]

2016-12-08T10:45:57,910+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [org/killbill/billing/util/email/templates/HtmlInvoiceTemplate.mustache] for [org.killbill.template.name] on [org.killbill.billing.util.template.translation.TranslatorConfig#getTemplateName()]

2016-12-08T10:45:57,911+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [org/killbill/billing/util/email/templates/HtmlInvoiceTemplate.mustache] for [org.killbill.manualPayTemplate.name] on [org.killbill.billing.util.template.translation.TranslatorConfig#getManualPayTemplateName()]

2016-12-08T10:45:57,928+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [NoOverdueConfig.xml] for [org.killbill.overdue.uri] on [org.killbill.billing.overdue.OverdueProperties#getConfigURI()]

2016-12-08T10:45:57,943+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.mail.smtp.host] on [org.killbill.billing.util.email.EmailConfig#getSmtpServerName()]

2016-12-08T10:45:57,943+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.mail.smtp.port] on [org.killbill.billing.util.email.EmailConfig#getSmtpPort()]

2016-12-08T10:45:57,944+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.mail.smtp.auth] on [org.killbill.billing.util.email.EmailConfig#useSmtpAuth()]

2016-12-08T10:45:57,944+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.mail.smtp.user] on [org.killbill.billing.util.email.EmailConfig#getSmtpUserName()]

2016-12-08T10:45:57,944+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.mail.smtp.password] on [org.killbill.billing.util.email.EmailConfig#getSmtpPassword()]

2016-12-08T10:45:57,944+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [sup...@example.com] for [org.killbill.mail.from] on [org.killbill.billing.util.email.EmailConfig#getDefaultFrom()]

2016-12-08T10:45:57,944+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.mail.useSSL] on [org.killbill.billing.util.email.EmailConfig#useSSL()]

2016-12-08T10:45:57,945+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [Your invoice] for [org.killbill.mail.invoiceEmailSubject] on [org.killbill.billing.util.email.EmailConfig#getInvoiceEmailSubject()]

2016-12-08T10:45:58,047+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [1h] for [org.killbill.rbac.globalSessionTimeout] on [org.killbill.billing.util.config.definition.RbacConfig#getGlobalSessionTimeout()]

2016-12-08T10:45:58,067+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [50] for [org.killbill.payment.globalLock.retries] on [org.killbill.billing.util.config.definition.PaymentConfig#getMaxGlobalLockRetries()]

2016-12-08T10:45:58,067+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [2] for [org.killbill.payment.failure.retry.multiplier] on [org.killbill.billing.util.config.definition.PaymentConfig#getPluginFailureRetryMultiplier()]

2016-12-08T10:45:58,067+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [15s,1m,3m,1h,1d,1d,1d,1d,1d] for [org.killbill.payment.janitor.transactions.retries] on [org.killbill.billing.util.config.definition.PaymentConfig#getIncompleteTransactionsRetries()]

2016-12-08T10:45:58,068+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [8] for [org.killbill.payment.failure.retry.max.attempts] on [org.killbill.billing.util.config.definition.PaymentConfig#getPluginFailureRetryMaxAttempts()]

2016-12-08T10:45:58,069+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [] for [org.killbill.payment.invoice.plugin] on [org.killbill.billing.util.config.definition.PaymentConfig#getPaymentControlPluginNames()]

2016-12-08T10:45:58,069+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [1h] for [org.killbill.payment.janitor.rate] on [org.killbill.billing.util.config.definition.PaymentConfig#getJanitorRunningRate()]

2016-12-08T10:45:58,069+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [12h] for [org.killbill.payment.janitor.attempts.delay] on [org.killbill.billing.util.config.definition.PaymentConfig#getIncompleteAttemptsTimeSpanDelay()]

2016-12-08T10:45:58,069+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [__external_payment__] for [org.killbill.payment.provider.default] on [org.killbill.billing.util.config.definition.PaymentConfig#getDefaultPaymentProvider()]

2016-12-08T10:45:58,070+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [30s] for [org.killbill.payment.plugin.timeout] on [org.killbill.billing.util.config.definition.PaymentConfig#getPaymentPluginTimeout()]

2016-12-08T10:45:58,070+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [100] for [org.killbill.payment.plugin.threads.nb] on [org.killbill.billing.util.config.definition.PaymentConfig#getPaymentPluginThreadNb()]

2016-12-08T10:45:58,070+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [8,8,8] for [org.killbill.payment.retry.days] on [org.killbill.billing.util.config.definition.PaymentConfig#getPaymentFailureRetryDays()]

2016-12-08T10:45:58,071+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [300] for [org.killbill.payment.failure.retry.start.sec] on [org.killbill.billing.util.config.definition.PaymentConfig#getPluginFailureInitialRetryInSec()]

2016-12-08T10:45:58,095+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [classpath:shiro.ini] for [org.killbill.security.shiroResourcePath] on [org.killbill.billing.util.config.definition.SecurityConfig#getShiroResourcePath()]

2016-12-08T10:45:58,096+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [200000] for [org.killbill.security.shiroNbHashIterations] on [org.killbill.billing.util.config.definition.SecurityConfig#getShiroNbHashIterations()]

2016-12-08T10:45:58,096+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.security.ldap.userDnTemplate] on [org.killbill.billing.util.config.definition.SecurityConfig#getShiroLDAPUserDnTemplate()]

2016-12-08T10:45:58,096+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.security.ldap.searchBase] on [org.killbill.billing.util.config.definition.SecurityConfig#getShiroLDAPSearchBase()]

2016-12-08T10:45:58,096+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [memberOf=uid={0}] for [org.killbill.security.ldap.groupSearchFilter] on [org.killbill.billing.util.config.definition.SecurityConfig#getShiroLDAPGroupSearchFilter()]

2016-12-08T10:45:58,097+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [memberOf] for [org.killbill.security.ldap.groupNameId] on [org.killbill.billing.util.config.definition.SecurityConfig#getShiroLDAPGroupNameID()]

2016-12-08T10:45:58,097+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [admin = *:*

finance = invoice:*, payment:*

support = entitlement:*, invoice:item_adjust] for [org.killbill.security.ldap.permissionsByGroup] on [org.killbill.billing.util.config.definition.SecurityConfig#getShiroLDAPPermissionsByGroup()]

2016-12-08T10:45:58,097+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [ldap://127.0.0.1:389] for [org.killbill.security.ldap.url] on [org.killbill.billing.util.config.definition.SecurityConfig#getShiroLDAPUrl()]

2016-12-08T10:45:58,098+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.security.ldap.systemUsername] on [org.killbill.billing.util.config.definition.SecurityConfig#getShiroLDAPSystemUsername()]

2016-12-08T10:45:58,098+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning null default value for [org.killbill.security.ldap.systemPassword] on [org.killbill.billing.util.config.definition.SecurityConfig#getShiroLDAPSystemPassword()]

2016-12-08T10:45:58,098+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [simple] for [org.killbill.security.ldap.authenticationMechanism] on [org.killbill.billing.util.config.definition.SecurityConfig#getShiroLDAPAuthenticationMechanism()]

2016-12-08T10:45:58,098+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.security.ldap.disableSSLCheck] on [org.killbill.billing.util.config.definition.SecurityConfig#disableShiroLDAPSSLCheck()]

2016-12-08T10:45:58,108+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [5s] for [org.killbill.tenant.broadcast.rate] on [org.killbill.billing.util.config.definition.TenantConfig#getTenantBroadcastServiceRunningRate()]

2016-12-08T10:45:58,117+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [30s] for [org.killbill.jaxrs.timeout] on [org.killbill.billing.util.config.definition.JaxrsConfig#getJaxrsTimeout()]

2016-12-08T10:45:58,117+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [30] for [org.killbill.jaxrs.threads.pool.nb] on [org.killbill.billing.util.config.definition.JaxrsConfig#getJaxrsThreadNb()]

2016-12-08T10:45:58,118+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [true] for [org.killbill.jaxrs.location.full.url] on [org.killbill.billing.util.config.definition.JaxrsConfig#isJaxrsLocationFullUrl()]

2016-12-08T10:45:58,122+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [15m,30m,2h,12h,1d] for [org.killbill.billing.server.notifications.retries] on [org.killbill.billing.util.config.definition.NotificationConfig#getPushNotificationsRetries()]

2016-12-08T10:45:59,438+0000 lvl='INFO', log='HikariDataSource', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', HikariCP pool main is starting.

2016-12-08T10:45:59,984+0000 lvl='INFO', log='PersistentBusProvider', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Creating Persistent bus for bus_events

2016-12-08T10:46:00,121+0000 lvl='INFO', log='PersistentBusProvider', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Creating Persistent bus for bus_ext_events

2016-12-08T10:46:00,479+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Initializing an object of class org.killbill.billing.catalog.StandaloneCatalog from xml file at: EmptyCatalog.xml

2016-12-08T10:46:00,749+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Errors: 0 for EmptyCatalog.xml

2016-12-08T10:46:00,757+0000 lvl='INFO', log='DefaultPaymentProviderPluginRegistry', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering service='__EXTERNAL_PAYMENT__'

2016-12-08T10:46:00,758+0000 lvl='INFO', log='DefaultPaymentProviderPluginRegistry', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering service='__DEFAULT_PAYMENT_CONTROL__'

2016-12-08T10:46:00,758+0000 lvl='INFO', log='DefaultPaymentProviderPluginRegistry', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering service='__INVOICE_PAYMENT_CONTROL_PLUGIN__'

2016-12-08T10:46:00,760+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Initializing an object of class org.killbill.automaton.DefaultStateMachineConfig from xml file at: jar:file:/home/ubuntu/killbill/webapps/ROOT/WEB-INF/lib/killbill-payment-0.18.1.jar!/org/killbill/billing/payment/retry/RetryStates.xml

2016-12-08T10:46:00,812+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Errors: 0 for jar:file:/home/ubuntu/killbill/webapps/ROOT/WEB-INF/lib/killbill-payment-0.18.1.jar!/org/killbill/billing/payment/retry/RetryStates.xml

2016-12-08T10:46:00,824+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Initializing an object of class org.killbill.billing.overdue.config.DefaultOverdueConfig from xml file at: NoOverdueConfig.xml

2016-12-08T10:46:00,848+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Errors: 0 for NoOverdueConfig.xml

2016-12-08T10:46:00,848+0000 lvl='INFO', log='HikariDataSource', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', HikariCP pool osgi is starting.

2016-12-08T10:46:00,896+0000 lvl='INFO', log='HikariDataSource', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', HikariCP pool shiro is starting.

2016-12-08T10:46:00,912+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Cache with name 'iniRealm.authenticationCache' does not yet exist.  Creating now.

2016-12-08T10:46:00,917+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Added EhCache named [iniRealm.authenticationCache]

2016-12-08T10:46:00,918+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Cache with name 'iniRealm.authorizationCache' does not yet exist.  Creating now.

2016-12-08T10:46:00,924+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Added EhCache named [iniRealm.authorizationCache]

2016-12-08T10:46:00,924+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Cache with name 'org.killbill.billing.util.security.shiro.realm.KillBillJdbcRealm.authorizationCache.1' does not yet exist.  Creating now.

2016-12-08T10:46:00,928+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Added EhCache named [org.killbill.billing.util.security.shiro.realm.KillBillJdbcRealm.authorizationCache.1]

2016-12-08T10:46:00,929+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Cache with name 'shiro-activeSessionCache' does not yet exist.  Creating now.

2016-12-08T10:46:00,932+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Added EhCache named [shiro-activeSessionCache]

2016-12-08T10:46:00,935+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Using existing EHCache named [iniRealm.authenticationCache]

2016-12-08T10:46:00,935+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Using existing EHCache named [iniRealm.authorizationCache]

2016-12-08T10:46:00,936+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Cache with name 'org.killbill.billing.util.security.shiro.realm.KillBillJdbcRealm.authenticationCache.1' does not yet exist.  Creating now.

2016-12-08T10:46:00,941+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Added EhCache named [org.killbill.billing.util.security.shiro.realm.KillBillJdbcRealm.authenticationCache.1]

2016-12-08T10:46:00,941+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Using existing EHCache named [org.killbill.billing.util.security.shiro.realm.KillBillJdbcRealm.authorizationCache.1]

2016-12-08T10:46:00,993+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Cache with name 'org.killbill.billing.server.security.KillbillJdbcTenantRealm.authenticationCache.2' does not yet exist.  Creating now.

2016-12-08T10:46:00,997+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Added EhCache named [org.killbill.billing.server.security.KillbillJdbcTenantRealm.authenticationCache.2]

2016-12-08T10:46:00,998+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Cache with name 'org.killbill.billing.server.security.KillbillJdbcTenantRealm.authorizationCache.2' does not yet exist.  Creating now.

2016-12-08T10:46:01,003+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Added EhCache named [org.killbill.billing.server.security.KillbillJdbcTenantRealm.authorizationCache.2]

2016-12-08T10:46:01,003+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Using existing EHCache named [org.killbill.billing.server.security.KillbillJdbcTenantRealm.authenticationCache.2]

2016-12-08T10:46:01,004+0000 lvl='INFO', log='EhCacheManager', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Using existing EHCache named [org.killbill.billing.server.security.KillbillJdbcTenantRealm.authorizationCache.2]

2016-12-08T10:46:01,050+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle firing stage BOOT

2016-12-08T10:46:01,051+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler init for service nodes-service

2016-12-08T10:46:01,210+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle firing stage LOAD_CATALOG

2016-12-08T10:46:01,210+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler loadCatalog for service catalog-service

2016-12-08T10:46:01,211+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Initializing an object of class org.killbill.billing.catalog.StandaloneCatalog from xml file at: SpyCarBasic.xml

2016-12-08T10:46:01,312+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Errors: 0 for SpyCarBasic.xml

2016-12-08T10:46:01,312+0000 lvl='INFO', log='DefaultCatalogService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Successfully loaded the default catalog SpyCarBasic.xml

2016-12-08T10:46:01,312+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler loadConfig for service overdue-service

2016-12-08T10:46:01,312+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Initializing an object of class org.killbill.billing.overdue.config.DefaultOverdueConfig from xml file at: NoOverdueConfig.xml

2016-12-08T10:46:01,326+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Errors: 0 for NoOverdueConfig.xml

2016-12-08T10:46:01,326+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle firing stage INIT_BUS

2016-12-08T10:46:01,327+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler startBus for service bus-service

2016-12-08T10:46:01,355+0000 lvl='INFO', log='DBBackedQueue', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', DBBackedQueue-bus-bus_events: Initialized with queueId = 1, mode = STICKY_EVENTS, isQueueOpenForWrite = true, isQueueOpenForRead = true

2016-12-08T10:46:01,357+0000 lvl='INFO', log='DefaultQueueLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Bus: Starting...

2016-12-08T10:46:01,358+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler startBus for service external-bus-service

2016-12-08T10:46:01,359+0000 lvl='INFO', log='DBBackedQueue', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', DBBackedQueue-bus-bus_ext_events: Initialized with queueId = 2, mode = STICKY_EVENTS, isQueueOpenForWrite = true, isQueueOpenForRead = true

2016-12-08T10:46:01,360+0000 lvl='INFO', log='DefaultQueueLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Bus: Starting...

2016-12-08T10:46:01,359+0000 lvl='INFO', log='DefaultQueueLifecycle', th='bus_events-lifecycle-th-1', xff='', rId='', aRId='', tRId='', Bus: Thread bus_events-lifecycle-th-1 [28] starting

2016-12-08T10:46:01,360+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle firing stage INIT_PLUGIN

2016-12-08T10:46:01,360+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service osgi-service

2016-12-08T10:46:01,361+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle8/version0.0

2016-12-08T10:46:01,361+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle8

2016-12-08T10:46:01,361+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle7/version0.0

2016-12-08T10:46:01,361+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle7

2016-12-08T10:46:01,361+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle4/version0.0

2016-12-08T10:46:01,361+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle4

2016-12-08T10:46:01,362+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle18/version0.0

2016-12-08T10:46:01,362+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle18

2016-12-08T10:46:01,362+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle2/version0.0

2016-12-08T10:46:01,362+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle2

2016-12-08T10:46:01,363+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle3/version0.0

2016-12-08T10:46:01,363+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle3

2016-12-08T10:46:01,363+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle1/version0.0/bundle.jar-embedded

2016-12-08T10:46:01,363+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle1/version0.0

2016-12-08T10:46:01,363+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle1

2016-12-08T10:46:01,363+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle19/version0.0

2016-12-08T10:46:01,364+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle19

2016-12-08T10:46:01,364+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle11/version0.0

2016-12-08T10:46:01,364+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle11

2016-12-08T10:46:01,364+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle0

2016-12-08T10:46:01,364+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle5/version0.0

2016-12-08T10:46:01,365+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle5

2016-12-08T10:46:01,365+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle15/version0.0

2016-12-08T10:46:01,365+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle15

2016-12-08T10:46:01,366+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle6/version0.0

2016-12-08T10:46:01,366+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle6/data/config

2016-12-08T10:46:01,366+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle6/data

2016-12-08T10:46:01,366+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle6

2016-12-08T10:46:01,366+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle16/version0.0

2016-12-08T10:46:01,366+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle16

2016-12-08T10:46:01,367+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle12/version0.0

2016-12-08T10:46:01,367+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle12

2016-12-08T10:46:01,367+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle13/version0.0

2016-12-08T10:46:01,367+0000 lvl='INFO', log='DefaultQueueLifecycle', th='bus_ext_events-lifecycle-th-1', xff='', rId='', aRId='', tRId='', Bus: Thread bus_ext_events-lifecycle-th-1 [29] starting

2016-12-08T10:46:01,367+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle13

2016-12-08T10:46:01,371+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle20/version0.0

2016-12-08T10:46:01,371+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle20

2016-12-08T10:46:01,371+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle14/version0.0

2016-12-08T10:46:01,372+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle14

2016-12-08T10:46:01,372+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle17/version0.0

2016-12-08T10:46:01,372+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle17

2016-12-08T10:46:01,372+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle9/version0.0

2016-12-08T10:46:01,372+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle9/data/packages

2016-12-08T10:46:01,373+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle9/data

2016-12-08T10:46:01,373+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle9

2016-12-08T10:46:01,373+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle10/version0.0

2016-12-08T10:46:01,373+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache/bundle10

2016-12-08T10:46:01,373+0000 lvl='INFO', log='DefaultOSGIService', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Deleted recursively /var/tmp/felix/osgi-cache

2016-12-08T10:46:01,582+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.dependencymanager.runtime-3.1.0.jar

2016-12-08T10:46:01,591+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.scr-1.8.2.jar

2016-12-08T10:46:01,593+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.dependencymanager.annotation-3.1.0.jar

2016-12-08T10:46:01,594+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.dependencymanager.shell-3.0.1.jar

2016-12-08T10:46:01,604+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.scr.ds-annotations-1.2.4.jar

2016-12-08T10:46:01,605+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.configadmin-1.8.0.jar

2016-12-08T10:46:01,607+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.metatype-1.0.10.jar

2016-12-08T10:46:01,608+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/killbill-platform-osgi-bundles-webconsolebranding-0.36.1.jar

2016-12-08T10:46:01,609+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.deploymentadmin-0.9.5.jar

2016-12-08T10:46:01,610+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.shell-1.4.3.jar

2016-12-08T10:46:01,612+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.scr.annotations-1.9.8.jar

2016-12-08T10:46:01,613+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.bundlerepository-1.6.6.jar

2016-12-08T10:46:01,614+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.shell.remote-1.1.2.jar

2016-12-08T10:46:01,615+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.log-1.0.1.jar

2016-12-08T10:46:01,616+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/killbill-platform-osgi-bundles-logger-0.36.1.jar

2016-12-08T10:46:01,624+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.dependencymanager-3.1.0.jar

2016-12-08T10:46:01,626+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.gogo.runtime-0.12.0.jar

2016-12-08T10:46:01,627+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.webconsole-4.2.2-all.jar

2016-12-08T10:46:01,633+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing Java OSGI bundle from /var/tmp/bundles/platform/org.apache.felix.dependencymanager.compat-3.0.1.jar

2016-12-08T10:46:01,648+0000 lvl='INFO', log='PluginFinder', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Adding plugin killbill-kpm-1.1.0

2016-12-08T10:46:01,649+0000 lvl='WARN', log='PluginFinder', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Configuration root dir /var/tmp/bundles/plugins/java is not a valid directory

2016-12-08T10:46:01,649+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Installing JRuby bundle for plugin jruby-killbill-kpm

2016-12-08T10:46:04,492+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle firing stage INIT_SERVICE

2016-12-08T10:46:04,492+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service broadcast-service

2016-12-08T10:46:04,508+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service jaxrs-service

2016-12-08T10:46:04,509+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service subscription-service

2016-12-08T10:46:04,514+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service catalog-service

2016-12-08T10:46:04,514+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service payment-service

2016-12-08T10:46:04,515+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Initializing an object of class org.killbill.automaton.DefaultStateMachineConfig from xml file at: jar:file:/home/ubuntu/killbill/webapps/ROOT/WEB-INF/lib/killbill-payment-0.18.1.jar!/org/killbill/billing/payment/PaymentStates.xml

2016-12-08T10:46:04,572+0000 lvl='INFO', log='XMLLoader', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Errors: 0 for jar:file:/home/ubuntu/killbill/webapps/ROOT/WEB-INF/lib/killbill-payment-0.18.1.jar!/org/killbill/billing/payment/PaymentStates.xml

2016-12-08T10:46:04,579+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service entitlement-service

2016-12-08T10:46:04,579+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler registerForNotifications for service beatrix-service

2016-12-08T10:46:04,580+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler registerForNotifications for service server-service

2016-12-08T10:46:04,580+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service invoice-service

2016-12-08T10:46:04,581+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service tenant-service

2016-12-08T10:46:04,619+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service overdue-service

2016-12-08T10:46:04,619+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service config-service

2016-12-08T10:46:04,620+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler initialize for service security-service

2016-12-08T10:46:04,620+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle firing stage START_PLUGIN

2016-12-08T10:46:04,621+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler start for service osgi-service

2016-12-08T10:46:04,621+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.dependencymanager.runtime-3.1.0.jar

2016-12-08T10:46:04,665+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.scr-1.8.2.jar

2016-12-08T10:46:04,684+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.dependencymanager.annotation-3.1.0.jar

2016-12-08T10:46:04,685+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.dependencymanager.shell-3.0.1.jar

2016-12-08T10:46:04,689+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.scr.ds-annotations-1.2.4.jar

2016-12-08T10:46:04,690+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.configadmin-1.8.0.jar

2016-12-08T10:46:04,706+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.metatype-1.0.10.jar

2016-12-08T10:46:04,726+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Skipping fragment bundle file:/var/tmp/bundles/platform/killbill-platform-osgi-bundles-webconsolebranding-0.36.1.jar

2016-12-08T10:46:04,727+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.deploymentadmin-0.9.5.jar

2016-12-08T10:46:04,738+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.shell-1.4.3.jar

2016-12-08T10:46:04,754+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.scr.annotations-1.9.8.jar

2016-12-08T10:46:04,754+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.bundlerepository-1.6.6.jar

2016-12-08T10:46:04,803+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.shell.remote-1.1.2.jar

2016-12-08T10:46:04,807+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.log-1.0.1.jar

2016-12-08T10:46:04,817+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/killbill-platform-osgi-bundles-logger-0.36.1.jar

2016-12-08T10:46:04,825+0000 lvl='INFO', log='Activator', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering the killbill LogReaderService listener

2016-12-08T10:46:04,842+0000 lvl='INFO', log='killbill-platform-osgi-bundles-logger:0_36_1', th='Thread-11', xff='', rId='', aRId='', tRId='', [javax.servlet.Servlet] ServiceEvent REGISTERED

2016-12-08T10:46:04,844+0000 lvl='INFO', log='DefaultServletRouter', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering OSGI servlet at /killbill-osgi-logger

2016-12-08T10:46:04,845+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.dependencymanager-3.1.0.jar

2016-12-08T10:46:04,845+0000 lvl='INFO', log='killbill-platform-osgi-bundles-logger:0_36_1', th='Thread-11', xff='', rId='', aRId='', tRId='', BundleEvent STARTED

2016-12-08T10:46:04,845+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.gogo.runtime-0.12.0.jar

2016-12-08T10:46:04,846+0000 lvl='INFO', log='dependencymanager:3_1_0', th='Thread-11', xff='', rId='', aRId='', tRId='', BundleEvent STARTED

2016-12-08T10:46:04,849+0000 lvl='INFO', log='runtime:0_12_0', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.service.threadio.ThreadIO] ServiceEvent REGISTERED

2016-12-08T10:46:04,852+0000 lvl='INFO', log='runtime:0_12_0', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.service.command.CommandProcessor] ServiceEvent REGISTERED

2016-12-08T10:46:04,854+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.webconsole-4.2.2-all.jar

2016-12-08T10:46:04,855+0000 lvl='INFO', log='runtime:0_12_0', th='Thread-11', xff='', rId='', aRId='', tRId='', BundleEvent STARTED

2016-12-08T10:46:04,858+0000 lvl='INFO', log='killbill-platform-osgi-bundles-webconsolebranding:0_36_1', th='Thread-11', xff='', rId='', aRId='', tRId='', BundleEvent RESOLVED

2016-12-08T10:46:04,858+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', BundleEvent RESOLVED

2016-12-08T10:46:04,858+0000 lvl='INFO', log='killbill-platform-osgi-bundles-webconsolebranding:0_36_1', th='Thread-11', xff='', rId='', aRId='', tRId='', BundleEvent RESOLVED

2016-12-08T10:46:04,864+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.webconsole.ConfigurationPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,866+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.webconsole.ConfigurationPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,866+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.webconsole.ConfigurationPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,869+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.webconsole.ConfigurationPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,870+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.webconsole.ConfigurationPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,871+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.webconsole.ConfigurationPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,872+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.webconsole.ConfigurationPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,883+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.webconsole.ConfigurationPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,885+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.webconsole.bundleinfo.BundleInfoProvider] ServiceEvent REGISTERED

2016-12-08T10:46:04,896+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.osgi.service.cm.ManagedService] ServiceEvent REGISTERED

2016-12-08T10:46:04,902+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.inventory.InventoryPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,903+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.inventory.InventoryPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,909+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.inventory.InventoryPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,909+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.inventory.InventoryPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,910+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [org.apache.felix.inventory.InventoryPrinter] ServiceEvent REGISTERED

2016-12-08T10:46:04,913+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [javax.servlet.Servlet] ServiceEvent REGISTERED

2016-12-08T10:46:04,914+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [javax.servlet.Servlet] ServiceEvent REGISTERED

2016-12-08T10:46:04,916+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [javax.servlet.Servlet] ServiceEvent REGISTERED

2016-12-08T10:46:04,916+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [javax.servlet.Servlet] ServiceEvent REGISTERED

2016-12-08T10:46:04,916+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [javax.servlet.Servlet] ServiceEvent REGISTERED

2016-12-08T10:46:04,917+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', [javax.servlet.Servlet] ServiceEvent REGISTERED

2016-12-08T10:46:04,917+0000 lvl='INFO', log='webconsole:4_2_2_all', th='Thread-11', xff='', rId='', aRId='', tRId='', BundleEvent STARTED

2016-12-08T10:46:04,918+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle file:/var/tmp/bundles/platform/org.apache.felix.dependencymanager.compat-3.0.1.jar

2016-12-08T10:46:04,920+0000 lvl='INFO', log='compat:3_0_1', th='Thread-11', xff='', rId='', aRId='', tRId='', BundleEvent RESOLVED

2016-12-08T10:46:04,920+0000 lvl='INFO', log='compat:3_0_1', th='Thread-11', xff='', rId='', aRId='', tRId='', BundleEvent STARTED

2016-12-08T10:46:04,920+0000 lvl='INFO', log='FileInstall', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Starting bundle jruby-killbill-kpm

2016-12-08T10:46:04,930+0000 lvl='INFO', log='jruby:0_36_1', th='Thread-11', xff='', rId='', aRId='', tRId='', BundleEvent RESOLVED

2016-12-08T10:46:04,936+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-11', xff='', rId='', aRId='', tRId='', OSGI bundle='org.kill-bill.billing.killbill-platform-osgi-bundles-jruby-1' received START command

2016-12-08T10:46:04,945+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-11', xff='', rId='', aRId='', tRId='', JRuby plugin killbill-kpm activated (symbolicName = org.kill-bill.billing.killbill-platform-osgi-bundles-jruby-1)

2016-12-08T10:46:04,948+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-11', xff='', rId='', aRId='', tRId='', Starting JRuby plugin killbill-kpm (symbolicName = org.kill-bill.billing.killbill-platform-osgi-bundles-jruby-1, pluginMain=Killbill::Plugin::Api::NotificationPluginApi)

2016-12-08T10:46:04,949+0000 lvl='INFO', log='JRubyPlugin', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Creating scripting container with localContextScope SINGLETHREAD

2016-12-08T10:46:09,864+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-11', xff='', rId='', aRId='', tRId='', Found Rack configuration file at /var/tmp/bundles/plugins/ruby/killbill-kpm/1.1.0/config.ru

2016-12-08T10:46:09,880+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-11', xff='', rId='', aRId='', tRId='', Using Killbill::Plugin::RackHandler as rack handler

2016-12-08T10:46:09,882+0000 lvl='INFO', log='DefaultServletRouter', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering OSGI servlet at /killbill-kpm

2016-12-08T10:46:09,882+0000 lvl='INFO', log='jruby:0_36_1', th='Thread-11', xff='', rId='', aRId='', tRId='', [javax.servlet.http.HttpServlet] ServiceEvent REGISTERED

2016-12-08T10:46:09,883+0000 lvl='INFO', log='KillbillLogWriter', th='Thread-11', xff='', rId='', aRId='', tRId='', JRuby plugin killbill-kpm (symbolicName = org.kill-bill.billing.killbill-platform-osgi-bundles-jruby-1) started

2016-12-08T10:46:09,883+0000 lvl='INFO', log='jruby:0_36_1', th='Thread-11', xff='', rId='', aRId='', tRId='', BundleEvent STARTED

2016-12-08T10:46:09,885+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle firing stage START_SERVICE

2016-12-08T10:46:09,885+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler start for service nodes-service

2016-12-08T10:46:09,902+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler start for service broadcast-service

2016-12-08T10:46:09,902+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler start for service subscription-service

2016-12-08T10:46:09,902+0000 lvl='INFO', log='DBBackedQueue', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', DBBackedQueue-notif-notifications: Initialized with queueId = 3, mode = STICKY_POLLING, isQueueOpenForWrite = false, isQueueOpenForRead = false

2016-12-08T10:46:09,903+0000 lvl='INFO', log='DefaultQueueLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', NotificationQ: Starting...

2016-12-08T10:46:09,903+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler start for service payment-service

2016-12-08T10:46:09,903+0000 lvl='INFO', log='DefaultQueueLifecycle', th='notifications-lifecycle-th-1', xff='', rId='', aRId='', tRId='', NotificationQ: Thread notifications-lifecycle-th-1 [53] starting

2016-12-08T10:46:09,903+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler start for service entitlement-service

2016-12-08T10:46:09,917+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler start for service server-service

2016-12-08T10:46:09,917+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler start for service invoice-service

2016-12-08T10:46:09,917+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler start for service tenant-service

2016-12-08T10:46:09,918+0000 lvl='INFO', log='DefaultLifecycle', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Killbill lifecycle calling handler start for service overdue-service

2016-12-08T10:46:10,001+0000 lvl='INFO', log='Reflections', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Reflections took 56 ms to scan 1 urls, producing 285 keys and 560 values

2016-12-08T10:46:10,746+0000 lvl='INFO', log='PackagesResourceConfig', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Scanning for root resource and provider classes in the packages:

  org.killbill.billing.jaxrs.mappers

  org.killbill.billing.jaxrs.resources

  io.swagger.jaxrs.listing

2016-12-08T10:46:10,794+0000 lvl='INFO', log='ScanningResourceConfig', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Root resource classes found:

  class org.killbill.billing.jaxrs.resources.TagResource

  class io.swagger.jaxrs.listing.ApiListingResource

  class org.killbill.billing.jaxrs.resources.UsageResource

  class org.killbill.billing.jaxrs.resources.SubscriptionResource

  class org.killbill.billing.jaxrs.resources.InvoicePaymentResource

  class org.killbill.billing.jaxrs.resources.TransactionResource

  class org.killbill.billing.jaxrs.resources.NodesInfoResource

  class org.killbill.billing.jaxrs.resources.PaymentGatewayResource

  class org.killbill.billing.jaxrs.resources.OverdueResource

  class org.killbill.billing.jaxrs.resources.TenantResource

  class org.killbill.billing.jaxrs.resources.PaymentMethodResource

  class org.killbill.billing.jaxrs.resources.AccountResource

  class org.killbill.billing.jaxrs.resources.TestResource

  class org.killbill.billing.jaxrs.resources.PluginInfoResource

  class io.swagger.jaxrs.listing.AcceptHeaderApiListingResource

  class org.killbill.billing.jaxrs.resources.SecurityResource

  class org.killbill.billing.jaxrs.resources.AdminResource

  class org.killbill.billing.jaxrs.resources.InvoiceResource

  class org.killbill.billing.jaxrs.resources.BundleResource

  class org.killbill.billing.jaxrs.resources.CreditResource

  class org.killbill.billing.jaxrs.resources.TagDefinitionResource

  class org.killbill.billing.jaxrs.resources.ExportResource

  class org.killbill.billing.jaxrs.resources.PluginResource

  class org.killbill.billing.jaxrs.resources.CustomFieldResource

  class org.killbill.billing.jaxrs.resources.CatalogResource

  class org.killbill.billing.jaxrs.resources.PaymentResource

2016-12-08T10:46:10,796+0000 lvl='INFO', log='ScanningResourceConfig', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Provider classes found:

  class org.killbill.billing.jaxrs.mappers.OverdueErrorMapper

  class org.killbill.billing.jaxrs.mappers.BillingExceptionBaseMapper

  class org.killbill.billing.jaxrs.mappers.EntityPersistenceExceptionMapper

  class org.killbill.billing.jaxrs.mappers.TenantApiExceptionMapper

  class io.swagger.jaxrs.listing.SwaggerSerializers

  class org.killbill.billing.jaxrs.mappers.InvoiceApiExceptionMapper

  class org.killbill.billing.jaxrs.mappers.TagApiExceptionMapper

  class org.killbill.billing.jaxrs.mappers.AccountApiExceptionMapper

  class org.killbill.billing.jaxrs.mappers.SubscriptionBillingApiExceptionMapper

  class org.killbill.billing.jaxrs.mappers.BlockingApiExceptionMapper

  class org.killbill.billing.jaxrs.mappers.ShiroExceptionMapper

  class org.killbill.billing.jaxrs.mappers.RuntimeExceptionMapper

  class org.killbill.billing.jaxrs.mappers.CurrencyValueNullMapper

  class org.killbill.billing.jaxrs.mappers.CatalogApiExceptionMapper

  class org.killbill.billing.jaxrs.mappers.SubscriptionApiExceptionMapper

  class org.killbill.billing.jaxrs.mappers.IllegalStateExceptionMapper

  class org.killbill.billing.jaxrs.mappers.EntitlementApiExceptionMapper

  class org.killbill.billing.jaxrs.mappers.IllegalArgumentExceptionMapper

  class org.killbill.billing.jaxrs.mappers.EmailApiExceptionMapper

  class org.killbill.billing.jaxrs.mappers.IllegalPlanChangeMapper

  class org.killbill.billing.jaxrs.mappers.TagDefinitionApiExceptionMapper

  class org.killbill.billing.jaxrs.mappers.SubscriptionRepairExceptionMapper

  class org.killbill.billing.jaxrs.mappers.JsonMappingExceptionMapper

  class org.killbill.billing.jaxrs.mappers.PaymentApiExceptionMapper

  class org.killbill.billing.jaxrs.mappers.OverdueApiExceptionMapper

2016-12-08T10:46:10,853+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering com.fasterxml.jackson.jaxrs.json.JacksonJsonProvider as a provider class

2016-12-08T10:46:10,853+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.AccountResource as a root resource class

2016-12-08T10:46:10,854+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.BundleResource as a root resource class

2016-12-08T10:46:10,854+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.CatalogResource as a root resource class

2016-12-08T10:46:10,854+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.CreditResource as a root resource class

2016-12-08T10:46:10,854+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.CustomFieldResource as a root resource class

2016-12-08T10:46:10,854+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.ExportResource as a root resource class

2016-12-08T10:46:10,854+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.InvoicePaymentResource as a root resource class

2016-12-08T10:46:10,855+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.InvoiceResource as a root resource class

2016-12-08T10:46:10,855+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.PaymentGatewayResource as a root resource class

2016-12-08T10:46:10,855+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.PaymentMethodResource as a root resource class

2016-12-08T10:46:10,855+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.PaymentResource as a root resource class

2016-12-08T10:46:10,859+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.PluginResource as a root resource class

2016-12-08T10:46:10,860+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.SecurityResource as a root resource class

2016-12-08T10:46:10,860+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.SubscriptionResource as a root resource class

2016-12-08T10:46:10,860+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.TagDefinitionResource as a root resource class

2016-12-08T10:46:10,861+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.TagResource as a root resource class

2016-12-08T10:46:10,861+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.TenantResource as a root resource class

2016-12-08T10:46:10,861+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.TestResource as a root resource class

2016-12-08T10:46:10,861+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.TransactionResource as a root resource class

2016-12-08T10:46:10,861+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.UsageResource as a root resource class

2016-12-08T10:46:10,862+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.AdminResource as a root resource class

2016-12-08T10:46:10,862+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.PluginInfoResource as a root resource class

2016-12-08T10:46:10,862+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Registering org.killbill.billing.jaxrs.resources.NodesInfoResource as a root resource class

2016-12-08T10:46:10,864+0000 lvl='INFO', log='WebApplicationImpl', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Initiating Jersey application, version 'Jersey: 1.18.1 02/19/2014 03:28 AM'

2016-12-08T10:46:10,935+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding com.fasterxml.jackson.jaxrs.json.JacksonJsonProvider to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,114+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.CatalogResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,132+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.BundleResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,151+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.AccountResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,156+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.TestResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,157+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.NodesInfoResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,172+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.InvoiceResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,175+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.PluginResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,176+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.CreditResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,182+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.OverdueResource to GuiceInstantiatedComponentProvider

2016-12-08T10:46:11,186+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.AdminResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,189+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.InvoicePaymentResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,195+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.PaymentResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,197+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.CustomFieldResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,200+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.TenantResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,202+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.ExportResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,203+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.TagResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,205+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.PaymentMethodResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,207+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.TransactionResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,209+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.SecurityResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,209+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.PluginInfoResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,211+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.TagDefinitionResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,212+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.PaymentGatewayResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,216+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.SubscriptionResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,218+0000 lvl='INFO', log='GuiceComponentProviderFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Binding org.killbill.billing.jaxrs.resources.UsageResource to GuiceManagedComponentProvider with the scope "Singleton"

2016-12-08T10:46:11,229+0000 lvl='INFO', log='KillbillGuiceFilter', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Kill Bill server has started

2016-12-08T10:46:11,230+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning value [https://raw.github.com/killbill/killbill/master/profiles/killbill/src/main/resources/update-checker/killbill-server-update-list.properties] for [org.killbill.server.updateCheck.url] on [org.killbill.billing.server.config.UpdateCheckConfig#updateCheckURL()]

2016-12-08T10:46:11,231+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [false] for [org.killbill.server.updateCheck.skip] on [org.killbill.billing.server.config.UpdateCheckConfig#shouldSkipUpdateCheck()]

2016-12-08T10:46:11,231+0000 lvl='INFO', log='ConfigurationObjectFactory', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', Assigning default value [3000] for [org.killbill.server.updateCheck.connectTimeout] on [org.killbill.billing.server.config.UpdateCheckConfig#updateCheckConnectionTimeout()]

2016-12-08T10:46:11,233+0000 lvl='INFO', log='UpdateChecker', th='localhost-startStop-1', xff='', rId='', aRId='', tRId='', For Kill Bill Commercial Support, visit http://thebillingproject.com or send an email to sup...@thebillingproject.com

Dec 08, 2016 10:46:11 AM org.apache.catalina.startup.HostConfig deployWAR

INFO: Deploying web application archive /home/ubuntu/killbill/webapps/kaui.war

Dec 08, 2016 10:46:23 AM org.apache.coyote.AbstractProtocol start

INFO: Starting ProtocolHandler ["http-bio-8080"]

Dec 08, 2016 10:46:23 AM org.apache.coyote.AbstractProtocol start

INFO: Starting ProtocolHandler ["ajp-bio-8009"]

Dec 08, 2016 10:46:23 AM org.apache.catalina.startup.Catalina start

INFO: Server startup in 28938 ms

2016-12-08T10:48:54,615+0000 lvl='INFO', log='AbstractValidatingSessionManager', th='http-bio-8080-exec-5', xff='', rId='', aRId='', tRId='', Enabling session validation scheduler...

2016-12-08T10:49:37,367+0000 lvl='INFO', log='EhCacheManager', th='http-bio-8080-exec-5', xff='', rId='', aRId='', tRId='', Using existing EHCache named [shiro-activeSessionCache]

2016-12-08T10:49:37,398+0000 lvl='INFO', log='LoggingFilter', th='http-bio-8080-exec-5', xff='', rId='30bff38e-dd73-481b-a6eb-f54c01adda6f', aRId='', tRId='', 1 * Server in-bound request

1 > GET http://54.91.110.81:8080/1.0/kb/security/permissions

1 > accept: application/json

1 > user-agent: killbill/1.1.0; jruby 1.7.24 (1.9.3p551) 2016-01-20 bd68d85 on OpenJDK 64-Bit Server VM 1.8.0_111-8u111-b14-2ubuntu0.16.04.2-b14 +jit [linux-amd64]

1 > authorization: Basic YWRtaW46cGFzc3dvcmQ=

1 > host: 54.91.110.81:8080

1 >

2016-12-08T10:49:37,433+0000 lvl='INFO', log='LoggingFilter', th='http-bio-8080-exec-5', xff='', rId='30bff38e-dd73-481b-a6eb-f54c01adda6f', aRId='', tRId='', 1 * Server out-bound response

1 < 200

1 < Content-Type: application/json

1 <

2016-12-08T10:52:00,407+0000 lvl='INFO', log='LoggingFilter', th='http-bio-8080-exec-7', xff='', rId='59528ddc-65ef-4c6f-b852-e5563f0b4137', aRId='', tRId='', 2 * Server in-bound request

2 > GET http://54.91.110.81:8080/1.0/kb/security/subject

2 > accept: application/json

2 > user-agent: killbill/1.1.0; jruby 1.7.24 (1.9.3p551) 2016-01-20 bd68d85 on OpenJDK 64-Bit Server VM 1.8.0_111-8u111-b14-2ubuntu0.16.04.2-b14 +jit [linux-amd64]

2 > cookie: JSESSIONID=29b732c9-87de-4672-af21-0b389a4182bc

2 > host: 54.91.110.81:8080

2 >

2016-12-08T10:52:00,434+0000 lvl='INFO', log='LoggingFilter', th='http-bio-8080-exec-7', xff='', rId='59528ddc-65ef-4c6f-b852-e5563f0b4137', aRId='', tRId='', 2 * Server out-bound response

2 < 200

2 < Content-Type: application/json

2 <

[Алексей Васильев]

Additional log:

Dec 08, 2016 11:11:46 AM org.apache.catalina.core.ApplicationContext log

INFO: Request method='GET', uri='http://54.91.110.81:8080/1.0/kb/security/subject'

Dec 08, 2016 11:12:46 AM org.apache.catalina.core.ApplicationContext log

INFO: Timeout::Error Timeout::Error. /home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/protocol.rb:146:in `rbuf_fi

ll'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/protocol.rb:122:in `readuntil'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/protocol.rb:132:in `readline'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:2571:in `read_status_line'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:2560:in `read_new'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:1328:in `transport_request'

org/jruby/RubyKernel.java:1242:in `catch'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:1325:in `transport_request'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:1302:in `request'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/gems/gems/killbill-client-1.1.0/lib/killbill_client/api/net_http_adapter.rb:165:in `request'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:746:in `start'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/gems/gems/killbill-client-1.1.0/lib/killbill_client/api/net_http_adapter.rb:165:in `request'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/gems/gems/killbill-client-1.1.0/lib/killbill_client/api/api.rb:43:in `get'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/gems/gems/killbill-client-1.1.0/lib/killbill_client/models/resource.rb:43:in `get'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/gems/gems/killbill-client-1.1.0/lib/killbill_client/models/security.rb:14:in `find_subject'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/gems/gems/kaui-0.15.0/app/models/kaui/user.rb:28:in `authenticated_with_killbill?'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/gems/gems/kaui-0.15.0/config/initializers/killbill_authenticatable.rb:33:in `(root)'

org/jruby/RubyProc.java:281:in `call'

[Pierre-Alexandre Meyer]

Hi Алексей,

On Thu, Dec 8, 2016 at 3:14 AM, Алексей Васильев <ale...@wasilyev.ru> wrote:

INFO: Timeout::Error Timeout::Error. /home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/protocol.rb:146:in `rbuf_fi

ll'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/protocol.rb:122:in `readuntil'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/protocol.rb:132:in `readline'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:2571:in `read_status_line'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:2560:in `read_new'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:1328:in `transport_request'

org/jruby/RubyKernel.java:1242:in `catch'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:1325:in `transport_request'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:1302:in `request'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/gems/gems/killbill-client-1.1.0/lib/killbill_client/api/net_http_adapter.rb:165:in `request'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/lib/jruby-stdlib-1.7.24.jar!/META-INF/jruby.home/lib/ruby/1.9/net/http.rb:746:in `start'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/gems/gems/killbill-client-1.1.0/lib/killbill_client/api/net_http_adapter.rb:165:in `request'

/home/ubuntu/killbill/webapps/kaui/WEB-INF/gems/gems/killbill-client-1.1.0/lib/killbill_client/api/api.rb:43:in `get'

It looks like Kaui is unable to talk to Kill Bill. Are you sure the ports are open? Did you also verify the connectivity to the database?

--

Pierre

[Алексей Васильев]

Kaui an killbill sits on the same machine. Firewall is stopped, security group is fully opened.

I can manually curl on 8080 port and manually connect to mysql with mentioned credentials.

Is ./bin/catalina.sh run enough to start everything?

[Pierre-Alexandre Meyer]

Yes, that should be it.

One thought: is the VM properly sized? When running both servers on the same machine, make sure to allocate enough memory (at the very least 2GB, more if the database is also on that VM).

--

Pierre

[Алексей Васильев]

this vm has 4gb of ram, i see at least 1.5 gb free after killbill launch.

[Алексей Васильев]

I keep killbill in running state, and after night it just start work. Very strange.

But after restart - same problem. Looks like some kind long running (or just waiting for something) process during startup

[Pierre-Alexandre Meyer]

If you can reproduce it, could you inspect the VM (top, ps, etc.) as well as the JVM processes (jstack, etc.) to see if there is something obvious happening?

Also, are you sure the VM has enough entropy? Check /proc/sys/kernel/random/entropy_avail (should be > 3k, otherwise install rngtools) and make sure Kill Bill is started with -Djava.security.egd=file:/dev/.urandom.

--

Pierre

[Алексей Васильев]

Already done, nothing interesting in ps/top. No high cpu or disk usage, system looks idle.

Will check entropy.

[Алексей Васильев]

Good, it helps. Finally solved entropy problem with haveged installed.