killbill / killbill-platform

Kill Bill core platform
https://killbill.io
Apache License 2.0
25 stars 42 forks source link

Update org.osgi.service.log to 1.5.x #120

Closed xsalefter closed 1 year ago

xsalefter commented 2 years ago

We have this. But it turn out that working on this need more work and testing than I thought, so the PR will be closed and work will be allocated after https://github.com/killbill/killbill-oss-parent/issues/552 completed.

Quote from the PR:

Wondering if we can better refactor this...

OSGI bundles can currently request a LogService which is provided by KillbillLogWriter. Our implementation simply delegates it to (slf4j) LoggerFactory (logback in practice).

LogService has been deprecated (https://docs.osgi.org/specification/osgi.cmpn/7.0.0/service.log.html) and bundles should now be using (osgi) LoggerFactory. I still think we should support it for now though, but the "main" service implementation should be a KillbillLoggerFactory which implements (osgi) LoggerFactory, returns a KillbillLogger, which then delegates to (slf4j) LoggerFactory.

KillbillLogWriter should essentially internally only rely on KillbillLoggerFactory / KillbillLogger (instead of relying on both slf4j and (osgi) LoggerFactory as you have refactored.

See slide 17 of https://www.slideshare.net/bjhargrave/the-new-osgi-logservice-14-and-integrating-with-slf4j which describes exactly our problem: we have bundles (e.g. Kill Bill plugins) directly relying on slf4j and pure osgi bundles relying on the OSGI log services (e.g. core Felix framework). We should feed everything into slf4j (option 1 of slide 18).

Maybe we can also re-use existing work... There might be some classes upstream (slf4j project? Felix?) which can already implement some of this, to be investigated (the (osgi) Logger has quite a few methods to implement...). The only tricky bit is the integration with LogEntriesManager, which provides an HTTP API (Server-sent events) to retrieve these logs (this is how the KPM UI in Kaui works). We should make sure this doesn't break.

As part of this, I recommend doing quite a bit of testing with a Kill Bill plugin but also some generic OSGI bundle (https://felix.apache.org/documentation/downloads.html), to verify the logs still flow correctly to the main slf4j system (and that the logback configuration applies to these, e.g. logs from bundles should respect the defined logback format from the logback.xml).

Note: the astute reader will notice that LogEntriesManager only receives OSGI logs, not slf4j ones (e.g. logs from Kill Bill plugins using slf4j directly). This is a long standing limitation (last I checked, there isn't a way to listen to slf4j logs).

BTW feel free to remove jruby references (support removed in 0.23.x).

pierre commented 2 years ago

Since the upgrade will involve heavily testing the SSE logs integration with Kaui, we should look at https://github.com/killbill/killbill-platform/issues/61 at the same time.

xsalefter commented 1 year ago

Testing preparation

To make sure testing are repeatable and could be understand clearly, we need to prepare configuration before testing executed.

  1. killbill-server properties configuration: See file named "platform-120-killbill-server.properties" below
  2. logback configuration: See file named "platform-120-logback.xml" below
  3. killbill-platform build with <osgi-export>org.killbill.billing.osgi.bundles.logger;version=${project.version}</osgi-export>
  4. Killbill plugin used for testing are the killbill-hello-world-java-plugin and killbill-platform-osgi-bundles-eureka.
  5. Felix Plugin used for testing are <call reset && grep -Rl "org.slf4j.LoggerFactory" to /mnt/data/vcs/git/github/apache/felix-dev>
  6. Killbill run locally using this command:
    mvn jetty:run \
     -Dorg.killbill.server.properties=file:///home/xsalefter/killbill-workspace/platform-120-killbill-server.properties \
     -Dlogback.configurationFile=file:///home/xsalefter/killbill-workspace/platform-120-logback.xml
  7. Use killbill-platform-osgi-bundles-eureka's README.md for Eureka installation (except that we only use 1 killbill instance).

Testing Execution

To see if logback log messages properly, testing will only use ROLLING appender so there's no log message will be showing up in the console.

Verify that a KB plugin using slf4j directly sends correctly logs to logback

  1. Run Eureka server
  2. Install killbill-platform-osgi-bundles-logger and killbill-platform-osgi-bundles-eureka plugins
  3. Run killbill (see point 6 above)
  4. Using killbill-http-client, call putOutOfRotation()

We should see these new lines in log output files (but nothing showing up in the console):

--------------> Setting Eureka Status to DOWN <----------------
--------------> Finished setting Eureka Status to DOWN <----------------

:heavy_check_mark:

Verify that a KB plugin relying on the new OSGI LoggerFactory has its logs sent to logback when the logger bundle is installed

  1. Install killbill-platform-osgi-bundles-logger, modified version of killbill-hello-world-java-plugin <TODO link should be added> and killbill-platform-osgi-bundles-eureka plugins
  2. Run killbill (see point 6 above)
  3. Call GET http://localhost:8080/plugins/hello-world-plugin

There's 3 lines of log that comes from:

  1. Native logback logger
  2. New OSGI's LoggerFactory implementation
  3. Deprecated (but need to be supported) OSGI's LogService implementation

:heavy_check_mark:

Check what happens when a KB plugin is relying on the new OSGI LoggerFactory and when the logger bundle is NOT installed (“service not present exception” maybe?)

  1. Make sure that killbill-platform-osgi-bundles-logger (and killbill-platform-osgi-bundles-eureka, is used) get removed.
  2. Install killbill-hello-world-java-plugin
  3. Run killbill (see point 6 above)

There's 2 condition:

  1. If bundle declaring OSGI import statement, then the exception is:
    org.osgi.framework.BundleException: 
    Unable to resolve org.kill-bill.billing.plugin.java.hello-world-plugin [1](R 1.0): 
    missing requirement [org.kill-bill.billing.plugin.java.hello-world-plugin [1](R 1.0)] osgi.wiring.package; (&(osgi.wiring.package=org.killbill.billing.osgi.bundles.logger)(version>=0.41.0.SNAPSHOT)) 
    Unresolved requirements: [[org.kill-bill.billing.plugin.java.hello-world-plugin [1](R 1.0)] osgi.wiring.package; (&(osgi.wiring.package=org.killbill.billing.osgi.bundles.logger)(version>=0.41.0.SNAPSHOT))]
  2. If bundle not declaring OSGI import, then the exception is:
    2022-12-09T23:51:44,633+0000 lvl='WARN', log='FileInstall', th='main', xff='', rId='', tok='', aRId='', tRId='', Unable to start bundle
    org.osgi.framework.BundleException: Activator start error in bundle org.kill-bill.billing.plugin.java.hello-world-plugin [1]

:heavy_check_mark:

Install a generic OSGI bundle (e.g. from Felix project) and check that its logs flow to the core logback system

  1. Make sure that killbill-platform-osgi-bundles-logger installed.
  2. Run killbill (see point 6 above)

Webconsole showing up, and I checked the log appear in the shell console.

felix-webconsole

Run Killbill with KAUI and make sure that SSE pass thrugh KAUI console

  1. Make sure that killbill-platform-osgi-bundles-logger and kpm installed.
  2. Run killbill (see point 6 above)
  3. Run KAUI

I think my changes not breaking anything, since I see this: killbill-kpm-logs

xsalefter commented 1 year ago

File: platform-120-logback.xml :

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE configuration>

<configuration>

  <conversionRule conversionWord="maskedMsg" converterClass="org.killbill.billing.server.log.obfuscators.ObfuscatorConverter" />

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%date{"yyyy-MM-dd'T'HH:mm:ss,SSSZ", UTC} lvl='%level', log='%logger{0}', th='%thread', xff='%X{req.xForwardedFor}', rId='%X{req.requestId}', tok='%X{kb.userToken}', aRId='%X{kb.accountRecordId}', tRId='%X{kb.tenantRecordId}', %maskedMsg%n</pattern>
    </encoder>
  </appender>

  <appender name="ROLLING" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>killbill-log.txt</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
      <fileNamePattern>killbill-log-%d{yyyy-MM-dd}.%i.txt</fileNamePattern>
      <maxFileSize>200KB</maxFileSize>
      <totalSizeCap>10GB</totalSizeCap>
    </rollingPolicy>
    <encoder>
      <pattern>%msg%n</pattern>
    </encoder>
  </appender>

  <!-- These loggers are needed, otherwise there's bunch of log4jdbc spamming -->

  <logger name="jdbc.sqlonly" level="OFF" additivity="false">
    <appender-ref ref="SIFT-jdbc-sqlonly"/>
  </logger>
  <logger name="jdbc.sqltiming" level="OFF" additivity="false">
    <appender-ref ref="SIFT-jdbc-sqltiming"/>
  </logger>
  <logger name="jdbc.audit" level="OFF" additivity="false">
    <appender-ref ref="SIFT-jdbc-audit"/>
  </logger>
  <logger name="jdbc.resultset" level="OFF" additivity="false">
    <appender-ref ref="SIFT-jdbc-resultset"/>
  </logger>
  <logger name="jdbc.resultsettable" level="OFF" additivity="false">
    <appender-ref ref="SIFT-jdbc-resultsettable"/>
  </logger>
  <logger name="jdbc.connection" level="OFF" additivity="false">
    <appender-ref ref="SIFT-jdbc-connection"/>
  </logger>
  <logger name="org.jooq.Constants" level="OFF"/>
  <logger name="com.dmurph" level="OFF"/>
  <logger name="org.eclipse" level="INFO"/>
  <logger name="org.killbill.billing.server.updatechecker" level="INFO"/>
  <logger name="org.killbill.billing.jaxrs.resources" level="INFO"/>
  <logger name="org.killbill.notificationq" level="INFO"/>
  <logger name="org.killbill.queue" level="INFO"/>

  <root level="INFO">
    <appender-ref ref="STDOUT" />
    <!--<appender-ref ref="ROLLING" />-->
  </root>

</configuration>
xsalefter commented 1 year ago

File named platform-120-killbill-server.properties :

org.killbill.dao.url=jdbc:mysql://127.0.0.1:3306/killbill_dev
org.killbill.dao.user=root
org.killbill.dao.password=admin

# Database config (OSGI plugins)
org.killbill.billing.osgi.dao.url=jdbc:mysql://127.0.0.1:3306/killbill_osgi_dev
org.killbill.billing.osgi.dao.user=root
org.killbill.billing.osgi.dao.password=admin

# Eureka client specifics configuration. Read more https://github.com/Netflix/eureka/wiki/Configuring-Eureka
eureka.serviceUrl.default=http://localhost:8761/eureka

eureka.registration.enabled=true
eureka.name=killbill
eureka.port.enabled=true
eureka.securePort.enabled=false

eureka.statusPageUrlPath=/1.0/metrics
eureka.healthCheckUrlPath=/1.0/healthCheck

eureka.decoderName=JacksonJson
eureka.preferSameZone=true
eureka.shouldUseDns=false

# Enable eureka in Kill Bill
org.killbill.eureka=true

org.killbill.osgi.bundle.install.dir=/home/xsalefter/killbill-plugins

# needed if want to use KAUI user interface
org.killbill.security.shiroResourcePath=/home/xsalefter/killbill-workspace/shiro.ini