HTTP correlation IDs
A typical request to a software system is handled by multiple subsystems, many of which might be distinct servers residing on distinct hosts and locations. Tracing the request flow on distributed systems can be challenging, because log messages are scattered across various systems and intermingled with messages for other requests. To make this easier, a correlation ID can be assigned to a request, which is then added to every associated operation as the request flows through the larger system. The correlation ID allows related log messages to be easily located and grouped. The server supports correlation IDs for all HTTP requests received through its HTTP(S) Connection Handler.
When an HTTP request is received, it is automatically assigned a correlation ID. This ID can be used to correlate HTTP responses with messages recorded to the HTTP Detailed Operation log and the trace log. For specific web APIs, the correlation ID can also be passed to the LDAP subsystem. For the SCIM 1, Delegated Admin, Consent, and Directory REST APIs, the correlation ID will also appear with associated requests in LDAP logs in the correlationID key. The correlation ID is also used as the default client request ID value in Intermediate Client Request Controls used by the SCIM 2, Consent, and Directory REST APIs. Values related to the Intermediate Client Request Control appear in the LDAP logs in the via key, and are forwarded to downstream LDAP servers when received by the PingDirectoryProxy server. The correlation ID header is also added to requests forwarded by the PingAuthorize gateway.
For Server SDK extensions that have access to the current HttpServletRequest, the current correlation ID can be retrieved as a string through the HttpServletRequest’s com.pingidentity.pingdata.correlation_id attribute. For example:
(String) request.getAttribute("com.pingidentity.pingdata.correlation_id");
Configuring HTTP correlation ID support
Correlation ID support is enabled by default for each HTTP connection handler.
-
To enable correlation ID support for the HTTPS connection handler:
$ bin/dsconfig set-connection-handler-prop \ --handler-name "HTTPS Connection Handler" \ --set use-correlation-id-header:true -
To disable correlation ID support for the HTTPS connection handler:
$ bin/dsconfig set-connection-handler-prop \ --handler-name "HTTPS Connection Handler" \ --set use-correlation-id-header:false
Configuring the correlation ID response header
-
The server will generate a correlation ID for every HTTP request and send it in the response through the
Correlation-Idresponse header. This response header name can be customized. The following example changes thecorrelation-id-response-headerproperty to"X-Request-Id."$ bin/dsconfig set-connection-handler-prop \ --handler-name "HTTPS Connection Handler" \ --set correlation-id-response-header:X-Request-Id
Accepting an incoming correlation ID from the request
-
By default, the server generates a new, unique correlation ID for each HTTP request, and ignores any correlation ID that can be set on the request. This can be changed by designating the names of one or more HTTP request headers that contain an existing correlation ID value. This enables the server to integrate with a larger system consisting of every server using correlation IDs.
$ bin/dsconfig set-connection-handler-prop \ --handler-name "HTTPS Connection Handler" \ --set correlation-id-request-header:X-Request-Id \ --set correlation-id-request-header:X-Correlation-Id \ --set correlation-id-request-header:Correlation-Id \ --set correlation-id-request-header:X-Amzn-Trace-Id
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