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

OSGI dynamically loading issue with postgresql-9.4.1207 #497

Closed
lewie opened this issue Jan 21, 2016 · 29 comments
Closed

OSGI dynamically loading issue with postgresql-9.4.1207 #497

lewie opened this issue Jan 21, 2016 · 29 comments

Comments

@lewie
Copy link

@lewie lewie commented Jan 21, 2016

Versions before can be loaded dynamically as OSGI bundle since Version 1207 this does not work any longer.

These jars from maven-repo are not working:
postgresql-9.4.1207.jar
postgresql-9.4.1207.jre6.jar
postgresql-9.4.1207.jre7.jar

We use these drivers with our Database Services with openHAB:
openhab/openhab1-addons#3862 (comment)

Rgds
Helmut

@vlsi
Copy link
Member

@vlsi vlsi commented Jan 21, 2016

Can you provide a test case?

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Jan 21, 2016

@lewie, can some tests from openhab be used as integration tests for pgjdbc? I mean add a Travis check, so we always know if a particular change in pgjdbc impacts openhab.

Loading

@lewie
Copy link
Author

@lewie lewie commented Jan 21, 2016

Puhh,
try to load "java.sql.Driver" with name "org.postgresql.Driver" from postgresql-9.4.xxxx\META-INF\services.

This we try to do:
JdbcConfiguration.java

try {
            Class.forName("org.postgresql.Driver");
            logger.debug("JDBC::updateConfig: load JDBC-driverClass was successful: '{}'", dn);
        } catch

We do this with other Drivers too:
https://github.com/openhab/openhab/wiki/JDBC-Persistence#jdbc-driver-files

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Jan 21, 2016

  public static void main(String[] args) throws ClassNotFoundException {
    Class<?> klass = Class.forName("org.postgresql.Driver");
    System.out.println("klass = " + klass);
    System.out.println("klass.getConstructors() = " + Arrays.toString(klass.getConstructors()));
  }
klass = class org.postgresql.Driver
klass.getConstructors() = [public org.postgresql.Driver()]

What's the problem with that?

Loading

@davecramer
Copy link
Member

@davecramer davecramer commented Jan 21, 2016

This can happen if the jar is not correct for the JVM.

Which jar are you using and which JVM ?

Dave Cramer

On 21 January 2016 at 10:14, Vladimir Sitnikov notifications@github.com
wrote:

public static void main(String[] args) throws ClassNotFoundException {
Class<?> klass = Class.forName("org.postgresql.Driver");
System.out.println("klass = " + klass);
System.out.println("klass.getConstructors() = " + Arrays.toString(klass.getConstructors()));
}

klass = class org.postgresql.Driver
klass.getConstructors() = [public org.postgresql.Driver()]

What's the problem with that?


Reply to this email directly or view it on GitHub
#497 (comment).

Loading

@davecramer
Copy link
Member

@davecramer davecramer commented Jan 26, 2016

Helmut,

Did you figure this out ?

Dave Cramer

On 21 January 2016 at 10:34, Dave Cramer davecramer@gmail.com wrote:

This can happen if the jar is not correct for the JVM.

Which jar are you using and which JVM ?

Dave Cramer

On 21 January 2016 at 10:14, Vladimir Sitnikov notifications@github.com
wrote:

public static void main(String[] args) throws ClassNotFoundException {
Class<?> klass = Class.forName("org.postgresql.Driver");
System.out.println("klass = " + klass);
System.out.println("klass.getConstructors() = " + Arrays.toString(klass.getConstructors()));
}

klass = class org.postgresql.Driver
klass.getConstructors() = [public org.postgresql.Driver()]

What's the problem with that?


Reply to this email directly or view it on GitHub
#497 (comment).

Loading

@lewie
Copy link
Author

@lewie lewie commented Jan 26, 2016

@davecramer,

I tested all Versions,
postgresql-9.4.1207.jar
postgresql-9.4.1207.jre6.jar
postgresql-9.4.1207.jre7.jar
so it is no JVM problem.

We had similar problem with one version of SQLite drivers two Month ago.
It seems to be a OSGI Bundle loading problem. I could not figure out why.

Superficial I have seen that the meta-data structure in the bundle has changed a lot, compared to the older versions.

Loading

@davecramer
Copy link
Member

@davecramer davecramer commented Jan 26, 2016

Do you have a test case we can try ?

We aren't OSGI experts by any means

Dave Cramer

On 26 January 2016 at 16:28, Helmut Lehmeyer notifications@github.com
wrote:

@davecramer https://github.com/davecramer,

