Destination 'SessionDBDest' caught unexpected SQLException wM v9

,
1

After more than a month of the platform running fine, I am now getting continual errors as follows. I would appreciate any help in understanding the cause and correction. Have checked ISInternal JDBC alias; tests fine and restarts without error. Running version 9 SP1, empower fixes applied 12/20/13. SQL Server 2012 DB, Windows OS 2012. Thanks, Steve.

2013-12-23 07:29:00 PST [WmAuditingSC.destination.1105E] Destination ‘SessionDBDest’ caught unexpected SQLException inserting value for field ‘com.wm.app.b2b.server.audit.type.ClientApplicationFieldType’ into PreparedStatement: [SoftwareAG][SQLServer JDBC Driver]Invalid parameter binding(s).
2013-12-23 07:29:00 PST [WmAuditingSC.destination.1122E] Destination ‘SessionDBDest’ caught unexpected Throwable logging audit event: Destination ‘SessionDBDest’ caught unexpected SQLException inserting value for field ‘com.wm.app.b2b.server.audit.type.ClientApplicationFieldType’ into PreparedStatement: [SoftwareAG][SQLServer JDBC Driver]Invalid parameter binding(s).
2013-12-23 07:29:00 PST [WmAuditingSC.queue.2406E] AuditQueueWorker for queue ‘Session Queue’ failed to log event to destination ‘SessionDBDest’; reason ‘[SoftwareAG][SQLServer JDBC Driver]Invalid parameter binding(s).’; stack trace follows
2013-12-23 07:29:00 PST [WmAuditingSC.queue.2416I] In queue ‘Session Queue’ worker, the preceding error is non-recoverable; failing-over
2013-12-23 07:29:00 PST [WmAuditingSC.queue.2098E] The following record could not be written to the Failed Audit Log: WMSESSION f1fce620-6be6-11e3-9158-f637e36d548e f1fce620-6be6-11e3-9158-f637e36d548e 9bab5c1a-88d4-2d41-b7db-1907160ad180 WMDEVMWS.nvdps.state.nv.us:5555 2013-12-23T15:28:59.801Z 2013-12-23T15:29:00.661Z 2 Administrator 127.0.0.1 2 11 f1febae06be611e39159f3207df251e1

2

Please make sure you ran all the scripts for ISCoreAudit via db configurator and also the JDBC Pools page the ISCoreAudit is pointed to the right database pool alias.

And restart your IS:

HTH,
RMG

3

