AA Multiple Credential configuration

book

Article ID: 210669

calendar_today

Updated On:

Products

CA Advanced Authentication - Strong Authentication (AuthMinder / WebFort)

Issue/Introduction

Advanced Authentication (Multiple Credentials capability) allows two types of token for the same user. This document describes how Global Admin UI can be used to create Issuance Profile and Authentication Policy so that two types of tokens can be supported for the same user.

Cause

Clarification required for associating Issuance Profile(s) to a Authentication profile (s), essentially allowing same user to have more than one Authentication token type ( for example both HOTP and TOTP token).

Environment

Release : 9.1

Component : AuthMinder(Arcot WebFort)

Resolution

Document discusses briefly the creation an additional ArcotOTP (TOTP) credential. The excerpts below deal with TOTP only.   Other authentication tokens such as HOTP can be created using this document and associated with a user.

The AFM logs below show the Configuration, Creation or Provisioning of the multiple credentials with respect to a single user.

The two TOTP profile/policy combinations  that are used in this scenario are as follows:

  • iTOPT1 (Issuance) / aTOPT1 (Authentication)
  • iTOPT2 (Issuance) / aTOTP2 (Authentication)

Issuance Profile is iTOPT1    (

Authentication Policy is aTOPT1

These Profiles and Policies can be created using the Global Admin Console and are as shown in the screen shots below. Note that in the example below the string “TOTP1” in Issuance related “Usage Type” should also be in Authentication  “Usage type for Verification”. Only iTOPT1 and aTOPT1 screens are shown below, similar setting needs to be done for iTOTP2 and aTOTP2.

 

a. arcotafm.log (ArcotOTP  - TOTP)

(Configuration SUCCESS)

 

2013-02-15 20:26:59,531 [localhost-startStop-1] INFO  integrations.frontend.InitializeTokenSvrClientServlet(123)  -> Initializing State Manager API

2013-02-15 20:26:59,547 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(91)  -> Loading property file /arcotafm.properties

2013-02-15 20:26:59,547 [localhost-startStop-1] DEBUG helpers.util.ResourceHelper(267)  -> Loaded resource /arcotafm.properties from local classpath

2013-02-15 20:26:59,547 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(100)  -> Successfully loaded property file /arcotafm.properties

2013-02-15 20:26:59,547 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(299)  -> -------------------------------------------------------------------------------------------

2013-02-15 20:26:59,547 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(300)  ->  VALIDATING : AFM PROPERTIES

2013-02-15 20:26:59,547 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(301)  -> -------------------------------------------------------------------------------------------

2013-02-15 20:26:59,547 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(409)  -> -------------------------------------------------------------------------------------------

2013-02-15 20:26:59,547 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(124)  -> Logging all the properties set for AFM

2013-02-15 20:26:59,547 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(126)  -> -------------------------------------------------------------------------------------------

2013-02-15 20:26:59,547 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(127)  ->  LISTING : AFM PROPERTIES

2013-02-15 20:26:59,547 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(128)  -> -------------------------------------------------------------------------------------------

2013-02-15 20:26:59,563 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(133)  -> AIDExpiryAuthMechanism...................................:QNA,AOTP_MOBILEAPP

2013-02-15 20:26:59,563 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(133)  -> AOTPAuthPolicy...........................................:aTOTP1

2013-02-15 20:26:59,563 [localhost-startStop-1] INFO  helpers.util.ResourceHelper(133)  -> AOTPProfileName..........................................:iTOTP1

 

 

b. arcotafm.log  (ArcotOTP  - TOTP)

Enrollment Flow -(Creation and Provisioning) – SUCCESS)

 

2013-02-15 20:28:32,422 [http-bio-8080-exec-2] INFO  tasks.lifecycle.CreateAOTPTask(25)  -> Instantiated CreateAOTPTask with enableReissueAOTP : true

