Error at disconnect

[shalamyansky]

Hello!

I developе services based on Java 8, Spring JPA, Firebird and use IntelliJ IDEA with maven as tool. Recently, the service generates an error when closing. This error appears only when debugging under IDEA, but not in production mode. Therefore, it is uncritical, but unpleasant. Here is stack frames from log:

2023-02-17 17:57:30.999  INFO 2588 --- [ionShutdownHook] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'default'
2023-02-17 17:57:31.002  INFO 2588 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
[WARNING]
java.lang.UnsatisfiedLinkError: Error looking up function 'isc_detach_database': Library has been unloaded
    at com.sun.jna.Function.<init>[WARNING]
java.lang.UnsatisfiedLinkError: Error looking up function 'isc_detach_database': Library has been unloaded
    at com.sun.jna.Function.<init>[WARNING]
java.lang.UnsatisfiedLinkError: Error looking up function 'isc_detach_database': Library has been unloaded
 (Function.java:252)
        at com.sun.jna.NativeLibrary.getFunction (NativeLibrary.java:620)
    atat com.sun.jna.Function.<init> com.sun.jna.NativeLibrary.getFunction (Function.java:252)
     (NativeLibrary.java:596)
    at com.sun.jna.NativeLibrary.getFunctionat com.sun.jna.NativeLibrary.getFunction (NativeLibrary.java:620)
    at (NativeLibrary.java:582)
     com.sun.jna.NativeLibrary.getFunctionat com.sun.jna.Library$Handler.invoke (Library.java:248)
     (NativeLibrary.java:596)
    at com.sun.jna.NativeLibrary.getFunction (NativeLibrary.java:582)
    at com.sun.jna.Library$Handler.invoke (Library.java:248)
    atat org.firebirdsql.gds.ng.jna.FbClientFeatureAccessHandler.invoke org.firebirdsql.gds.ng.jna.FbClientFeatureAccessHandler.invoke (FbClientFeatureAccessHandler.java:75)
    at com.sun.proxy.$Proxy130.isc_detach_database (FbClientFeatureAccessHandler.java:75)
     (Unknown Source)at
     com.sun.proxy.$Proxy130.isc_detach_databaseat org.firebirdsql.gds.ng.jna.JnaDatabase.internalDetach (Unknown Source)
 (JnaDatabase.java:93)
        atat org.firebirdsql.gds.ng.AbstractFbDatabase.close org.firebirdsql.gds.ng.jna.JnaDatabase.internalDetach (AbstractFbDatabase.java:190)
     (JnaDatabase.java:93)
    atat org.firebirdsql.gds.impl.GDSHelper.detachDatabase org.firebirdsql.gds.ng.AbstractFbDatabase.close (GDSHelper.java:159)
     (AbstractFbDatabase.java:190)
    at org.firebirdsql.gds.impl.GDSHelper.detachDatabase (GDSHelper.java:159)
    at org.firebirdsql.jaybird.xca.FBManagedConnection.destroy (FBManagedConnection.java:357)
    at org.firebirdsql.jaybird.xca.FBStandAloneConnectionManager.connectionClosed (FBStandAloneConnectionManager.java:57)
    at org.firebirdsql.jaybird.xca.FBManagedConnection.notify (FBManagedConnection.java:1118)
    at org.firebirdsql.jaybird.xca.FBManagedConnection.close (FBManagedConnection.java:1032)
    at org.firebirdsql.jdbc.FBConnection.close (FBConnection.java:458)
    at com.zaxxer.hikari.pool.PoolBase.quietlyCloseConnection (PoolBase.java:143)
    at com.zaxxer.hikari.pool.HikariPool.lambda$closeConnection$1at org.firebirdsql.jaybird.xca.FBManagedConnection.destroy (FBManagedConnection.java:357)
    at org.firebirdsql.jaybird.xca.FBStandAloneConnectionManager.connectionClosed (HikariPool.java:451)
    at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:624)
    at java.lang.Thread.run (Thread.java:748)
 (FBStandAloneConnectionManager.java:57)
    at org.firebirdsql.jaybird.xca.FBManagedConnection.notify (FBManagedConnection.java:1118)
    at org.firebirdsql.jaybird.xca.FBManagedConnection.close (FBManagedConnection.java:1032)
    at org.firebirdsql.jdbc.FBConnection.close (FBConnection.java:458)
    at com.zaxxer.hikari.pool.PoolBase.quietlyCloseConnection (PoolBase.java:143)
    at com.zaxxer.hikari.pool.HikariPool.lambda$closeConnection$1 (HikariPool.java:451)
    at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:624)
    at java.lang.Thread.run (Thread.java:748)

Sometimes instead of Error looking up function 'isc_detach_database': Library has been unloaded I see Memory access error.

I use Jaybird native access to Firebird via jna.

What's the matter?

-------------------------------------------------
Platform:
Windows 10 Pro 21H2 64-bit
JDK 1.8.0.311
Firebird       4.0.2.2816  64-bit
fbclient.dll  4.0.2.2816  64-bit
jna.dll          6.1.6.0         64-bit

