Logging: 'client.setup_logging()' doesn't identify the underlying platform

[guillaumeblaquiere]

My objective is to format correctly the logs into my Python app for having a good ingestion and formatting on Stackdriver logging console with level well interpreted.

The standard logging doesn't work for App Engine python 3.7 (work in Python 2) and on Cloud Run, because the logs aren't formatted in FluentD.
However, with Cloud Function, it's the case.

I found how to perform a workaround, (see example), but I think there is a bug in your library. Indeed, the function client.setup_logging() should set up my logger with the correct format according with the environment.

It's not the case, and that's why I have to implement the workaround. Sadly, this workaround don't take into account the environment and when I run locally the app, I have this log trace:

 * Serving Flask app "server" (lazy loading)
 * Environment: production
   WARNING: This is a development server. Do not use it in a production deployment.
   Use a production WSGI server instead.
 * Debug mode: off
{"message": " * Running on http://0.0.0.0:8080/ (Press CTRL+C to quit)", "timestamp": {"seconds": 1571789029, "nanos": 987048387}, "thread": 140201867048192, "severity": "INFO"}
{"message": "call info1", "timestamp": {"seconds": 1571789035, "nanos": 285192966}, "thread": 140201732208384, "severity": "INFO"}
{"message": "call info2", "timestamp": {"seconds": 1571789035, "nanos": 285630702}, "thread": 140201732208384, "severity": "INFO"}
{"message": "this is an error2", "timestamp": {"seconds": 1571789035, "nanos": 285893201}, "thread": 140201732208384, "severity": "ERROR"}
{"message": "127.0.0.1 - - [23/Oct/2019 02:03:55] \"GET / HTTP/1.1\" 200 -", "timestamp": {"seconds": 1571789035, "nanos": 286895513}, "thread": 140201732208384, "severity": "INFO"}

Which is in FluentD format, but barely lisible.

The automatic configuration promised at this page doesn't happen!

Environment details

1. Specify the API at the beginning of the title (for example, "BigQuery: ...")
   General, Core, and Other are also allowed as types

Logging API for App Engine and Cloud Run

2. OS type and version
   Python 3.7, linux( appengine, container, local environment)

3. Python version and virtual environment information: python --version
   3.7. Version not detailed because occur on App Engine

4. google-cloud- version: pip show google-<service> or pip freeze
   google-cloud-logging==1.14.0

Steps to reproduce

Deploy an app on Cloud Run or App Engine standard Python 3.7. Bellow an example with the workaround. Try to change the log handler with client.setup_logging() no special formater are set, and the log on Stackdriver aren't well ingested.

Code example

This is a working example. I don't use client.setup_logging()

import os
from flask import Flask, request
import logging
from google.cloud.logging.handlers.container_engine import ContainerEngineHandler


# This change nothing to the standard logger on App Engine and Cloud Run env
# client = google.cloud.logging.Client()
# client.setup_logging()

# This is a working workaround on GCP but with not lisible log in local env
handler = ContainerEngineHandler()
cloud_logger = logging.getLogger()
cloud_logger.setLevel(logging.DEBUG)
cloud_logger.addHandler(handler)

app = Flask(__name__)
@app.route('/', methods=['GET'])

def call_oracle_connection():
    logger = logging.getLogger("cloudLogger")
    logger.info('call info1')
    logger = logging.getLogger()
    logger.info('call info2')
    logging.error('this is an error2')
    return oracle_connection(request)

if __name__ == "__main__":
    app.run(host='0.0.0.0',port=int(os.environ.get('PORT',8080)))

Thanks!

[adamalton]

I also have the same issue. I've followed the instructions here: https://cloud.google.com/logging/docs/setup/python

But when viewing the logs in the Cloud web Console they're all badly formatted (line breaks are missing, so tracebacks are unreadable) and the 'level' info is missing, so you can't filter by info/warning/error/etc.

This has got to be a bug in the library. It can't possibly be deliberate to have the logs look this terrible, or to require such levels of weird voodoo configuration to get it the formatting to work.

[jakebiesinger-onduo]

I filed https://issuetracker.google.com/issues/150734081 and then stumbled on this issue, which is basically a dupe of both the problem and workaround.

+1 to no voodoo to getting logging working properly. According to [the docs]:(https://cloud.google.com/run/docs/logging#writing_structured_logs)

You can use the Google Cloud's operations suite Logging Client Libraries to get this functionality automatically.

Both the level and the trace should be set in stackdriver logs by virtue of explicitly setting up a google.cloud.logging handler.

[oliviernguyenquoc]

Is there any update on this or workarround ? It makes application monitoring very difficult...
We can't track bugs without this feature.

[daniel-sanche]

Currently, this library doesn't integrate well with newer GCP environments like Cloud Run and Cloud Functions. This is a known high-priority issue we're working on fixing this quarter.

@oliviernguyenquoc As reported above, you should be able to set the handler explicitly as a workaround. Is that not working for you?

[oliviernguyenquoc]

@daniel-sanche : This work arround is not working on Cloud Run. We tried multiple times, by multiple developpers.
Is priority P3 change your estimate of patching in Q1 ?

This is an important feature to track our bug in production.

Thanks !

[daniel-sanche]

@oliviernguyenquoc

Can you explain what you're seeing vs what you expect to see? Cloud Run isn't yet officially supported by the library, so it won't be auto-detected. But you should still be able to see logs, and populate missing fields manually. Are you seeing any logs on Cloud Run at all?

I'm hoping to add full Cloud Run support this quarter. But we need to add better tests and make a couple other structural fixes first

[oliviernguyenquoc]

Logs are appearing well in cloud logging, but not with the right logging level.

But we would need to get noticed as soon as an error logging is triggered in production.
Meanwhile, we run in kind of blind mode.

Thanks for your work and we widely waiting for this feature :)

[daniel-sanche]

Hmm I did a quick test with the code described in the docs and the severity fields seemed to work for me on Cloud Run.

If you can send me a container image that reproduces your issue, I can try to take a look and find a workaround for you

[daniel-sanche]

This should be fixed after #200. You will see it in the next release