I tested all Versions,
postgresql-9.4.1207.jar
postgresql-9.4.1207.jre6.jar
postgresql-9.4.1207.jre7.jar
so it is no JVM problem.

We had similar problem with one version of SQLite drivers two Month ago.
It seems to be a OSGI Bundle loading problem. I could not figure out why.

Superficial I have seen that the meta-data structure in the bundle has
changed a lot, compared to the older versions.


Reply to this email directly or view it on GitHub
#497 (comment).

Loading

@lewie
Copy link
Author

@lewie lewie commented Jan 26, 2016

@vlsi, the cause seems to be to find already on OSGI level.

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Jan 26, 2016

@lewie , I am not following you.
Do you have a test case that would access pgjdbc via OSGi (and reproduce the problem)?
Having such a test case in the regular pgdjbc test suite would be great.

Loading

@lewie
Copy link
Author

@lewie lewie commented Jan 26, 2016

@davecramer, @vlsi,

as test case, you need a OSGI environment like Apache karaf or equinox, to see whats going on at boot time.

My test case is OpenHAB, running live in karaf or for development in Eclipse.

My time is a little tight but I will examine the bundle detail and to report to you.

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Jan 26, 2016

as test case, you need a OSGI environment like Apache karaf or equinox, to see whats going on at boot time.

I understand that. I have never ran a single karaf instance though.

My time is a little tight but I will examine the bundle detail and to report to you.

That is fine. I just thought some basic command like clone openhab; mvn exec:exec -Ddp=postgresql might exist that would spin up an OpenHAB instance with PG configuration.

Loading

@lewie
Copy link
Author

@lewie lewie commented Jan 26, 2016

OK, I thought you mean a small peace of code to test it.

I will configure you a openHAB with most simple configuration for testing.
It is a mass of overhead, but it is the fastest way.

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Jan 26, 2016

It is a mass of overhead, but it is the fastest way.

Just to be clear: I do not insist on openHAB. On the other hand, having some "live" project for a integration & regression testing is always a plus.

One day I might read&understand how integration tests for Karaf are to be written.

Loading

@lewie
Copy link
Author

@lewie lewie commented Jan 26, 2016

@vlsi,
download this preconfigured Openhab 1.8 and unzip into any folder (equinox, 40 MB)

It should run with JVM >= 1.6, better use 1.8.x

/addons folder is observed for changes, subfolders will be ignored.
Here you place always only one pgjdbc jar file for testing. (actually there are org.openhab.persistence.jdbc and running postgresql-9.4-1206)

In openHAB root folder use start.sh or start.bat to start openHAB.
I have configured /configurations/logback.xml for debugging org.openhab.persistence.jdbc.
It is tested, this openHAB should load 'org.postgresql.Driver' because /addons/postgresql-9.4-1206-jdbc41.jar.

In console output and /logs/openhab.log you can see logging data.

If bundle is loaded you see:

2016-01-26 23:30:23.652 [WARN ] [p.j.internal.JdbcConfiguration] - JDBC::updateConfig: try to load JDBC-driverClass: 'org.postgresql.Driver'
2016-01-26 23:30:23.657 [DEBUG] [p.j.internal.JdbcConfiguration] - JDBC::updateConfig: load JDBC-driverClass was successful: 'org.postgresql.Driver'
2016-01-26 23:30:23.657 [DEBUG] [p.j.internal.JdbcConfiguration] - JDBC::updateConfig: configuration complete. service=jdbc
2016-01-26 23:30:23.657 [DEBUG] [o.o.p.jdbc.internal.JdbcMapper] - JDBC::pingDB
2016-01-26 23:30:23.657 [DEBUG] [o.o.p.jdbc.internal.JdbcMapper] - JDBC::openConnection isDriverAvailable: true

If not:

2016-01-26 23:31:32.241 [WARN ] [p.j.internal.JdbcConfiguration] - JDBC::updateConfig: try to load JDBC-driverClass: 'org.postgresql.Driver'
2016-01-26 23:31:32.241 [ERROR] [p.j.internal.JdbcConfiguration] - JDBC::updateConfig: could NOT load JDBC-driverClassName or JDBC-dataSourceClassName ClassNotFoundException: 'org.postgresql.Driver'
2016-01-26 23:31:32.241 [WARN ] [p.j.internal.JdbcConfiguration] - 

    !!!
    To avoid this error, place a appropriate JDBC driver file for serviceName 'postgresql' in addons directory.
    Copy missing JDBC-Driver-jar to your OpenHab/addons Folder.
    !!!
    DOWNLOAD: 
    PostgreSQL:version >= 9.4-1201-jdbc41 from    http://mvnrepository.com/artifact/org.postgresql/postgresql