POM.XML (fragments):
    <properties>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
        <java.version>1.8</java.version>
        <spring-boot.version>2.7.7</spring-boot.version>
    </properties>
    <dependencies>

        <dependency>
            <groupId>org.firebirdsql.jdbc</groupId>
            <artifactId>jaybird</artifactId>
            <version>5.0.1.java8</version>
        </dependency>
        <dependency>
            <groupId>net.java.dev.jna</groupId>
            <artifactId>jna</artifactId>
            <version>5.13.0</version>
        </dependency>

    </dependencies>

application.properties (fragments):
spring.datasource.driverClassName:org.firebirdsql.jdbc.FBDriver
spring.datasource.url:jdbc:firebirdsql:local:egrulapi?encoding=WIN1251

Tool:
IntelliJ IDEA 2022.3.2 (Community Edition)
Build #IC-223.8617.56, built on January 26, 2023
Runtime version: 17.0.5+1-b653.25 amd64
VM: OpenJDK 64-Bit Server VM by JetBrains s.r.o.

[Mark Rotteveel]

On 17-02-2023 16:39, shalamyansky wrote:
> I developе services based on Java 8, Spring JPA, Firebird and use
> IntelliJ IDEA with maven as tool. Recently, the service generates an
> error when closing. This error appears only when debugging under IDEA,
> but not in production mode. Therefore, it is uncritical, but unpleasant.
> Here is stack frames from log:
>
> 2023-02-17 17:57:30.999  INFO 2588 --- [ionShutdownHook]
> j.LocalContainerEntityManagerFactoryBean : Closing JPA
> EntityManagerFactory for persistence unit 'default'
> 2023-02-17 17:57:31.002  INFO 2588 --- [ionShutdownHook]
> com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown
> initiated...
> [WARNING]
> java.lang.UnsatisfiedLinkError: Error looking up function
> 'isc_detach_database': Library has been unloaded
>     at com.sun.jna.Function.<init>[WARNING]
> java.lang.UnsatisfiedLinkError: Error looking up function
> 'isc_detach_database': Library has been unloaded
>     at com.sun.jna.Function.<init>[WARNING]

[..]

>
> Sometimes instead of Error looking up function 'isc_detach_database':
> Library has been unloaded I see Memory access error.
>
> I use Jaybird native access to Firebird via jna.
>
> What's the matter?

It sounds like the shutdown hook or the NativeResourceUnloadWebListener
has run. I need exact reproduction steps to be able to identify a cause,
but likely it is caused by some form of the runtime
replacement/reloading of classes triggering a servlet context reload, or
maybe the servlet context being closed before other things that still
need to use connections.

I would be grateful if you could provide me with a reproduction recipe
with a minimal set of code and steps to reproduce to see if that is
something that can be addressed.

