Based on one of the tricky issues on which I recently worked on for SRM Approval Integration, thought to share troubleshooting tips which was useful for resolving it.
Problem: Service Request was getting stuck in ‘Waiting Approval’ Status intermittently and Few of them were having duplicate approver signatures attached.
1) For such scenarios, We should have Approval Debug Logs, Server Side logs => API/SQL/Filter logs, arjavaplugin*.log (means all logs for arjavaplugin including std_err and std_out) all from the same timestamp when issue occurs.
If there are multiple servers in server group, we need server side logs from all servers. We always face challenges gathering logs from all servers when issue is intermittent, but when we have it once, it makes everything else easier.
2) We expect after approving signature successfully, Service request should move to next status i.e. Planning. So we should check Approval Server Debug logs for related ‘Sig-Approved’ command.
For the customer issue, I was having the signature ID which was approved earlier 000000004025607, so when I checked in Approval Debug logs I found Sig-Approved processed successfully at Wed Dec 20 2017 15:06:13.0684, which set Detail record to Approved status successfully.
3) So while approval server is processing Sig-Approved command, it sets the AP:Detail record to ‘Approved’ status. And during SetEntry API 'APR:AVD:RunITSMUtilPlugin' filter executes which is responsible to set status of service request as ‘Planning’ i.e. 7=4000.
This filter calls ITSM Util Plugin i.e. Filter API plugin which is responsible to change status.
From the customer logs, I could see during SE API on AP:Detail, ITSM Util Plugin got called, but it resulted into error:
Plugin result message (301385500) = ERROR (552): The SQL database operation failed.; Invalid column name 'C900000005INR'.
Since this was just a set field action for Plugin Code and Plugin Result Message, it didn’t make SETEntry on AP:Detail to fail. So Detail record got approved successfully.
4) Next when plugin gets called with input value as 7=4000, it triggers SetEntry API on SRM:Request and try to set the status value to 4000. We could get more details about this when we have arjavaplugin logs captured with Debug level on.
This Set Entry was failing with same error as we get it in Plugin Result Message. ‘ERROR (552): The SQL database operation failed.; Invalid column name 'C900000005INR'.
From API/Sql/Filter logs, we could get complete SetEntry API on SRM:Request to understand at which step exactly it was giving this error.
This was custom form, where currency column was missing in the database.
During the setEntry on SRM:Request, customer was pushing data to custom forms as well where it broken due to currency column was not available.
<FLTR> <TID: 0000000412> <RPC ID: 0001686949> <Queue: Fast > <Client-RPC: 390620 > <USER: Remedy Application Service > <Overlay-Group: 1 > /* Wed Dec 20 2017 15:06:15.4390 */ End of filter processing (phase 1) -- Operation - CREATE on XXX:SR_HWSWRequest_Request Details_Transactions - <NULL>
<SQL > <TID: 0000000412> <RPC ID: 0001686949> <Queue: Fast > <Client-RPC: 390620 > <USER: Remedy Application Service > <Overlay-Group: 1 > /* Wed Dec 20 2017 15:06:15.4390 */ INSERT INTO T3478(C536870914,C2,C7,C8,C930000501,C900000384,C900000386,C910000253,C912060701,C910000252,C900000492,C900000490,C900000491,C900000200,C900000041V,C900000041C,C900000041D,C900000041USD,C900000042,C900000043,C940000407,C900000054,C900000050,C900000051,C900000004,C900000005V,C900000005C,C900000005D,C900000005USD,C900000005INR,C900000006,C900000007,C900000003,C900000012,C900000014,C900000008,C900000009V,C900000009C,C900000009D,C900000009USD,C900000010,C900000267,C900000021,C900000022,C900000019,C900000028,C900000031,C900000024,C900000025,C900000026V,C900000026C,C900000026D,C900000026USD,C900000027,C900000106,C900000112,C900000383,C900000085,C900000080,C900000092,C900000605,C900000093,C900000094,C900000090,C900000991,C900000990,C900000989,C900000103,C900000065,C900000302V,C900000302C,C900000302D,C900000302USD,C900007132,C909000000,C912060903,C5,C3,C6,C1) VALUES(1,'667426',0,'OneC_user','000000000218810','Bangalore','STE000000013127','000000003205128','1','000000003205128','Intel','Travel Purpose','Physical',4000,585.0000000000,'USD',1513756636,585.00,1,1,0,1,60,1,'XXX Standard laptop',0E-10,'USD',1513737537,0.00,0.00,1513756633,1546194600,'PDV000000293045','667426','Laptop',13,585.0000000000,'USD',1513756634,585.00,'XXX Asset','Yes','XXX Standard laptop','REQ000010844303','Hardware','XXX Standard laptop',1,'Onsite Travel','Monthly',45.0000000000,'USD',1513737527,45.00,'Laptop','BLR - MBP - G3 SEZ','AGGAA5V0H0QLIAPBJCD5PA2M00EUCF','India','Laptop','-','18-LAPTOP','Pavan P Patil','PDV000000293045','MBPG3B006A05A003','9 * 6','Laptop','Processing Unit','Hardware','143502;194194;150493;143502;143502','"NO"',0E-10,'USD',0,0.00,0,0,0,'Remedy Application Service',1513762574,1513762574,'000000002655011')
<SQL > <TID: 0000000412> <RPC ID: 0001686949> <Queue: Fast > <Client-RPC: 390620 > <USER: Remedy Application Service > <Overlay-Group: 1 > /* Wed Dec 20 2017 15:06:15.4430 */
<FLTR> <TID: 0000000412> <RPC ID: 0001686949> <Queue: Fast > <Client-RPC: 390620 > <USER: Remedy Application Service > <Overlay-Group: 1 > /* Wed Dec 20 2017 15:06:15.4670 */ **** Error while performing filter action. Error Number: 552
<FLTR> <TID: 0000000412> <RPC ID: 0001686949> <Queue: Fast > <Client-RPC: 390620 > <USER: Remedy Application Service > <Overlay-Group: 1 > /* Wed Dec 20 2017 15:06:15.4670 */ ERROR (552): The SQL database operation failed.; Invalid column name 'C900000005INR'
Here since SetEntry on SRM:Request was failed, Service Request kept in 'Waiting Approval' status only. After some escalations modified same Request record, filter which is responsible on triggering approval process executed successfully and same signature got attached to Service request. Hence Duplicate signatures created in this case.
- Customer had to add Currency column to have it working as expected.
For any SRM-Approval Integration issue, troubleshooting flow should be as follows:
Approval(Approval Debug Logs) =>ITSMUtilPlugin (arjavaplugin DEBUG logs) => SRM (API/SQL/Filter)