2013-02-15 20:28:32,672 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> Invoking: com.arcot.integrations.frontend.tasks.lifecycle.LoadUserDetailsTask |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:32,672 [http-bio-8080-exec-2] INFO  api.impl.TxnMarker(30)  -> [http-bio-8080-exec-2] Txn-Begin : OP=USER_FETCH

2013-02-15 20:28:33,438 [http-bio-8080-exec-2] INFO  api.impl.TxnMarker(58)  -> [http-bio-8080-exec-2] Txn-End : STxID=20006 | CTxID=[WFI_UdAu_http-bio-8080-exec-2_1] | OP=USER_FETCH | RC=0 | REC=0 | TOT=766 | SRT=-1 | TGC=15 | TRC=0 | TWR=0 | TRD=375 | TCR=15 | RTC=0 | NCA=0 | NCB=1

2013-02-15 20:28:33,438 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> Invoking: com.arcot.integrations.frontend.tasks.DecideMigrationTask |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:33,438 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> DecideMigrationTask: Policy: migrate_if_aotp_does_not_exist, pamStartValue (if applicable): 'null' |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:33,438 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> Deciding migration status of (user,org)=(temp9,null) |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:33,438 [http-bio-8080-exec-2] INFO  api.impl.TxnMarker(30)  -> [http-bio-8080-exec-2] Txn-Begin : OP=CRED_FETCH

2013-02-15 20:28:33,860 [http-bio-8080-exec-2] INFO  api.impl.TxnMarker(58)  -> [http-bio-8080-exec-2] Txn-End : STxID=20007 | CTxID=[WFI_UdAu_http-bio-8080-exec-2_2] | OP=CRED_FETCH | RC=5800 | REC=0 | TOT=422 | SRT=-1 | TGC=0 | TRC=0 | TWR=0 | TRD=344 | TCR=-1 | RTC=0 | NCA=-1 | NCB=-1

2013-02-15 20:28:33,860 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> DecideMigration = YES because ArcotOTP not found: The credential was not found for the user ( TEMP9 ). |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:33,860 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> Invoking: com.arcot.integrations.frontend.tasks.RcvOTPTask |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:33,860 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> Validating OTP for (user,org)=(temp9,null) |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:33,860 [http-bio-8080-exec-2] INFO  api.impl.TxnMarker(30)  -> [http-bio-8080-exec-2] Txn-Begin : OP=OTP_VERIFY

2013-02-15 20:28:33,954 [http-bio-8080-exec-2] INFO  api.impl.TxnMarker(58)  -> [http-bio-8080-exec-2] Txn-End : STxID=20008 | CTxID=[WFA_UdAu_http-bio-8080-exec-2_1] | OP=OTP_VERIFY | RC=0 | REC=0 | TOT=94 | SRT=-1 | TGC=0 | TRC=0 | TWR=0 | TRD=78 | TCR=-1 | RTC=0 | NCA=-1 | NCB=-1

2013-02-15 20:28:33,954 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> WebFort transactionID for verifyOTP is 20008 |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:33,954 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> verifyOTP success |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:33,954 [http-bio-8080-exec-2] WARN  integrations.frontend.LifeCycleStateData(482)  -> 707051664: Flow is not part of the supported out of box flows: Current flow: 'aotpEnrollment'. Supported flows: aidAuth, aotpAuth, enrollment, aotpEnrollment, preEnrollAuth, updateUserProfile, updateQnA, resetAID, resetAOTP, secAuth, fypAuth, roamingAuth, aidExpiryAuth, aotpExpiryAuth, enrollOTT |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:33,954 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> Invoking: com.arcot.integrations.frontend.tasks.lifecycle.CreateAOTPTask |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:33,954 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> Creating ArcotOTP for user (user,org)=(temp9,null) |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:33,954 [http-bio-8080-exec-2] INFO  api.impl.TxnMarker(30)  -> [http-bio-8080-exec-2] Txn-Begin : OP=CRED_CREATE