In any case, the workaround is to disable the native resource unloading
(set system property org.firebirdsql.nativeResourceShutdownDisabled to
true (e.g. -Dorg.firebirdsql.nativeResourceShutdownDisabled=true in your
run properties), or just not use native URLs.

To be honest, in a web application like yours it is my opinion that you
should use the pure Java connections, not native connections. There is
IMHO no good reason to use native connections, except maybe when you
need to use embedded (but then again, you shouldn't use embedded in a
web application).

[..]

>
> application.properties (fragments):
> spring.datasource.driverClassName:org.firebirdsql.jdbc.FBDriver
> spring.datasource.url:jdbc:firebirdsql:local:egrulapi?encoding=WIN1251

Have you read the Jaybird 5 release notes[1]? The sub-protocol local is
deprecated (technically even removed and aliased to native) and will
probably be removed entirely in a future version (maybe Jaybird 6, maybe
later). What you have works exactly the same as specifying native and is
not guaranteed to use a "local" IPC connection (neither did previous
versions, which is why it is deprecated). If you want to ensure you're
using "local" IPC connections, you'll need to use
jdbc:firebirdsql:native:xnet://egrulapi?encoding=WIN1251 (be aware, the
linked release notes have a typo, showing xnet// instead of xnet://).

However, my main advice would be to use
jdbc:firebirdsql://localhost/egrulapi?encoding=WIN1251 instead.

Mark

[1]:
https://www.firebirdsql.org/file/documentation/drivers_documentation/java/5.0.x/release_notes.html#local-protocol-removed

--
Mark Rotteveel

[shalamyansky]

Thanks, Mark!

Yes, I've read the release notes. I have changed and will change local: to native:xnet:// wherever I can change, but I suppose that in this case it is not a help.
Just checked: native:xnet:// keeps the error.

пятница, 17 февраля 2023 г. в 19:27:28 UTC+3, Mark Rotteveel:

[shalamyansky]

I would be grateful if you could provide me with a reproduction recipe
with a minimal set of code and steps to reproduce to see if that is
something that can be addressed.

I'll try to make a sample, maybe a little later. 

In any case, the workaround is to disable the native resource unloading
(set system property org.firebirdsql.nativeResourceShutdownDisabled to
true (e.g. -Dorg.firebirdsql.nativeResourceShutdownDisabled=true in your
run properties), or just not use native URLs.

Yes, it have solved the problem.

To be honest, in a web application like yours it is my opinion that you
should use the pure Java connections, not native connections. There is
IMHO no good reason to use native connections, except maybe when you
need to use embedded (but then again, you shouldn't use embedded in a
web application).

If your driver supports IPC (Inter Process Communication) why shouldn't I use it?
Presumably IPC is faster than TCP/IP.

Thanks for the fast help,

Sincerely yours,

Mikhail Shalamyansky

[Mark Rotteveel]

On 17-02-2023 18:14, shalamyansky wrote:
> Yes, I've read the release notes. I have changed and will change local:
> to native:xnet:// wherever I can change, but I suppose that in this case
> it is not a help.
> Just checked: native:xnet:// keeps the error.

It will indeed not help for this specific error, it was intended as an
additional observation.

Mark
--
Mark Rotteveel

[Mark Rotteveel]

On 17-02-2023 19:06, shalamyansky wrote:
>> I would be grateful if you could provide me with a reproduction recipe
>> with a minimal set of code and steps to reproduce to see if that is
>> something that can be addressed.
>
> I'll try to make a sample, maybe a little later.

Thanks, that would be very welcome.

>> In any case, the workaround is to disable the native resource unloading
>> (set system property org.firebirdsql.nativeResourceShutdownDisabled to
>> true (e.g. -Dorg.firebirdsql.nativeResourceShutdownDisabled=true in your
>> run properties), or just not use native URLs.
>
> Yes, it have solved the problem.

Glad to hear.

>> To be honest, in a web application like yours it is my opinion that you
>> should use the pure Java connections, not native connections. There is
>> IMHO no good reason to use native connections, except maybe when you
>> need to use embedded (but then again, you shouldn't use embedded in a
>> web application).
>
> If your driver supports IPC (Inter Process Communication) why shouldn't
> I use it?
> Presumably IPC is faster than TCP/IP.

It is slightly faster, but 1) xnet is Windows-only, making it less
portable and 2) you're loading a native library into your Java process.
Bugs in native libraries (or say a bug in Jaybird using the native
library) can potentially crash your entire Java process. It is my
opinion if you can avoid that, you should.

But to be clear, this is my opinion, caused by a history of native
components causing annoying and hard to debug issues. I try to avoid
them when possible ;).

Mark

--
Mark Rotteveel

[shalamyansky]

Hello, Mark!

Here is a simple test project to demonstrate the problem.

The most likely cause is the VM debug setting -Dspring-boot.run.fork=false. If set to false, the error pops up, otherwise no error is shown.

Since version 2.2 spring-boot.run forks a process by default and I need to set spring-boot.run.fork=false to be able to set breakpoints in IntelliJ IDEA.

Environment and tools are described above and below:

Platform:
Windows 10 Pro 21H2 64-bit
JDK 1.8.0.311
Firebird       4.0.2.2816  64-bit
fbclient.dll  4.0.2.2816  64-bit
jna.dll          6.1.6.0         64-bit

Tool:
IntelliJ IDEA 2022.3.2 (Community Edition)
Build #IC-223.8617.56, built on January 26, 2023
Runtime version: 17.0.5+1-b653.25 amd64
VM: OpenJDK 64-Bit Server VM by JetBrains s.r.o.

Best wishes,

Mikhail Shalamyansky

[Mark Rotteveel]

On 20-02-2023 16:18, shalamyansky wrote:
> Here is a simple test project to demonstrate the problem.
>
> The most likely cause is the VM debug setting
> -Dspring-boot.run.fork=false. If set to false, the error pops up,
> otherwise no error is shown.
>
> Since version 2.2 spring-boot.run forks a process by default and I need
> to set spring-boot.run.fork=false to be able to set breakpoints in
> IntelliJ IDEA.

Thanks. I'll look at it in detail later this week, but the scenario you
describe actually sounds pretty logical for triggering this error.

The servlet context gets destroyed, which triggers Jaybird calling
fb_shutdown on the library, and which makes the loaded library unusable
for subsequent usage. Then because it doesn't fork a new process, the
next load creates a new servlet context within the same process, and
then JNA uses the already loaded DLL, even though it has been shutdown
and disposed.

I guess that the workaround I gave you previously is the only option
here, but I'll double check the JNA documentation if there is some
option I have missed, and play with your reproduction example to see if
there is something else I've missed.

Mark
--
Mark Rotteveel

[shalamyansky]

Oh, and db creation script:
--------------------------------------------------
create database 'test'
user 'sysdba' password 'masterkey'
page_size 16384
default character set utf8 collation utf8;

recreate table test (
    id    integer not null,
    name  varchar(8191)
);

alter table test add constraint pk_test primary key (id);
--------------------------------------------------

Mikhail Shalamyansky