HTTP correlation IDs

Correlation IDs make it easier to track log messages across a software system request that passes through multiple subsystems.

Scattered and intermingled log messages create challenges for tracing the request flow on distributed systems. A correlation ID can be assigned to a request and added to all associated operations as the request is processed. A 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 or HTTPS 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 might also be passed to the LDAP subsystem.

The correlation ID appears with associated requests in LDAP logs in the correlationID key for the following REST APIs:

SCIM 1
Delegated admin
Consent
Directory

The correlation ID is used as the default client request ID value in intermediate client request controls used by the following REST APIs:

SCIM 2
Consent
Directory

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 PingDirectoryProxy server. The correlation ID header is also added to requests forwarded by the PingDirectory 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 com.pingidentity.pingdata.correlation_id attribute, as shown.

(String) request.getAttribute("com.pingidentity.pingdata.correlation_id");

Configuring HTTP correlation ID support

About this task

Correlation ID support is enabled by default for each HTTP Connection Handler.

Steps

To enable or disable correlation ID support for the HTTPS Connection Handler, use the set-connection-handler-prop option with dsconfig.

Example:

This example shows how to enable correlation ID support.
```
$ dsconfig set-connection-handler-prop \
  --handler-name "HTTPS Connection Handler" \
  --set use-correlation-id-header:true
```
Example:

This example shows how to disable correlation ID support.
```
$ dsconfig set-connection-handler-prop \
  --handler-name "HTTPS Connection Handler" \
  --set use-correlation-id-header:false
```
To customize the response header name for the correlation ID, use the set-connection-handler-prop option with dsconfig.

The server generates a correlation ID for every HTTP request and sends it in the response through the Correlation-Id response header.

Example:

This example changes the correlation-id-response-header property value to X-Request-Id.
```
$ dsconfig set-connection-handler-prop \
   --handler-name "HTTPS Connection Handler" \
   --set correlation-id-response-header:X-Request-Id
```

To designate the names of one or more HTTP request headers that contain an existing correlation ID value, use the set-connection-handler-prop option with dsconfig.

This enables the server to integrate with a larger system consisting of every servers using correlation IDs.

By default, the server generates a new, unique correlation ID for each HTTP request and ignores any correlation ID that might be set on the request.

Example:

$ 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

In this example, a request to the directory REST API is made and the correlation ID enables finding HTTP-specific log messages that also have LDAP-specific log messages. The response to the API call includes a Correlation-Id header with the value ee919049-6710-4594-9c66-28b4ada4b127.

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"
     ]
 }

The correlation ID can be used to search the HTTP trace log for matching log records, as in the following example.

$  grep 'correlationID="ee919049-6710-4594-9c66-28b4ada4b127"' PingDirectory/logs/debug-trace
      [02/Nov/2018:10:16:50.294 -0500] HTTP REQUEST requestID=369 correlationID="ee919049-6710-4594-9c66-28b4ada4b127" product="{pingdir}  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="{pingdir}  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="{pingdir}  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, as in the following example.

$  grep 'correlationID="ee919049-6710-4594-9c66-28b4ada4b127"' PingDirectory/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='PingDirectory-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='PingDirectory-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="bypass-acl,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='PingDirectory-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="ds-cfg-password-attribute" resultCode=0 resultCodeName="Success" etime=0.065 preAuthZUsedPrivileges="bypass-acl,config-read" entriesReturned=1