2016-01-26 23:31:32.241 [DEBUG] [p.j.internal.JdbcConfiguration] - JDBC::updateConfig: configuration complete. service=jdbc

I hope it helps.

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Feb 7, 2016

@lewie, I find no start.sh in the archive. Did you archive the proper folder?

In the mean time, I've prepared a test suite via pax-exam, and it seems to work fine: #507

$ LC_ALL=C ls -la
total 223056
drwxr-xr-x   16        544 Feb  7 16:56 .
drwxr-xr-x   93       3162 Feb  7 16:56 ..
-rw-r--r--@   1         60 Feb  4  2013 .eclipseproduct
drwxr-xr-x@   2         68 Jan 10 22:26 addons
-rw-r--r--@   1      85652 Jan 10 22:26 artifacts.xml
drwxrwxrwx@   6        204 Jan 10 22:30 configuration
-rw-r-----@   1  113669967 Jan 25 16:28 distribution-1.8.0-designer-linux64bit.zip
-rw-r--r--@   1      15551 Aug 21  2012 epl-v10.html
drwxrwxrwx@  25        850 Jan 10 20:28 features
-rwxr-xr-x@   1     335360 Jan 10 22:24 libcairo-swt.so
-rw-r--r--@   1       9229 Aug 21  2012 notice.html
-rwxr-xr-x@   1      71223 Jan 10 22:24 openHAB-Designer
-rw-r--r--@   1        286 Jan 10 22:27 openHAB-Designer.ini
drwxrwxrwx@   4        136 Jan 10 22:30 p2
drwxrwxrwx@ 341      11594 Jan 10 22:30 plugins
drwxrwxrwx@   3        102 Jan 10 22:30 readme

Loading

@lewie
Copy link
Author

@lewie lewie commented Feb 8, 2016

@vlsi,

have tested the file once again:

wget https://github.com/lewie/openhab/blob/pgjdbc/bundles/persistence/org.openhab.persistence.jdbc/pgjdbc.live.test/distribution-1.8.0_pgjdbc.zip?raw=true

Then there is a file distribution-1.8.0_pgjdbc.zip?raw=true. Delete ?raw=true from Filename.

unzip distribution-1.8.0_pgjdbc.zip

Then you get this content:
pgjdbc

Tried to run https://github.com/vlsi/pgjdbc/tree/7942a254717e35a200d8ac4798191a075f815bdc with mvn clean install i had no luck. Manny errors and missing local postgresql instance...

OK, comparing postgresql-9.4.1207.jre7.jar and postgresql-9.4-1206-jdbc41.jar in 1207 i found a folder META-INF/maven/ other jdbc drivers does or does not not have this META-INF/maven/ folder.

