[GO] What I did to output application logs on GAE Flexible Environment.

Log output on Google Appengine Flexible Environment

Everyone, do you spit out logs to the storage on the application server when you create an application? ??

In GAE / go (Standard Environment), if you use google.golang.org/appengine/log, it will output to the log viewer, you can easily filter the log, etc.," What a wonderful !! " I think I was impressed.

However, GAE / FE did not output to the log viewer without doing anything.

I had a lot of trouble and was able to output as expected, so I will write it in detail because it may be useful for someone someday, including various investigations.

Log output strategy (1st generation)

The first log output method I thought of was to hit the StackDriver Logging API (v2) on my own. → here

When using this method, it is necessary to sort the output destination (API connection destination) when hitting in the local development environment, hitting in the staging environment, hitting in the production environment, and one request Since it is not good to hit the API multiple times with, it seems necessary to create a mechanism to buffer writes in the request scope and execute the Logging API.

In such a situation, fluentd is running in the FE environment, and I got the information that the file spit out in the appropriate format is output to the log viewer in the appropriate format, and the log output strategy immediately goes to the second generation.

Log output strategy (second generation)

The agent is installed in the FE environment, and a mechanism to output logs is prepared.

`To connect your App Engine flexible environment application to Stackdriver Error Reporting, send structured data to a custom log file. ``

ʻThe Stackdriver Logging agent is installed and configured by default on the App Engine Flexible Environment app. ``

https://cloud.google.com/error-reporting/docs/setup/app-engine-flexible-environment

I see, I'm grateful for this. According to the information, by outputting to a fixed file in a fixed format, you can collect it nicely. When.

What is the fixed file and the fixed format?

I understand that there is a mechanism to output, but I do not know the output destination and the shape of the JSON to be output ...

I referred to documents such as Using Cloud logging in App Engine apps, but it doesn't work subtly.

Isn't it faster to give up the document from this point and steadily investigate the source code and environment? I felt that, so I switched to that method.

First, grasp the environment while looking at the repository of settings around the container of the FE environment called Managed VM Sidecar Containers.

Instances in the FE environment can be ssh connected.

Write code → deploy → wait to death until you realize that you can ssh. It was a penance, but if you can connect, this one. I will investigate various things.

Click "Instance" of appengine and click "SSH" of the instance to start the terminal on the browser.

The destination connected by the terminal will be an instance of the FE environment. (Maybe it's a GCE instance?) Let's check the container running with the following command.

$ sudo docker ps
CONTAINER ID        IMAGE                                                                                                                         COMMAND                  CREATED             STATUS              PORTS                                        NAMES
61096f77d1a5        gcr.io/google_appengine/nginx-proxy                                                                                           "/var/lib/nginx/bin/s"   About an hour ago   Up About an hour    8080/tcp, 8090/tcp, 0.0.0.0:8443->8443/tcp   thirsty_brattain
3e176f20673a        us.gcr.io/fe-stud/appengine/default.20161206t152342@sha256:330d6b553033c80ad0313fe3c2fd713bdaec873197d00193b6f8a32beda0ca73   "/docker-entrypoint.b"   About an hour ago   Up About an hour    8080/tcp                                     gaeapp
73675d907c83        gcr.io/google_appengine/api-proxy                                                                                             "/proxy"                 About an hour ago   Up About an hour                                                 api
5430f456d28c        gcr.io/google_appengine/fluentd-logger                                                                                        "/opt/google-fluentd/"   About an hour ago   Up About an hour                                                 stupefied_heisenberg

It seems that the instance of FE environment has 4 containers running on Docker, and when the log is spit out from the gaeapp (application) to the shared host instance directory, the fluentd container picks it up and sends the log.

Since it is fluentd, the log file to be collected is defined in File in Github.

/fluentd_logger/managed_vms.conf

It is as follows.

I wonder if this is the standard target. Please note that it is the path inside the fluentd container! (I was a little addicted to the belief that the same path would be in the gaeapp container ...)

Here's how I got hooked. Directory path correspondence table

Did you notice? Yes, the path of the log directory of the host instance and the container of fluentd are the same, but for some reason the path of the log directory of gaeapp is different. .. ..

So, even if I look at the fluentd configuration file and output the log file in gaeapp for that directory, fluentd does not pick it up ... (tears.

I think it's a good idea to put this area in a fluentd container and try it while tailing the log.

To enter the fluentd container on the host instance

$ sudo docker exec -it stupefied_heisenberg bash

Enter the container with

# tail -f /var/log/google-fluentd/google-fluentd.log

You can see it at. By the way, if the log is correctly picked up by fluentd

2016-12-06 07:47:25 +0000 [info]: following tail of /var/log/app_engine/app/app.json
2016-12-06 07:54:25 +0000 [info]: following tail of /var/log/app_engine/app/app.log.json

A log like this is output. (Note that it is output only the first time the file is found.)

What is the JSON format required for output? ??

First of all, how is the log that is not in JSON format output by the log viewer?

If you output the text log to a file with the extension * .log, it will be output as text. What is different from JSON format logs is that information such as log level cannot be added.

Example of outputting app.log Sorry for the elongated image. .. When it is output as text (the content is in JSON format in the example), it is output without the log level (icon on the left).

I still want the log level when outputting from the application. Therefore, the JSON format required for output is shown below.

To output a JSON format log and output it cleanly to the log viewer. (final?)

Use JsonFormatter.java and LogContext.java in appengine-java-vm-runtime to format the JSON. ..

Even when using it in other languages, the format method in JsonFormatter.java does not do so difficult processing, so I think that you can implement it by referring to that.

So, the JSON format sample that concludes is as follows.

{
  "timestamp":{"seconds":1481005920,"nanos":927000000},
  "severity":"ERROR",
  "thread":"qtp1347137144-13",
  "message":"TestLogger: === TEST LOG ==="
}

By the way, when using the previous JsonFormatter, you will use java.util.logging.LogRecord, but as a caveat, you need to enter the logger name using LogRecord # setLoggerName. It doesn't cause an error even if I don't enter it, but the JSON message looks like " null: === TEST LOG ===" and it's not cool.

Rough sample code

Level level = Level.SEVERE; //Log level, equivalent to Error
LogRecord record = new LogRecord(level, "=== TEST LOG ===");
record.setLoggerName("TestLogger");
JsonFormatter formatter = new JsonFormatter();
String logString = formatter.format(record); //You can output this String as a line in the json file.

If you can prepare so far, you will be able to spit out JSON to a file and output it to the log viewer cleanly. The example is output at the error level, so there is an icon that seems not to be just a thing [! !! ]

Output method in Java (Appendix)

When using with Scala (Java), I would like to output using slf4j / logback etc., but I was able to output by the following method.

Add ʻappengine-java-logging and ʻappengine-managed-runtime to the project pom.xml

pom.xml

<!-- https://mvnrepository.com/artifact/com.google.appengine/appengine-java-logging -->
<dependency>
    <groupId>com.google.appengine</groupId>
    <artifactId>appengine-java-logging</artifactId>
    <version>1.9.31</version>
</dependency>
<!-- https://mvnrepository.com/artifact/com.google.appengine/appengine-managed-runtime -->
<dependency>
    <groupId>com.google.appengine</groupId>
    <artifactId>appengine-managed-runtime</artifactId>
    <version>1.9.31</version>
</dependency>

Call VmRuntimeFileLogHandler # init somewhere in your application.

This internally specifies the log output settings.

VmRuntimeFileLogHandler.java

// ~~ snip ~~
    private static String fileLogPattern() {
        String pattern = System.getenv("APP_ENGINE_LOG_CONFIG_PATTERN");
        if(pattern != null) {
            return pattern;
        } else {
            String directory = System.getProperty("com.google.apphosting.logs", "/var/log/app_engine");
            pattern = System.getProperty("com.google.apphosting.vmruntime.VmRuntimeFileLogHandler.pattern");
            return pattern != null?(pattern.startsWith("/")?pattern:directory + "/" + pattern):directory + "/" + "app.%g.log.json";
        }
    }
// ~~ snip ~~

You may post the specified contents to logback.xml etc. by referring to this class. In that case, you don't have to call VmRuntimeFileLogHandler # init.

Generate a logger and output a log

LogSample.java

Logger logger = Logger.getLogger("com");  //Logger generation

logger.warning("= WARNING TEST ="); //Log output

Set logging.properties as needed

.level=ALL

com.level=SEVERE

Acknowledgments

We would like to thank @soundTricker for giving us various information and consultation regarding log output in the FE environment.