Google-cloud-java: Logging with google-cloud-logging-logback on K8S: resources.labels are empty

[yanns]

I'm trying the used structured logging with google-cloud-logging-logback on Kubernetes.
Most of the resource labels are empty, except project_id and zone:

 resource: {
  labels: {
   cluster_name: ""    
   container_name: ""    
   instance_id: ""    
   namespace_id: ""    
   pod_id: ""    
   project_id: "<project ID>"    
   zone: "<zone>"    
  }
  type: "container"   
 }

I guess the reason for this is that only project_id and zone are configured for resource of type container:

https://github.com/GoogleCloudPlatform/google-cloud-java/blob/937e49d7159c9327255e167f6339c51bb7372c37/google-cloud-logging/src/main/java/com/google/cloud/logging/MonitoredResourceUtil.java#L95

[pongad]

@yanns Are you looking for something like #2669? If so, we're not supporting the feature yet, but we're tracking it in feature backlog wiki.

[yanns]

@pongad no, I'm speaking about the information that should be read from the environment.
For ex, in K8S, the library should automatically read the namespace ID, the pod ID...

https://github.com/GoogleCloudPlatform/google-cloud-java/issues/2669 is about user defined labels AFAIU.

[pongad]

@yanns I see. I must admit I'm not super familiar with this part of the code base.
@jabubake There are a couple things I'm quite confused by; could you help clarify?

1. http://metadata/computeMetadata/v1/instance/cluster-name seems to not exist. At least it's not documented on this page. Should it be removed?

2. How are the empty strings being populated? In particular the string pod_id and container_name doesn't exist anywhere in google-cloud-java. @yanns Could it be that you're adding these yourself, perhaps using LoggingEnhancer?

[yanns]

@pongad LoggingEnhancer is used for labels and not for resources.labels.

[yanns]

If I use the stackdriver agent that parsed stdout/stderr, all the resources.labels fields are set:

 resource: {
  labels: {
   cluster_name: "<defined>"    
   container_name: "<defined>"    
   instance_id: "<defined>"    
   namespace_id: "<defined>"    
   pod_id: "<defined>"    
   project_id: "<defined>"    
   zone: "<defined>"    
  }
  type: "container"   
 }

Maybe we should read some values from the K8S API?

[yanns]

I went through all values I could find under http://metadata.google.internal/computeMetadata/v1/?recursive=true&alt=text and this is what I could find:

• cluster_name: "http://metadata.google.internal/computeMetadata/v1/instance/attributes/cluster-name"
• instance_id: "http://metadata.google.internal/computeMetadata/v1/instance/id"
• project_id: "http://metadata.google.internal/computeMetadata/v1/project/project-id"
• zone: "http://metadata.google.internal/computeMetadata/v1/instance/zone"

Missing:

• container_name
• namespace_id
• pod_id

[jabubake]

@pongad : cluster_name: "http://metadata.google.internal/computeMetadata/v1/instance/attributes/cluster-name"
should be fixed.

pod_id may be available as HOSTNAME env var.

@yanns : on GKE, you may be better off using the Stackdriver agent to handle the logging for you. You can use a console handler / logback appender within your application.
https://cloud.google.com/kubernetes-engine/docs/how-to/logging#enabling_stackdriver_logging

[yanns]

@jabubake this is what I'm using right now.
I'm using logback to log to stdout/stderr, but this has several limitations:

• Stackdriver detects only 2 severity levels (from stdout/stderr) instead of the usual DEBUG/INFO/WARN/ERROR
• Multi-line entries (entries with line feed characters) are not processed correctly. It means that stacktraces are not processed correctly.

By looking for a solution to all those problems, I found https://cloud.google.com/logging/docs/setup/java#wzxhzdk57wzxhzdk58logback_appender_for_product_name which leads me to this logback appender.
But this has also several limitations, as mentioned in this ticket.

And even if I could fix those limitations, I still have a problems that I still need stdout/stderr to quickly check the logs on one pod. It means that the log entries would be duplicated: one send with this logback appender, and one parsed by the Stackdriver agent from stdout/stderr.

Maybe you have a better suggestion?

Maybe I should try the console appender but with a json format?

[jabubake]

Json format might be your friend, but totally understand your concerns here.
@saturnism might be able to offer better recommendations.
We'll make sure to clarify the documentation around this based on the resolution of this question.

[saturnism]

Hiya! Agreed w/ @jabubake. I do prefer GKE w/ STDOUT. For the right severity level and multi-line traces, I also recommend JSON logging. If you do use JSON logging, it'll also be readable via kubectl logs, but you'll need to filter it through jq or something to parse the JSON on the way out.

[pongad]

No more action items in this repo. I'll close this for now.

[yanns]

@jabubake @saturnism I just tried using stdout with json, and it looks to work well.
Thx for the info!

In case anyone is interested in the solution I took:
I added this library: https://github.com/logstash/logstash-logback-encoder

I configured logback that way:

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <target>System.out</target>
        <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
            <providers>
                <timestamp><fieldName>timestamp</fieldName></timestamp>
                <loggerName/>
                <logLevel><fieldName>severity</fieldName></logLevel>
                <message />
                <stackHash />
                <stackTrace>
                    <throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
                        <maxDepthPerThrowable>30</maxDepthPerThrowable>
                        <maxLength>2048</maxLength>
                        <shortenedClassNameLength>20</shortenedClassNameLength>
                        <rootCauseFirst>true</rootCauseFirst>
                    </throwableConverter>
                </stackTrace>
            </providers>
        </encoder>
    </appender>

    <appender name="ASYNCSTDOUT" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="STDOUT"/>
    </appender>

This may evolve in the future, but fulfills the first use-cases.
The field severity is correctly parsed by the stackdriver agent.

[jabubake]

@dzlier-gcp : we might want to update the Java logging setup page to include this information.

[ocervell]

+1 I'm running into the same and opened a separate issue #3109 because the docs are incomplete. Having the log level in Stackdriver is essential if you want to make log-based metrics based on the 'severity' field.

[JoaoPPinto]

Hello,
I'm using the google-cloud-logging-logback appender on an application running on GKE, and I'm facing the same issue: some resource.labels are not defined.

resource: {
 labels: {
   cluster_name: <defined>   
   container_name: ""    
   instance_id: <defined>
   namespace_id: ""    
   pod_id: <defined>
   project_id: <defined>
   zone: <defined>
  }
  type: "container"   
 }

Not having the namespace_id and container_name defined is a bit of a nuisance when trying to find/interpret logs.

Is the recommended solution to switch to logstash-logback-encoder and output logs to stdout, or is there a workaround so we can use the google-cloud-logging-logback appender?

[ohlen1]

Did somebody manage to get the namespace_name field included? This is a showstopper for us, since we will have multiple GKE applications running in a different project, all logging to the same project. Without the namespace we will be unable to create the Stackdriver policies and dashboards that we require for monitoring of our applications.... Any help in the right direction is very appreciated!

[yanns]

@ohlen1 As I wrote before: https://github.com/googleapis/google-cloud-java/issues/2912#issuecomment-369552213, we're now using json logging, and it works very well.

[ohlen1]

@yanns that works fine for us too, but in the production environment we have a restriction that we have to log to our own project, since our GKE workloads are running on cluster shared with other teams, in a common project. So console logging is not an option for us.