Reading the Provisioning Server's etatrans log

Products

• CA Identity Manager
• CA Identity Governance
• CA Identity Portal

Issue/Introduction

How to read the Provisioning Server's etatrans log?

Environment

Release:
Component: IDSVA

Resolution

For troubleshoooting of problems it is recommended to have the Provisioning Server's Transaction Log set to Level of 7. This is configured within the Provisioning Manager under the System\Domain Configuration settings and is written to the etatrans log file on the Provisioning Server. Detailed Instruction is here.

When reviewing the etatrans log the first column represents the date and the second column represents the time. The third colum is the thread ID (i.e. TID) but keep in mind that a thread may spawn child threads so the TID value may change while tracing an operation if the operation spawned additional threads. 

In the below example we can see that the Provisioning Server has received a request to modify the Provisioning User called testuser to set the eTTitle to the value of New_Title and to propagate this value to accounts since eTSyncAccounts=1 is in the same modify request. Also note that since the value for eTUseOperationID does not start with the prefix of "IM-" that this request did not originate from the IM Server.

20190402:111426:TID=000b38:Modify    :E462:----:S: External Modify (eTGlobalUserName=testuser) Requested by User imadmin - TenantNot
20190402:111426:TID=000b38:Modify    :E462:----:S:+Set
20190402:111426:TID=000b38:Modify    :E462:----:P:     dn: eTGlobalUserName=a1,eTGlobalUserContainerName=Global Users,eTNamespaceNam
20190402:111426:TID=000b38:Modify    :E462:----:P:+    e=CommonObjects,dc=im
20190402:111426:TID=000b38:Modify    :E462:----:P:     eTTitle:  New_Title [REPLACE]
20190402:111426:TID=000b38:Modify    :E462:----:P:     eTSyncAccounts:  1 [REPLACE]
20190402:111426:TID=000b38:Modify    :E462:----:P:     eTUseOperationID:  94de11d0-257d-4c0d-9d7c-8abbaab42a1e [REPLACE]
20190402:111426:TID=000b38:Modify    :E462:----:P:     eTUpdateNode:  IMPS_HOST [REPLACE]
20190402:111426:TID=000b38:Modify    :E462:----:P:     modifiersName:  ETGLOBALUSERNAME=IMADMIN,ETGLOBALUSERCONTAINERNAME=GLOBAL USE
20190402:111426:TID=000b38:Modify    :E462:----:P:+    RS,ETNAMESPACENAME=COMMONOBJECTS,DC=IM,DC=ETA [REPLACE]
20190402:111426:TID=000b38:Modify    :E462:----:P:     modifyTimestamp:  20190402181426Z [REPLACE]

During the course of an External request the Provisioning Server may send requests to the Provisioning Repository. Such requests will be "DB" requests. As we can see the Provisioning Server has sent a modify request to update the eTTitle value for the Provisioning User object stored within the Provisioning Repository and the TID value is still the same. 

20190402:111426:TID=000b38:Modify    :D466:E462:S: DB Modify (eTGlobalUserName=testuser) Requested by User imadmin - TenantNotSet
20190402:111426:TID=000b38:Modify    :D466:E462:P:     URL: ldaps://IMPS_HOST:20391
20190402:111426:TID=000b38:Modify    :D466:E462:P:     dn: eTGlobalUserName=testuser,eTGlobalUserContainerName=Global Users,eTNamesp
20190402:111426:TID=000b38:Modify    :D466:E462:P:+    aceName=CommonObjects,dc=im
20190402:111426:TID=000b38:Modify    :D466:E462:P:     eTTitle:  New_Title [REPLACE]
20190402:111426:TID=000b38:Modify    :D466:E462:P:     eTUpdateNode:  IMPS_HOST [REPLACE]
20190402:111426:TID=000b38:Modify    :D466:E462:P:     eTUpdateUserid:  imadmin [REPLACE]
20190402:111426:TID=000b38:Modify    :D466:E462:P:     eTUpdateUserName:  im admin [REPLACE]
20190402:111426:TID=000b38:Modify    :D466:E462:P:     eTUpdateDate:  0000119092 [REPLACE]
20190402:111426:TID=000b38:Modify    :D466:E462:P:     eTUpdateTime:  0004046600 [REPLACE]
20190402:111426:TID=000b38:Modify    :D466:E462:F: SUCCESS: DB Modify (eTGlobalUserName=testuser)

During the course of an External request the Provisioning Server may send requests to the Connector Server. Such requests will be "Connector Server" requests. As we can see the Provisioning Server has sent a modify request to update the eTADSTitle value for the ADS Account object which is handled by the Connector Server and the TID value is still the same.

20190402:111601:TID=000b38:Modify    :S494:C492:S: Connector Server Modify (eTADSAccountName=testuser) Requested by User imadmin - T
20190402:111601:TID=000b38:Modify    :S494:C492:S:+enantNotSet
20190402:111601:TID=000b38:Modify    :S494:C492:P:     URL: ldaps://CS_HOST:20411
20190402:111601:TID=000b38:Modify    :S494:C492:P:     dn: eTADSAccountName=testuser,eTADSOrgUnitName=test_ou,eTADSDirectoryName=tes
20190402:111601:TID=000b38:Modify    :S494:C492:P:+    t_endpoint,eTNamespaceName=ActiveDirectory,dc=im
20190402:111601:TID=000b38:Modify    :S494:C492:P:     eTADStitle:  New_Title [REPLACE]
20190402:111603:TID=000b38:Modify    :S494:C492:F: SUCCESS: Connector Server Modify (eTADSAccountName=testuser)

Here we can see that the original External Modify request has now completed with a SUCCESS and the result was that the Provisioning user was updated along with one associated account.

20190402:111603:TID=000b38:Modify    :E462:----:F: SUCCESS: External Modify (eTGlobalUserName=testuser)
20190402:111603:TID=000b38:Modify    :E462:----:F:     msg: :ETA_S_0028<MGU>, Global User 'testuser' and associated accounts updated
20190402:111603:TID=000b38:Modify    :E462:----:F:+ successfully: (accounts updated: 1, unchanged: 0, failures: 0)