[FOLIO-2511] SPIKE: investigate JSON layout to Okapi and RMB logs Created: 13/Mar/20 Updated: 25/Aug/20 Resolved: 25/Aug/20 |
|
| Status: | Closed |
| Project: | FOLIO |
| Components: | None |
| Affects versions: | None |
| Fix versions: | None |
| Type: | Task | Priority: | P2 |
| Reporter: | Jakub Skoczen | Assignee: | Mikhail Fokanov |
| Resolution: | Done | Votes: | 0 |
| Labels: | instrumentation, platform-backlog | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original estimate: | Not Specified | ||
| Issue links: |
|
||||||||||||||||||||||||
| Sprint: | CP: sprint 92, CP: sprint 94, CP: sprint 95, CP: sprint 90, CP: sprint 91 | ||||||||||||||||||||||||
| Story Points: | 3 | ||||||||||||||||||||||||
| Development Team: | Core: Platform | ||||||||||||||||||||||||
| Description |
|
Goal Investigate if JSON format can be used to provider structured logs in FOLIO, both for Okapi and backend modules (with RMB providing default logging configuration). If successful JSON format will be used to provide structured data in the logs. The following fields are candidates for inclusion:
A complete set is still being discussed, see https://folio-org.atlassian.net/wiki/pages/viewpage.action?pageId=1776544 Caveats FOLIO DevOps team has been experimenting with JSON logging configuration and have seen the following issues trying to enable JSON logging:
See details of this investigation below. Implementation We will put utilities (e.g FolioLoggingContext) and default log4j config in a shared project (okapi-common since it's used by RMB and will make the classes available in all RMB projects). We will let module developers know to remove their existing log4j configuration to make use of the default one. They will be also able to use the default one as a starting point and put in additional customize. |
| Comments |
| Comment by Wayne Schneider [ 13/Mar/20 ] |
|
JSON logging configuration:
<Configuration status="WARN" monitorInterval="30">
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<JSONLayout compact="true" eventEOL="true"/>
</Console>
</Appenders>
<Loggers>
<Root level="INFO">
<AppenderRef ref="Console"/>
</Root>
</Loggers>
</Configuration>
Okapi log output (pretty-printed for clarity):
{
"thread": "vert.x-eventloop-thread-1",
"level": "INFO",
"loggerName": "okapi",
"message": "X-Okapi-Request-Id: 177027/circulation;918494/configurations",
"endOfBatch": false,
"loggerFqcn": "org.apache.logging.log4j.spi.AbstractLogger",
"threadId": 102,
"instant": {
"epochSecond": 1583852446,
"nanoOfSecond": 282000000
},
"threadPriority": 5
}
RMB log output (mod-inventory-storage-18.2.3):
{
"timeMillis": 1583855032670,
"thread": "main",
"level": "INFO",
"loggerName": "org.folio.rest.tools.messages.Messages",
"message": "Loading messages from /infra-messages/APIMessages_de.properties ................................",
"endOfBatch": false,
"loggerFqcn": "io.vertx.core.logging.Logger",
"threadId": 1,
"threadPriority": 5
}
|
| Comment by Wayne Schneider [ 13/Mar/20 ] |
|
Observations from testing: Attempting to add a custom field (either a lookup or a constant) as documented (https://logging.apache.org/log4j/2.x/manual/layouts.html#JSONLayout) does not work as expected for Okapi. You end up with log entries like this:
{
"logEvent": "setTimer delay 432000000",
"customField1": "custom value"
}
Note that the log is quite a bit thinner, and structured very differently. This is quite different from the expected behavior, according to the log4j2 documentation. For RMB, attempting to add a custom field simply doesn't work – the log output is not changed. |