Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Packaged Traefik 2.9.4 has incorrect access logs #7301

Closed
taoyouh opened this issue Apr 18, 2023 · 2 comments
Closed

Packaged Traefik 2.9.4 has incorrect access logs #7301

taoyouh opened this issue Apr 18, 2023 · 2 comments
Assignees
@brandond @VestigeJ
Labels
area/packaged-components
Milestone
v1.27.2+k3s1

Comments

@taoyouh
Copy link

taoyouh commented Apr 18, 2023

Environmental Info:
K3s Version:

k3s version v1.26.3+k3s1 (01ea3ff)
go version go1.19.7

Node(s) CPU architecture, OS, and Version:

Linux ecs-wulanchabu-1 5.4.0-146-generic #163-Ubuntu SMP Fri Mar 17 18:26:02 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

Cluster Configuration:

Single node. 1 server.

Describe the bug:
The access logs of Traefik (the packaged 2.9.4 version) do not have all status codes recorded correctly. Some status codes are recorded as 0. Traefik maintainers said they had a bug before 2.9.5 and suggested to try 2.9.10 (see issue). My try of 2.9.10 seemed to be good. k3s should update the packaged traefik version soon.

Steps To Reproduce:

  • Installed K3s:
curl -sfL https://rancher-mirror.rancher.cn/k3s/k3s-install.sh | INSTALL_K3S_MIRROR=cn sh -s - --cluster-cidr=xxx --service-cidr=xxx --flannel-ipv6-masq
  • Enabled Traefik access log by adding this file in manifest:
apiVersion: helm.cattle.io/v1
kind: HelmChartConfig
metadata:
  name: traefik
  namespace: kube-system
spec:
  valuesContent: |-
    service:
      spec:
        externalTrafficPolicy: Local
    logs:
      access:
        enabled: true
  • Waited for many requests to come in (e.g. the internal "ping" request) and checked Traefik access log:
sudo kubectl logs -l app.kubernetes.io/name=traefik -n kube-system

Expected behavior:
The access log should record the status codes:

{IP address hidden} - - [18/Apr/2023:02:51:04 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 173 "ping@internal" "-" 0ms
{IP address hidden} - - [18/Apr/2023:02:51:04 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 172 "ping@internal" "-" 0ms

Actual behavior:
Some log lines has 0 status codes:

{IP address hidden} - - [15/Apr/2023:08:27:57 +0000] "GET /ping HTTP/1.1" 0 0 "-" "-" 69237 "ping@internal" "-" 0ms

Additional context / logs:

Tried to update traefik to 2.9.10 by changing the manifest above to:

apiVersion: helm.cattle.io/v1
kind: HelmChartConfig
metadata:
  name: traefik
  namespace: kube-system
spec:
  valuesContent: |-
    image:
      registry: docker.io
      name: traefik
      tag: 2.9.10
    service:
      spec:
        externalTrafficPolicy: Local
    logs:
      access:
        enabled: true

The access logs seemed correct.
@brandond
Copy link
Member

Thanks for the report. We'll likely bump it as part of our next release cycle.

@brandond brandond added this to the v1.26.5+k3s1 milestone Apr 18, 2023
@brandond brandond moved this to Next Up in K3s Development Apr 18, 2023
This was referenced Apr 19, 2023
Merged
Merged
Merged
@brandond brandond self-assigned this Apr 19, 2023
@brandond brandond moved this from Next Up to Peer Review in K3s Development Apr 19, 2023
@caroline-suse-rancher caroline-suse-rancher moved this from Peer Review to To Test in K3s Development May 8, 2023
@brandond brandond modified the milestones: v1.26.5+k3s1, v1.27.2+k3s1 May 9, 2023
This was referenced May 9, 2023
Closed
Closed
Closed
@VestigeJ VestigeJ assigned VestigeJ and unassigned bguzman-3pillar May 11, 2023
@VestigeJ
Copy link

This issue was not reproducible in my standalone deployment but I was able to confirm the newer image versions used. I think we can just treat this as a validation for the version bump.

COMMIT=8f450bafe1cad0e962e521d56eb74a38a73722c7

$ kg pod/traefik-899bbd849-v4gpb -o yaml -n kube-system | grep -i image

    image: rancher/mirrored-library-traefik:2.9.10
    imagePullPolicy: IfNotPresent
    image: docker.io/rancher/mirrored-library-traefik:2.9.10
    imageID: docker.io/rancher/mirrored-library-traefik@sha256:aaec134463b277ca7aa4f88807c8b67f2ec05d92a8f0432c0540b7ecc8fe724a

$ k logs -l app.kubernetes.io/name=traefik -n kube-system

10.42.0.1 - - [11/May/2023:18:11:50 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 21 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:11:50 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 22 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:00 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 23 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:00 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 24 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:10 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 25 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:10 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 26 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:20 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 27 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:20 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 28 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:30 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 30 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:30 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 29 "ping@internal" "-" 0ms

I did not observe the same behavior from the initial issue on v1.27.1+k3s1 with the listed Traefik version. Tried to reproduce on v1.26 instead

$ kg pod/traefik-fb68c966d-7njrg -o yaml -n kube-system | grep -i image

    image: rancher/mirrored-library-traefik:2.9.4
    imagePullPolicy: IfNotPresent
    image: docker.io/rancher/mirrored-library-traefik:2.9.4
    imageID: docker.io/rancher/mirrored-library-traefik@sha256:0842af6afcdf4305d17e862bad4eaf379d0817c987eedabeaff334e2273459c1

$ k logs -l app.kubernetes.io/name=traefik -n kube-system

10.42.0.1 - - [11/May/2023:18:11:57 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 24 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:11:57 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 25 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:07 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 26 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:07 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 27 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:17 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 28 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:17 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 29 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:27 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 30 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:27 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 31 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:37 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 32 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:12:37 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 33 "ping@internal" "-" 0ms
ec2-user@ip-172-31-22-28:~$ k3s -v
k3s version v1.27.1+k3s1 (bc5b42c2)
go version go1.20.3

v1.26.4+k3s1 did not show the missing status codes

$ kg pod/traefik-6b695786fd-xpxb8 -o yaml -n kube-system | grep -i image

    image: rancher/mirrored-library-traefik:2.9.4
    imagePullPolicy: IfNotPresent
    image: docker.io/rancher/mirrored-library-traefik:2.9.4
    imageID: docker.io/rancher/mirrored-library-traefik@sha256:0842af6afcdf4305d17e862bad4eaf379d0817c987eedabeaff334e2273459c1

$ k logs -l app.kubernetes.io/name=traefik -n kube-system

10.42.0.1 - - [11/May/2023:18:19:52 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 24 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:19:52 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 25 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:20:02 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 26 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:20:02 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 27 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:20:12 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 28 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:20:12 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 29 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:20:22 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 30 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:20:22 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 31 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:20:32 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 32 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:20:32 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 33 "ping@internal" "-" 0ms


$ k3s -v

k3s version v1.26.4+k3s1 (8d0255a)
go version go1.19.8


I was not able to reproduce this across these versions 

$ k apply -f enable_traefik_log.yaml

helmchartconfig.helm.cattle.io/traefik created


$ kgp -A

NAMESPACE NAME READY STATUS RESTARTS AGE
kube-system coredns-7c444649cb-g4gtm 1/1 Running 0 100s
kube-system helm-install-traefik-8c884 0/1 Completed 0 59s
kube-system helm-install-traefik-crd-lbsxc 0/1 Completed 0 101s
kube-system local-path-provisioner-5d56847996-dpdsh 1/1 Running 0 100s
kube-system metrics-server-7b67f64457-brm8w 1/1 Running 0 100s
kube-system svclb-traefik-818ec1dd-8nzrk 2/2 Running 0 53s
kube-system traefik-6b695786fd-lm9br 1/1 Running 0 57s


$ kg pod/traefik-6b695786fd-lm9br -o yaml -n kube-system | grep -i image

image: rancher/mirrored-library-traefik:2.9.4
imagePullPolicy: IfNotPresent
image: docker.io/rancher/mirrored-library-traefik:2.9.4
imageID: docker.io/rancher/mirrored-library-traefik@sha256:0842af6afcdf4305d17e862bad4eaf379d0817c987eedabeaff334e2273459c1


$ k logs -l app.kubernetes.io/name=traefik -n kube-system

10.42.0.1 - - [11/May/2023:18:23:28 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 7 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:23:28 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 8 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:23:38 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 9 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:23:38 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 10 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:23:48 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 11 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:23:48 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 12 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:23:58 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 13 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:23:58 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 14 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:24:08 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 16 "ping@internal" "-" 0ms
10.42.0.1 - - [11/May/2023:18:24:08 +0000] "GET /ping HTTP/1.1" 200 2 "-" "-" 15 "ping@internal" "-" 0ms


$ k3s -v

k3s version v1.26.3+k3s1 (01ea3ff)
go version go1.19.7

@github-project-automation github-project-automation bot moved this from To Test to Done Issue in K3s Development May 11, 2023
@brandond brandond mentioned this issue Jun 7, 2023
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@brandond brandond

@VestigeJ VestigeJ

Labels
area/packaged-components
Projects
K3s Development
Archived in project
Milestone
v1.27.2+k3s1
Development

No branches or pull requests
4 participants
@brandond @VestigeJ @taoyouh @bguzman-3pillar