Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Provide Liquibase SLF4J bridge as an OSGi fragment #12

Closed
erwindl0 opened this issue Jan 5, 2022 · 14 comments
Closed

Provide Liquibase SLF4J bridge as an OSGi fragment #12

erwindl0 opened this issue Jan 5, 2022 · 14 comments

Comments

@erwindl0
Copy link

erwindl0 commented Jan 5, 2022

In an OSGi runtime we also would like to bridge Liquibase 4.x's logging to SLF4J.

To get this working, Liquibase-SLF4J should be packaged as a fragment, with Liquibase core as the host bundle.
Then the Slf4JLogService can be discovered by Liquibase's ServiceLocator.

Cfr ongoing work and discussions:

I propose to prepare a PR for this?

erwindl0 added a commit to erwindl0/liquibase-slf4j that referenced this issue Jan 5, 2022
@mattbertolini
Copy link
Owner

Hi. Thanks for reporting. I'm only vaguely familiar with OSGi and what I have been exposed to has left me a bit underwhelmed. I am pretty hesitant to add something I will need to maintain that I don't necessary understand. Based on that first link, it sounds like this fragment has been created and published. Is there some reason that the other library can't be used?

@erwindl0
Copy link
Author

erwindl0 commented Jan 6, 2022

Thanks for the quick reaction.

I would prefer that the "real source" of the Liquibase-SLF4J bridge would support both basic Java runtimes and modular ones.
(Also, the Karaf feature project has not yet been updated to liquibase 4.x.)

But if you prefer I can either contact them to ask them to upgrade, or maintain my own fork independently?

@mattbertolini
Copy link
Owner

mattbertolini commented Jan 29, 2022

@erwindl0 I was able to generate this manifest with BND. Will this work?

Manifest-Version: 1.0
Ant-Version: Apache Ant 1.10.12
Automatic-Module-Name: com.mattbertolini.liquibase.logging.slf4j
Bnd-LastModified: 1643486539173
Bundle-ManifestVersion: 2
Bundle-Name: liquibase-slf4j
Bundle-SymbolicName: com.mattbertolini.liquibase.logging.slf4j
Bundle-Version: 4.1.0-SNAPSHOT
Created-By: 17 (Eclipse Adoptium)
Export-Package: com.mattbertolini.liquibase.logging.slf4j;version="4.1
 .0-SNAPSHOT"
Fragment-Host: org.liquibase.core;bundle-version=4.1.0
Implementation-Title: liquibase-slf4j
Implementation-Version: 4.1.0-SNAPSHOT
Import-Package: org.slf4j;version="[1.7,2)"
Originally-Created-By: 17+35 (Eclipse Adoptium)
Require-Capability: osgi.ee;filter:="(&(osgi.ee=JavaSE)(version=1.8))"
Specification-Title: liquibase-slf4j
Specification-Version: 4.1.0-SNAPSHOT
Tool: Bnd-6.1.0.202111221555

@mattbertolini
Copy link
Owner

I published a snapshot with the generated manifest. Let me know if it works for you.

https://oss.sonatype.org/content/repositories/snapshots/com/mattbertolini/liquibase-slf4j/4.1.0-SNAPSHOT/

@gmilani
Copy link

gmilani commented Feb 16, 2022

Hello guys,
I'm also trying to bridge Liquibase and SLF4J using Apache Karaf (4.2.15).
@mattbertolini I was able to install your SNAPSHOT, it is resolved and attached to liquibase-core (4.1.0), but for now still having "UnexpectedLiquibaseException: Cannot find default log service".

 47 │ Resolved │  60 │ 4.1.0.SNAPSHOT     │ liquibase-slf4j, Hosts: 247
247 │ Active   │  60 │ 4.1.0              │ liquibase-core, Fragments: 47
liquibase-slf4j (47)
--------------------
Ant-Version = Apache Ant 1.10.10
Automatic-Module-Name = com.mattbertolini.liquibase.logging.slf4j
Bnd-LastModified = 1643552376881
Created-By = 11.0.14 (Eclipse Adoptium)
Fragment-Host = org.liquibase.core;bundle-version="[4.1.0,5)"
Implementation-Title = liquibase-slf4j
Implementation-Version = 4.1.0-SNAPSHOT
Manifest-Version = 1.0
Originally-Created-By = 11.0.14+9 (Eclipse Adoptium)
Specification-Title = liquibase-slf4j
Specification-Version = 4.1.0-SNAPSHOT
Tool = Bnd-6.1.0.202111221555

Bundle-ManifestVersion = 2
Bundle-Name = liquibase-slf4j
Bundle-SymbolicName = com.mattbertolini.liquibase.logging.slf4j
Bundle-Version = 4.1.0.SNAPSHOT

