Cannot set logger level to INFO

[boudhayan-dev]

I am using sap_java_buildpack (11) to deploy a java servlet service. I have added the following dependencies -

1. logback-classic (compile)
2. cf-java-logging-support-logback (compile)
3. slf4j-api (provided, since it causes conflicts during deployment as sap_java_buildpack already provides it).

I have a logback config as follows

<configuration debug="false" scan="false">
    <appender name="STDOUT-JSON" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="com.sap.hcp.cf.logback.encoder.JsonEncoder"/>
    </appender>
    <root level="${LOG_ROOT_LEVEL:-INFO}">
        <appender-ref ref="STDOUT-JSON" />
    </root>
</configuration>

In the CF manifest I have set the log level to INFO as mentioned here - SET_LOGGING_LEVEL

SET_LOGGING_LEVEL: '{ROOT: INFO}'

However, when the application is pushed, it is noticed that the change of logger level triggers an auditlog event, which fails to register in the auditlog service. FYI, the app is also bound to an oauth2 plan of audit log service. I have verified the functionality of the auditlog and it works fine.

Currently, the auditlog is instantitated as a singleton, right after the servlet starts up using a listener callback.

Following are the logs which depict the nature of the error -

{
    "logger": "com.sap.xs.logging.catalina.LoggingLevelChangeListener",
    "msg": "Logging level configuration"
}

{
    "logger": "com.sap.xs.logging.catalina.LoggingLevelChangeListener",
    "msg": "Logging level changed. Location: ROOT changed level from ERROR to INFO. "
}
 {
    "logger": "com.sap.xs.audit.client.impl.TokenFactory",
    "msg": "Got client credentials grant JWT token"
}
 {
    "logger": "com.sap.xs.logging.catalina.LoggingLevelChangeListener",
    "msg": "Error while setting Logging level:INFO for location:ROOT",
    "stacktrace": [
        "com.sap.xs.audit.api.exception.AuditLogWriteException: Audit log client made 4 failed attempts to send the audit log message. The message might not have been written in the audit log storage. Received HTTP status code is 500 and response body: \"{\"error\":\"Internal Server Error.\"}\".",
        "\tat com.sap.xs.audit.client.impl.HttpCommunicator.sendAndRetryOnHttpErrorCodes(HttpCommunicator.java:433)",
        "\tat com.sap.xs.audit.client.impl.HttpCommunicator.send(HttpCommunicator.java:366)",
        "\tat com.sap.xs.audit.client.impl.TransactionalLogImpl.logStatus(TransactionalLogImpl.java:130)",
        "\tat com.sap.xs.audit.client.impl.TransactionalLogImpl.logSuccess(TransactionalLogImpl.java:69)",
        "\tat com.sap.xs.audit.client.impl.v2.ConfigurationChangeMessageImpl.log(ConfigurationChangeMessageImpl.java:38)",
        "\tat com.sap.xs.logging.catalina.LoggingLevelChangeListener.setLoggingLevel(LoggingLevelChangeListener.java:125)",
        "\tat com.sap.xs.logging.catalina.LoggingLevelChangeListener.setupLoggingLevels(LoggingLevelChangeListener.java:80)",
        "\tat com.sap.xs.logging.catalina.LoggingLevelChangeListener.lifecycleEvent(LoggingLevelChangeListener.java:50)",
        "\tat org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)",
        "\tat org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423)",
        "\tat org.apache.catalina.util.LifecycleBase.setState(LifecycleBase.java:366)",
        "\tat org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:756)",
        "\tat org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)",
        "\tat org.apache.catalina.startup.Catalina.start(Catalina.java:688)",
        "\tat java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)",
        "\tat java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)",
        "\tat java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)",
        "\tat java.base/java.lang.reflect.Method.invoke(Method.java:566)",
        "\tat org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:345)",
        "\tat org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:476)"
    ]
}

OUT Container became healthy

1. How to set the default log level for the application to INFO ?
2. Why is the auditlog event triggered ?
3. Does the auditlog failt to register the event because the auditlog instance is initialized after the container is healthy i.e. after servlet setup ? Any which ways, it should not fail since the instance is bound to the app.

Regards.

[KarstenSchnitter]

Hi,

thanks for reporting this issue. The environment variable SET_LOGGING_LEVEL is a feature of the SAP Java buildpack. Please contact the relevant team for information on that. The default log level can be configured in the logback.xml, in the `. See the logback documentation on configuration for details. The auditlog event might indicate problems with the Audit Logging service. Please contact the relevant team for those problems.

Best Regards, Karsten