A recent request on the mailing list caught my attention as I’ve been working on this just recently. In OpenAM, every log entry has a ContextID but which context is this really? Unfortunately, the answer is not too simple, and tracing activity over the course of a federated authentication, for example, is not trivial.
I’ll take a typical scenario where OpenAM is an IDP in a SAML2 federation, with focus on the following log events:
- SP sends AuthnRequest to OpenAM IDP
- Module based authentication using LDAP module
- Login success log message
- (Post processing log message)
- ArtifactResolve and Response
- Single logout
As stated above, each log entry has a ContextID which is the OpenAM session ID of the user who performs the log operation. Easy, right? Well, no. Taking the first event here, an SP who sends an AuthnRequest to the IDP (OpenAM), then the incoming AuthnRequest is logged to the SAML2 log but since we don’t have a user in the picture (no response has been sent to the user yet) then this is logged by an administrative user. This means that for #1, the ContextID is actually a session ID that may also be shared by other log operations for different users. The AuthnRequest xml contains a MessageID which can be used later for tracing purposes.
The next message in this scenario, where the user authenticates using the LDAP module, could be success or failure – in any case, the user at this point is in dialog with OpenAM and has received an AMAuth cookie which represents their session. So for #2 the ContextID is the session ID of the user whilst they are authenticating. As we will see, the session is replaced with an authenticated session shortly afterwards.
By the time the user has met the authentication requirements in the module or chain/service, then a big change happens: in the LoginState class the temporary session used whilst authenticating is destroyed and a new authenticated session created containing user attributes. the iPlanetDirectoryPro cookie is set with the session ID of this new session and the AMAuth cookie is removed. After this point (#3 and #4) all the user operations are logged with a ContextID that is the session ID of their authenticated session.
One exception to this is in a SAML2 Artifact profile, where the SP has received a token and calls a web service to resolve it, the ArtifactResolve message. This request is direct from SP to IDP and not via the user’s browser, so OpenAM has no immediate access to the user’s session cookie. The receipt of the ArtifactResolve message is therefore logged as an administrative user, similar to #1 but not necessarily the same, and not unique to the user involved. So the ContextID in #5 is fairly meaningless. However, the SAML2 messages are traceable through the MessageID and InResponseTo attributes. Also, in the ArtifactResponse message (the SAML Assertion), there is a session ID which is separate from the OpenAM session ID, and that can be traced to #6 Single logout.
–
The above behaviour is partly due to the information available at each time, but there are definitely ways of improving traceability of log messages. This is on the roadmap here at ForgeRock; watch this space!
(PS: This post is written from memory so there may be some misplaced details. I’ll try to review it with my notes in front of me next week)