Require-Capability = 
	osgi.ee;filter:=(&(osgi.ee=JavaSE)(version=1.8))

Export-Package = 
	com.mattbertolini.liquibase.logging.slf4j;version=4.1.0.SNAPSHOT
Import-Package = 
	org.slf4j;version="[1.7,2)"

I'll let you know if I find more information about this issue.

@mattbertolini
Copy link
Owner

Thanks for the report. I don't know too much about OSGi so any assistance would be appreciated. Do you have a stacktrace for the error? That will help pinpoint where in Liquibase its having issues.

The "Cannot find default log service" usually means something is trying to load the service before the scope is fully active in Liquibase. I also know that Liquibase frequently breaks OSGi support. I think they just fixed something else in 4.7.1 so I would try an updated version.

Lastly, I don't have an example project using OSGi so if you one or have pointers on how to set one up, that would be greatly appreciated.

@gmilani
Copy link

gmilani commented Feb 16, 2022

I'm quite busy those days but here is already some information, I'll try to expand asap.

The following stacktrace is displayed during the connection pre-hook. This hook is called during the datasource creation, before it is available for services trying to inject it.

java.lang.ExceptionInInitializerError: null
	at myproject.database.migration.Migrator.prepare(Migrator.java:41) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.DataSourceRegistration.<init>(DataSourceRegistration.java:88) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.DataSourceConfigManager.lambda$null$0(DataSourceConfigManager.java:85) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.ServiceTrackerHelper$1.addingService(ServiceTrackerHelper.java:132) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261) ~[osgi.core-6.0.0.jar:?]
	at org.ops4j.pax.jdbc.config.impl.ServiceTrackerHelper.track(ServiceTrackerHelper.java:141) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.DataSourceConfigManager.lambda$null$1(DataSourceConfigManager.java:81) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.ServiceTrackerHelper$1.addingService(ServiceTrackerHelper.java:132) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261) ~[osgi.core-6.0.0.jar:?]
	at org.ops4j.pax.jdbc.config.impl.ServiceTrackerHelper.track(ServiceTrackerHelper.java:141) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.ServiceTrackerHelper.track(ServiceTrackerHelper.java:86) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.DataSourceConfigManager.lambda$null$2(DataSourceConfigManager.java:80) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.ServiceTrackerHelper$1.addingService(ServiceTrackerHelper.java:132) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318) ~[osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261) ~[osgi.core-6.0.0.jar:?]
	at org.ops4j.pax.jdbc.config.impl.ServiceTrackerHelper.track(ServiceTrackerHelper.java:141) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.ServiceTrackerHelper.track(ServiceTrackerHelper.java:86) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.DataSourceConfigManager.lambda$updated$3(DataSourceConfigManager.java:79) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.ServiceTrackerHelper.track(ServiceTrackerHelper.java:147) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.ServiceTrackerHelper.track(ServiceTrackerHelper.java:86) ~[?:?]
	at org.ops4j.pax.jdbc.config.impl.DataSourceConfigManager.updated(DataSourceConfigManager.java:78) ~[?:?]
	at org.apache.felix.cm.impl.helper.ManagedServiceFactoryTracker.updated(ManagedServiceFactoryTracker.java:159) ~[!/:?]
	at org.apache.felix.cm.impl.helper.ManagedServiceFactoryTracker.provideConfiguration(ManagedServiceFactoryTracker.java:93) [!/:?]
	at org.apache.felix.cm.impl.ConfigurationManager$UpdateConfiguration.run(ConfigurationManager.java:1416) [!/:?]
	at org.apache.felix.cm.impl.UpdateThread.run0(UpdateThread.java:122) [!/:?]
	at org.apache.felix.cm.impl.UpdateThread.run(UpdateThread.java:84) [!/:?]
	at java.lang.Thread.run(Thread.java:750) [?:1.8.0_322]
Caused by: liquibase.exception.UnexpectedLiquibaseException: Cannot find default log service
	at liquibase.Scope.getCurrentScope(Scope.java:85) ~[?:?]
	at liquibase.database.DatabaseFactory.<clinit>(DatabaseFactory.java:20) ~[?:?]
	... 42 more

Here is the PreHook :

package myproject.database.migration;

import liquibase.Contexts;
import liquibase.Liquibase;
import liquibase.database.Database;
import liquibase.database.DatabaseFactory;
import liquibase.database.jvm.JdbcConnection;
import liquibase.exception.LiquibaseException;
import liquibase.lockservice.LockServiceFactory;
import liquibase.lockservice.StandardLockService;
import liquibase.resource.OSGiResourceAccessor;
import org.ops4j.pax.cdi.api.OsgiServiceProvider;
import org.ops4j.pax.cdi.api.Properties;
import org.ops4j.pax.cdi.api.Property;
import org.ops4j.pax.jdbc.hook.PreHook;
import org.osgi.framework.BundleContext;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import javax.inject.Inject;
import javax.inject.Singleton;
import javax.sql.DataSource;
import java.sql.Connection;
import java.sql.SQLException;

