Uploaded image for project: 'PUBLIC - Liferay Portal Community Edition'
  1. PUBLIC - Liferay Portal Community Edition
  2. LPS-145235

Inject LogContext keys into Log4j ThreadContext

    Details

      Description

      Motivation:
       
      As of LPS-133670 we added support for log context information. This mean any app can populate their own log context (i.e. key-value pairs) and it will be included in the output of the logs. For example, this is the case of the AuditLogContext (see LPS-133646). While the feature is working, as we've tried to process the output logs with tools such as StackDrive, we realized that the LogContext JSON are not well formed. For instance, in this trace:

      {AuditLogContext{"clientIP":"188.6.143.206,34.117.76.194","companyId":"120890709","emailAddress":"","serverName":"instance-admin-int-dev.liferay.online","sessionId":"+eedHNLV/ctHw4FE8ZeCeI7ONa6h3jotqvdAuvD6VMI=","userId":"","virtualHostName":"instance-admin-int-dev.liferay.online","xRequestId":"d3320467-4c10-2d68-abf0-fffe4a586839"}}{"clientHost":"188.6.143.206","serverName":"instance-admin-int-dev.liferay.online","className":"com.liferay.portal.kernel.model.User","eventType":"LOGIN_FAILURE","sessionID":"F4F160EF6F5A5E6067992B8433437E06","serverPort":
      

      AuditLogContext is missing quotes.

      Since log4j allows to customize the output format through Layouts in the portal-log4j-ext.xml file, we considered that it'd be a better approach to simple make the logcontext values available in the logs, and define their formatting through the  portal-log4j-ext.xml
       
      Technical Solution:
       
      Log4j2 introduced the TheadContext (see https://logging.apache.org/log4j/2.x/manual/thread-context.html) as a way to inject custom information into the log context. The information can latter be displayed in the logs by configuring the log layouts.
       
      Acceptance Criteria: 

      • Given an application producing custom log info via LogContext services in Liferay, when the log4j is configured to include the log4j thread context properties in the log, then the logs include the properties in the defined format.

      How to test it:

      • Copy the portal-impl/src/META-INF/portal-log4j.xml into bundles/tomcat/webapps/ROOT/WEB-INF/classes/META-INF
      • Rename the file to portal-log4j-ext.xml
      • Modify the first log appender to include the ThreadContext properties:

       

      <?xml version="1.0"?><?xml version="1.0"?>
      <Configuration strict="true"> <Appenders> <Appender name="CONSOLE" type="Console"> <Layout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t][%c{1}:%L] %m%n %X" type="PatternLayout"/> </Appender>
      
      ....
      </Configuration>
      • Notice the %X in the Layout pattern. As documented in https://logging.apache.org/log4j/2.x/manual/thread-context.html, this option includes the full threadContext properties in the log.
      • Start the portal
      • Go to Control Panel > System Settings > Audit > Audit Log Context, check "Enabled" and Save
      • Go to Control Panel > Server Administration > Log Levels and add a new category for "com.liferay.commerce" with level DEBUG
      • Force a log trace of com.liferay.commerce. For example, by executing:

       

      curl --location --request GET 'http://localhost:8080/o/headless-commerce-delivery-cart/v1.0/channels/48167/account/49873/carts' \--header 'Authorization: Basic dGVzdEBsaWZlcmF5LmNvbTp0ZXN0'
      
      • Assert that the log contains the Audit Log Context information, in the position defined in the layout pattern of the portal-log4j-ext.xml:
      2022-01-12 15:09:49.850 DEBUG [http-nio-8080-exec-3][CommerceChannelPersistenceImpl:1791] No CommerceChannel exists with the primary key 48167
       {AuditLogContext.clientIP=127.0.0.1, AuditLogContext.companyId=20099, AuditLogContext.emailAddress=, AuditLogContext.serverName=localhost, AuditLogContext.sessionId=Gp+N1wVKciocgX8OQ8sP9hak1aCdbJQG/W+38Akl/II=, AuditLogContext.userId=, AuditLogContext.virtualHostName=localhost, AuditLogContext.xRequestId=952571a4-a79e-ad15-f9d2-5531dbc4f847}
      

       

      Produce a valid JSON output:

      To produce a valid JSON-formatted log output including the thread context properties, change the configuration in the porta-log4j-ext.xml file like this and restart:

      Configuration strict="true">
          <Appenders>
              <Appender name="CONSOLE" type="Console">
                  <JSONLayout properties="true" />
              </Appender>
      ...
      

      Then, by repeating the steps to test, you will obtain the following output in the logs:

      {
        "instant" : {
          "epochSecond" : 1640296450,
          "nanoOfSecond" : 978000000
        },
        "thread" : "http-nio-8080-exec-10",
        "level" : "DEBUG",
        "loggerName" : "com.liferay.commerce.product.service.persistence.impl.CommerceChannelPersistenceImpl",
        "message" : "No CommerceChannel exists with the primary key 48167",
        "endOfBatch" : false,
        "loggerFqcn" : "com.liferay.portal.kernel.log.SanitizerLogWrapper",
        "contextMap" : {
          "AuditLogContext.clientIP" : "127.0.0.1",
          "AuditLogContext.companyId" : "20099",
          "AuditLogContext.emailAddress" : "",
          "AuditLogContext.serverName" : "localhost",
          "AuditLogContext.sessionId" : "WfhjCJRWT5lRyn1jXaKay6rKfAMjjGHUGfJ1eywFmkQ=",
          "AuditLogContext.userId" : "",
          "AuditLogContext.virtualHostName" : "localhost",
          "AuditLogContext.xRequestId" : "c9658af2-3edc-5ddc-009a-e74715f50dad"
        },
        "threadId" : 155,
        "threadPriority" : 5
      }
      

       

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              victor.ware Victor Ware
              Reporter:
              eduardo.garcia Eduardo García (Inactive)
              Engineering Assignee:
              Eduardo García (Inactive)
              Recent user:
              Jürgen Kappler
              Participants of an Issue:
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:

                  Packages

                  Version Package
                  Master