TASK [run KPM install] *****
task path: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/roles/killbill/tasks/main.yml:40
changed: [localhost] => {"changed": true, "msg": "I, [2020-04-27T18:31:01.391533 #523] INFO -- : Starting download of org.kill-bill.billing:killbill-profiles-killbill:war:0.22.8 to /tmp/d20200427-523-1jdsk8p\nI, [2020-04-27T18:31:02.761708 #523] INFO -- : Successful installation of org.kill-bill.billing:killbill-profiles-killbill:war:0.22.8 to /var/lib/tomcat/webapps\nI, [2020-04-27T18:31:03.532062 #523] INFO -- : Starting download of org.kill-bill.billing:killbill-platform-osgi-bundles-defaultbundles:tar.gz:0.39.15 to /tmp/d20200427-523-1mtw4w6\nI, [2020-04-27T18:31:06.112810 #523] INFO -- : Successful installation of org.kill-bill.billing:killbill-platform-osgi-bundles-defaultbundles:tar.gz:0.39.15 to /var/lib/killbill/bundles/platform\n"}
META: ran handlers
META: ran handlers
-XX:+CMSClassUnloadingEnabled -XX:+CMSConcurrentMTEnabled -XX:CMSInitiatingOccupancyFraction=50 -XX:+CMSParallelRemarkEnabled -XX:+CMSScavengeBeforeRemark -XX:+DisableExplicitGC -XX:GCLogFileSize=104857600 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/var/lib/tomcat/logs/ -XX:InitialHeapSize=536870912 -XX:+ManagementServer -XX:MaxHeapSize=2147483648 -XX:MaxNewSize=1073741824 -XX:NewSize=268435456 -XX:NumberOfGCLogFiles=14 -XX:OldPLABSize=16 -XX:-OmitStackTraceInFastThrow -XX:+PrintCommandLineFlags -XX:+PrintGC -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintTenuringDistribution -XX:+ScavengeBeforeFullGC -XX:SurvivorRatio=10 -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCodeCacheFlushing -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseGCLogFileRotation -XX:+UseParNewGC
Listening for transport dt_socket at address: 12345
openjdk version "1.8.0_232"
OpenJDK Runtime Environment (build 1.8.0_232-8u232-b09-0ubuntu1~16.04.1-b09)
OpenJDK 64-Bit Server VM (build 25.232-b09, mixed mode)
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server version: Apache Tomcat/8.5.16
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server built: Jun 21 2017 17:01:09 UTC
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server number: 8.5.16.0
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Name: Linux
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Version: 4.15.0-1075-azure
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Architecture: amd64
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Java Home: /usr/lib/jvm/java-8-openjdk-amd64/jre
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Version: 1.8.0_232-8u232-b09-0ubuntu1~16.04.1-b09
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Vendor: Private Build
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_BASE: /var/lib/tomcat
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_HOME: /opt/apache-tomcat-8.5.16
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dnop
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+PrintCommandLineFlags
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+HeapDumpOnOutOfMemoryError
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:HeapDumpPath=/var/lib/tomcat/logs/
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+UseCodeCacheFlushing
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xms512m
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xmx2G
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=12345
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+CMSClassUnloadingEnabled
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:-OmitStackTraceInFastThrow
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+UseParNewGC
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+UseConcMarkSweepGC
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+CMSConcurrentMTEnabled
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+ScavengeBeforeFullGC
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+CMSScavengeBeforeRemark
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+CMSParallelRemarkEnabled
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+UseCMSInitiatingOccupancyOnly
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:CMSInitiatingOccupancyFraction=50
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:NewSize=256m
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:MaxNewSize=1024m
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:SurvivorRatio=10
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+DisableExplicitGC
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xloggc:/var/lib/tomcat/logs/gc.log
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+PrintGCApplicationConcurrentTime
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+PrintGCApplicationStoppedTime
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+PrintGCDateStamps
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+PrintGCDetails
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+PrintTenuringDistribution
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+UseGCLogFileRotation
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:NumberOfGCLogFiles=14
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:GCLogFileSize=100M
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcom.sun.xml.bind.v2.bytecode.ClassTailor.noOptimize=true
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcom.sun.management.jmxremote=true
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcom.sun.management.jmxremote.port=8000
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcom.sun.management.jmxremote.rmi.port=8000
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcom.sun.management.jmxremote.ssl=false
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.rmi.server.hostname=localhost
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.security.egd=file:/dev/./urandom
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djruby.compile.invokedynamic=false
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dlog4jdbc.sqltiming.error.threshold=1000
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dorg.killbill.queue.creator.name=localhost
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dlogback.configurationFile=/var/lib/killbill/logback.xml
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dorg.killbill.server.properties=file:///var/lib/killbill/killbill.properties
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.base=/var/lib/tomcat
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.home=/usr/share/tomcat
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.io.tmpdir=/var/tmp
Apr 27, 2020 6:31:07 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: Loaded APR based Apache Tomcat Native library [1.2.12] using APR version [1.5.2].
Apr 27, 2020 6:31:07 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
Apr 27, 2020 6:31:07 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
Apr 27, 2020 6:31:07 PM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFO: OpenSSL successfully initialized [OpenSSL 1.0.2g 1 Mar 2016]
Apr 27, 2020 6:31:07 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-nio-8080"]
Apr 27, 2020 6:31:07 PM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
INFO: Using a shared selector for servlet write/read
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 1179 ms
Apr 27, 2020 6:31:07 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service [Catalina]
Apr 27, 2020 6:31:07 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/8.5.16
Apr 27, 2020 6:31:08 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive [/var/lib/tomcat/webapps/ROOT.war]
Apr 27, 2020 6:31:16 PM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
18:31:16,688 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [/var/lib/killbill/logback.xml] at [file:/var/lib/killbill/logback.xml]
18:31:16,799 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
18:31:16,811 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Will scan for changes in [file:/var/lib/killbill/logback.xml]
18:31:16,811 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Setting ReconfigureOnChangeTask scanning period to 30 seconds
18:31:16,813 |-INFO in ch.qos.logback.classic.joran.action.JMXConfiguratorAction - begin
18:31:16,820 |-INFO in ch.qos.logback.core.joran.action.ConversionRuleAction - registering conversion word maskedMsg with class [org.killbill.billing.server.log.obfuscators.ObfuscatorConverter]
18:31:16,820 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
18:31:16,883 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [MAIN]
18:31:16,984 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@83104158 - Will use gz compression
18:31:16,986 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@83104158 - Will use the pattern /var/lib/tomcat/logs/killbill-%d{yyyy-MM-dd}.%i.out for the active file
18:31:16,989 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@2be9d606 - The date pattern is 'yyyy-MM-dd' from file name pattern '/var/lib/tomcat/logs/killbill-%d{yyyy-MM-dd}.%i.out.gz'.
18:31:16,989 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@2be9d606 - Roll-over at midnight.
18:31:16,990 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@2be9d606 - Setting initial period to Mon Apr 27 18:31:16 UTC 2020
18:31:16,990 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@2be9d606 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
18:31:16,990 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@2be9d606 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
18:31:16,992 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@83104158 - Cleaning on start up
18:31:16,993 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - first clean up after appender initialization
18:31:16,994 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - Multiple periods, i.e. 32 periods, seem to have elapsed. This is expected at application start.
18:31:16,994 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
18:31:17,194 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[MAIN] - Active log file name: /var/lib/tomcat/logs/killbill.out
18:31:17,194 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[MAIN] - File property is set to [/var/lib/tomcat/logs/killbill.out]
18:31:17,196 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
18:31:17,196 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [JDBI]
18:31:17,197 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@19339457 - Will use gz compression
18:31:17,197 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@19339457 - Will use the pattern /var/lib/tomcat/logs/jdbi-%d{yyyy-MM-dd}.%i.out for the active file
18:31:17,198 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@338da720 - The date pattern is 'yyyy-MM-dd' from file name pattern '/var/lib/tomcat/logs/jdbi-%d{yyyy-MM-dd}.%i.out.gz'.
18:31:17,198 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@338da720 - Roll-over at midnight.
18:31:17,198 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@338da720 - Setting initial period to Mon Apr 27 18:31:17 UTC 2020
18:31:17,198 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@338da720 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
18:31:17,198 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@338da720 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
18:31:17,199 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@19339457 - Cleaning on start up
18:31:17,199 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - first clean up after appender initialization
18:31:17,199 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - Multiple periods, i.e. 32 periods, seem to have elapsed. This is expected at application start.
18:31:17,200 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
18:31:17,202 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[JDBI] - Active log file name: /var/lib/tomcat/logs/jdbi.out
18:31:17,202 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[JDBI] - File property is set to [/var/lib/tomcat/logs/jdbi.out]
18:31:17,203 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender]
18:31:17,205 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-sqlonly]
18:31:17,214 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender]
18:31:17,214 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-sqltiming]
18:31:17,215 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender]
18:31:17,215 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-audit]
18:31:17,215 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender]
18:31:17,215 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-resultset]
18:31:17,216 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender]
18:31:17,216 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-resultsettable]
18:31:17,216 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender]
18:31:17,217 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-connection]
18:31:17,282 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.sqlonly] to OFF
18:31:17,282 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.sqlonly] to false
18:31:17,283 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-sqlonly] to Logger[jdbc.sqlonly]
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.sqltiming] to ERROR
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.sqltiming] to false
18:31:17,284 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-sqltiming] to Logger[jdbc.sqltiming]
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.audit] to OFF
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.audit] to false
18:31:17,284 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-audit] to Logger[jdbc.audit]
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.resultset] to OFF
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.resultset] to false
18:31:17,284 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-resultset] to Logger[jdbc.resultset]
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.resultsettable] to OFF
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.resultsettable] to false
18:31:17,284 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-resultsettable] to Logger[jdbc.resultsettable]
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.connection] to OFF
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.connection] to false
18:31:17,284 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-connection] to Logger[jdbc.connection]
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.jooq.Constants] to OFF
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.dmurph] to INFO
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.killbill.billing.notificationq] to INFO
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.killbill.billing.queue] to INFO
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.eclipse] to INFO
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.killbill.billing.server.updatechecker] to WARN
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.killbill.commons.jdbi.guice.DBIProvider] to INFO
18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.killbill.commons.jdbi.guice.DBIProvider] to false
18:31:17,285 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [JDBI] to Logger[org.killbill.commons.jdbi.guice.DBIProvider]
18:31:17,285 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
18:31:17,285 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [MAIN] to Logger[ROOT]
18:31:17,285 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
18:31:17,285 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@17d1382e - Registering current configuration as safe fallback point
I'm using the killbill/killbill:latest image. Also provided the following variables:KILLBILL_DAO_URL , KILLBILL_DAO_USER, KILLBILL_DAO_PASSWORD
The database is Mariadb on Azure.
The log:
ansible-playbook 2.9.4 config file = None configured module search path = [u'/var/lib/tomcat/.ansible/plugins/modules', u'/usr/share/ansible/plugins/modules'] ansible python module location = /usr/local/lib/python2.7/dist-packages/ansible executable location = /usr/local/bin/ansible-playbook python version = 2.7.12 (default, Oct 8 2019, 14:14:10) [GCC 5.4.0 20160609] No config file found; using defaults statically imported: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/roles/common/tasks/main.yml statically imported: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/roles/tomcat/tasks/main.yml statically imported: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/roles/killbill/tasks/main.yml
PLAYBOOK: killbill.yml ***** 1 plays in /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/killbill.yml
PLAY [Deploy Kill Bill] ****
TASK [Gathering Facts] ***** task path: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/killbill.yml:2 ok: [localhost] META: ran handlers
TASK [ansible_ruby_interpreter setup] ** task path: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/roles/common/tasks/main.yml:2 ok: [localhost] => {"ansible_facts": {"ansible_ruby_interpreter": "/opt/kpm-0.8.1-linux-x86_64/lib/ruby/bin/ruby"}, "changed": false}
TASK [ensure Tomcat dirs exist] **** task path: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/roles/tomcat/tasks/main.yml:2 ok: [localhost] => (item=bin) => {"ansible_loop_var": "item", "changed": false, "gid": 1000, "group": "tomcat", "item": "bin", "mode": "0755", "owner": "tomcat", "path": "/var/lib/tomcat/bin", "size": 4096, "state": "directory", "uid": 1000} ok: [localhost] => (item=conf) => {"ansible_loop_var": "item", "changed": false, "gid": 1000, "group": "tomcat", "item": "conf", "mode": "0755", "owner": "tomcat", "path": "/var/lib/tomcat/conf", "size": 4096, "state": "directory", "uid": 1000} ok: [localhost] => (item=lib) => {"ansible_loop_var": "item", "changed": false, "gid": 1000, "group": "tomcat", "item": "lib", "mode": "0755", "owner": "tomcat", "path": "/var/lib/tomcat/lib", "size": 4096, "state": "directory", "uid": 1000} ok: [localhost] => (item=logs) => {"ansible_loop_var": "item", "changed": false, "gid": 1000, "group": "tomcat", "item": "logs", "mode": "0755", "owner": "tomcat", "path": "/var/lib/tomcat/logs", "size": 4096, "state": "directory", "uid": 1000} ok: [localhost] => (item=webapps) => {"ansible_loop_var": "item", "changed": false, "gid": 1000, "group": "tomcat", "item": "webapps", "mode": "0755", "owner": "tomcat", "path": "/var/lib/tomcat/webapps", "size": 4096, "state": "directory", "uid": 1000} ok: [localhost] => (item=work) => {"ansible_loop_var": "item", "changed": false, "gid": 1000, "group": "tomcat", "item": "work", "mode": "0755", "owner": "tomcat", "path": "/var/lib/tomcat/work", "size": 4096, "state": "directory", "uid": 1000} ok: [localhost] => (item=temp) => {"ansible_loop_var": "item", "changed": false, "gid": 1000, "group": "tomcat", "item": "temp", "mode": "0755", "owner": "tomcat", "path": "/var/lib/tomcat/temp", "size": 4096, "state": "directory", "uid": 1000}
TASK [generate Tomcat files] *** task path: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/roles/tomcat/tasks/main.yml:15 ok: [localhost] => (item={u'dest': u'/var/lib/tomcat/conf', u'src': u'tomcat/conf', u'name': u'context.xml', u'mode': u'u=rw,g=r,o=r'}) => {"ansible_loop_var": "item", "changed": false, "dest": "/var/lib/tomcat/conf/context.xml", "item": {"dest": "/var/lib/tomcat/conf", "mode": "u=rw,g=r,o=r", "name": "context.xml", "src": "tomcat/conf"}, "src": "/var/lib/tomcat/.ansible/tmp/ansible-local-7wF_TBA/tmpzYjA89/context.xml.j2"} ok: [localhost] => (item={u'dest': u'/var/lib/tomcat/conf', u'src': u'tomcat/conf', u'name': u'server.xml', u'mode': u'u=rw,g=r,o=r'}) => {"ansible_loop_var": "item", "changed": false, "dest": "/var/lib/tomcat/conf/server.xml", "item": {"dest": "/var/lib/tomcat/conf", "mode": "u=rw,g=r,o=r", "name": "server.xml", "src": "tomcat/conf"}, "src": "/var/lib/tomcat/.ansible/tmp/ansible-local-7wF_TBA/tmpYFWB7t/server.xml.j2"} ok: [localhost] => (item={u'dest': u'/var/lib/tomcat/bin', u'src': u'tomcat/conf', u'name': u'setenv.sh', u'mode': u'u=rwx,g=rx,o=rx'}) => {"ansible_loop_var": "item", "changed": false, "dest": "/var/lib/tomcat/bin/setenv.sh", "item": {"dest": "/var/lib/tomcat/bin", "mode": "u=rwx,g=rx,o=rx", "name": "setenv.sh", "src": "tomcat/conf"}, "src": "/var/lib/tomcat/.ansible/tmp/ansible-local-7wF_TBA/tmpoKNYRW/setenv.sh.j2"} ok: [localhost] => (item={u'dest': u'/var/lib/tomcat/conf', u'src': u'tomcat/conf', u'name': u'web.xml', u'mode': u'u=rw,g=r,o=r'}) => {"ansible_loop_var": "item", "changed": false, "dest": "/var/lib/tomcat/conf/web.xml", "item": {"dest": "/var/lib/tomcat/conf", "mode": "u=rw,g=r,o=r", "name": "web.xml", "src": "tomcat/conf"}, "src": "/var/lib/tomcat/.ansible/tmp/ansible-local-7wF_TBA/tmpIf9aX6/web.xml.j2"}
TASK [ensure Kill Bill dirs exist] ***** task path: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/roles/killbill/tasks/main.yml:2 ok: [localhost] => (item=/var/lib/killbill) => {"ansible_loop_var": "item", "changed": false, "gid": 1000, "group": "tomcat", "item": "/var/lib/killbill", "mode": "0755", "owner": "tomcat", "path": "/var/lib/killbill", "size": 4096, "state": "directory", "uid": 1000} ok: [localhost] => (item=/var/lib/killbill/bundles) => {"ansible_loop_var": "item", "changed": false, "gid": 1000, "group": "tomcat", "item": "/var/lib/killbill/bundles", "mode": "0755", "owner": "tomcat", "path": "/var/lib/killbill/bundles", "size": 4096, "state": "directory", "uid": 1000}
TASK [generate Kill Bill files] **** task path: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/roles/killbill/tasks/main.yml:10 changed: [localhost] => (item={u'name': u'killbill.properties'}) => {"ansible_loop_var": "item", "changed": true, "checksum": "ba865437ace56aa1ade3924224af4b717d5a4b76", "dest": "/var/lib/killbill/killbill.properties", "gid": 1000, "group": "tomcat", "item": {"name": "killbill.properties"}, "md5sum": "71fa61d3c958df1ad7e4f2c9712ac54c", "mode": "0644", "owner": "tomcat", "size": 724, "src": "/var/lib/tomcat/.ansible/tmp/ansible-tmp-1588012258.23-107513440801245/source", "state": "file", "uid": 1000} changed: [localhost] => (item={u'name': u'logback.xml'}) => {"ansible_loop_var": "item", "changed": true, "checksum": "0727f46785236b2525bf4efc0ca2b59035d32b2d", "dest": "/var/lib/killbill/logback.xml", "gid": 1000, "group": "tomcat", "item": {"name": "logback.xml"}, "md5sum": "0f7e997349693bc3e10155014c56290f", "mode": "0644", "owner": "tomcat", "size": 13394, "src": "/var/lib/tomcat/.ansible/tmp/ansible-tmp-1588012258.93-153047265889265/source", "state": "file", "uid": 1000}
TASK [generate Tomcat files] *** task path: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/roles/killbill/tasks/main.yml:24 changed: [localhost] => (item={u'dest': u'/var/lib/tomcat/bin', u'src': u'killbill/conf', u'name': u'setenv2.sh', u'mode': u'u=rwx,g=rx,o=rx'}) => {"ansible_loop_var": "item", "changed": true, "checksum": "b1f1d704dcf6ce484a4a8aba80e0950d4f552784", "dest": "/var/lib/tomcat/bin/setenv2.sh", "gid": 1000, "group": "tomcat", "item": {"dest": "/var/lib/tomcat/bin", "mode": "u=rwx,g=rx,o=rx", "name": "setenv2.sh", "src": "killbill/conf"}, "md5sum": "e3b9b421eee9a3127a0a3af9c4245245", "mode": "0755", "owner": "tomcat", "size": 325, "src": "/var/lib/tomcat/.ansible/tmp/ansible-tmp-1588012259.32-103801515307546/source", "state": "file", "uid": 1000}
TASK [run KPM install] ***** task path: /var/lib/tomcat/.ansible/roles/killbill-cloud/ansible/roles/killbill/tasks/main.yml:40 changed: [localhost] => {"changed": true, "msg": "I, [2020-04-27T18:31:01.391533 #523] INFO -- : Starting download of org.kill-bill.billing:killbill-profiles-killbill:war:0.22.8 to /tmp/d20200427-523-1jdsk8p\nI, [2020-04-27T18:31:02.761708 #523] INFO -- : Successful installation of org.kill-bill.billing:killbill-profiles-killbill:war:0.22.8 to /var/lib/tomcat/webapps\nI, [2020-04-27T18:31:03.532062 #523] INFO -- : Starting download of org.kill-bill.billing:killbill-platform-osgi-bundles-defaultbundles:tar.gz:0.39.15 to /tmp/d20200427-523-1mtw4w6\nI, [2020-04-27T18:31:06.112810 #523] INFO -- : Successful installation of org.kill-bill.billing:killbill-platform-osgi-bundles-defaultbundles:tar.gz:0.39.15 to /var/lib/killbill/bundles/platform\n"} META: ran handlers META: ran handlers
PLAY RECAP ***** localhost : ok=8 changed=3 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0
-XX:+CMSClassUnloadingEnabled -XX:+CMSConcurrentMTEnabled -XX:CMSInitiatingOccupancyFraction=50 -XX:+CMSParallelRemarkEnabled -XX:+CMSScavengeBeforeRemark -XX:+DisableExplicitGC -XX:GCLogFileSize=104857600 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/var/lib/tomcat/logs/ -XX:InitialHeapSize=536870912 -XX:+ManagementServer -XX:MaxHeapSize=2147483648 -XX:MaxNewSize=1073741824 -XX:NewSize=268435456 -XX:NumberOfGCLogFiles=14 -XX:OldPLABSize=16 -XX:-OmitStackTraceInFastThrow -XX:+PrintCommandLineFlags -XX:+PrintGC -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintTenuringDistribution -XX:+ScavengeBeforeFullGC -XX:SurvivorRatio=10 -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCodeCacheFlushing -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseGCLogFileRotation -XX:+UseParNewGC Listening for transport dt_socket at address: 12345 openjdk version "1.8.0_232" OpenJDK Runtime Environment (build 1.8.0_232-8u232-b09-0ubuntu1~16.04.1-b09) OpenJDK 64-Bit Server VM (build 25.232-b09, mixed mode)
Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Server version: Apache Tomcat/8.5.16 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Server built: Jun 21 2017 17:01:09 UTC Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Server number: 8.5.16.0 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: OS Name: Linux Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: OS Version: 4.15.0-1075-azure Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Architecture: amd64 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Java Home: /usr/lib/jvm/java-8-openjdk-amd64/jre Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: JVM Version: 1.8.0_232-8u232-b09-0ubuntu1~16.04.1-b09 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: JVM Vendor: Private Build Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: CATALINA_BASE: /var/lib/tomcat Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: CATALINA_HOME: /opt/apache-tomcat-8.5.16 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dnop Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Djdk.tls.ephemeralDHKeySize=2048 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+PrintCommandLineFlags Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+HeapDumpOnOutOfMemoryError Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:HeapDumpPath=/var/lib/tomcat/logs/ Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+UseCodeCacheFlushing Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Xms512m Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Xmx2G Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=12345 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+CMSClassUnloadingEnabled Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:-OmitStackTraceInFastThrow Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+UseParNewGC Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+UseConcMarkSweepGC Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+CMSConcurrentMTEnabled Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+ScavengeBeforeFullGC Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+CMSScavengeBeforeRemark Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+CMSParallelRemarkEnabled Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+UseCMSInitiatingOccupancyOnly Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:CMSInitiatingOccupancyFraction=50 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:NewSize=256m Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:MaxNewSize=1024m Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:SurvivorRatio=10 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+DisableExplicitGC Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Xloggc:/var/lib/tomcat/logs/gc.log Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+PrintGCApplicationConcurrentTime Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+PrintGCApplicationStoppedTime Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+PrintGCDateStamps Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+PrintGCDetails Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+PrintTenuringDistribution Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:+UseGCLogFileRotation Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:NumberOfGCLogFiles=14 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -XX:GCLogFileSize=100M Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dcom.sun.xml.bind.v2.bytecode.ClassTailor.noOptimize=true Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dcom.sun.management.jmxremote=true Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dcom.sun.management.jmxremote.authenticate=false Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dcom.sun.management.jmxremote.port=8000 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dcom.sun.management.jmxremote.rmi.port=8000 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dcom.sun.management.jmxremote.ssl=false Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Djava.rmi.server.hostname=localhost Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Djava.security.egd=file:/dev/./urandom Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Djruby.compile.invokedynamic=false Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dlog4jdbc.sqltiming.error.threshold=1000 Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dorg.killbill.queue.creator.name=localhost Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dlogback.configurationFile=/var/lib/killbill/logback.xml Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dorg.killbill.server.properties=file:///var/lib/killbill/killbill.properties Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dcatalina.base=/var/lib/tomcat Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dcatalina.home=/usr/share/tomcat Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Djava.io.tmpdir=/var/tmp Apr 27, 2020 6:31:07 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent INFO: Loaded APR based Apache Tomcat Native library [1.2.12] using APR version [1.5.2]. Apr 27, 2020 6:31:07 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true]. Apr 27, 2020 6:31:07 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent INFO: APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true] Apr 27, 2020 6:31:07 PM org.apache.catalina.core.AprLifecycleListener initializeSSL INFO: OpenSSL successfully initialized [OpenSSL 1.0.2g 1 Mar 2016] Apr 27, 2020 6:31:07 PM org.apache.coyote.AbstractProtocol init INFO: Initializing ProtocolHandler ["http-nio-8080"] Apr 27, 2020 6:31:07 PM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector INFO: Using a shared selector for servlet write/read Apr 27, 2020 6:31:07 PM org.apache.catalina.startup.Catalina load INFO: Initialization processed in 1179 ms Apr 27, 2020 6:31:07 PM org.apache.catalina.core.StandardService startInternal INFO: Starting service [Catalina] Apr 27, 2020 6:31:07 PM org.apache.catalina.core.StandardEngine startInternal INFO: Starting Servlet Engine: Apache Tomcat/8.5.16 Apr 27, 2020 6:31:08 PM org.apache.catalina.startup.HostConfig deployWAR INFO: Deploying web application archive [/var/lib/tomcat/webapps/ROOT.war] Apr 27, 2020 6:31:16 PM org.apache.jasper.servlet.TldScanner scanJars INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time. 18:31:16,688 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [/var/lib/killbill/logback.xml] at [file:/var/lib/killbill/logback.xml] 18:31:16,799 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set 18:31:16,811 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Will scan for changes in [file:/var/lib/killbill/logback.xml] 18:31:16,811 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Setting ReconfigureOnChangeTask scanning period to 30 seconds 18:31:16,813 |-INFO in ch.qos.logback.classic.joran.action.JMXConfiguratorAction - begin 18:31:16,820 |-INFO in ch.qos.logback.core.joran.action.ConversionRuleAction - registering conversion word maskedMsg with class [org.killbill.billing.server.log.obfuscators.ObfuscatorConverter] 18:31:16,820 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender] 18:31:16,883 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [MAIN] 18:31:16,984 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@83104158 - Will use gz compression 18:31:16,986 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@83104158 - Will use the pattern /var/lib/tomcat/logs/killbill-%d{yyyy-MM-dd}.%i.out for the active file 18:31:16,989 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@2be9d606 - The date pattern is 'yyyy-MM-dd' from file name pattern '/var/lib/tomcat/logs/killbill-%d{yyyy-MM-dd}.%i.out.gz'. 18:31:16,989 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@2be9d606 - Roll-over at midnight. 18:31:16,990 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@2be9d606 - Setting initial period to Mon Apr 27 18:31:16 UTC 2020 18:31:16,990 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@2be9d606 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead 18:31:16,990 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@2be9d606 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy 18:31:16,992 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@83104158 - Cleaning on start up 18:31:16,993 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - first clean up after appender initialization 18:31:16,994 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - Multiple periods, i.e. 32 periods, seem to have elapsed. This is expected at application start. 18:31:16,994 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 18:31:17,194 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[MAIN] - Active log file name: /var/lib/tomcat/logs/killbill.out 18:31:17,194 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[MAIN] - File property is set to [/var/lib/tomcat/logs/killbill.out] 18:31:17,196 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender] 18:31:17,196 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [JDBI] 18:31:17,197 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@19339457 - Will use gz compression 18:31:17,197 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@19339457 - Will use the pattern /var/lib/tomcat/logs/jdbi-%d{yyyy-MM-dd}.%i.out for the active file 18:31:17,198 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@338da720 - The date pattern is 'yyyy-MM-dd' from file name pattern '/var/lib/tomcat/logs/jdbi-%d{yyyy-MM-dd}.%i.out.gz'. 18:31:17,198 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@338da720 - Roll-over at midnight. 18:31:17,198 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@338da720 - Setting initial period to Mon Apr 27 18:31:17 UTC 2020 18:31:17,198 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@338da720 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead 18:31:17,198 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@338da720 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy 18:31:17,199 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@19339457 - Cleaning on start up 18:31:17,199 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - first clean up after appender initialization 18:31:17,199 |-INFO in c.q.l.core.rolling.helper.TimeBasedArchiveRemover - Multiple periods, i.e. 32 periods, seem to have elapsed. This is expected at application start. 18:31:17,200 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 18:31:17,202 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[JDBI] - Active log file name: /var/lib/tomcat/logs/jdbi.out 18:31:17,202 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[JDBI] - File property is set to [/var/lib/tomcat/logs/jdbi.out] 18:31:17,203 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 18:31:17,205 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-sqlonly] 18:31:17,214 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 18:31:17,214 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-sqltiming] 18:31:17,215 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 18:31:17,215 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-audit] 18:31:17,215 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 18:31:17,215 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-resultset] 18:31:17,216 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 18:31:17,216 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-resultsettable] 18:31:17,216 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 18:31:17,217 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SIFT-jdbc-connection] 18:31:17,282 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.sqlonly] to OFF 18:31:17,282 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.sqlonly] to false 18:31:17,283 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-sqlonly] to Logger[jdbc.sqlonly] 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.sqltiming] to ERROR 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.sqltiming] to false 18:31:17,284 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-sqltiming] to Logger[jdbc.sqltiming] 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.audit] to OFF 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.audit] to false 18:31:17,284 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-audit] to Logger[jdbc.audit] 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.resultset] to OFF 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.resultset] to false 18:31:17,284 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-resultset] to Logger[jdbc.resultset] 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.resultsettable] to OFF 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.resultsettable] to false 18:31:17,284 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-resultsettable] to Logger[jdbc.resultsettable] 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [jdbc.connection] to OFF 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [jdbc.connection] to false 18:31:17,284 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SIFT-jdbc-connection] to Logger[jdbc.connection] 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.jooq.Constants] to OFF 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.dmurph] to INFO 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.killbill.billing.notificationq] to INFO 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.killbill.billing.queue] to INFO 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.eclipse] to INFO 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.killbill.billing.server.updatechecker] to WARN 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.killbill.commons.jdbi.guice.DBIProvider] to INFO 18:31:17,284 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.killbill.commons.jdbi.guice.DBIProvider] to false 18:31:17,285 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [JDBI] to Logger[org.killbill.commons.jdbi.guice.DBIProvider] 18:31:17,285 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO 18:31:17,285 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [MAIN] to Logger[ROOT] 18:31:17,285 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 18:31:17,285 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@17d1382e - Registering current configuration as safe fallback point