Thanks, RMG, but that doesn’t seem to have done it. DB Configurator migrated ISCoureAudit from 45 to 46 without issues, and JDBC pool reports fine, but IS log at restart indicates the problem picked up again right away:
… (tail end of restart log)…
2013-12-23 08:20:32 PST [ISS.0028.0012I] WmTaskClient: Startup service (wm.task.taskclient:init)
2013-12-23 08:20:32 PST [ISP.0046.0012I] Enabling HTTP Listener on port 9999
2013-12-23 08:20:32 PST [ISP.0046.0012I] Enabling HTTP Listener on port 5555
2013-12-23 08:20:32 PST [ISP.0046.0012I] Enabling HTTP Listener on port 15006
2013-12-23 08:20:32 PST [ISS.0098.0021I] Persistent Trigger Output Dispatcher started
2013-12-23 08:20:32 PST [ISS.0098.0021I] Exactly Once Trigger Output Dispatcher started
2013-12-23 08:20:32 PST [ISS.0098.0034I] webM IS RequestReplyHandler starting execution.
2013-12-23 08:20:32 PST [ISS.0098.0027I] PersistenceManager started all Stores
2013-12-23 08:20:32 PST [ISS.0025.0036I] Dispatcher started
2013-12-23 08:20:32 PST [ISS.0025.0013I] Cache Sweeper started
2013-12-23 08:20:32 PST [WmAuditingSC.destination.1105E] Destination ‘CoreAuditDBDest’ caught unexpected SQLException inserting value for field ‘com.wm.app.b2b.server.audit.type.TxErrorMessageFieldType’ into PreparedStatement: [SoftwareAG][SQLServer JDBC Driver]Invalid parameter binding(s).
2013-12-23 08:20:32 PST [WmAuditingSC.destination.1122E] Destination ‘CoreAuditDBDest’ caught unexpected Throwable logging audit event: Destination ‘CoreAuditDBDest’ caught unexpected SQLException inserting value for field ‘com.wm.app.b2b.server.audit.type.TxErrorMessageFieldType’ into PreparedStatement: [SoftwareAG][SQLServer JDBC Driver]Invalid parameter binding(s).
2013-12-23 08:20:32 PST [WmAuditingSC.logger.3405E] In logger ‘Guaranteed Delivery Outbound Logger’, failed to log to destination; reason: Destination ‘CoreAuditDBDest’ caught unexpected SQLException inserting value for field ‘com.wm.app.b2b.server.audit.type.TxErrorMessageFieldType’ into PreparedStatement: [SoftwareAG][SQLServer JDBC Driver]Invalid parameter binding(s).
2013-12-23 08:20:32 PST [ISS.0025.0025I] Broker Synchronizer initialized
2013-12-23 08:20:32 PST [ISS.0014.0002C] Initialization completed in 53 seconds.
2013-12-23 08:20:32 PST [ISS.0025.0016I] Config File Directory Saved
2013-12-23 08:20:32 PST [ISS.0025.0057I] Reading system level information
2013-12-23 08:20:33 PST [WmAuditingSC.destination.1105E] Destination ‘CoreAuditDBDest’ caught unexpected SQLException inserting value for field ‘com.wm.app.b2b.server.audit.type.TxErrorMessageFieldType’ into PreparedStatement: [SoftwareAG][SQLServer JDBC Driver]Invalid parameter binding(s).
2013-12-23 08:20:33 PST [WmAuditingSC.destination.1122E] Destination ‘CoreAuditDBDest’ caught unexpected Throwable logging audit event: Destination ‘CoreAuditDBDest’ caught unexpected SQLException inserting value for field ‘com.wm.app.b2b.server.audit.type.TxErrorMessageFieldType’ into PreparedStatement: [SoftwareAG][SQLServer JDBC Driver]Invalid parameter binding(s).
2013-12-23 08:20:33 PST [WmAuditingSC.queue.2406E] AuditQueueWorker for queue ‘Guaranteed Delivery Outbound Queue’ failed to log event to destination ‘CoreAuditDBDest’; reason ‘[SoftwareAG][SQLServer JDBC Driver]Invalid parameter binding(s).’; stack trace follows
2013-12-23 08:20:33 PST [WmAuditingSC.queue.2416I] In queue ‘Guaranteed Delivery Outbound Queue’ worker, the preceding error is non-recoverable; failing-over
2013-12-23 08:20:33 PST [WmAuditingSC.queue.2098E] The following record could not be written to the Failed Audit Log: WMTXOUT 253c1590-6bee-11e3-9f4c-a054d8cdc567 253c1590-6bee-11e3-9f4c-a054d8cdc567 fd44e718-b4e8-6c03-ea98-cd7d21e79c9d WMDEVMWS.nvdps.state.nv.us:5555 2013-12-23T16:20:32.233Z 2013-12-23T16:20:33.197Z 1 TXRmtJobManager

4

What was the latest fix applied on 12/20/12?

5

Sai, I’ve attached the log from the UpdateManager; not sure how much of it you want to see.

I should add that this started happening when I first setup our JDBC Adaptor package to access a SQL and an Oracle database. Had to install the SQL and ORA jars and setup the SQLServerDataSource, etc. I got those working fine, but these other ‘SessionDBDest’ errors have been showing up since then. I’m too new at this to see if they’re related. The internal IS and MWS jdbc pool use the DataDirect Connect drivers, which I don’t believe were changed during the SQL and ORA setup…

Thanks,
Steve
info.log (597 KB)

6

Refer KB Articles below, this should help to solve problems

URLS:

https://empower.softwareag.com/sl24sec/SecuredServices/KCFullTextASP/viewing/view.asp?KEY=099532-17020522&DSN=PIVOTAL&DST=TCD&HL=1&QUERY=WmAuditingSC.logger.3405E&SessionID=980304787

