Protected Resource Authentication Trace

When a protected resource is configured to require authentication, both Identity Server and Embedded Service Provider of Access Gateway generate log entries for the process. The following sections explain how to correlate the entries from the logs:

Entries from an Identity Server Log

<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>

Entries from an Access Gateway Log

<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>

Correlating the Log Entries between Identity Server and Access Gateway

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.