Google App Engine request style logging in a kubernetes container app

9/18/2019

I need to setup logging in a custom web app which ideally would match the magic which happens when running a web app in Google app engine

For example, in GAE there is a request_log which can be viewed. This groups all log statements together under each request and each request has the http status code together with the endpoint path of the url. Here is an example (I apologise in advance for the crude editing here)

enter image description here

In a flask application I are deploying to Google Kubernetes Engine I would like to get the same level of logging in place. Trouble is I just do not know where to start.

I have got as far as installing the google-cloud-logging python library and have some rudimentary logging in place like this....

enter image description here

..but this is no where near the level I would like.

So the question is - where do I start?? Any searches / docs I have found so far have come up short.

-- solo1977
google-app-engine
google-kubernetes-engine
logging
python
stackdriver

3 Answers

9/22/2019

I am writing this here letting people know what I have come up with during my investigations.

The information supplied by sllopis got me to to the closest solution - using a mixture of structured logging and refactoring some of the code in the flask-gcp-log-groups library I am able to get requests logged in Stackdriver with log lines correlated underneath

Unfortunately this solution has a few gaping holes making it far from ideal albeit it is the best I can come up with so far based on Stackdrivers rigidness.

Each time I drill into a request there is a "flash" as Stackdriver searches and grabs all the trace entries matching that request. The bigger the collection of entries, the longer the flash takes to complete.

I cannot search for text within the correlated lines when only looking at the "request" log. For example, say a correlated log entry underneath a request has a string with the text "now you see me" - if I search for the string "see" it will not bring up that request in the list of search results.

I may be missing something obvious but I have spent several very frustrating days trying to achieve something which you think should be quite simple.

Ideally I would create a protoPayload per log entry, within I would put an array under the property "line" similar to how Google App Engine does its logging.

However there does not appear to be a way of doing this as protoPayload is reserved for Audit Logs.

Thanks to sllopis for the information supplied - if I don't find a better solution soon I will mark the answer as correct as it is the closest I believe I will get to what I want to achieve.

Given the situation I am very tempted to ditch Stackdriver in favour of a better logging solution - any suggestions welcome!

-- solo1977
Source: StackOverflow

9/18/2019

Click on "View options" at top right corner in the logs panel > "Modify Custom fields"

https://cloud.google.com/logging/docs/view/overview#custom-fields

-- PiSquared
Source: StackOverflow

9/18/2019

Structured Logging

In Stackdriver Logging, structured logs refer to log entries that use the jsonPayload field to add structure to their payloads. If you use the Stackdriver Logging API or the command-line utility, gcloud logging, you can control the structure of your payloads. Here's an example of what a jsonPayload would look like:

{
     insertId:  "1m9mtk4g3mwilhp"
     jsonPayload: {
      [handler]:  "/"
      [method]:  "GET"
      [message]: "200 OK" 
     }
     labels: {
      compute.googleapis.com/resource_name:  "add-structured-log-resource"
     }
     logName:  "projects/my-sample-project-12345/logs/structured-log"
     receiveTimestamp:  "2018-03-21T01:53:41.118200931Z"
     resource: {
      labels: {
       instance_id:  "5351724540900470204"
       project_id:  "my-sample-project-12345"
       zone:  "us-central1-c"
      }
      type:  "gce_instance"
     }
     timestamp:  "2018-03-21T01:53:39.071920609Z"
    }

You can set your own customizable jsonPayload with the parameters and values that you would like to obtain and then write this information to Stackdriver Logs Viewer.

Setting Debug mode to True

When setting debug=True, you will be able see your app in debugging mode. You will be able to see the HTTP requests, as they will appear on your console for debugging purposes, which you could then write these requests to Stackdriver Logs Viewer. An example of a Hello world Flask app running in Debug mode.

from flask import Flask
app = Flask(__name__)

@app.route("/")
def hello():
    return "Hello World!"

if __name__ == "__main__":
    app.run(port='5000', debug=True)

Which you could add a Flask logging handler as follows:

import logging
from logging.handlers import RotatingFileHandler

from flask import Flask

app = Flask(__name__)

@app.route('/')
def foo():
    app.logger.warning('A warning occurred (%d apples)', 42)
    app.logger.error('An error occurred')
    app.logger.info('Info')
    return "foo"

if __name__ == '__main__':
    handler = RotatingFileHandler('foo.log', maxBytes=10000, backupCount=1)
    handler.setLevel(logging.INFO)
    app.logger.addHandler(handler)
    app.run()

As you can see, there are ways to achieve this, by following the proper log configuration; although, the Stackdriver Logs Viewer UI will not look the same for Kubernetes logs as in App Engine Stackdriver Logs Viewer.


Additionally, you could also take a look into Combining correlated log lines in Google Stackdriver since it will give you a better idea of how to batch your logs by categories or groups in case you need to do so.

-- sllopis
Source: StackOverflow