Not able to start IS getting stuck

2020-06-29 03:29:52 EDT [ISS.0028.0012I] NA_Utilities: Startup service (na_Utilities.configurations.init:loadAllAuditGroups)
2020-06-29 04:49:45 EDT [CommonLib.MWS.0002W] Found inactive subscription 1945. Check time: 1593413385000

HI Praveen,

Can you please take thread dump when IS is in this state? This would help to diagnose the problem.

Thanks,
-Kalpesh.

Dear Praveen,

Please increase the logging level to debug from server.cnf and start the IS and post the server logs here.

Thanks Kalpesh.
2020-06-29 10:05:30 EDT [ISS.0028.0012I] PSUtilities: Startup service (PSUtilities.config:loadPSUtilitiesConfig)
2020-06-29 10:05:30 EDT [ISS.0028.0012I] PSUtilities: Startup service (PSUtilities.config:setACLs)
2020-06-29 10:05:30 EDT [ISS.0028.0012I] NA_Utilities: Startup service (na_Utilities.configurations.init:loadAllAuditGroups)
2020-06-29 11:37:01 EDT [SCC.0121.0034E] commit failed: more than 1 local trans enlisted. xid = [FormatId=45744, GlobalId=usmlrs26.arrow.com_5559/1593439531069, BranchQ
ual=2] rxid = {2}
2020-06-29 11:37:01 EDT [SCC.0121.0990E] XA Transaction Logging: commitResources-IllegalStateException for xid: usmlrs26.arrow.com_5559/1593439531069 → java.lang.Illeg
alStateException: commit failed. more than one local transaction enlisted.
2020-06-29 11:37:02 EDT [ART.0114.1007E] Adapter Runtime: Error Logged. See Error log for details. Error: [ADA.1.107] Failed to rollback local transaction.“java.sql.SQL
RecoverableException: No more data to read from socket”
No more data to read from socket
2020-06-29 11:37:02 EDT [SCC.0121.0017E] rollback failed: [ADA.1.107] Failed to rollback local transaction.“java.sql.SQLRecoverableException: No more data to read from
socket”
No more data to read from socket javax.transaction.xa.XAException xid = usmlrs26.arrow.com_5559/1593439531069 resource = na_EC_Adapters.JDBC603.connections:procAuditCon
n
2020-06-29 11:37:02 EDT [SCC.0121.0026E] delisted transaction commit failed: java.lang.IllegalStateException: commit failed. more than one local transaction enlisted. x
id = usmlrs26.arrow.com_5559/1593439531069
2020-06-29 11:37:02 EDT [ART.0114.1007E] Adapter Runtime: Error Logged. See Error log for details. Error: [ART.117.4018] Adapter Runtime (Adapter Service): Error while
closing transactions at service completion Error:[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapter connections.
[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapter connections…
[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapter connections.
[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapter connections.
2020-06-29 11:37:02 EDT [ISS.0015.9998E] Exception → com.wm.pkg.art.error.DetailedServiceException: [ART.117.4018] Adapter Runtime (Adapter Service): Error while clos
ing transactions at service completion Error:[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapter connections.
[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapter connections…
[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapter connections.
[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapter connections.
2020-06-29 11:37:02 EDT [ISS.0028.0013E] Startup service exited with the following error: com.wm.pkg.art.error.DetailedServiceException: [ART.117.4018] Adapter Runtime
(Adapter Service): Error while closing transactions at service completion Error:[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapte
r connections.
[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapter connections…
[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapter connections.
[ART.117.4015] Adapter Runtime (Adapter Service): Error(s) occurred while closing adapter connections.
2020-06-29 11:37:02 EDT [ISS.0028.0012I] NA_Utilities: Startup service (na_Utilities.logging.init:loadLoggers)
2020-06-29 11:37:02 EDT [ISS.0028.0012I] WmPIPTools: Startup service (wm.ip.rn.ui:addSubmenu)
2020-06-29 11:37:02 EDT [ISP.0046.0012I] Enabling HTTP Listener on port 5559

This had started now.

That’s great! Thanks for the updates Praveen. For future, if this type of problem occurs, please make sure that you take thread dump as it would help to diagnose the problem.

You might want to check the implementation of startup service na_Utilities.configurations.init:loadAllAuditGroups as there seems to be a timeout issue during loading the AuditGroups from DB.
Focus on the Transaction types of the involved adapter services as there seems to be one XA Transaction and at least 2 Local Transactions involved in this issue.

Just wondering why there are transactions involved when there is data only being retreived from DB and nothing needs to be updated there.