2013-02-15 20:28:34,047 [http-bio-8080-exec-2] INFO  api.impl.TxnMarker(58)  -> [http-bio-8080-exec-2] Txn-End : STxID=20009 | CTxID=[WFI_UdAu_http-bio-8080-exec-2_3] | OP=CRED_CREATE | RC=5801 | REC=0 | TOT=93 | SRT=-1 | TGC=0 | TRC=0 | TWR=0 | TRD=78 | TCR=-1 | RTC=0 | NCA=-1 | NCB=-1

2013-02-15 20:28:34,047 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> ArcotOTP creation failed : ArcotOTP-OATH credential is already present for the user ( TEMP9 ).. Will try to reset/reissue ArcotOTP |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:34,047 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> Flow type is : aotpEnrollment |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:34,047 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> Operation to be performed is : Reset |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:34,047 [http-bio-8080-exec-2] INFO  api.impl.TxnMarker(30)  -> [http-bio-8080-exec-2] Txn-Begin : OP=CRED_RESET

2013-02-15 20:28:34,375 [http-bio-8080-exec-2] INFO  api.impl.TxnMarker(58)  -> [http-bio-8080-exec-2] Txn-End : STxID=20010 | CTxID=[WFI_UdAu_http-bio-8080-exec-2_4] | OP=CRED_RESET | RC=0 | REC=0 | TOT=328 | SRT=-1 | TGC=0 | TRC=0 | TWR=0 | TRD=313 | TCR=-1 | RTC=0 | NCA=-1 | NCB=-1

2013-02-15 20:28:34,532 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> AOTP repsonse::DIGS=06::ORG_=DEFAULTORG::TSTP=30::TVAR=0::TYPE=TOTP::UDK_=338B73D15800E3B367C3D20A2142900BD2D67C16::UIDS=0001::UID_=TEMP9::USER=TEMP9::VER_=0.0.0:: |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:34,532 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> Creation/Reset of ArcotOTP credential for user (user,org)=(temp9,null) is successful. |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:34,532 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> Flow: ArcotOTP Provisioning,CDS,CIUE=OK=OK,RO=OK,RAP=OK,EXIT,DPG= |0286870c72f813c2c62a7f8e4a2b31de39731b7a

2013-02-15 20:28:34,532 [http-bio-8080-exec-2] DEBUG integrations.frontend.LifeCycleStateData(466)  -> jsonpCallback({"XML": "<response><status>success</status><reqid>1234567</reqid><aid>temp9</aid><displayName>temp9</displayName><logoUrl>http://otp.arcot.com/otp/is?type=hotp&amp;brand=otp</logoUrl><algo><algoType>TOTP</algoType><cs>::DIGS=06::ORG_=DEFAULTORG::TSTP=30::TVAR=0::TYPE=TOTP::UDK_=338B73D15800E3B367C3D20A2142900BD2D67C16::UIDS=0001::UID_=TEMP9::USER=TEMP9::VER_=0.0.0::</cs></algo></response>"}); |0286870c72f813c2c62a7f8e4a2b31de39731b7a

c. arcotafmlog (ArcotOTP Authentication) TOPT

 Authentication Flow - (Auth Policy showing as – aTOPT1 and key usage type TOPT1 – Auth Success for user TEMP9  around  20:22:31.543)

02/15/13 20:22:31.543 DEBUG TXN_NATIVE   00005804 00019672 -                     Organization : [DEFAULTORG]

02/15/13 20:22:31.543 DEBUG TXN_NATIVE   00005804 00019672 - ---------------------------------------------------------------

02/15/13 20:22:31.543 DEBUG TXN_NATIVE   00005804 00019672 - [UDS] ArDBPoolManagerImpl::getLockedDBConnection: [primary] DSN [arcotdsn] is active. Will get the connection from this

02/15/13 20:22:31.559 DEBUG TXN_NATIVE   00005804 00019672 - [UDS] ArDBPoolManagerImpl::getLockedDBConnection: Returning DBPool [00C9DE80]

