AA Multiple Credential configuration
Article ID: 210669
Updated On:
Products
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&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
Feedback