Just for fun, I replaced hole 1207 META-INF/* by 1206 META-INF/* ... and behold the bundle starts.

Don't know whats going on. I only know, anything has changed fundamentally since 1206 version.

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Feb 8, 2016

Thanks I'll check new zip.

META-INF/maven/ other jdbc drivers does or does not not have this META-INF/maven/ folder.

This is "just for information".

Manny errors and missing local postgresql instance..

You can build with -DskipTests to, well, skip tests.

1206 was ant-based, 1207 is maven-based.

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Feb 8, 2016

@lewie
The issue is:

  1. pgjdbc's descriptors have wrong constraints:
Require-Capability: osgi.ee;filter:="(&(|(osgi.ee=J2SE)(osgi.ee=JavaSE))
 (version>=1.8))"

Even for JRE6 & JRE7 jars.
I'll fix that.

  1. After I fix "version>=" in manifest, openhab prints lots of bundle start warnings:
23:07:11.073 [WARN ] [OSGi                          :77   ] - Error while starting bundle: file:/Users/vladimirsitnikov/Documents/work/openhab/addons/postgresql-9.4.1207.jre7.jar
org.osgi.framework.BundleException: Exception in org.postgresql.osgi.PGBundleActivator.start() of bundle org.postgresql.jdbc41.
    at org.eclipse.osgi.framework.internal.core.BundleContextImpl.startActivator(BundleContextImpl.java:734) ~[na:na]
    at org.eclipse.osgi.framework.internal.core.BundleContextImpl.start(BundleContextImpl.java:683) ~[na:na]
    at org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:381) ~[na:na]
    at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:300) ~[na:na]
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1247) ~[na:na]
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1219) ~[na:na]
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.startAllBundles(DirectoryWatcher.java:1208) ~[na:na]
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:503) ~[na:na]
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:291) ~[na:na]
Caused by: java.lang.NoClassDefFoundError: org/osgi/service/jdbc/DataSourceFactory
    at org.postgresql.osgi.PGBundleActivator.start(PGBundleActivator.java:32) ~[na:na]
    at org.eclipse.osgi.framework.internal.core.BundleContextImpl$1.run(BundleContextImpl.java:711) ~[na:na]
    at java.security.AccessController.doPrivileged(Native Method) ~[na:1.8.0_66]
    at org.eclipse.osgi.framework.internal.core.BundleContextImpl.startActivator(BundleContextImpl.java:702) ~[na:na]
    ... 8 common frames omitted
23:07:11.073 [INFO ] [OSGi                          :76   ] - BundleEvent STOPPED

Is it expected?
It seems to be due to "openhab not including org.osgi.enterprise" (the one with org/osgi/service/jdbc/DataSourceFactory)

Loading

@vlsi vlsi closed this in a3e2045 Feb 8, 2016
@vlsi
Copy link
Member

@vlsi vlsi commented Feb 8, 2016

Re "java.lang.NoClassDefFoundError: org/osgi/service/jdbc/DataSourceFactory", I've added try-catch block, so pgjdbc does not setup DataSourceFactory when it does not exist.

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Feb 8, 2016

JFYI: here's a snapshot version: https://oss.sonatype.org/content/repositories/snapshots/org/postgresql/postgresql/9.4.1208.jre7-SNAPSHOT/

postgresql-9.4.1208.jre7-20160208.210048-45.jar or newer.

00:01:59.809 [INFO ] [OSGi                          :76   ] - FrameworkEvent STARTED
00:01:59.809 [INFO ] [OSGi                          :76   ] - FrameworkEvent STARTLEVEL CHANGED
00:02:02.016 [INFO ] [OSGi                          :76   ] - BundleEvent INSTALLED
00:02:02.017 [INFO ] [OSGi                          :76   ] - Installed /Users/vladimirsitnikov/Documents/work/openhab/addons/postgresql-9.4.1208.jre7-20160208.210048-45.jar
00:02:02.020 [INFO ] [OSGi                          :76   ] - BundleEvent INSTALLED
00:02:02.020 [INFO ] [OSGi                          :76   ] - Installed /Users/vladimirsitnikov/Documents/work/openhab/addons/org.openhab.persistence.jdbc-1.9.0-SNAPSHOT.jar
00:02:02.053 [INFO ] [OSGi                          :76   ] - BundleEvent RESOLVED
00:02:02.053 [INFO ] [OSGi                          :76   ] - BundleEvent RESOLVED
00:02:02.054 [INFO ] [OSGi                          :76   ] - FrameworkEvent PACKAGES REFRESHED
java.lang.IllegalArgumentException: Unable to load DataSourceFactory. Will ignore DataSourceFactory registration. If you need one, ensure org.osgi.enterprise is on the classpath
    at org.postgresql.osgi.PGBundleActivator.start(PGBundleActivator.java:38)
    at org.eclipse.osgi.framework.internal.core.BundleContextImpl$1.run(BundleContextImpl.java:711)
    at java.security.AccessController.doPrivileged(Native Method)
    at org.eclipse.osgi.framework.internal.core.BundleContextImpl.startActivator(BundleContextImpl.java:702)
    at org.eclipse.osgi.framework.internal.core.BundleContextImpl.start(BundleContextImpl.java:683)
    at org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:381)
    at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:300)
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1247)
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1219)
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:508)
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:291)
Caused by: java.lang.NoClassDefFoundError: org/osgi/service/jdbc/DataSourceFactory
    at org.postgresql.osgi.PGBundleActivator.start(PGBundleActivator.java:33)
    ... 10 more
Caused by: java.lang.ClassNotFoundException: org.osgi.service.jdbc.DataSourceFactory
    at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:501)
    at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:421)
    at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:412)
    at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(DefaultClassLoader.java:107)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
    ... 11 more
00:02:02.059 [INFO ] [OSGi                          :76   ] - Started bundle: file:/Users/vladimirsitnikov/Documents/work/openhab/addons/postgresql-9.4.1208.jre7-20160208.210048-45.jar
00:02:02.063 [INFO ] [OSGi                          :76   ] - BundleEvent STARTED
00:02:02.072 [DEBUG] [o.p.j.i.JdbcPersistenceService:89   ] - JDBC::setItemRegistry
00:02:02.072 [DEBUG] [o.p.j.i.JdbcPersistenceService:59   ] - JDBC::activate: persistence service activated
00:02:02.072 [DEBUG] [o.p.j.i.JdbcPersistenceService:213  ] - JDBC::updateConfig
00:02:02.074 [DEBUG] [p.j.internal.JdbcConfiguration:64   ] - JDBC::JdbcConfiguration
00:02:02.074 [DEBUG] [p.j.internal.JdbcConfiguration:72   ] - JDBC::updateConfig: configuration.size = 7
00:02:02.075 [DEBUG] [p.j.internal.JdbcConfiguration:77   ] - JDBC::updateConfig: url=jdbc:postgresql://127.0.0.1:5432/postgres
00:02:02.075 [DEBUG] [p.j.internal.JdbcConfiguration:87   ] - JDBC::updateConfig: found serviceName = 'postgresql'
00:02:02.075 [DEBUG] [p.j.internal.JdbcConfiguration:98   ] - JDBC::updateConfig: Init Data Access Object Class: 'org.openhab.persistence.jdbc.db.JdbcPostgresqlDAO'
00:02:02.082 [DEBUG] [ersistence.jdbc.db.JdbcBaseDAO:108  ] - JDBC::initSqlTypes: Initialize the type array
00:02:02.082 [DEBUG] [ersistence.jdbc.db.JdbcBaseDAO:81   ] - JDBC::initSqlQueries: 'JdbcPostgresqlDAO'
00:02:02.082 [DEBUG] [.o.p.jdbc.db.JdbcPostgresqlDAO:51   ] - JDBC::initSqlQueries: 'JdbcPostgresqlDAO'
00:02:02.082 [DEBUG] [.o.p.jdbc.db.JdbcPostgresqlDAO:78   ] - JDBC::initSqlTypes: Initialize the type array sqlTypes=[SMALLINT, VARCHAR, VARCHAR, VARCHAR, TIMESTAMP, VARCHAR, VARCHAR, VARCHAR, SMALLINT, DOUBLE PRECISION]
00:02:02.083 [DEBUG] [p.j.internal.JdbcConfiguration:105  ] - JDBC::updateConfig: dBDAO ClassName=org.openhab.persistence.jdbc.db.JdbcPostgresqlDAO
00:02:02.084 [DEBUG] [p.j.internal.JdbcConfiguration:145  ] - JDBC::updateConfig:  user=postgres
00:02:02.084 [ERROR] [p.j.internal.JdbcConfiguration:155  ] - JDBC::updateConfig: SQL password is missing. Attempting to connect without password. To specify a password configure the jdbc:password parameter in openhab.cfg.
00:02:02.084 [DEBUG] [p.j.internal.JdbcConfiguration:217  ] - JDBC::updateConfig: enableLogTime false
00:02:02.084 [WARN ] [p.j.internal.JdbcConfiguration:238  ] - JDBC::updateConfig: try to load JDBC-driverClass: 'org.postgresql.Driver'
00:02:02.085 [DEBUG] [p.j.internal.JdbcConfiguration:241  ] - JDBC::updateConfig: load JDBC-driverClass was successful: 'org.postgresql.Driver'
00:02:02.085 [DEBUG] [p.j.internal.JdbcConfiguration:268  ] - JDBC::updateConfig: configuration complete. service=jdbc
00:02:02.085 [DEBUG] [o.o.p.jdbc.internal.JdbcMapper:41   ] - JDBC::pingDB
00:02:02.085 [DEBUG] [o.o.p.jdbc.internal.JdbcMapper:161  ] - JDBC::openConnection isDriverAvailable: true
00:02:02.085 [WARN ] [o.o.p.jdbc.internal.JdbcMapper:163  ] - JDBC::openConnection: setupDataSource.
00:02:02.092 [DEBUG] [com.zaxxer.hikari.HikariConfig:828  ] - HikariPool-0 - configuration:
00:02:02.094 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - allowPoolSuspension.............false
00:02:02.095 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - autoCommit......................true
00:02:02.095 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - catalog.........................
00:02:02.095 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - connectionInitSql...............
00:02:02.095 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - connectionTestQuery.............
00:02:02.095 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - connectionTimeout...............30000
00:02:02.095 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - dataSource......................
00:02:02.096 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - dataSourceClassName.............
00:02:02.096 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - dataSourceJNDI..................
00:02:02.096 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - dataSourceProperties............{user=postgres, password=<masked>}
00:02:02.096 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - driverClassName.................org.postgresql.Driver
00:02:02.096 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - healthCheckProperties...........{}
00:02:02.096 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - healthCheckRegistry.............
00:02:02.096 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - idleTimeout.....................600000
00:02:02.096 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - initializationFailFast..........true
00:02:02.097 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - isolateInternalQueries..........false
00:02:02.097 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - jdbc4ConnectionTest.............false
00:02:02.097 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - jdbcUrl.........................jdbc:postgresql://127.0.0.1:5432/postgres
00:02:02.097 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - leakDetectionThreshold..........0
00:02:02.097 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - maxLifetime.....................1800000
00:02:02.097 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - maximumPoolSize.................10
00:02:02.097 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - metricRegistry..................
00:02:02.097 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - metricsTrackerFactory...........
00:02:02.097 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - minimumIdle.....................10
00:02:02.098 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - password........................<masked>
00:02:02.098 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - poolName........................HikariPool-0
00:02:02.098 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - readOnly........................false
00:02:02.098 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - registerMbeans..................false
00:02:02.098 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - scheduledExecutorService........
00:02:02.098 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - threadFactory...................
00:02:02.098 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - transactionIsolation............
00:02:02.098 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - username........................
00:02:02.098 [DEBUG] [com.zaxxer.hikari.HikariConfig:839  ] - validationTimeout...............5000
00:02:02.099 [INFO ] [zaxxer.hikari.HikariDataSource:70   ] - HikariPool-0 - is starting.
00:02:02.156 [DEBUG] [om.zaxxer.hikari.pool.PoolBase:430  ] - HikariPool-0 - Connection.setNetworkTimeout() is not supported (Метод org.postgresql.jdbc.PgConnection.getNetworkTimeout() ещё не реализован)
00:02:02.167 [DEBUG] [.zaxxer.hikari.pool.HikariPool:459  ] - HikariPool-0 - Added connection org.postgresql.jdbc.PgConnection@5e3ca06
00:02:02.171 [INFO ] [org.knowm.yank.YankPoolManager:83   ] - Initialized pool 'HikariPool-0'
00:02:02.171 [DEBUG] [p.j.internal.JdbcConfiguration:325  ] - JDBC::setDbConnected true
00:02:02.175 [DEBUG] [.zaxxer.hikari.pool.HikariPool:459  ] - HikariPool-0 - Added connection org.postgresql.jdbc.PgConnection@4adcded9
00:02:02.179 [DEBUG] [.zaxxer.hikari.pool.HikariPool:459  ] - HikariPool-0 - Added connection org.postgresql.jdbc.PgConnection@4bdd6507
00:02:02.183 [DEBUG] [.zaxxer.hikari.pool.HikariPool:459  ] - HikariPool-0 - Added connection org.postgresql.jdbc.PgConnection@44926f4b
00:02:02.185 [DEBUG] [o.o.p.jdbc.internal.JdbcMapper:75   ] - JDBC::createItemsTableIfNot
00:02:02.185 [DEBUG] [.o.p.jdbc.db.JdbcPostgresqlDAO:107  ] - JDBC::doCreateItemsTableIfNot sql=CREATE TABLE IF NOT EXISTS items (itemid SERIAL NOT NULL, itemname VARCHAR(500) NOT NULL, CONSTRAINT items_pkey PRIMARY KEY (itemid))
00:02:02.187 [DEBUG] [o.o.p.jdbc.internal.JdbcMapper:91   ] - JDBC::getItemIDTableNames
00:02:02.187 [DEBUG] [ersistence.jdbc.db.JdbcBaseDAO:244  ] - JDBC::doGetItemIDTableNames sql=SELECT itemid, itemname FROM items
00:02:02.188 [DEBUG] [.zaxxer.hikari.pool.HikariPool:459  ] - HikariPool-0 - Added connection org.postgresql.jdbc.PgConnection@5fba3e25
00:02:02.189 [DEBUG] [o.p.j.i.JdbcPersistenceService:104  ] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
00:02:02.190 [DEBUG] [o.p.j.i.JdbcPersistenceService:224  ] - JDBC::updateConfig: configuration complete for service=jdbc.
00:02:02.190 [INFO ] [OSGi                          :76   ] - ServiceEvent REGISTERED
00:02:02.191 [DEBUG] [o.p.j.i.JdbcPersistenceService:104  ] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
00:02:02.191 [DEBUG] [o.p.j.i.JdbcPersistenceService:104  ] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
00:02:02.191 [DEBUG] [.p.internal.PersistenceManager:146  ] - Initializing jdbc persistence service.
00:02:02.192 [DEBUG] [o.p.j.i.JdbcPersistenceService:104  ] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
00:02:02.192 [DEBUG] [o.p.j.i.JdbcPersistenceService:104  ] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
00:02:02.192 [DEBUG] [.zaxxer.hikari.pool.HikariPool:459  ] - HikariPool-0 - Added connection org.postgresql.jdbc.PgConnection@73bc091d
00:02:02.193 [DEBUG] [o.p.j.i.JdbcPersistenceService:104  ] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
00:02:02.197 [DEBUG] [.zaxxer.hikari.pool.HikariPool:459  ] - HikariPool-0 - Added connection org.postgresql.jdbc.PgConnection@53e9af30
00:02:02.203 [DEBUG] [.zaxxer.hikari.pool.HikariPool:459  ] - HikariPool-0 - Added connection org.postgresql.jdbc.PgConnection@4566a31
00:02:02.207 [DEBUG] [.zaxxer.hikari.pool.HikariPool:459  ] - HikariPool-0 - Added connection org.postgresql.jdbc.PgConnection@a932788
00:02:02.211 [DEBUG] [.zaxxer.hikari.pool.HikariPool:459  ] - HikariPool-0 - Added connection org.postgresql.jdbc.PgConnection@19f43326
00:02:02.211 [DEBUG] [.zaxxer.hikari.pool.HikariPool:382  ] - After adding  pool HikariPool-0 stats (total=10, active=0, idle=10, waiting=0)
00:02:02.288 [INFO ] [OSGi                          :76   ] - ServiceEvent REGISTERED
00:02:02.289 [INFO ] [OSGi                          :76   ] - BundleEvent STARTED
00:02:02.293 [INFO ] [OSGi                          :76   ] - BundleEvent STARTED
00:02:02.297 [DEBUG] [c.internal.ModelRepositoryImpl:64   ] - Configuration model 'jdbc.persist' can not be found
00:02:02.298 [DEBUG] [o.p.j.i.JdbcPersistenceService:104  ] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
00:02:02.298 [INFO ] [OSGi                          :76   ] - Started bundle: file:/Users/vladimirsitnikov/Documents/work/openhab/addons/org.openhab.persistence.jdbc-1.9.0-SNAPSHOT.jar
00:02:02.298 [INFO ] [OSGi                          :76   ] - BundleEvent STARTED
00:02:32.110 [DEBUG] [.zaxxer.hikari.pool.HikariPool:382  ] - Before cleanup    pool HikariPool-0 stats (total=10, active=0, idle=10, waiting=0)
00:02:32.110 [DEBUG] [.zaxxer.hikari.pool.HikariPool:382  ] - After cleanup pool HikariPool-0 stats (total=10, active=0, idle=10, waiting=0)
00:03:02.112 [DEBUG] [.zaxxer.hikari.pool.HikariPool:382  ] - Before cleanup    pool HikariPool-0 stats (total=10, active=0, idle=10, waiting=0)
00:03:02.112 [DEBUG] [.zaxxer.hikari.pool.HikariPool:382  ] - After cleanup pool HikariPool-0 stats (total=10, active=0, idle=10, waiting=0)

Loading

@lewie
Copy link
Author

@lewie lewie commented Feb 9, 2016

@vlsi,
interesting, so far I did not know the message, it's new for me:

Is it expected?
It seems to be due to "openhab not including org.osgi.enterprise" (the one with org/osgi/service/jdbc/DataSourceFactory)
Re "java.lang.NoClassDefFoundError: org/osgi/service/jdbc/DataSourceFactory", I've added try-catch block, so pgjdbc does not setup DataSourceFactory when it does not exist.

Well done!
it's started by OSGI automatically:

00:02:02.059 [INFO ] [OSGi                          :76   ] - Started bundle: file:/Users/vladimirsitnikov/Documents/work/openhab/addons/postgresql-9.4.1208.jre7-20160208.210048-45.jar

We could connect the database:

00:02:02.085 [DEBUG] [o.o.p.jdbc.internal.JdbcMapper:41   ] - JDBC::pingDB

Tested postgresql-9.4.1208.jre7-20160208.210048-45.jar, works like a charme.
Yea!

Thanks
Helmut

Loading

@thhart
Copy link

@thhart thhart commented Jul 6, 2016

Hi, just wanted to let you know that I had no luck with openHab 2.0, I tried the integrated persistence configurator as well as manually placing several postgresql driver jars (1201-1208) into the addons directory, the NoClassDefFoundError remains. I assume there is probably a class duplicate somewhere deep in the openHab installation, but this is only a poor guess. I decided not to use postgresql for the time being.

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Jul 6, 2016

@thhart , can you list full error message that you run into with 1208 driver?

Loading

@thhart
Copy link

@thhart thhart commented Jul 6, 2016

2016-07-06 07:29:28.652 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/opt/openHAB/addons/postgresql-9.4
 org.osgi.framework.BundleException: Exception in org.postgresql.osgi.PGBundleActivator.start() of bundle org.postgresql.jdbc42.
         at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:792)[org.eclipse.osgi-3.10.2.v20150203
         at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:721)[org.eclipse.osgi-3.10.2.v20150203-1939.jar
         at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:936)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:
         at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:319)[org.eclipse.osgi-3.10.2.v20150
         at org.eclipse.osgi.container.Module.doStart(Module.java:571)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
         at org.eclipse.osgi.container.Module.start(Module.java:439)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
         at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:393)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
         at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1245)[8:org.apache.felix.fileinstall:3.5.
         at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1217)[8:org.apache.felix.fileinstall:3.5
         at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:509)[8:org.apache.felix.fileinstall:3.5.0]
         at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:358)[8:org.apache.felix.fileinstall:3.5.0]
         at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:310)[8:org.apache.felix.fileinstall:3.5.0]
*Caused by: java.lang.NoClassDefFoundError: org/osgi/service/jdbc/DataSourceFactory
         at org.postgresql.osgi.PGBundleActivator.start(PGBundleActivator.java:32)
         at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:771)[org.eclipse.osgi-3.10.2.v20150203-1939.jar
         at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:1)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
         at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_91]
         at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:764)[org.eclipse.osgi-3.10.2.v20150203
         ... 11 more
 Caused by: java.lang.ClassNotFoundException: org.osgi.service.jdbc.DataSourceFactory cannot be found by org.postgresql.jdbc42_9.4.1207
         at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:432)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:
         at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:345)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
         at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:337)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
         at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:160)[org.eclipse.osgi-3.10.2.v20150203-1939.ja
         at java.lang.ClassLoader.loadClass(ClassLoader.java:357)[:1.8.0_91]
         ... 16 more

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Jul 6, 2016

This is jdbc42_9.4.1207 that is known to be openhab-incompatible.
The error should be solved by 9.4.1208

 Caused by: java.lang.ClassNotFoundException: org.osgi.service.jdbc.DataSourceFactory cannot be found by org.postgresql.jdbc42_9.4.1207

Loading

@thhart
Copy link

@thhart thhart commented Jul 6, 2016

This is with 1208 (jre7 or 42) put into addons:

java.lang.IllegalArgumentException: Unable to load DataSourceFactory. Will ignore DataSourceFactory registration. If you need one, ensure org.osgi.enterprise is on the classpath
        at org.postgresql.osgi.PGBundleActivator.start(PGBundleActivator.java:38)
        at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:771)
        at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:1)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:764)
        at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:721)
        at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:936)
        at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:319)
        at org.eclipse.osgi.container.Module.doStart(Module.java:571)
        at org.eclipse.osgi.container.Module.start(Module.java:439)
        at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:393)
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1245)
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1217)
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:509)
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:358)
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:310)
Caused by: java.lang.NoClassDefFoundError: org/osgi/service/jdbc/DataSourceFactory
        at org.postgresql.osgi.PGBundleActivator.start(PGBundleActivator.java:33)
        ... 15 more
Caused by: java.lang.ClassNotFoundException: org.osgi.service.jdbc.DataSourceFactory cannot be found by org.postgresql.jdbc42_9.4.1208
        at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:432)
        at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:345)
        at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:337)
        at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:160)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        ... 16 more
13:34:15.370 [ERROR] [ence.jdbc.internal.JdbcConfiguration] - JDBC::updateConfig: could NOT load JDBC-driverClassName or JDBC-dataSourceClassName ClassNotFoundException: 'org.postgresql.Driver cannot be found by org.openhab.persistence.jdbc_1.9.0.201607040111'
13:34:15.381 [WARN ] [ence.jdbc.internal.JdbcConfiguration] - 
        !!!
        To avoid this error, place a appropriate JDBC driver file for serviceName 'postgresql' in addons directory.
        Copy missing JDBC-Driver-jar to your OpenHab/addons Folder.
        !!!
        DOWNLOAD: 
        PostgreSQL:version >= 9.4-1201-jdbc41 from    http://mvnrepository.com/artifact/org.postgresql/postgresql

Loading

@vlsi
Copy link
Member

@vlsi vlsi commented Jul 6, 2016

@thhart , can you share your openhab installation and/or steps to reproduce the problem?

By the way, the stacktrace from 1208 is not an error. We might need to reduce verbosity, however it should not fail the startup.

Loading

@shakul26
Copy link

@shakul26 shakul26 commented May 24, 2018

Thank you all for such a good discussion.
you guys really saved my day. I was facing the similar problem.

Loading

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

Successfully merging a pull request may close this issue.

None yet
5 participants