02/15/13 20:22:31.559 DEBUG TXN_NATIVE   00005804 00019672 - [UDS] ArDBM::Number of queries being executed [1]

02/15/13 20:22:31.559 DEBUG TXN_NATIVE   00005804 00019672 - [UDS] ArDBM::Executing Query[ArUDSUserMgmtQuery_retrieveUser_dynamic]

02/15/13 20:22:31.559 DEBUG TXN_NATIVE   00005804 00019672 - [UDS] Number of rows fetched : 1

02/15/13 20:22:31.559 DEBUG TXN_NATIVE   00005804 00019672 - [UDS] Releasing in primary, ctxtIndex=3

02/15/13 20:22:31.559 INFO  TXN_NATIVE   00005804 00019672 - [UDS] UDS Log : Successfully retrieved the user [TEMP9] for organization [DEFAULTORG]

…………………………………………………

 

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - ---------------------------------------------------------------

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - ---------------------------------------------------------------

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - ArcotOTPAuthVerifyTxnData (Request)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                        Operation : 1070 (AUTH_ARCOT_OTP_VERIFY)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                           Locale : [en_US]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -            AdditionalInputs-List { (size : 1)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                             Name : [AR_WF_AUTH_POLICY]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                         ValueStr : [aTOTP1]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                                  }

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -           AdditionalOutputs-List { (size : 0) }

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -           AuditInfoInternal-List { (size : 0) }

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -           AuditInfoExternal-List { (size : 0) }

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                        UseAdProc : 0 (OFF)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                         CredType : 8 (ARCOT_OTP)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                           CredID : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                    FetchUserInfo : 0 (NO)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                 FetchAccountInfo : 0 (NO)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                        UsageType : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                       CredStatus : -1 (UNKNOWN)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                      StrikeCount : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -          LastSuccesfulStrikeDate : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -             LastFailedStrikeDate : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                ValidityStartDate : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                  ValidityEndDate : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                 DisableStartDate : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                   DisableEndDate : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                OwnerOrganization : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                LesseOrganization : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                  ConfigurationID : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                ConfigurationName : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -              ConfigurationStatus : 1 (Bitmap)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -             ConfigurationVersion : -1

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                       ConfigType : -1 (Undefined)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                RecordCreatedDate : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -           RecordLastModifiedDate : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                             DMDV : 70

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                       UsageCount : 0

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                  UsageCountLimit : -1 (Unlimited)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                    AuthTokenType : 7 (NONE)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                     AuthTokenStr : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                     AuthComplete : 0 (NO)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                 SessionTrackerID : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -            RemainingValidityDays : 0 (Days)

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                SupplementHandler : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                   AuthPolicyName : [aTOTP1]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - ---------------------------------------------------------------

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - ---------------------------------------------------------------

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - UserCoords

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                           UserID :  <S>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                      AccountType : <NA>

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 -                     Organization : [DEFAULTORG]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - ---------------------------------------------------------------

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBPoolManagerImpl::getLockedDBConnection: [primary] DSN [arcotdsn] is active. Will get the connection from this

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBPoolManagerImpl::getLockedDBConnection: Returning DBPool [00E5DE80]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBM::Number of queries being executed [1]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBM::Executing Query[ArUDSUserMgmtQuery_retrieveUser_dynamic]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] Number of rows fetched : 1

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] Releasing in primary, ctxtIndex=2

02/15/13 20:29:49.565 INFO  TXN_NATIVE   00002268 00020011 - [UDS] UDS Log : Successfully retrieved the user [TEMP9] for organization [DEFAULTORG]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBPoolManagerImpl::getLockedDBConnection: [primary] DSN [arcotdsn] is active. Will get the connection from this

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBPoolManagerImpl::getLockedDBConnection: Returning DBPool [00E5DE80]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] DBTransactionProtector::starting transaction on connection [01430AA0]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBM::Number of queries being executed [1]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBM::Executing Query[UDSUserAuditNextSeqID]

