Skip to content

Misleading Error is logged #13746

@davidhadas

Description

@davidhadas

When a client abruptly closes a connection to a service, queue logs an error.

What version of Knative?

1.9

Expected Behavior

Debug log will be shown indicating a termination took place.
No Info, No Warning, No Error.

Actual Behavior

{"severity":"ERROR","timestamp":"2023-02-27T18:17:18.1904124Z","logger":"queueproxy","caller":"network/error_handler.go:33","
message":"error reverse proxying request; sockstat: sockets: used 591\nTCP: inuse 242 orphan 53 tw 15 alloc 2604 mem 503\nUDP: inuse 0 mem 8\nUDPLITE: inuse 0\nRAW: inuse 0\nFRAG: inuse 0 memory 0\n","commit":"a53136c-dirty","knative.dev/key":"default/testsrv-00003","knative.dev/pod":"testsrv-00003-deployment-54cb559948-6bjfx","error":"context canceled","stacktrace":"knative.dev/pkg/network.ErrorHandler.func1\n\tknative.dev/pkg@v0.0.0-20230215234751-2f55fe00c5a1/network/error_handler.go:33\nnet/http/httputil (*ReverseProxy).ServeHTTP\n\tnet/http/httputil/reverseproxy.go:315\nknative.dev/serving/pkg/queue (*appRequestMetricsHandler).ServeHTTP\n\tknative.dev/serving@v0.36.1-0.20230217163907-7aeb55d6418d/pkg/queue/request_metric.go:199\nknative.dev/serving/pkg/queue.ProxyHandler.func1\n\tknative.dev/serving@v0.36.1-0.20230217163907-7aeb55d6418d/pkg/queue/handler.go:76\nnet/http.HandlerFunc.ServeHTTP\n\tnet/http/server.go:2109\nknative.dev/serving/pkg/queue.ForwardedShimHandler.func1\n\tknative.dev/serving@v0.36.1-0.20230217163907-7aeb55d6418d/pkg/queue/forwarded_shim.go:54\nnet/http.HandlerFunc.ServeHTTP\n\tnet/http/server.go:2109\nknative.dev/serving/pkg/http/handler.(*timeoutHandler).ServeHTTP.func4\n\tknative.dev/serving@v0.36.1-0.20230217163907-7aeb55d6418d/pkg/http/handler/timeout.go:118"}

Steps to Reproduce the Problem

kn service create testsrv --image davidhadas/test-service --env SLEEP=3s --scale-min 1
wrk -t10 -c4000 -d2000s http://testsrv.default.127.0.0.1.sslip.io

Then ^C wrk.

Note: the testsrv service sleeps for SLEEP seconds on every request
Note: It probably can be reproduced with a much simpler setup using curl instead of wrk.

Metadata

Metadata

Assignees

No one assigned

    Labels

    kind/bugCategorizes issue or PR as related to a bug.triage/acceptedIssues which should be fixed (post-triage)

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions