HTTP correlation ID example use
In this example, a request to the Directory REST API is made and the correlation ID enables finding HTTP-specific log messages with LDAP-specific log messages. The response to the API call includes a Correlation-Id header with the value a54aee33-c6c6-4467-be25-efd1db7a8b76.
GET /directory/v1/me?includeAttributes=mail HTTP/1.1
Accept: /
Accept-Encoding: gzip, deflate
Authorization: Bearer ...
Connection: keep-alive
Host: localhost:1443
User-Agent: HTTPie/0.9.9
HTTP/1.1 200 OK
Content-Length: 266
Content-Type: application/hal+json
Correlation-Id: ee919049-6710-4594-9c66-28b4ada4b127
Date: Fri, 02 Nov 2018 15:16:50 GMT
Request-Id: 369
{
"_dn": "uid=user.86,ou=People,dc=example,dc=com",
"_links": {
"schemas": [
{
"href": "https://localhost:1443/directory/v1/schemas/
inetOrgPerson"
}
],
"self": {
"href": "https://localhost:1443/directory/v1/
uid=user.86,ou=People,dc=example,dc=com"
}
},
"mail": [
"user.86@example.com"
]
}
This correlation ID can be used to search the HTTP trace log for matching log records, as follows:
$ grep 'correlationID="ee919049-6710-4594-9c66-28b4ada4b127"'
{pingdir}/logs/debug-trace
[02/Nov/2018:10:16:50.294 -0500] HTTP REQUEST requestID=369
correlationID="ee919049-6710-4594-9c66-28b4ada4b127" product="Ping Identity
Directory Server" instanceName="ds1" startupID="W9ikqA==" threadID=52358 from=
[0:0:0:0:0:0:0:1]:58918 method=GET
url="https://0:0:0:0:0:0:0:1:1443/directory/v1/me?includeAttributes=mail"
[02/Nov/2018:10:16:50.526 -0500] DEBUG ACCESS-TOKEN-VALIDATOR-PROCESSING
requestID=369 correlationID="ee919049-6710-4594-9c66-28b4ada4b127"
msg="Identity Mapper with DN 'cn=User ID Identity Mapper,cn=Identity
Mappers,cn=config' mapped ID 'user.86' to entry DN
'uid=user.86,ou=people,dc=example,dc=com'"
[02/Nov/2018:10:16:50.526 -0500] DEBUG ACCESS-TOKEN-VALIDATOR-PROCESSING
requestID=369 correlationID="ee919049-6710-4594-9c66-28b4ada4b127"
accessTokenId="201811020831" msg="Token Validator 'Mock Access Token
Validator' validated access token with active = 'true', sub = 'user.86', owner
= 'uid=user.86,ou=people,dc=example,dc=com', clientId = 'client1', scopes =
'ds', expiration = 'none', not-used-before = 'none', current time = 'Nov 2,
2018 10:16:50 AM CDT' "
[02/Nov/2018:10:16:50.531 -0500] HTTP RESPONSE requestID=369
correlationID="ee919049-6710-4594-9c66-28b4ada4b127"
accessTokenId="201811020831" product="Ping Identity Directory Server"
instanceName="ds1" startupID="W9ikqA==" threadID=52358 statusCode=200
etime=236.932 responseContentLength=266
[02/Nov/2018:10:16:50.531 -0500] DEBUG HTTP-FULL-REQUEST-AND-RESPONSE
requestID=369 correlationID="ee919049-6710-4594-9c66-28b4ada4b127"
accessTokenId="201811020831" product="Ping Identity Directory Server"
instanceName="ds1" startupID="W9ikqA==" threadID=52358 from=
[0:0:0:0:0:0:0:1]:58918 method=GET
url="https://0:0:0:0:0:0:0:1:1443/directory/v1/me?includeAttributes=mail"
statusCode=200 etime=236.932 responseContentLength=266 msg="The LDAP log messages associated with this request can also be located:
$ grep 'correlationID="ee919049-6710-4594-9c66-28b4ada4b127"'
{pingdir}/logs/access
[02/Nov/2018:10:16:50.529 -0500] SEARCH RESULT instanceName="ds1"
threadID=52358 conn=-371045 op=1657393 msgID=1657394 origin="Directory REST
API" httpRequestID="369" correlationID="ee919049-6710-4594-9c66-28b4ada4b127"
authDN="uid=user.86,ou=people,dc=example,dc=com" requesterIP="internal"
requesterDN="uid=user.86,ou=People,dc=example,dc=com"
requestControls="1.3.6.1.4.1.30221.2.5.2" via="app='{pingdir}ds1'
clientIP='0:0:0:0:0:0:0:1' sessionID='201811020831' requestID='ee919049-6710-
4594-9c66-28b4ada4b127'" base="uid=user.86,ou=people,dc=example,dc=com"
scope=0 filter="(&)" attrs="mail,objectClass" resultCode=0
resultCodeName="Success" etime=0.684 entriesReturned=1
[02/Nov/2018:10:16:50.530 -0500] EXTENDED RESULT instanceName="ds1"
threadID=52358 conn=-371046 op=1657394 msgID=1657395 origin="Directory REST
API" httpRequestID="369" correlationID="ee919049-6710-4594-9c66-28b4ada4b127"
authDN="cn=Internal Client,cn=Internal,cn=Root DNs,cn=config"
requesterIP="internal" requesterDN="cn=Internal Client,cn=Internal,cn=Root
DNs,cn=config" requestControls="1.3.6.1.4.1.30221.2.5.2"
via="app='{pingdir}-ds1' clientIP='0:0:0:0:0:0:0:1'
sessionID='201811020831' requestID='ee919049-6710-4594-9c66-28b4ada4b127'"
requestOID="1.3.6.1.4.1.30221.1.6.1" requestType="Password Policy State"
resultCode=0 resultCodeName="Success" etime=0.542 usedPrivileges="bypassacl,password-reset" responseOID="1.3.6.1.4.1.30221.1.6.1"
responseType="Password Policy State"
dn="uid=user.86,ou=People,dc=example,dc=com"
[02/Nov/2018:10:16:50.530 -0500] SEARCH RESULT instanceName="ds1"
threadID=52358 conn=-371048 op=1657397 msgID=1657398 origin="Directory REST
API" httpRequestID="369" correlationID="ee919049-6710-4594-9c66-28b4ada4b127"
authDN="cn=Internal Client,cn=Internal,cn=Root DNs,cn=config"
requesterIP="internal" requesterDN="cn=Internal Client,cn=Internal,cn=Root
DNs,cn=config" requestControls="1.3.6.1.4.1.30221.2.5.2"
via="app='{pingdir}ds1' clientIP='0:0:0:0:0:0:0:1'
sessionID='201811020831' requestID='ee919049-6710-4594-9c66-28b4ada4b127'"
base="cn=Default Password Policy,cn=Password Policies,cn=config" scope=0
filter="(&)" attrs="dscfg- password-attribute" resultCode=0
resultCodeName="Success" etime=0.065 preAuthZUsedPrivileges="bypassacl,config-read" entriesReturned=1