https://empower.softwareag.com/sl24sec/SecuredServices/KCFullTextASP/viewing/view.asp?KEY=100081-14215357&DSN=PIVOTAL&DST=TCD&HL=1&QUERY=WmAuditingSC.destination.1122E&SessionID=980304787

https://empower.softwareag.com/sl24sec/SecuredServices/KCFullTextASP/viewing/view.asp?KEY=098040-3224853&DSN=PIVOTAL&DST=TCD&HL=1&QUERY=WmAuditingSC.destination.1105E&SessionID=980304787

Details Below

======================================================
webMethods Integration Server - [WmAuditingSC.destination.1105E] Destination ‘SessionDBDest’ caught unexpected SQLException inserting value for field ‘com.wm.app.b2b.server.audit.type.SessionIdFieldType’ into PreparedStatement

KB #: 1744038 Operating System Family: ALL
Product: webMethods Integration Server (PIE) Operating System: All
Version:
Last Updated: 13-MAY-2013
Description:

The DB itself seems to work well. User can test all the JDBC-Connections in the Integration Server Admin Page, but find the above error in the server log.

Resolution:

Please make sure if you are not ignoring any jvm parameters while startup especially:

-Dcom.webMethods.sc.auditing.Use80TableFormat=true

=================================================================
webMethods Integration Server - WmAuditingSC errors in server.log

KB #: 1746057 Operating System Family: PC
Product: webMethods Integration Server (PIE) Operating System: Windows Server 2008
Version: 9.0.1
Last Updated: 08-AUG-2013
Description:

The following errors appeared in server.log. But the IS Core Audit has been configured successfully during installation, the configured JDBC Pools in IS Admin Console are working and ISCoreAudit and ISInternal database scripts have executed successfully using Database Component Configurator.

2013-07-11 16:10:48 WST [WmAuditingSC.destination.1105E] Destination ‘CoreAuditDBDest’ caught unexpected SQLException inserting value for field ‘com.wm.app.b2b.server.audit.type.TxErrorMessageFieldType’ into PreparedStatement: [SoftwareAG][Oracle JDBC Driver]Invalid parameter binding(s).
2013-07-11 16:10:48 WST [WmAuditingSC.destination.1122E] Destination ‘CoreAuditDBDest’ caught unexpected Throwable logging audit event: Destination ‘CoreAuditDBDest’ caught unexpected SQLException inserting value for field ‘com.wm.app.b2b.server.audit.type.TxErrorMessageFieldType’ into PreparedStatement: [SoftwareAG][Oracle JDBC Driver]Invalid parameter binding(s).
2013-07-11 16:10:48 WST [WmAuditingSC.queue.2406E] AuditQueueWorker for queue ‘Guaranteed Delivery Outbound Queue’ failed to log event to destination ‘CoreAuditDBDest’; reason ‘[SoftwareAG][Oracle JDBC Driver]Invalid parameter binding(s).’; stack trace follows
2013-07-11 16:10:48 WST [WmAuditingSC.queue.2416I] In queue ‘Guaranteed Delivery Outbound Queue’ worker, the preceding error is non-recoverable; failing-over
2013-07-11 16:10:48 WST [WmAuditingSC.queue.2098E] The following record could not be written to the Failed Audit Log: WMTXOUT 6423c970-ea01-11e2-a426-ffef682a0b4d

Resolution:

The root cause is starting up IS from \profiles\IS\bin.
If IS is started up with startup.bat in \IntegrationServer\bin, audit function works fine.

It is not supported to start up IS from \profiles\IS\bin and also modify the configuration files there.
Correct way to start up IS is always from \IntegrationServer\bin.
This is same for ver.8.2 as well.

The scripts under \IntegrationServer\bin handles some initialization required for Integration Server unlike the ones from \profiles\IS\bin.

webMethods Process Engine - Cannot insert the value NULL into column ‘EXTERNALID’

KB #: 1745590 Operating System Family: PC
Product: webMethods Process Engine (WPE) Operating System: Windows Server 2008
Version: 8.2.2
Last Updated: 28-JUN-2013
Description:

Seeing in IS server.log the following errors:

