qwc-services / jasper-reporting-service

Web service for publishing Jasper Reports
GNU General Public License v3.0
11 stars 11 forks source link

No reconnect after lost DB connection #5

Closed pfeimich closed 2 years ago

pfeimich commented 4 years ago

After losing a DB connection due to reboot of the DB Server jasper-reporting-service does not automatically reconnect the DB connection

2020-03-09 07:27:16.379 ERROR 1 --- [nio-8080-exec-5] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is net.sf.jasperreports.engine.JRRuntimeException: net.sf.jasperreports.engine.JRException: Error preparing statement for executing the report query:
SELECT *
FROM dbo.REP_VIEW_FUNDSTELLEN
where FST_NR=?
] with root cause
java.sql.SQLException: Connection is closed
    at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection$1.invoke(ProxyConnection.java:468) ~[HikariCP-2.6.0.jar!/:na]
    at com.sun.proxy.$Proxy77.getMetaData(Unknown Source) ~[na:na]
    at com.zaxxer.hikari.pool.HikariProxyConnection.getMetaData(HikariProxyConnection.java) ~[HikariCP-2.6.0.jar!/:na]
    at net.sf.jasperreports.engine.query.OracleProcedureCallHandler.isOracle(OracleProcedureCallHandler.java:72) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at net.sf.jasperreports.engine.query.JRJdbcQueryExecuter.isProcedureCall(JRJdbcQueryExecuter.java:539) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at net.sf.jasperreports.engine.query.JRJdbcQueryExecuter.createStatement(JRJdbcQueryExecuter.java:369) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at net.sf.jasperreports.engine.query.JRJdbcQueryExecuter.createDatasource(JRJdbcQueryExecuter.java:297) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at net.sf.jasperreports.engine.fill.JRFillDataset.createQueryDatasource(JRFillDataset.java:1245) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at net.sf.jasperreports.engine.fill.JRFillDataset.initDatasource(JRFillDataset.java:723) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at net.sf.jasperreports.engine.fill.BaseReportFiller.setParameters(BaseReportFiller.java:438) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at net.sf.jasperreports.engine.fill.JRBaseFiller.fill(JRBaseFiller.java:550) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at net.sf.jasperreports.engine.fill.BaseReportFiller.fill(BaseReportFiller.java:396) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at net.sf.jasperreports.engine.fill.JRFillSubreport.fillSubreport(JRFillSubreport.java:732) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at net.sf.jasperreports.engine.fill.JRSubreportRunnable.run(JRSubreportRunnable.java:59) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at net.sf.jasperreports.engine.fill.AbstractThreadSubreportRunner.run(AbstractThreadSubreportRunner.java:221) ~[jasperreports-6.4.1.jar!/:6.4.1]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) ~[na:na]
    at java.base/java.lang.Thread.run(Thread.java:844) [na:na]
HusseinKabbout commented 4 years ago

@pfeimich Thank you for creating this issue!

I tried to reproduce your problem but the reporting service worked on my machine even after restarting the postgres service.

jasper-reporting-service Version: master branch application.properties:

# Datasource
spring.datasource0.url=jdbc:postgresql://localhost/jasper_test
spring.datasource0.username=****
spring.datasource0.password=****
spring.datasource0.driver-class-name=org.postgresql.Driver
# Custom Parameters
reports.directory=demo/reports/
reports.locale=de_CH

Steps I made to reproduce the problem:

  1. Start postgres service
  2. Start jasper reporting service
  3. Try to access demo report --> success
  4. Stop postgres service
  5. Try to access demo report --> fails
  6. Start postgres service
  7. Try to access demo report --> success
pfeimich commented 4 years ago

@HusseinKabbout thanks for your answer. Not so here. After restarting postgres service we have the error

2020-03-19 14:01:05.143  WARN 1 --- [nio-8080-exec-7] org.postgresql.jdbc.PgConnection         : Validating connection.
org.postgresql.util.PSQLException: FATAL: terminating connection due to administrator command

But we are running v2.0.9 from Sourcepole gitlab and this seems to be a little bit different from this master version here. Our application.properties

spring.h2.console.enabled=false
# Datasource
spring.datasource0.url=jdbc:postgresql://****/***?ssl=true&sslfactory=org.postgresql.ssl.NonValidatingFactory
spring.datasource0.username=*****
spring.datasource0.password=******
spring.datasource0.driver-class-name=org.postgresql.Driver
# Custom Parameters
reports.directory=/reports/
reports.locale=de_CH
HusseinKabbout commented 4 years ago

I have tested it again with the version you use. This time I also got the same error message, but the service still delivered the demo report. The service kind of ignores the exception and just creates a new connection if he needs it. @pfeimich Do the reports not work at all?

pfeimich commented 4 years ago

Yes with the Postgres Connection Reports I determinded nearly the same behaviour. But for some reports we have an SQL Server Connection and this report doesn't work at all after the reboot of the DB Server.

edigonzales commented 4 years ago

Since it does still not work, some thoughts: The connections are never returned to the pool. When requesting a report, the connections are created from the datasources once. The connections will be passed to the ModelAndView object which is responsible for creating the PDF. But that's it. Who should be responsible for returning the connection to the pool?

If the application keeps the connection endlessly and the database server will be restarted, the connection will not work anymore. And I don't think that - out of the box - the application will request a new connection from the pool.

When using logging.level.com.zaxxer.hikari=debug I see that there is one connection active. When closing the connection (dataConnX.close()) after the PDF creation, there is no active connection.

@HusseinKabbout What do you think?

HusseinKabbout commented 4 years ago

If the application keeps the connection endlessly and the database server will be restarted, the connection will not work anymore. And I don't think that - out of the box - the application will request a new connection from the pool.

The funny thing is that this only happens with SQL Server and not with postgres. With postgres even if you restart the server, the application will automatically reconnect.

Just to be sure, you already tried setting

testOnBorrow=true
SELECT 1

in the application.properties file?

edigonzales commented 4 years ago

testOnBorrow is a tomcat pooling option. Hikari doesn't know it. We use connection-test-query=SELECT 1. But I think Hikari will validate the connection with this test query before giving the connection to the application. Since the application (= jasper server) never closes (= returning the connection to the pool) the connection, the test query has not any impact. And a connection outside the pool is never closed by the pool itself.