PingDirectory

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-Id response header. This response header name can be customized. The following example changes the correlation-id-response-header property 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