Google-cloud-dotnet: Google.Cloud.Logging.Log4Net.GoogleStackdriverAppender resourceType = k8s_container

[shawn-mccorkell]

Environment details

• OS: Windows Server 2016 Node Pool host running in GKE
• .NET version: 4.6.1
• Package name and version: Google.Cloud.Logging.Log4Net 3.2.0

We have the logging working using the the markup below in an ASP.NET MVC 4.6.1 project located in the web.config

Issue

1. If we let resource type be auto detected, we see the logs, but they are categorized as resource.type="gce_instance"
2. If we set disableResourceTypeDetection=true and set resource.type="k8s_container" and populate all required resource type labels, nothing is logged.

Is there any way to get the resource type set correctly to resource.type="k8s_container" in order to have the logs show up with our other logs being collected which are running in our linux node pool? Or is GKE not supported currently for this Log4Net appender?

Current Markup

Thanks!

[shawn-mccorkell]

log4net-appender.txt

[jskeet]

I will look at this on Monday. There's a corresponding Gax issue but I can't remember the details offhand.

[shawn-mccorkell]

Thanks @jskeet

[jskeet]

I'm slightly confused - your point 2 says that nothing is logged, but you later say you do want that resource type set. Given this issue I'd actually expect the resource type to be "gke_container".

But if the autodetected resource type is gce_instance, that's a separate issue.

Could you print out the results of Google.Api.Gax.Platform.Instance() somewhere in some debug logs that you can access? (If you write to the console, you may well fine those appear... or just deploy a web app and make that the result of the request.)

Basically we need to approach this in two different aspects:

• The expected resource type details
• Autodetection of the platform

It's possible that it's not detecting being on GKE due to permissions; this is an area which I believe has changed a bit over the years. I'll try creating a service myself on a test cluster and see what happens.

[jskeet]

Whoops - I didn't review that issue carefully enough, which does say: "Those are for legacy Stackdriver; to support Stackdriver Kubernetes Engine Monitoring we need to use "k8s_container" instead."

... and looking at the code, that is what it should provide. Testing now to see what happens on my k8s cluster.

[jskeet]

Okay, now deployed to the k8s cluster, and this is what my monitored resource looks like:

{
   "type":"k8s_container",
   "labels":{
      "project_id":"[redacted]",
      "cluster_name":"[redacted]",
      "namespace_name":"default",
      "pod_name":"[redacted]",
      "container_name":"",
      "location":"us-central1-a"
   }
}

and the result from Platform.Instance():

[GKE: ProjectId='[redacted]', ClusterLocation='us-central1-a', ClusterName='[redacted]', HostName='[redacted]', InstanceId='[redacted]', Zone='projects/[redacted]/zones/us-central1-a', NamespaceId='default', PodId='[redacted]', ContainerName='']

So that all looks to be working okay. I haven't tried the Log4Net integration, but that can come next.

[shawn-mccorkell]

We are running the website Windows Node pool in GKE cluster, I am thinking it may be Windows vs Linux specific.

Our website is not .NET Core and running ASP.NET MVC 4.6.1, so we need to run on a Windows host.

Agreed I doubt it is a specific Log4Net issue, more of overall inability to classify the resource type automatically and I am wondering if it is a Windows only issue.

I will try to print some of the results you asked for later today or first thing tomorrow.

[jskeet]

Ah, that's interesting. Yes, I wouldn't be surprised if this were an issue on Windows GKE - if you look at the GKE platform details loading code it assumes Unix-style paths... I've no idea what the equivalent of those would be on Windows.

Apologies for not noticing before that this was Windows, when you'd included that in the original comment.

I'll file an issue in the GAX repo for platform detection on Windows GKE - so that leaves the issue of not seeing logs when you are specifying the monitored resource explicitly. Could you give more details on that? When you say "nothing is logged" is there absolutely no sign of the logs anywhere? Could you share an example of how you're populating the monitored resource, so I could try to reproduce in that way?

[shawn-mccorkell]

Thanks,

When I set disableResourceTypeDetection=false an manually populate the resource type (k8s_container) and and associated labels for this type, nothing shows up in my logs under Kubernetes Container, also I the logs don't show up in any other other types. See the attachement above for the code I have commented out in the web.config which I was testing with when I set disableResourceTypeDetection=true. I will post back with the output I am getting for Google.Api.Gax.Platform.Instance() tonight. We are only using this log4net appender in this once specific container that must run on Windows, all of our other containers run on Linux nodes and the logs are all picked up automatically and classified as k8s_container resource type.

[jskeet]

Okay. I'll try to reproduce this tomorrow, first logging with resource detection (in my Linux cluster) and then with the hard-coded ones.

I don't use log4net very often so I may go down a few cul-de-sacs first I'm afraid, but hopefully we'll get there.

[shawn-mccorkell]

So, I tested a few scenarios. I have a feeling this is Windows node pool related, when running in GKE. All our other containers running on Linux nodes inside GKE just log without issue or any extra configuration.

I can see the pod logs for our Windows containers when they start up logging as resource type = k8s_pod

With the following in web.config

log4net>
    <appender name="CloudLogger" type="Google.Cloud.Logging.Log4Net.GoogleStackdriverAppender,Google.Cloud.Logging.Log4Net">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%-4timestamp [%thread] %-5level %logger %ndc - %message" />
      </layout>
      <logId value="stdout" />
      <!-- No buffering, send to GCP right away -->
      <maxMemoryCount value="1" />
      <!-- Defaults to false. Setting this to true disables automatic resourceType setting based on platform detection. -->
    </appender>
    <root>
      <level value="ALL" />
      <appender-ref ref="CloudLogger" />
    </root>
  </log4net>

it produces this log

{
  "textPayload": "14507 [19] DEBUG PS.[redacted].Web.Mvc.WebApiConfig (null) - [GCE: ProjectId='[redacted]', InstanceId='[redacted]', ZoneName='projects/[redacted]/zones/northamerica-northeast1-a']",
  "insertId": "[redacted]",
  "resource": {
    "type": "gce_instance",
    "labels": {
      "instance_id": "[redacted]",
      "project_id": "[redacted]",
      "zone": "northamerica-northeast1-a"
    }
  },
  "timestamp": "2020-11-30T20:09:33.092290600Z",
  "severity": "DEBUG",
  "logName": "projects/[redacted]/logs/stdout",
  "receiveTimestamp": "2020-11-30T20:09:34.068950912Z"
}

Then, I tried to set resource type manually like this

<log4net>
    <appender name="CloudLogger" type="Google.Cloud.Logging.Log4Net.GoogleStackdriverAppender,Google.Cloud.Logging.Log4Net">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%-4timestamp [%thread] %-5level %logger %ndc - %message" />
      </layout>
      <logId value="stdout" />
      <!-- No buffering, send to GCP right away -->
      <maxMemoryCount value="1" />
      <!-- Defaults to false. Setting this to true disables automatic resourceType setting based on platform detection. -->
      <disableResourceTypeDetection value="true" />
      <!-- Allows the Monitored resources resource type to be specified; must be set to an entry on the Monitored Resource List. If unset, the default value depends on the detected platform: -->
      <resourceType value="k8s_container" />
      <resourceLabel>
        <key value="namespace_name" />
        <value value="frontend" />
      </resourceLabel>
      <resourceLabel>
        <key value="cluster_name" />
        <value value="[redacted]" />
      </resourceLabel>
      <resourceLabel>
        <key value="project_id" />
        <value value="[redacted]" />
      </resourceLabel>
      <resourceLabel>
        <key value="location" />
        <value value="northamerica-northeast1-a-dev" />
      </resourceLabel>
    </appender>
    <root>
      <level value="ALL" />
      <appender-ref ref="CloudLogger" />
    </root>
  </log4net>

When ever I try to manually specify the correct resource type "k8s_container" and set disableResourceTypeDetection=true, nothing is ever logged.

Also, I would like to disable local buffering completely and send each log directly to GCP Logging, right now I have maxMemoryCount = 1, but is there a way to disable local buffering completely?

[jskeet]

(As an aside, in GitHub issues, if you put code/xml/json etc blocks in triple-backtick fences, it makes them much easier to read. I've edited your comment above just in terms of that. I'm about to try to reproduce the issue.

Please could we keep this issue to just the resource type? It's already been about platform detection and resource type handling - I don't want to introduce a third aspect. Please file a separate issue about buffering. (I don't know the answer offhand.)

[shawn-mccorkell]

Sounds good, I think the main issue here is that the resource type is not being detected properly, I would prefer that fix then having to specific manually.

Interested to know if it detects on Linux, possible Windows GKE only issue.

[jskeet]

Okay, update... on my Linux cluster, the container_name label is not detected, but the monitored resource otherwise matches the one written by stdout.

I have not yet managed to get anything written with the log4net provider, but I have managed to write log entries directly with the raw API client. Unfortunately log4net is enough of a black box that it's very hard to work out what's going on.

I'm not going to be able to spend much more time on this today - I started work about 7 hours ago, and haven't spent any time on my main task at the moment, due to trying to diagnose other issues. (Not just this one.)

I'm not expecting the result of this immediate investigation to be a fix for Windows GKE detection, btw. My expected order of getting things working is:

• Log4Net using resource detection on GKE Linux
• Log4Net using manually-specified resources on GKE Linux
• Log4Net using manually-specified resources on GKE Windows
• Automatic resource detection on GKE Windows

To set expectations (given the rest of my working year) I don't expect to have a released version of GAX with the Windows fix until at least January.

[jskeet]

Okay, some progress. It turns out that log4net 2.0.11 has a bug that stops it from working properly on Linux. Once I'd upgraded to log4net 2.0.12, I was able to log with a directly-obtained ILog.

Both automatic and manual resource specification worked fine - but I'd initially got - and _ mixed up in the cluster name in manual specification, which made it look like nothing was being logged. Please check your config really, really carefully. I'd suggest adding the container_name label too. Oh, and setting the logId to log4net makes it easier to separate log4net output from true stdout.

Note that your config doesn't include projectId - I'd advise you to specify that explicitly to start with, just to avoid issues.

Initially I saw warnings due to the maxMemoryCount being set to 1. I need to look more closely into what that does, but I've currently got it set to 10.

[jskeet]

In terms of the buffering - this isn't a buffer that waits until it's full before logging. It's a buffer so that log entries can still be written while the logging RPC is taking place. The RPC happens in the background, to avoid slowing down your application, but they're still written as soon as they can be, while sticking to one RPC in flight at a time. So I think you can just remove your maxMemoryCount configuration - it should still log immediately.

I've filed two GAX issues for resource name detection:

• GKE on Windows
• container_name label

At that point I've diagnosed as far as I can, I believe.

I still don't know why your code isn't working with manual resource specification, but I'd suggest next steps of:

• Removing maxMemoryCount
• Specifying the container_name
• Specifying the projectId element
• Using a distinctive value for logId

Please let me know when you've had a chance to test that.

[shawn-mccorkell]

Awesome, thanks for all your work on this, I will try your suggestions

[shawn-mccorkell]

I reverted back to all the suggestions you posted above and switched my log to log4net to make it easier to find, see config below.

The container name is still not showing up, probably related to the GAX detection on Windows in GKE. My logs are showing up under VM Instance and the text payload below.

I think once the GAX detection issues are fixed all will work as expected.

Thanks again for all your help, we can close this issue if you like.

```

{
textPayload: "25863 [10] DEBUG [redacted].Mvc.WebApiConfig (null) - Hello World - Debug"
insertId: "59b8892c-b334-4eca-a36c-948a8671cf71:0"
resource: {
type: "gce_instance"
labels: {
zone: "northamerica-northeast1-a"
project_id: "[redacted]"
instance_id: "1025619367608917769"
}
}
timestamp: "2020-12-01T22:26:05.933952800Z"
severity: "DEBUG"
logName: "projects/[redacted]/logs/log4net"
receiveTimestamp: "2020-12-01T22:26:08.853355704Z"
}
```

[jskeet]

Great - that's how I'd expect without resource detection. I would expect it to all be fine with explicit resource specification though. Will close this now, but please subscribe to the two issues linked above to follow their progress :)

[jskeet]

Oh, and I think you can remove the remaining resourceLabel bits from your XML - those are only used if either you've disabled resource detection, or it doesn't detect anything at all. (So if you've just included it for local debug for example, that's fine.)