Spring boot app engine logs not properly formatted

Question

I've deployed a spring boot 2 application on appengine and its doing great.

The only thing is that the standard logging mechanism clashes with the gcp logging system. What I get are hundred of info logs, even when there's an exception thrown or a warning.

I think the problem is that the logs are really long and starts with some unnecessary data.

In my configuration I use lombok+Slf4j to log inside my application, and I think logback is enabled by default since I've spring-boot-starter-web.

my pom has these depencencies:

   <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-data-rest</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>org.springframework.boot</groupId>
                    <artifactId>spring-boot-starter-tomcat</artifactId>
                </exclusion>
            </exclusions>
        </dependency>
        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-gcp-starter</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-gcp-starter-data-datastore</artifactId>
        </dependency>

        <!--Standard dep-->

        <dependency>
            <groupId>org.projectlombok</groupId>
            <artifactId>lombok</artifactId>
            <optional>true</optional>
        </dependency>
        <dependency>
            <groupId>com.google.appengine</groupId>
            <artifactId>appengine-api-1.0-sdk</artifactId>
            <version>${appengine.target.version}</version>
        </dependency>
        <dependency>
            <groupId>com.google.api-client</groupId>
            <artifactId>google-api-client-appengine</artifactId>
            <version>1.29.2</version>
        </dependency>

        <!--Provided-->
        <dependency>
            <groupId>javax.servlet</groupId>
            <artifactId>javax.servlet-api</artifactId>
            <version>3.1.0</version>
            <scope>provided</scope>
        </dependency>

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-configuration-processor</artifactId>
            <optional>true</optional>
        </dependency>

        <!--Test related-->

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>

and in the resource folder I've the logging.properties file as suggested in the spring boot page for app engine (avoid stack overflow errors during the startup)

With the only difference that if I exclude jul-to-slf4j, I won't see any log in the console.

Anyone more expert on logback / spring boot can point me in the right direction ?

Dab

Answer 1

In the end I didn't find the proper way to display the logs by console printer in app engine standard with spring boot. However, by using the stackdriver api the logs are indeed prettier.

What I did was including:

        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-gcp-starter-logging</artifactId>
        </dependency>

And in logback-spring.xml

<include resource="org/springframework/cloud/gcp/autoconfigure/logging/logback-appender.xml"/>
<include resource="org/springframework/boot/logging/logback/defaults.xml"/>
<include resource="org/springframework/boot/logging/logback/console-appender.xml"/>

<springProfile name="local">
    <root level="INFO">
        <appender-ref ref="CONSOLE"/>
    </root>
</springProfile>

<springProfile name="!local">
    <root level="INFO">
        <appender-ref ref="STACKDRIVER"/>
    </root>
</springProfile>

However, the main request log level don't show the highest log level (but the "any log value") making filtering harder. On the other end, error reporting works because the inner logs have the proper level set.

Dab

Answer 2

Add a logback.xml file to the resources folder of your project. Spring boot will load this at startup and it will override the default logback configuration bundled with spring boot.

Inside your logback.xml you can define your own logging pattern and remove the unnecessary data.

<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%-5level %logger{36} - %msg%n</pattern>
    </encoder>
  </appender>

  <root level="info">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

The example above won't contain the timestamp or the thread in the log pattern. You can change this to suit your specific use case.

UPDATE

Alternatively, you can achieve this by overriding the log pattern via an application property.

For console logging

logging.pattern.console=%-5level %logger{36} - %msg%n

For file logging

logging.pattern.file=%-5level %logger{36} - %msg%n

You can find an explanation on the meaning of each part of the logging pattern here: https://logback.qos.ch/manual/layouts.html#conversionWord

Electrotechnics

After some tests I don't think that the problem is logback, maybe there's something that it's changing my logs before that. I see the logs changing as you suggest when I run it in local on remote, but in remote on GCP logs I always have some useless info before the logs like: "[h~projectx-dev/1-0-0.419452159733438541].<stdout>:" – Dab

sorry man, I don't have any experience with app engine so can't provide any help there. – Electrotechnics