/**
 * Uses liquibase to apply all changesets from the file db/changesetes.xml to the DataSource.
 * The PreeHook will be called by pax-jdbc-config before publishing the DataSource.
 */
@OsgiServiceProvider
@Properties({@Property(name = "name", value = "migrator")})
@Singleton
public class Migrator implements PreHook {
    private static Logger logger = LoggerFactory.getLogger(Migrator.class);

    @Inject
    BundleContext bundleContext;

    @Override
    public void prepare(DataSource ds) throws SQLException {
        try (Connection connection = ds.getConnection()) {
            Database db = DatabaseFactory.getInstance().findCorrectDatabaseImplementation(new JdbcConnection(connection)); // This is line 41
            LockServiceFactory.getInstance().register(new StandardLockService());
            OSGiResourceAccessor resourceAccessor = new OSGiResourceAccessor(bundleContext.getBundle());
            try (Liquibase liquibase = new Liquibase("db/changesets.xml", resourceAccessor, db)) {
                logger.debug("Liquibase SQL check ...");
                liquibase.update(new Contexts());
                logger.debug("Liquibase SQL check done.");
            } catch (Exception e) {
                throw new LiquibaseException(e);
            }
        } catch (LiquibaseException e) {
            throw new RuntimeException(e);
        }
    }
}

I can later provide you a repository with a simple example to reproduce.
Thank you for the attention !

@mattbertolini
Copy link
Owner

mattbertolini commented Feb 16, 2022

I've published another snapshot to maven central snapshots. I've added the following to my manifest:

Provide-Capability: osgi.serviceloader; osgi.serviceloader=liquibase.logging.LogService
Require-Capability: osgi.serviceloader; filter:="(osgi.serviceloader=liquibase.logging.LogService)"; cardinality:=multiple

I realized that I wasn't exposing the JDK ServiceLoader info and after reading a blog post or two on OSGi I thought it was worth a shot.

@gmilani
Copy link

gmilani commented Feb 24, 2022

Hi @mattbertolini ,
Unfortunately I still have the same issue. To help you (or anybody else who could help), I prepared a basic Karaf application.
It is supposed to execute a migration script on a HSQL database when the datasource is created. The migrator is executed and the exception I mentioned before happens.

Of course, I were not further in the process and there will maybe an other issue with Liquibase during the migration once the logging issue is solved, so don't be surprised if the script isn't applied to the database.

https://github.com/gmilani/karaf-liquibase-logging

Don't hesitate to ask if I can help you, having your library running on OSGi would be a really valuable achievement for me.
Thank you for the job you already made !

@mattbertolini
Copy link
Owner

Thanks @gmilani. This is very helpful.

Are we sure that Liquibase works without the slfj4j jar? I ask because even if slfj4j isn't found from the bundle the default logger should be found and it is not. I am not sure the version of Liquibase used (4.4.x) is working with OSGi. Getting it to work without the slf4j logging bridge jar is the first step to knowing what's going on.

@erwindl0
Copy link
Author

Hi all,

Sorry I have not been active in helping out on this.

But just a rapid confirmation:

When you run liquibase(4.4.3 in my case) in an OSGi container (Equinox in my case), it does work.
But it uses the std Java logger which I am unable to configure in my environment.
There is no dependency on SLF4j in Liquibase itself (as can be checked in their MANIFEST).

The result of mixed logging (Slf4j for everything except Liquibase; java.util.loggin for Liquibase) is similar to below:
(LiquibaseChangeDeployer is my code to react on an event in the application to then trigger Liquibase)

image