02/15/13 20:29:49.565 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] DBTransactionProtector::commiting transaction on connection [01430AA0]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] Releasing in primary, ctxtIndex=3

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBPoolManagerImpl::getLockedDBConnection: [primary] DSN [arcotdsn] is active. Will get the connection from this

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBPoolManagerImpl::getLockedDBConnection: Returning DBPool [00E5DE80]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] DBTransactionProtector::starting transaction on connection [000C1788]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBM::Number of queries being executed [1]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] ArDBM::Executing Query[UserAuditRecordInsertQuery]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] DBTransactionProtector::commiting transaction on connection [000C1788]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - [UDS] Releasing in primary, ctxtIndex=0

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - ---------------------------------------------------------------

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - UserContext

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                        UserRefID : 36

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                           UserID :  <S>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                     Organization : [DEFAULTORG]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                       UserStatus : 1 (ACTIVE)

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -               GranularUserStatus : <NA>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                              PAM :  <S>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                        FirstName :  <S>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                         LastName :  <S>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                       MiddleName :  <S>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                            Email :  <S>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                  TelephoneNumber :  <S>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                  UserCreatedDate : <NA>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                 UserModifiedDate : <NA>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -        UserCustomAttributes-List { (size : 0) }

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                      AccountType : <NA>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                       UserStatus : <NA>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -               GranularUserStatus : <NA>

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -        UserContext.accounts-List { (size : 0) }

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - ---------------------------------------------------------------

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - Detecting registered handlers(if any) for pre-txn events

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - Detecting registered handlers(if any) for proc-txn events

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - Detecting registered handlers(if any) for post-txn events

02/15/13 20:29:49.580 INFO  TXN_NATIVE   00002268 00020011 - Transaction processing(internal-pre) is about to start.

02/15/13 20:29:49.580 INFO  TXN_NATIVE   00002268 00020011 - Transaction processing(internal-pre) is complete.

02/15/13 20:29:49.580 INFO  TXN_NATIVE   00002268 00020011 - Transaction processing(proc) is about to start.

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -                ConfigurationName : [aTOTP1]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - Using UsageType : [TOTP1]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - ArDBPoolManagerImpl::getLockedDBConnection: [primary] DSN [arcotdsn] is active. Will get the connection from this

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - ArDBPoolManagerImpl::getLockedDBConnection: Returning DBPool [00E5DE80]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - ArDBM::Number of queries being executed [1]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - ArDBM::Found query string for query-id : [ARWFARCOTOTP_SELECT_BY_USER].

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - ArDBM::Executing Query[ArcotOTPQuery_FetchRowByUser]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - Number of rows fetched : 1

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - Releasing in primary, ctxtIndex=1

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - Attempting to use the DK ( Config Name : [DefaultKeySym] ) corresponding to the current ArcotOTP

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - ---------------------------------------------------------------

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - OTPCounterTolerance

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -          OTPCounterAuthLookAhead : 10

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -           OTPCounterAuthLookBack : 0

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -        OTPCounterReSyncLookAhead : 100

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 -         OTPCounterReSyncLookBack : 0

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - ---------------------------------------------------------------

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - HandleTOTP:: CurrentTime (epoch) : 1360978189, LastKnownDrift : 0, Step : 30, LastVerifiedCounter = 0

02/15/13 20:29:49.580 INFO  TXN_NATIVE   00002268 00020011 - HandleTOTP::ReferenceCounter : 45365939, Auth Window: [45365939, 45365949], Sync Window : [45365939, 45366039]

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - FindMatch:: Trying a match between StartingCounter : 45365939, EndCounter : 45366039

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - Match(1) found at Counter : 45365939

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - HandleTOTP : Found a match at counter : 45365939

02/15/13 20:29:49.580 DEBUG TXN_NATIVE   00002268 00020011 - HandleTOTP : FinalCounter = 45365939, FinalDrift : 19 Sec

