Excessive logging from shim into containerd logs (with containerd 1.6.8+) including all ENV vars
Nobody has claimed this yet.
- Dominant language
- Go
- Stars
- 694
- Forks
- 304
- Avg merge
- 1d 19h
- Merged PRs (30d)
- 28
Description
Issue:
With the fix in containerd for (https://github.com/containerd/containerd/issues/6990), where shim logs was being redirected incorrectly to panic.log. All shim logs now on 1.6.8+ get redirected and goes correctly into containerd.log. But with just info level, all shim calls are being called with operation and detailed trace of parameters. This now caused the containerd.log to increase. and also with some operations like HcsCreateProcess, it prints all ENV vars which might include secrets.
Test (containerd 1.6.8 + shim v0.9.4):
Use normal log level for containerd, and test with a sample spec like the following:
cat sample_secret.yaml
apiVersion: v1
kind: Secret
metadata:
name: mysecret
type: Opaque
stringData:
SECRET_KEY: "THE_ACTUAL_SECRET"
cat test-one-pod.yaml
apiVersion: v1
kind: Pod
metadata:
name: test
spec:
nodeSelector:
kubernetes.io/os: windows
containers:
- name: test
env:
- name: THE_SECRET_VALUE
valueFrom:
secretKeyRef:
name: mysecret
key: SECRET_KEY
command:
- powershell.exe
- -command
- "while ($true) { Start-Sleep -Seconds 10; Get-Date; }"
image: mcr.microsoft.com/windows/servercore:ltsc2019
PS C:\etc\kubernetes\logs> Get-Content -Last 1000 .\containerd.log | Select-String "ACTUAL"
time="2022-09-29T22:49:57.167533600Z" level=info msg=Span duration=312.406ms endTime="2022-09-29 22:49:57.4799396
+0000 GMT m=+79.298800901" name=HcsCreateProcess parentSpanID=0000000000000000
processParameters="{\"CommandLine\":\"powershell.exe -command \\\"while ($true) { Start-Sleep -Seconds 10; Get-Date; }\
\\"\",\"WorkingDirectory\":\"C:\\\\\",\"Environment\":{\"KUBERNETES_PORT\":\"tcp://10.28.16.1:443\",\"KUBERNETES_PORT_4
43_TCP\":\"tcp://10.28.16.1:443\",\"KUBERNETES_PORT_443_TCP_ADDR\":\"10.28.16.1\",\"KUBERNETES_PORT_443_TCP_PORT\":\"44
3\",\"KUBERNETES_PORT_443_TCP_PROTO\":\"tcp\",\"KUBERNETES_SERVICE_HOST\":\"10.28.16.1\",\"KUBERNETES_SERVICE_PORT\":\"
443\",\"KUBERNETES_SERVICE_PORT_HTTPS\":\"443\",\"THE_SECRET_VALUE\":\"THE_ACTUAL_SECRET\"},\"CreateStdOutPipe\":true,\
"CreateStdErrPipe\":true}" spanID=7f329befb4853b75 startTime="2022-09-29 22:49:57.1675336 +0000 GMT m=+78.986394901"
traceID=bf394e65462626d4cdfdc7e92d914bf2
Also, many repeatable debug logs are coming from the shim, like the following:
{"level":"debug","msg":"Substituting RuntimeConfig DNS Nameservers: [10.28.16.10]","time":"2022-09-29T21:47:33Z"}
{"level":"debug","msg":"Substituting RuntimeConfig DNS Search: [kube-system.svc.cluster.local svc.cluster.local cluster.local c.ibrahimab-gke-dev.internal google.internal]","time":"2022-09-29T21:47:33Z"}
{"level":"debug","msg":"Substituting RuntimeConfig DNS Options: [ndots:5]","time":"2022-09-29T21:47:33Z"}
{"level":"debug","msg":"Parsing port mappings from []","time":"2022-09-29T21:47:33Z"}
{"level":"debug","msg":"[cni-net] Found network 17a89c98-c4a3-47b0-a96d-75eb3920ebe7 with subnet [{{10.32.1.0 ffffff00} 10.32.1.1 []}].","time":"2022-09-29T21:47:33Z"}
- Is there a way to control the amount, as seems debug info is written by default?
- Also, for operations like HcsCreateProcess where span for the method is logged, can we control what included or keep it on a higher level with less details (by default)?
Contributor guide
No contributing guide indexed for this repository
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Reproduce the logging with containerd 1.6.8+, shim v0.9.4, and the sample Secret and pod manifests. Start by tracing shim logging around HcsCreateProcess and the repeated DNS, port-mapping, and CNI messages. Done means verbosity is controllable and normal logging no longer exposes environment secrets or excessive operation details.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- operating-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Active
- Clarity
- Mostly clear
- Newbie friendliness
- 48/100