Not able to start IS getting stuck

,
1

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

2

HI Praveen,

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

Thanks,
-Kalpesh.

3

Dear Praveen,

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

4

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.

5

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.

6

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.