An authentication trace is logged to the catalina.out file of Identity Server that authenticates the user. If Access Gateway initiates the authentication because of a user request to a protected resource, the Embedded Service Provider log file of Access Gateway also contains entries for the authentication sequence. Identity Server logging must be enabled to produce authentication traces (see Section 22.3.1, Configuring Logging for Identity Server).
This section describes the following types of authentication traces:
The following trace is an example of a user logging directly into Identity Server to access the end user portal. The log entries are numbered, so that they can be described.
1. <amLogEntry> 2009-06-14T17:14:30Z INFO NIDS Application: AM#500105015: AMDEVICEID#9921459858EAAC29: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Processing login request with TARGET = http://10.10.15.19:8080/nidp/app, saved TARGET = . </amLogEntry> 2. <amLogEntry> 2009-06-14T17:14:30Z INFO NIDS Application: AM#500105009: AMDEVICEID#9921459858EAAC29: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Executing contract Name/Password - Form. </amLogEntry> 3. <amLogEntry> 2009-06-14T17:14:30Z INFO NIDS Application: AM#500105010: AMDEVICEID#9921459858EAAC29: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Contract Name/Password - Form requires additional interaction. </amLogEntry> 4. <amLogEntry> 2009-06-14T17:14:39Z INFO NIDS Application: AM#500105015: AMDEVICEID#9921459858EAAC29: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Processing login request with TARGET = http://10.10.15.19:8080/nidp/app, saved TARGET = http://10.10.15.19:8080/nidp/app. </amLogEntry> 5. <amLogEntry> 2009-06-14T17:14:39Z INFO NIDS Application: AM#500105009: AMDEVICEID#9921459858EAAC29: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Executing contract Name/Password - Form. </amLogEntry> 6. <amLogEntry> 2009-06-14T17:14:39Z INFO NIDS Application: AM#500105014: AMDEVICEID#9921459858EAAC29: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Attempting to authenticate user cn=bcf,o=novell with provided credentials. </amLogEntry> 7. <amLogEntry> 2009-06-14T17:14:39Z WARNING NIDS Application: Event Id: 3014666, Target: cn=bcf,o=novell, Sub-Target: F35A3C7AD7F2EEDEB3D17F99EC3F39D1, Note 1: Local, Note 2: This Identity Provider, Note 3: name/password/uri, Numeric 1: 0 </amLogEntry> 8. <amLogEntry> 2009-06-14T17:14:39Z WARNING NIDS Application: Event Id: 3015456, Note 1: F35A3C7AD7F2EEDEB3D17F99EC3F39D1, Note 2: Manager, Note 3: Document=(ou=xpemlPEP,ou=mastercdn,ou=Content PublisherContainer,ou=Partition,ou=PartitionsContainer,ou=VCDN_Root,ou=accessManagerContainer,o=novell:romaContentCollectionXMLDoc),Policy=(Manager),Rule=(1::RuleID_1181251958207),Action=(AddRole::ActionID_1181252224665), Numeric 1: 0 </amLogEntry> 9. <amLogEntry> 2009-06-14T17:14:39Z WARNING NIDS Application: Event Id: 3015456, Note 1: F35A3C7AD7F2EEDEB3D17F99EC3F39D1, Note 2: authenticated, Note 3: system-generated-action, Numeric 1: 0 </amLogEntry> 10. <amLogEntry> 2009-06-14T17:14:39Z INFO NIDS Application: AM#500199050: AMDEVICEID#9921459858EAAC29: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: IDP RolesPep.evaluate(), policy trace: ~~RL~1~~~~Rule Count: 1~~Success(67) ~~RU~RuleID_1181251958207~Manager~DNF~~1:1~~Success(67) ~~CS~1~~ANDs~~1~~True(69) ~~CO~1~LdapGroup(6645):no-param:hidden-value:~ldap-group-is-member-of~SelectedLdapGroup(66455):hidden-param:hidden-value:~~~True(69) ~~PA~ActionID_1181252224665~~AddRole~Manager~~~Success(0) ~~PC~ActionID_1181252224665~~Document=(ou=xpemlPEP,ou=mastercdn, ou=ContentPublisherContainer,ou=Partition,ou=PartitionsContainer,ou=VCDN_Root,ou=accessManagerContainer,o=novell:romaContentCollectionXMLDoc),Policy=(Manager),Rule=(1::RuleID_1181251958207),Action=(AddRole::ActionID_1181252224665)~AdditionalRole(6601):unknown():Manager:~~~Success(0) </amLogEntry> 11. <amLogEntry> 2009-06-14T17:14:39Z INFO NIDS Application: AM#500105013: AMDEVICEID#9921459858EAAC29: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Authenticated user cn=bcf,o=novell in User Store Local Directory with roles Manager,authenticated. </amLogEntry> 12. <amLogEntry> 2009-06-14T17:14:39Z INFO NIDS Application: AM#500105017: AMDEVICEID#9921459858EAAC29: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: nLogin succeeded, redirecting to http://10.10.15.19:8080/nidp/app. </amLogEntry>
Table 31-3 Log Entry Descriptions for an Authentication Trace from an Identity Server
|
Entry |
Description |
|---|---|
|
1 |
Indicates that a login request is in process. This is the first entry for a login request. The requester, even though login has not been successful, is assigned an authentication ID. You can use this ID to find the log entries related to this user. The entry also specifies the URL of the requested resource, in this case the /nidp/app resource called the End User Portal. The saved TARGET message does not contain a value, so this step will be repeated. |
|
2 |
Specifies the contract that is being used to perform the login. |
|
3 |
Indicates that the contract requires interaction with the user. |
|
4 |
Indicates that the a login request is in process. The saved TARGET message contains a value, so the required information has been gathered to start the authentication request. The AM# correlation tag is AM#500105015, which is the same value as the first log entry. |
|
5 |
Indicates that an exchange is occurring between the client and Identity Server to obtain the required credentials. Each contract requires a different exchange. The AM# correlation tag is AM#500105009, which is the same value as the second log entry. |
|
6 |
Provides the DN of the user attempting to log in and indicates that the user’s credentials are being sent to the LDAP server for verification. |
|
7 |
Provides information about an auditing event. If you have not enabled auditing or you have not selected the login events, this entry does not appear in your log file. This event contains information about who is logging in and the contract that is being used. |
|
8 |
Provides information about an auditing event. If you have not enabled auditing or you have not selected the login events, this entry does not appear in your log file. This event contains information about the Manager policy that is evaluated during login. |
|
9 |
Provides information about an auditing event. If you have not enabled auditing or you have not selected the login events, this entry does not appear in your log file. |
|
10 |
Contains the entry for processing a Role policy. When a user logs in, all Role policies are evaluated and the user is assigned any roles that the user has the qualifications for. For more information, see Section 31.15.2, Understanding Policy Evaluation Traces. |
|
11 |
Contains a summary of who logged in from which user store and the names of the Role policies that successfully assigned roles to the user. |
|
12 |
Contains the final results of the login, with the URL that the request is redirected to. |
When a protected resource is configured to require authentication, both Identity Server and the Embedded Service Provider of Access Gateway generate log entries for the process. The following sections explain how to correlate the entries from the logs.
<amLogEntry> 2009-07-31T17:36:39Z INFO NIDS Application: AM#500105016: AMDEVICEID#AA257DA77ED48DB0: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Processing login resulting from Service Provider authentication request. </amLogEntry> <amLogEntry> 2009-07-31T17:36:39Z INFO NIDS Application: AM#500105009: AMDEVICEID#AA257DA77ED48DB0: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Executing contract Name/Password - Form. </amLogEntry> <amLogEntry> 2009-07-31T17:36:39Z INFO NIDS Application: AM#500105010: AMDEVICEID#AA257DA77ED48DB0: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Contract Name/Password - Form requires additional interaction. </amLogEntry> <amLogEntry> 2009-07-31T17:36:49Z INFO NIDS Application: AM#500105016: AMDEVICEID#AA257DA77ED48DB0: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Processing login resulting from Service Provider authentication request. </amLogEntry> <amLogEntry> 2009-07-31T17:36:49Z INFO NIDS Application: AM#500105009: AMDEVICEID#AA257DA77ED48DB0: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Executing contract Name/Password - Form. </amLogEntry> <amLogEntry> 2009-07-31T17:36:49Z INFO NIDS Application: AM#500105014: AMDEVICEID#AA257DA77ED48DB0: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Attempting to authenticate user cn=admin,o=novell with provided credentials. </amLogEntry>
<amLogEntry> 2009-07-31T17:36:49Z INFO NIDS Application: AM#500105012: AMDEVICEID#AA257DA77ED48DB0: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Authenticated user cn=admin,o=novell in User Store Internal with no roles. </amLogEntry>
<amLogEntry> 2009-07-31T17:36:49Z INFO NIDS Application: AM#500105018: AMDEVICEID#AA257DA77ED48DB0: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Responding to AuthnRequest with artifact AAMoz+rm2jQjDSHjea8U9zm3Td/U2ax0YZCo/qBNool8WkZiTCt7N7Jx </amLogEntry>
<amLogEntry> 2009-07-31T17:36:49Z INFO NIDS Application: AM#500105019: AMDEVICEID#AA257DA77ED48DB0: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Sending AuthnResponse in response to artifact AAMoz+rm2jQjDSHjea8U9zm3Td/U2ax0YZCo/qBNool8WkZiTCt7N7Jx </amLogEntry>
<amLogEntry> 2009-07-31T17:35:05Z INFO NIDS Application: AM#500105005: AMDEVICEID#esp-2FA73CE1A376FD91: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Processing proxy request for login using contract name/password/uri and return url http://jwilson.provo.novell.com/ </amLogEntry> <amLogEntry> 2009-07-31T17:35:05Z INFO NIDS Application: AM#500105015: AMDEVICEID#esp-2FA73CE1A376FD91: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Processing login request with TARGET = http://jwilson.provo.novell.com/, saved TARGET = . </amLogEntry> <amLogEntry> 2009-07-31T17:35:05Z INFO NIDS Application: AM#500105009: AMDEVICEID#esp-2FA73CE1A376FD91: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Executing contract IDP Select. </amLogEntry> <amLogEntry> 2009-07-31T17:35:05Z INFO NIDS Application: AM#500105010: AMDEVICEID#esp-2FA73CE1A376FD91: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Contract IDP Select requires additional interaction. </amLogEntry> <amLogEntry> 2009-07-31T17:35:15Z INFO NIDS Application: AM#500105020: AMDEVICEID#esp-2FA73CE1A376FD91: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Received and processing artifact from IDP - AAMoz+rm2jQjDSHjea8U9zm3Td/U2ax0YZCo/qBNool8WkZiTCt7N7Jx </amLogEntry> <amLogEntry> 2009-07-31T17:35:15Z INFO NIDS Application: AM#500105021: AMDEVICEID#esp-2FA73CE1A376FD91: AMAUTHID#YfdEmqCT2ZutwybD1eYSpfph8g5a5aMl6MGryq1hIqc=: Sending artifact AAMoz+rm2jQjDSHjea8U9zm3Td/U2ax0YZCo/qBNool8WkZiTCt7N7Jx to URL http://jwilson1.provo.novell.com:8080/nidp/idff/soap at IDP </amLogEntry>
You can see that these two trace sequences are for the same authentication request because the artifact (AAMoz+rm2jQjDSHjea8U9zm3Td/U2ax0YZCo/qBNool8WkZiTCt7N7Jx) that is exchanged is the same. You can use the AMAUTHID in each file to search for other requests that this user has made.
To associate a distinguished name with the AMAUTHID, use the catalina.out file of Identity Server. Event AM#500105014 contains the DN of the user.