With a correctly built liquibase-slf4j fragment, we get a single integrated slf4j-based log as below.
(I have defined the manifest manually though, I'll try later today with the one you generated with BND) :

2022-02-25 11:09:06 TRACE [ Start Level: Equinox Container: cb0a510a-ede8-4c04-a6b6-d34f513807e7     ] checkDatabaseChanges() - entry - PU master [LiquibaseChangeDeployer:193]
2022-02-25 11:09:06 TRACE [ Start Level: Equinox Container: cb0a510a-ede8-4c04-a6b6-d34f513807e7     ] deployDatabaseChanges() - entry : changelog pas_xr_master_changelog.xml for PU master [LiquibaseChangeDeployer:69]
2022-02-25 11:09:06 INFO  [ Start Level: Equinox Container: cb0a510a-ede8-4c04-a6b6-d34f513807e7     ] Cannot load service: liquibase.license.LicenseService: Provider liquibase.license.pro.DaticalTrueLicenseService could not be instantiated [StandardServiceLocator:153]
2022-02-25 11:09:06 TRACE [ Start Level: Equinox Container: cb0a510a-ede8-4c04-a6b6-d34f513807e7     ] checkPreconditions() - entry : changelog pas_xr_master_changelog.xml for PU master [LiquibaseChangeDeployer:126]
2022-02-25 11:09:06 TRACE [ Start Level: Equinox Container: cb0a510a-ede8-4c04-a6b6-d34f513807e7     ] checkPreconditions() - exit : changelog pas_xr_master_changelog.xml for PU master - return true [LiquibaseChangeDeployer:173]
2022-02-25 11:09:07 INFO  [ Start Level: Equinox Container: cb0a510a-ede8-4c04-a6b6-d34f513807e7     ] Successfully acquired change log lock [StandardLockService:153]
2022-02-25 11:09:07 INFO  [ Start Level: Equinox Container: cb0a510a-ede8-4c04-a6b6-d34f513807e7     ] Reading from `xr_portal_2.0_master`.DATABASECHANGELOG [StandardChangeLogHistoryService:153]
2022-02-25 11:09:08 INFO  [ Start Level: Equinox Container: cb0a510a-ede8-4c04-a6b6-d34f513807e7     ] Successfully released change log lock [StandardLockService:153]
2022-02-25 11:09:08 INFO  [ Start Level: Equinox Container: cb0a510a-ede8-4c04-a6b6-d34f513807e7     ] Deployed database changes pas_xr_master_changelog.xml in PU master [LiquibaseChangeDeployer:91]
2022-02-25 11:09:08 TRACE [ Start Level: Equinox Container: cb0a510a-ede8-4c04-a6b6-d34f513807e7     ] deployDatabaseChanges() - exit : changelog pas_xr_master_changelog.xml for PU master [LiquibaseChangeDeployer:111]
2022-02-25 11:09:08 TRACE [ Start Level: Equinox Container: cb0a510a-ede8-4c04-a6b6-d34f513807e7     ] checkDatabaseChanges() - exit - PU master [LiquibaseChangeDeployer:205]

regards

erwin

@erwindl0
Copy link
Author

I just checked with your snapshot jar and in my osgi application/platform it does seem to work.
But as mentioned I'm still on Liquibase 4.4.3.

I.e. I get the right integrated logging.
And host&fragment are correctly associated:

id State Bundle
77 RESOLVED com.mattbertolini.liquibase.logging.slf4j_4.1.0.SNAPSHOT
Master=236
236 ACTIVE org.liquibase.core_4.4.3
Fragments=77

@mattbertolini
Copy link
Owner

mattbertolini commented Feb 25, 2022

That good to hear @erwindl0 . Thanks for taking a look.

Based on the available information, I'm inclined to believe the manifest is correct and there is something else wrong with either Liquibase or the example.

@gmilani I tried running the provided example without liquibase-slf4j to see if it didn't throw the UnexpectedLiquibaseException. Unfortunately it continued to throw the same error so I have to believe that there is something else wrong here. Liquibase should log to standard out by default so this exception could only appear if Liquibase itself couldn't find its own loggers (which are in the same bundle).

I noticed that the example doesn't use the OSGiResourceAccessor provided by Liquibase. Is there a particular reason for this? The original code example provided above seemed to use it. Also, is there a particular reason you are creating the Database object manually rather than passing the JdbcConnection to Liquibase directly. I was thinking simplifying the example might improve things, like this:

private void prepare(Connection connection) throws LiquibaseException {
    OSGiResourceAccessor resourceAccessor = new OSGiResourceAccessor(bundle);
    try (Liquibase liquibase = new Liquibase("migrations.xml", resourceAccessor, new JdbcConnection(connection))) {
        liquibase.update(new Contexts());
    }
}

Given @erwindl0's information, I might move ahead with publishing what I have on branch gen-osgi-bundle-bnd. Let me know your thoughts. Thanks.

@mattbertolini
Copy link
Owner

I wasn't able to validate the OSGi metadata with version 4.1.0 of Liquibase. The only version I was able to validate it with was the latest version (4.9.1). I believe this is because of various issues with the Liquibase OSGi metadata (liquibase/liquibase#2361). I also needed to add some additional bundles to the example application that @gmilani sent me. Liquibase requires the following capabilities:

osgi.extender; filter:="(osgi.extender=osgi.serviceloader.registrar)",
osgi.extender; filter:="(osgi.extender=osgi.serviceloader.processor)",

Those needed to work in order for the ServiceLoader to load the logging configuration.

I have updated liquibase-slf4j with this information and published version 4.1.0 with OSGi metadata. I am considering this issue closed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants