Google-cloud-java: Logging with google-cloud-logging-logback on K8S missing some resource.labels

[jessewebb]

Environment: GKE
Java Library: google-cloud-logging-logback
Version: 0.97.0-alpha

I am running some Java/Scala micro-services in GKE. Initially, we just logged to stdout and our logs appeared in Log Viewer automatically. Unfortunately, the logs were not showing proper severities and multi-line log entries were appearing as multiple entries.

Using the instructions on this doc page, we changed our apps to use the google-cloud-logging-logback lib to use Stackdriver Logging instead of stdout. This fixed our severity and multi-line issues.

But now we noticed that the logs created using the Stackdriver Logging logback lib doesn't include all of the correct resource.labels that exist when using stdout logging.

A stdout log entry looks like this:

{
 ...
 resource: {
  labels: {
   cluster_name:  "my-cluster"    
   container_name:  "my-app"    
   instance_id:  "12345"    
   namespace_id:  "default"    
   pod_id:  "my-app-123-aabc"    
   project_id:  "my-project"    
   zone:  "northamerica-northeast1-a"    
  }
  type:  "container"   
 }
 ...
}

But a Stackdriver Logging entry looks like this:

{
 ...
 resource: {
  labels: {
   cluster_name:  "my-cluster"    
   container_name:  ""    
   instance_id:  "12345"    
   namespace_id:  ""    
   pod_id:  "my-app-123-aabc"    
   project_id:  "my-project"    
   zone:  "northamerica-northeast1-a"    
  }
  type:  "container"   
 }
 ...
}

This is causing our logs to not show up when viewing "Container logs" from a GKE workload. When you are viewing the details of a GKE workload, and you click the link for "Container logs", it sends you to Log Viewer with the following filter:

resource.type="container"
resource.labels.cluster_name="my-cluster"
resource.labels.namespace_id="default"
resource.labels.project_id="my-project"
resource.labels.zone:"northamerica-northeast1-"
resource.labels.container_name="my-app"
resource.labels.pod_id:"my-app-"

This default filter doesn't show the logs correctly because of the missing filters.

I found an older, "Closed" issue which was created because all resource.labels were at one point empty.
https://github.com/googleapis/google-cloud-java/issues/2912
During work on that issue last year, some of the fields were changed to be populated, but not all. It seems resource.labels.container_name and resource.labels.namespace_id are still empty. Another user (@JoaoPPinto) even commented on that closed issue after it was closed, mentioning that they are also facing the same problem that I am.

Please update this lib to include the resource.labels.container_name and resource.labels.namespace_idmetadata on the logs so that "Container logs" filter works properly.

[pmakani]

@jessewebb i tested on K8S and i am able see resouce.labels.

resource: {
  labels: {
   cluster_name:  "testl-cluster"    
   container_name:  "spring-boot"    
   instance_id:  "5508768430932319372"    
   namespace_id:  "default"    
   pod_id:  "spring-boot-6c986b5c47-bsjbf"    
   project_id:  "my-project-01"    
   zone:  "us-central1-a"    
  }
  type:  "container"   
}

[jessewebb]

Hmmmm, it's interesting that you get those labels but I don't. This problem is happening for several micro-services of ours (8+) so I am curious what might be different between our setups.

We have akka based apps, with these dependencies in our build.sbt:

    "ch.qos.logback" % "logback-classic" % "1.2.3",
    "com.google.cloud" % "google-cloud-logging-logback" % "0.97.0-alpha",

Here is one of our logback.xml files:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appender name="CLOUD" class="com.google.cloud.logging.logback.LoggingAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
        <log>my-app</log>
    </appender>

    <root level="info">
        <appender-ref ref="CLOUD" />
    </root>

</configuration>

Maybe this isn't a problem with the library, since you did not get the same problem, but it does seem to affect other users too. As mentioned earlier, another user has posted elsewhere that they are experiencing the same problem.

[rgba]

I have the same issue, it seems that this is related to the google-cloud-logging dependencies, if I deploy my app with google-cloud-logging, my containers are missing some information when viewed in stackdriver kubernetes monitoring (container cannot be associated to a pod):

If I remove the google-cloud-logging dependencies, the container can be associated to a pod again:

I've used following dependency version:

"com.google.cloud" % "google-cloud-logging-logback" % "0.103.0-alpha"

[JoaoPPinto]

I tested this again today, and it seems that my resource labels are being correctly set now.
I did not follow any special procedure, just follow the instructions in the documentation and it worked oob.
Although now it seems that multi-line logs are being split into different entries.
Used version 0.103.0-alpha.

[jessewebb]

We tried upgrading to the latest version of the lib (0.103.0-alpha) and we were still experiencing this issue.

We decided to just switch our apps to use JSON logging instead to work around the problem.

To do this, we replaced the Google cloud logging dependency in our build.sbt files to use:

    "ch.qos.logback"            % "logback-classic"              % "1.2.3",
    "net.logstash.logback"      % "logstash-logback-encoder"     % "6.1",

And we also updated our logback.xml file to have the following config:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appender name="JSON-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="ASYNC-JSON-STDOUT" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="JSON-STDOUT"/>
    </appender>

    <root level="INFO">
        <appender-ref ref="ASYNC-JSON-STDOUT"/>
    </root>

</configuration>

Now the Log Viewer seems to show all of the correct labels for us.

[ohlen1]

I also added a comment today on closed issue #2912. But I figure it's better to use this issue that is still open.
Like I said in the other issue's thread: _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_

We are using the Spring Boot starter spring-cloud-gcp-starter-logging in version 1.1.2.RELEASE, which wraps google-cloud-logging-logback.

[ohlen1]

Tested to use google-cloud-logging-logback standalone, and not via spring-cloud-gcp-starter-logging, but unfortunately the namespace_id and container_name resource labels are still empty:

resource: {
  labels: {
   cluster_name: "payment-sandbox"    
   container_name: ""    
   instance_id: "3537624620997755422"    
   namespace_id: ""    
   pod_id: "iops-697c8cc7df-q8d9n"    
   project_id: "payment-project"    
   zone: "europe-west4-a"    
  }
  type: "container"   
 }

[ohlen1]

Obviously the namespace-id attribute is not registered as an attribute in the internal meta data server and, judging by the source, this seems to be the reason it is never set as a resource label(?):

curl "http://metadata.google.internal/computeMetadata/v1/instance/attributes/namespace-id" -H "Metadata-Flavor: Google"

= 404 Not found

curl "http://metadata.google.internal/computeMetadata/v1/instance/attributes/cluster-name" -H "Metadata-Flavor: Google"

= payment-cluster

curl "http://metadata.google.internal/computeMetadata/v1/instance/attributes/" -H "Metadata-Flavor: Google"

=

cluster-location
cluster-name
cluster-uid
configure-sh
created-by
disable-legacy-endpoints
enable-oslogin
gci-ensure-gke-docker
gci-update-strategy
google-compute-enable-pcid
instance-template
kube-env
kube-labels
kubelet-config
user-data

[codyoss]

Thanks for the report. I was able to reproduce this issue as well. The client library sources all of these field from one of two places. First is the metadata serve, which @ohlen1 points out does not have the information we need(container_name and namespace_id). The other place we can pull this metadata is from environment variables, sadly this does not have the information we need either.

At this time I don't think it is possible for the client library to source this information. The appropriate next step would be to open up a feature request to GKE via the Google Cloud Issue Tracker.. We would need them to either expose these bits of information from either the metadata server or environment variables by default to the pods. Once this is done we can open up another issue to properly source in the fields from the client lib.

@jessewebb Could I ask you to raise that issue if it is not too much trouble?

[codyoss]

As I said above this is not an issue the client libraries can currently solve. I have opened up a feature request to GKE. If that feature is implemented, we can work on exposing these values.

Issue is now being tracked via: https://issuetracker.google.com/145009094