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

Strange NullPointerException in PGConnection.finalize #1206

Closed
turbanoff opened this issue May 28, 2018 · 12 comments
Closed

Strange NullPointerException in PGConnection.finalize #1206

turbanoff opened this issue May 28, 2018 · 12 comments
Milestone

Comments

@turbanoff
Copy link

@turbanoff turbanoff commented May 28, 2018

Just caught NPE in PGConnection.close
default

  at org.postgresql.jdbc.PgConnection.close(PgConnection.java:659)
  at org.postgresql.jdbc.PgConnection.finalize(PgConnection.java:881)
  at java.lang.System$2.invokeFinalize(System.java:2125)
  at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:102)
  at java.lang.ref.Finalizer.access$100(Finalizer.java:34)
  at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:217)

Java 10.0.1 on Win 7x64

java version "10.0.1" 2018-04-17
Java(TM) SE Runtime Environment 18.3 (build 10.0.1+10)
Java HotSpot(TM) 64-Bit Server VM 18.3 (build 10.0.1+10, mixed mode)

There was some errors before this NPE (not sure if they are related).
First:

мая 27, 2018 12:52:25 ДП org.postgresql.core.v3.ConnectionFactoryImpl log
WARNING: IOException occurred while connecting to localhost:5432
java.net.SocketTimeoutException: connect timed out
at java.base/java.net.DualStackPlainSocketImpl.waitForConnect(Native Method)
at java.base/java.net.DualStackPlainSocketImpl.socketConnect(DualStackPlainSocketImpl.java:85)
at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:400)
at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:243)
at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:225)
at java.base/java.net.PlainSocketImpl.connect(PlainSocketImpl.java:148)
at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:402)
at java.base/java.net.Socket.connect(Socket.java:591)
at org.postgresql.core.PGStream.<init>(PGStream.java:69)
at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:156)
at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49)
at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:195)
at org.postgresql.Driver.makeConnection(Driver.java:452)
at org.postgresql.Driver.connect(Driver.java:254)
at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:117)
at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:123)
at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:365)
at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:194)
at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:467)
at com.zaxxer.hikari.pool.HikariPool.access$100(HikariPool.java:71)
at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:706)
at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:692)
at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:844)

Second:

мая 27, 2018 12:52:24 ДП org.postgresql.jdbc.PgConnection isValid
WARNING: Validating connection.
org.postgresql.util.PSQLException: Ошибка ввода/ввывода при отправке бэкенду
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:333)
at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365)
at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:155)
at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:132)
at org.postgresql.jdbc.PgConnection.isValid(PgConnection.java:1364)
at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:150)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128)
at org.christmas.dao.VkDataSource.getConnection(VkDataSource.java:31)
at org.christmas.dao.PostDAO.markAsReposted(PostDAO.java:127)
at org.christmas.RepostsMain.repost(RepostsMain.java:220)
at org.christmas.RepostsMain.lambda$startReposting$9(RepostsMain.java:190)
at java.base/java.lang.Thread.run(Thread.java:844)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.base/java.net.SocketInputStream.socketRead0(Native Method)
at java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:141)
at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:140)
at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:109)
at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:67)
at org.postgresql.core.PGStream.receiveChar(PGStream.java:293)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1947)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:306)
... 14 more
@davecramer
Copy link
Member

@davecramer davecramer commented May 28, 2018

What version of the driver ?

@turbanoff
Copy link
Author

@turbanoff turbanoff commented May 28, 2018

@davecramer version 42.2.2

@davecramer
Copy link
Member

@davecramer davecramer commented May 28, 2018

So I noticed you had the same issue with pg-ng. Was that a mistake

@turbanoff
Copy link
Author

@turbanoff turbanoff commented May 28, 2018

I mixed up repos :)

@bokken
Copy link
Member

@bokken bokken commented May 31, 2018

Can you provide the full stack trace of the NPE?

PGConnection close calls into QueryExecutorBase close, which is not thread safe.

@turbanoff
Copy link
Author

@turbanoff turbanoff commented May 31, 2018

@bokken I provided it. It just stack trace from IDEA - it wasn't logged anywhere, that's why it looks like this.

  at org.postgresql.jdbc.PgConnection.close(PgConnection.java:659)
  at org.postgresql.jdbc.PgConnection.finalize(PgConnection.java:881)
  at java.lang.System$2.invokeFinalize(System.java:2125)
  at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:102)
  at java.lang.ref.Finalizer.access$100(Finalizer.java:34)
  at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:217)
@turbanoff turbanoff closed this May 31, 2018
@bokken
Copy link
Member

@bokken bokken commented May 31, 2018

So you are observing this issue when debugging through code with debugger configured to stop on unhandled exceptions?

@turbanoff
Copy link
Author

@turbanoff turbanoff commented May 31, 2018

@bokken yes, exactly.

@turbanoff turbanoff reopened this May 31, 2018
@davecramer
Copy link
Member

@davecramer davecramer commented May 31, 2018

@turbanoff
Copy link
Author

@turbanoff turbanoff commented May 31, 2018

@davecramer Usually I run this app only in debug. But this exception happen inside Finalizer - looks like it do not log any exceptions (see http://hg.openjdk.java.net/jdk/jdk10/file/b09e56145e11/src/java.base/share/classes/java/lang/ref/Finalizer.java#l108). So, there is no way to know that.

@vlsi
Copy link
Member

@vlsi vlsi commented Jun 5, 2018

The case is as follows:

  1. Finalizable objects are registered to the finalization queue on invoke of Object.<init> constructor
  2. super.<init> must precede the <init> of the derived class

This enables unexpected leak of object in case the constructor fails.

The case is "connection refused" exception appears in the middle of PgConnection.<init>, thus no-one observes "uninitialized" PgConnection object besides finalizer (see #1 above).

Then it dances its way till finalize and happily blows with NPE on queryExecutor.close() since queryExecutor is null.

I suggest to put a cosmetic if (queryExecutor != null) check in the relevant close method.

@vlsi
Copy link
Member

@vlsi vlsi commented Jun 5, 2018

In the long-term, this might be a reason to use PhantomReferences for the cleanup.

@vlsi vlsi closed this in 03a1441 Jun 5, 2018
@vlsi vlsi added this to the 42.2.3 milestone Jun 5, 2018
rhavermans added a commit to bolcom/pgjdbc that referenced this issue Jul 13, 2018
Note: the NPE is not visible to the end users as it can be caught in debugger only.

fixes pgjdbc#1206
rhavermans added a commit to bolcom/pgjdbc that referenced this issue Jul 13, 2018
Note: the NPE is not visible to the end users as it can be caught in debugger only.

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

Successfully merging a pull request may close this issue.

None yet
4 participants
You can’t perform that action at this time.