CABI scheduled reports intermittently failing
search cancel

CABI scheduled reports intermittently failing

book

Article ID: 252936

calendar_today

Updated On:

Products

DX Unified Infrastructure Management (Nimsoft / UIM)

Issue/Introduction

Scheduled reports are failing intermittently with rare occurrences.  These failures always seem to occur in off hours with long times between these failures.
The following error messages are found in the jasperserver.log files

2022-10-22T21:05:01,653 DEBUG ReportExecutionJob,JasperServerScheduler_Worker-1:714 - generated baseFileName: *****<ReportName>******* for 12
2022-10-22T21:05:04,459 DEBUG InternalReportExecutor,JasperServerScheduler_Worker-1:233 - running report with pagination {paginated: null, maxPageHeight: null, maxPageWidth: null}
2022-10-22T21:05:04,973 DEBUG JRJdbcQueryExecuter,JasperServerScheduler_Worker-1:154 - DB is Microsoft SQL Server version Microsoft SQL Server 2016 - 13.0.5893.48 (13/0)
2022-10-22T21:05:04,992 DEBUG JRJdbcQueryExecuter,JasperServerScheduler_Worker-1:158 - driver is SQLServer version 6.0.0.000541 (F001205.U000618) (6/0)
2022-10-22T21:05:04,993 DEBUG JRJdbcQueryExecuter,JasperServerScheduler_Worker-1:162 - jdbc 4/0
2022-10-22T21:05:04,994 DEBUG JRJdbcQueryExecuter,JasperServerScheduler_Worker-1:164 - connection URL is jdbc:tibcosoftware:sqlserver://<ServerName>:1433;JDBCBEHAVIOR=1;APPLICATIONNAME=;AEKEYSTOREPRINCIPALID=;CATALOGOPTIONS=0;SNAPSHOTSERIALIZABLE=false;NETADDRESS=000000000000;XMLDESCRIBETYPE=;SOCKETDEFAULTSENDBUFFERSIZE=0;BULKLOADBATCHSIZE=1000;ENABLEBULKLOAD=false;DATABASENAME=CA_UIM;CONNECTIONRETRYDELAY=1;CLIENTUSER=;TRUNCATEFRACTIONALSECONDS=true;WORKAROUNDS=0;VALIDATESERVERCERTIFICATE=true;CONVERTNULL=1;CONNECTIONRETRYCOUNT=5;TRUSTSTORE=;PROGRAMNAME=;LOADLIBRARYPATH=;DATETIMEOUTPUTPARAMETERTYPE=auto;FETCHTWFSASTIME=false;MAXPOOLEDSTATEMENTS=0;COLUMNENCRYPTION=DISABLED;MULTISUBNETFAILOVER=false;CRYPTOPROTOCOLVERSION=;QUERYTIMEOUT=0;TRANSACTIONMODE=implicit;ALWAYSREPORTTRIGGERRESULTS=false;LONGDATACACHESIZE=2048;PROGRAMID=;SOCKETDEFAULTRECEIVEBUFFERSIZE=65536;WSID=;SECURERANDOMALGORITHM=;REGISTERSTATEMENTPOOLMONITORMBEAN=false;PACKETSIZE=-1;IMPORTSTATEMENTPOOL=;DOMAIN=;LOADBALANCING=false;LOGINTIMEOUT=0;AEKEYSTORECLIENTSECRET=;RANDOMGENERATOR=SECURERANDOM;HOSTPROCESS=0;FAILOVERGRANULARITY=nonAtomic;ACCOUNTINGINFO=;ENCRYPTIONMETHOD=NoEncryption;DEFAULTSCALE=4;SUPPRESSCONNECTIONWARNINGS=false;FAILOVERMODE=connect;SELECTMETHOD=direct;INITIALIZATIONSTRING=;BATCHPERFORMANCEWORKAROUND=false;AEKEYSTORESECRET=;STRINGINPUTPARAMETERTYPE=nvarchar;JAVADOUBLETOSTRING=false;CODEPAGEOVERRIDE=;AUTHENTICATIONMETHOD=auto;CLIENTHOSTNAME=;AEKEYSTORELOCATION=;RESULTSETMETADATAOPTIONS=0;FAILOVERPRECONNECT=false;DESCRIBEINPUTPARAMETERS=noDescribe;INSENSITIVERESULTSETBUFFERSIZE=2048;ISTLSTUNNEL=false;ENABLECANCELTIMEOUT=false;HOSTNAMEINCERTIFICATE=;AEKEYCACHETTL=7200;USESERVERSIDEUPDATABLECURSORS=false;DATETIMEINPUTPARAMETERTYPE=auto;FETCHTSWTZASTIMESTAMP=false;ALTERNATESERVERS=;STRINGOUTPUTPARAMETERTYPE=nvarchar;BULKLOADOPTIONS=2;TRUSTSTOREPASSWORD=;DESCRIBEOUTPUTPARAMETERS=noDescribe;APPLICATIONINTENT=READWRITE
2022-10-22T21:05:04,996 DEBUG JRJdbcQueryExecuter,JasperServerScheduler_Worker-1:206 - system timezone is sun.util.calendar.ZoneInfo[id="America/New_York",offset=-18000000,dstSavings=3600000,useDaylight=true,transitions=235,lastRule=java.util.SimpleTimeZone[id=America/New_York,offset=-18000000,dstSavings=3600000,useDaylight=true,startYear=0,startMode=3,startMonth=2,startDay=8,startDayOfWeek=1,startTime=7200000,startTimeMode=0,endMode=3,endMonth=10,endDay=1,endDayOfWeek=1,endTime=7200000,endTimeMode=0]]
2022-10-22T21:05:04,997 DEBUG JRJdbcQueryExecuter,JasperServerScheduler_Worker-1:207 - report timezone is sun.util.calendar.ZoneInfo[id="America/New_York",offset=-18000000,dstSavings=3600000,useDaylight=true,transitions=235,lastRule=java.util.SimpleTimeZone[id=America/New_York,offset=-18000000,dstSavings=3600000,useDaylight=true,startYear=0,startMode=3,startMonth=2,startDay=8,startDayOfWeek=1,startTime=7200000,startTimeMode=0,endMode=3,endMonth=10,endDay=1,endDayOfWeek=1,endTime=7200000,endTimeMode=0]]
2022-10-22T21:05:05,005 ERROR BaseJdbcDataSource,JasperServerScheduler_Worker-1:85 - Error closing connection. java.sql.SQLException: Already closed.

Around this time (before or after), we see the following:


2022-10-08T21:15:34,536  INFO ReportJobsQuartzScheduler,JasperServerScheduler_QuartzSchedulerThread:1232 - Quartz scheduler error: An error occurred while scanning for the next triggers to fire. org.quartz.JobPersistenceException: Failed to obtain DB connection from data source 'springNonTxDataSource.JasperServerScheduler': java.sql.SQLException: [TibcoSoftware][SQLServer JDBC Driver][SQLServer]SHUTDOWN is in progress. [See nested exception: java.sql.SQLException: [TibcoSoftware][SQLServer JDBC Driver][SQLServer]SHUTDOWN is in progress.]
Caused by: java.sql.SQLException: [TibcoSoftware][SQLServer JDBC Driver][SQLServer]SHUTDOWN is in progress.

Environment

Release : 20.4

Cause

The database server was undergoing patching at the time of the failures.  These connection failures were preventing the reports from running.

Resolution

Reschedule the reports to not run during the maintenance window or rerun the reports afterwards.

Powered by Wolken Software