SAP / cf-java-logging-support

The Java Logging Support for Cloud Foundry supports the creation of structured log messages and the collection of request metrics
Apache License 2.0
77 stars 48 forks source link

Request Logger no longer works without JsonEncoder since 3.6.0 #149

Closed beckermarc closed 2 years ago

beckermarc commented 2 years ago

Description

In the CAP Java sample application we use a logback-spring.xml file, which enables the JsonEncoder from cf-java-logging-support only when running the Spring Boot application with the cloud profile. In all other cases the standard logback configuration file is loaded.

With version 3.5.7 the logging library produced request logs even, if the cloud profile was not activated. Since 3.6.0 this no longer works. The request logs produced by version 3.5.7 looked like this:

2022-08-23 13:39:49.334  INFO 30845 --- [nio-8080-exec-1] c.s.h.c.l.servlet.filter.RequestLogger   : {"request":"/","referer":"-","response_sent_at":"2022-08-23T13:39:49.334Z","response_status":200,"method":"GET","response_size_b":8797,"request_size_b":-1,"remote_port":"redacted","layer":"[SERVLET]","remote_host":"redacted","remote_user":"redacted","protocol":"HTTP/1.1","remote_ip":"redacted","response_content_type":"-","request_received_at":"2022-08-23T13:39:49.308Z","response_time_ms":26.0,"direction":"IN"}

With version 3.6.0 the RequestLogger just produces the following output upon every request:

2022-08-23 13:39:12.643  INFO 29939 --- [nio-8080-exec-2] c.s.h.c.l.servlet.filter.RequestLogger   : 

Expectations

Was this an intended feature in 3.5.7 or did this only work accidentally? If it was intended, is it possible to somehow reestablish the behaviour of the previous version? If it wasn't intended, is it possible to somehow deactivate the RequestLogger automatically in those scenarios, as it is rather annoying that an empty log line is generated by it upon every request.

Steps to reproduce

  1. git clone https://github.com/SAP-samples/cloud-cap-samples-java
  2. cd cloud-cap-samples-java
  3. mvn spring-boot:run
  4. Open http://localhost:8080 and observe empty request logs written to stdout.
  5. Downgrade cf-java-logging-support version in pom.xml to 3.5.7, repeat step 3 & 4 and observe correct request logs written to stdout.
KarstenSchnitter commented 2 years ago

Hi,

thanks for reaching out about this issue.

Generation of request logs in the RequestLogger was refactored to no longer rely on the toString implementation in RequestRecord. This improves performance in the cloud profile significantly. As a side-effect, the log does no longer contain the JSON representation when not using the libraries JsonEncoder. This is the reason, why in your non-cloud profile the log messages contains no more representation of the request record.

This behaviour is completely intentional. It avoids an unnecessary generation of a JSON representation of the request log. The previous behaviour cannot easily be reestablished within the automatic instrumentation. You can disable the RequestLogger logs by setting its logging level to WARN or higher in the non-cloud scenarios.

You can also contact me directly over SAP internal channels, if you want to discuss this issue further.

Best Regards, Karsten

beckermarc commented 2 years ago

Okay, as it doesn't seem to be easily possible to automatically disable the RequestLogger in the library, we will add this explicitly to our configuration: https://github.com/SAP-samples/cloud-cap-samples-java/pull/164