02/15/13 20:29:49.580 INFO  TXN_NATIVE   00002268 00020011 - VerifyOTP Result : SUCCESS

 

d.  arcotafmlog (ArcotOTP Authentication) TOPT

(Auth Policy showing as – aTOPT2 and key usage type TOPT2 – Auth Success for user TEMP9  around  20:35:14.508)

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - [UDS] Releasing in primary, ctxtIndex=3

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - ---------------------------------------------------------------

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - UserContext

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                        UserRefID : 36

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                           UserID :  <S>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                     Organization : [DEFAULTORG]

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                       UserStatus : 1 (ACTIVE)

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -               GranularUserStatus : <NA>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                              PAM :  <S>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                        FirstName :  <S>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                         LastName :  <S>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                       MiddleName :  <S>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                            Email :  <S>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                  TelephoneNumber :  <S>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                  UserCreatedDate : <NA>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                 UserModifiedDate : <NA>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -        UserCustomAttributes-List { (size : 0) }

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                      AccountType : <NA>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                       UserStatus : <NA>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -               GranularUserStatus : <NA>

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -        UserContext.accounts-List { (size : 0) }

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - ---------------------------------------------------------------

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - Detecting registered handlers(if any) for pre-txn events

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - Detecting registered handlers(if any) for proc-txn events

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - Detecting registered handlers(if any) for post-txn events

02/15/13 20:35:14.539 INFO  TXN_NATIVE   00002268 00020019 - Transaction processing(internal-pre) is about to start.

02/15/13 20:35:14.539 INFO  TXN_NATIVE   00002268 00020019 - Transaction processing(internal-pre) is complete.

02/15/13 20:35:14.539 INFO  TXN_NATIVE   00002268 00020019 - Transaction processing(proc) is about to start.

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -                ConfigurationName : [aTOTP2]

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - Using UsageType : [TOTP2]

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - ArDBPoolManagerImpl::getLockedDBConnection: [primary] DSN [arcotdsn] is active. Will get the connection from this

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - ArDBPoolManagerImpl::getLockedDBConnection: Returning DBPool [00E5DE80]

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - ArDBM::Number of queries being executed [1]

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - ArDBM::Found query string for query-id : [ARWFARCOTOTP_SELECT_BY_USER].

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - ArDBM::Executing Query[ArcotOTPQuery_FetchRowByUser]

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - Number of rows fetched : 1

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - Releasing in primary, ctxtIndex=0

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - Attempting to use the DK ( Config Name : [DefaultKeySym] ) corresponding to the current ArcotOTP

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - ---------------------------------------------------------------

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - OTPCounterTolerance

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -          OTPCounterAuthLookAhead : 10

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -           OTPCounterAuthLookBack : 0

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -        OTPCounterReSyncLookAhead : 100

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 -         OTPCounterReSyncLookBack : 0

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - ---------------------------------------------------------------

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - HandleTOTP:: CurrentTime (epoch) : 1360978514, LastKnownDrift : 0, Step : 30, LastVerifiedCounter = 0

02/15/13 20:35:14.539 INFO  TXN_NATIVE   00002268 00020019 - HandleTOTP::ReferenceCounter : 45365950, Auth Window: [45365950, 45365960], Sync Window : [45365950, 45366050]

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - FindMatch:: Trying a match between StartingCounter : 45365950, EndCounter : 45366050

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - Match(1) found at Counter : 45365950

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - HandleTOTP : Found a match at counter : 45365950

02/15/13 20:35:14.539 DEBUG TXN_NATIVE   00002268 00020019 - HandleTOTP : FinalCounter = 45365950, FinalDrift : 14 Sec

02/15/13 20:35:14.539 INFO  TXN_NATIVE   00002268 00020019 - VerifyOTP Result : SUCCESS

 

 

 

 

Additional Information

None.

Attachments