[PRT.0101.0196I] started Process [PID=839ce320-cb77-11e2-bcfe-c7ddad827daf:1, MID=XX/YY, MVer=1]
[WmAuditingSC.destination.1122E] Destination ‘ProcessAuditDBDest’ caught unexpected Throwable logging audit event: [sag-cjdbc42-0011][SQLServer JDBC Driver][SQLServer]Cannot insert the value NULL into column ‘EXTERNALID’, table ‘wm82GA.dbo.WMPROCESSASSOC’; column does not allow nulls. INSERT fails.
[WmAuditingSC.logger.3405E] In logger ‘Process Logger’, failed to log to destination; reason: Fatal SQLException detected
[PRT.0101.0002E] ERROR: com.wm.app.prt.ProcessException
?
[WmAuditingSC.destination.1122E] Destination ‘ProcessAuditDBDest’ caught unexpected Throwable logging audit event: [sag-cjdbc42-0011][SQLServer JDBC Driver][SQLServer]Cannot insert the value NULL into column ‘EXTERNALID’, table ‘wm82GA.dbo.WMPROCESSASSOC’; column does not allow nulls. INSERT fails.
[WmAuditingSC.queue.2406E] AuditQueueWorker for queue ‘ProcessAuditQueue’ failed to log event to destination ‘ProcessAuditDBDest’; reason ‘[sag-cjdbc42-0011][SQLServer JDBC Driver][SQLServer]Cannot insert the value NULL into column ‘EXTERNALID’, table ‘wm82GA.dbo.WMPROCESSASSOC’; column does not allow nulls. INSERT fails.’; stack trace follows
[WmAuditingSC.queue.2416I] In queue ‘ProcessAuditQueue’ worker, the preceding error is non-recoverable; failing-over
[WmAuditingSC.destination.1206E] Destination ‘FailedAuditLog’ detects null value for required field type ‘com.wm.app.prt.audit.schema.ExternalIdFieldType’
[WmAuditingSC.destination.1206E] Destination ‘FailedAuditLog’ detects null value for required field type ‘com.wm.app.prt.audit.schema.ExternalIdFieldType’
[WmAuditingSC.queue.2098E] The following record could not be written to the Failed Audit Log: WMPROCESSASSOC 839ce320-cb77-11e2-bcfe-c7ddad827daf ?.

Resolution:

An invocation to logCustomId with a null value for the EXTERNALID will result in this exception from the Audit Logging Subsystem.
In this case , customer used the pub.prt.logCustomId in one of their Process?s steps ,and this cause the Exception as 'EXTERNALID? column in WMPROCESSASSOC DB table is not allowed to be null.

7

Sai, well done! Item # 2 seems to have resolved it.

"Resolution:

The root cause is starting up IS from \profiles\IS\bin.
If IS is started up with startup.bat in \IntegrationServer\bin, audit function works fine."

I will review the info provided, but am happy to say that it’s no longer spewing like it was! :smiley:
Thanks!
Steve

8

Great!!

9

Hi
We are getting below errors in the IS and after that IS stops responding. We have to kill the process and start the server when this happens. Any pointers on why these errors are coming would be helpful. We observed that this happens after a large number of adapter errors.

02:40:28 EST [WmAuditingSC.destination.1122E] Destination ‘ErrorDBDest’ caught unexpected Throwable logging audit event: [SoftwareAG][Oracle JDBC Driver]Login has timed out.
2014-02-25 02:40:28 EST [WmAuditingSC.logger.3405E] In logger ‘Error Logger’, failed to log to destination; reason: Fatal SQLException detected
2014-02-25

WM Version is 8.2

Regards
Shaya

10

Shaya, my problem wasn’t a timeout, but it could be related to a similar issue. In our case, I was starting the IS from the wrong scripts.

The root cause is starting up IS from \profiles\IS\bin.
If IS is started up with startup.bat in \IntegrationServer\bin, audit function works fine.

Apparently, there’s a variance in how the Adaptor is initiated.

You might see if that applies in your case…
Steve

11

Yes it’s always better IS to start from \IntegrationServer\bin with the appropriate root/sudo admin user.

HTH,
RMG

12

yes, we do always start the IS from IntegrationServer\bin,

When these errors happened, we had to clean up the WmRepository files, and then only the IS would start up properly,

I am trying to figure out the root cause for these Audit login timeout issues