time="2019-10-09T16:58:41Z" level=info msg="Configuration loaded from file: /config/static_config.toml"
time="2019-10-09T16:58:41Z" level=info msg="Traefik version 2.0.0 built on 2019-09-16T17:35:17Z"
time="2019-10-09T16:58:41Z" level=debug msg="Static configuration loaded {\"global\":{},\"serversTransport\":{\"maxIdleConnsPerHost\":200},\"entryPoints\":{\"metrics\":{\"address\":\":8080\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":10000000000},\"respondingTimeouts\":{\"idleTimeout\":180000000000}},\"forwardedHeaders\":{}},\"traefik\":{\"address\":\":8000\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":10000000000},\"respondingTimeouts\":{\"idleTimeout\":180000000000}},\"forwardedHeaders\":{}},\"web\":{\"address\":\":80\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":10000000000},\"respondingTimeouts\":{\"idleTimeout\":180000000000}},\"forwardedHeaders\":{}},\"websecure\":{\"address\":\":443\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":10000000000},\"respondingTimeouts\":{\"idleTimeout\":180000000000}},\"forwardedHeaders\":{}}},\"providers\":{\"providersThrottleDuration\":2000000000,\"kubernetesCRD\":{\"namespaces\":[\"ai-core\",\"ai-voice\"]}},\"api\":{\"dashboard\":true},\"metrics\":{\"prometheus\":{\"buckets\":[0.1,0.3,1.2,5],\"addEntryPointsLabels\":true,\"addServicesLabels\":true,\"entryPoint\":\"metrics\"}},\"ping\":{\"entryPoint\":\"traefik\"},\"log\":{\"level\":\"DEBUG\",\"format\":\"common\"},\"accessLog\":{\"format\":\"common\",\"filters\":{},\"fields\":{\"defaultMode\":\"keep\",\"headers\":{\"defaultMode\":\"drop\"}}}}"
time="2019-10-09T16:58:41Z" level=info msg="\nStats collection is disabled.\nHelp us improve Traefik by turning this feature on :)\nMore details on: https://docs.traefik.io/v2.0/contributing/data-collection/\n"
time="2019-10-09T16:58:41Z" level=debug msg="Configured Prometheus metrics" metricsProviderName=prometheus
time="2019-10-09T16:58:41Z" level=debug msg="Creating middleware" middlewareName=metrics-entrypoint middlewareType=Metrics entryPointName=web
time="2019-10-09T16:58:41Z" level=debug msg="Creating middleware" entryPointName=websecure middlewareName=metrics-entrypoint middlewareType=Metrics
time="2019-10-09T16:58:41Z" level=debug msg="Creating middleware" entryPointName=metrics middlewareName=metrics-entrypoint middlewareType=Metrics
time="2019-10-09T16:58:41Z" level=debug msg="Creating middleware" middlewareType=Metrics entryPointName=traefik middlewareName=metrics-entrypoint
time="2019-10-09T16:58:41Z" level=debug msg="No default certificate, generating one"
time="2019-10-09T16:58:41Z" level=debug msg="Start TCP Server" entryPointName=metrics
time="2019-10-09T16:58:41Z" level=info msg="Starting provider aggregator.ProviderAggregator {}"
time="2019-10-09T16:58:41Z" level=debug msg="Start TCP Server" entryPointName=web
time="2019-10-09T16:58:41Z" level=info msg="Starting provider *crd.Provider {\"namespaces\":[\"ai-core\",\"ai-voice\"]}"
time="2019-10-09T16:58:41Z" level=debug msg="Using label selector: \"\"" providerName=kubernetescrd
time="2019-10-09T16:58:41Z" level=info msg="label selector is: \"\"" providerName=kubernetescrd
time="2019-10-09T16:58:41Z" level=info msg="Creating in-cluster Provider client" providerName=kubernetescrd
time="2019-10-09T16:58:41Z" level=debug msg="Start TCP Server" entryPointName=traefik
time="2019-10-09T16:58:41Z" level=debug msg="Start TCP Server" entryPointName=websecure
time="2019-10-09T16:58:44Z" level=debug msg="Configuration received from provider kubernetescrd: {\"http\":{\"routers\":{\"ai-voice-negar-service-ingress-route-b0b01ca74222b075860f\":{\"entryPoints\":[\"web\"],\"service\":\"ai-voice-negar-service-ingress-route-b0b01ca74222b075860f\",\"rule\":\"HeadersRegexp(`X-Forwarded-Host`, `/negar`)\"}},\"services\":{\"ai-voice-negar-service-ingress-route-b0b01ca74222b075860f\":{\"loadBalancer\":{\"servers\":[{\"url\":\"h2c://10.233.102.144:50051\"},{\"url\":\"h2c://10.233.89.2:50051\"}],\"passHostHeader\":true}}}},\"tcp\":{},\"tls\":{}}" providerName=kubernetescrd
time="2019-10-09T16:58:44Z" level=debug msg="Creating middleware" routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd entryPointName=web serviceName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f middlewareName=pipelining middlewareType=Pipelining
time="2019-10-09T16:58:44Z" level=debug msg="Creating middleware" entryPointName=web serviceName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f middlewareName=metrics-service middlewareType=Metrics routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd
time="2019-10-09T16:58:44Z" level=debug msg="Creating load-balancer" routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd entryPointName=web serviceName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f
time="2019-10-09T16:58:44Z" level=debug msg="Creating server 0 h2c://10.233.102.144:50051" serviceName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd entryPointName=web serverName=0
time="2019-10-09T16:58:44Z" level=debug msg="Creating server 1 h2c://10.233.89.2:50051" routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd entryPointName=web serviceName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f serverName=1
time="2019-10-09T16:58:44Z" level=debug msg="Added outgoing tracing middleware ai-voice-negar-service-ingress-route-b0b01ca74222b075860f" middlewareType=TracingForwarder entryPointName=web routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd middlewareName=tracing
time="2019-10-09T16:58:44Z" level=debug msg="Creating middleware" entryPointName=web middlewareName=traefik-internal-recovery middlewareType=Recovery
time="2019-10-09T16:58:44Z" level=debug msg="Creating middleware" middlewareType=Metrics entryPointName=metrics middlewareName=metrics-entrypoint
time="2019-10-09T16:58:44Z" level=debug msg="Creating middleware" middlewareName=metrics-entrypoint middlewareType=Metrics entryPointName=traefik
time="2019-10-09T16:58:44Z" level=debug msg="Creating middleware" entryPointName=web middlewareName=metrics-entrypoint middlewareType=Metrics
time="2019-10-09T16:58:44Z" level=debug msg="Creating middleware" middlewareType=Metrics entryPointName=websecure middlewareName=metrics-entrypoint
time="2019-10-09T16:58:44Z" level=debug msg="No default certificate, generating one"
time="2019-10-09T16:58:44Z" level=debug msg="Skipping Kubernetes event kind *v1.Secret" providerName=kubernetescrd
time="2019-10-09T16:58:44Z" level=debug msg="Configuration received from provider kubernetescrd: {\"http\":{\"routers\":{\"ai-voice-negar-service-ingress-route-b0b01ca74222b075860f\":{\"entryPoints\":[\"web\"],\"service\":\"ai-voice-negar-service-ingress-route-b0b01ca74222b075860f\",\"rule\":\"HeadersRegexp(`X-Forwarded-Host`, `/negar`)\"}},\"services\":{\"ai-voice-negar-service-ingress-route-b0b01ca74222b075860f\":{\"loadBalancer\":{\"servers\":[{\"url\":\"h2c://10.233.102.144:50051\"},{\"url\":\"h2c://10.233.89.2:50051\"}],\"passHostHeader\":true}}}},\"tcp\":{},\"tls\":{}}" providerName=kubernetescrd
time="2019-10-09T16:58:44Z" level=debug msg="Skipping Kubernetes event kind *v1.Endpoints" providerName=kubernetescrd
time="2019-10-09T16:58:46Z" level=debug msg="Creating middleware" entryPointName=web middlewareType=Pipelining middlewareName=pipelining routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd serviceName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f
time="2019-10-09T16:58:46Z" level=debug msg="Creating middleware" middlewareName=metrics-service middlewareType=Metrics entryPointName=web routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd serviceName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f
time="2019-10-09T16:58:46Z" level=debug msg="Creating load-balancer" entryPointName=web routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd serviceName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f
time="2019-10-09T16:58:46Z" level=debug msg="Creating server 0 h2c://10.233.102.144:50051" entryPointName=web routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd serviceName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f serverName=0
time="2019-10-09T16:58:46Z" level=debug msg="Creating server 1 h2c://10.233.89.2:50051" entryPointName=web routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd serviceName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f serverName=1
time="2019-10-09T16:58:46Z" level=debug msg="Added outgoing tracing middleware ai-voice-negar-service-ingress-route-b0b01ca74222b075860f" entryPointName=web routerName=ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd middlewareName=tracing middlewareType=TracingForwarder
time="2019-10-09T16:58:46Z" level=debug msg="Creating middleware" entryPointName=web middlewareName=traefik-internal-recovery middlewareType=Recovery
time="2019-10-09T16:58:46Z" level=debug msg="Creating middleware" middlewareName=metrics-entrypoint middlewareType=Metrics entryPointName=metrics
time="2019-10-09T16:58:46Z" level=debug msg="Creating middleware" middlewareName=metrics-entrypoint middlewareType=Metrics entryPointName=traefik
time="2019-10-09T16:58:46Z" level=debug msg="Creating middleware" middlewareType=Metrics entryPointName=web middlewareName=metrics-entrypoint
time="2019-10-09T16:58:46Z" level=debug msg="Creating middleware" middlewareName=metrics-entrypoint middlewareType=Metrics entryPointName=websecure
time="2019-10-09T16:58:46Z" level=debug msg="No default certificate, generating one"
time="2019-10-09T16:58:58Z" level=debug msg="vulcand/oxy/roundrobin/rr: begin ServeHttp on request" Request="{\"Method\":\"POST\",\"URL\":{\"Scheme\":\"\",\"Opaque\":\"\",\"User\":null,\"Host\":\"\",\"Path\":\"/cafebazaar.ai.speech.v1.Speech/Recognize\",\"RawPath\":\"\",\"ForceQuery\":false,\"RawQuery\":\"\",\"Fragment\":\"\"},\"Proto\":\"HTTP/2.0\",\"ProtoMajor\":2,\"ProtoMinor\":0,\"Header\":{\"Accept-Encoding\":[\"identity,gzip\"],\"Content-Type\":[\"application/grpc\"],\"Grpc-Accept-Encoding\":[\"identity,deflate,gzip\"],\"Te\":[\"trailers\"],\"User-Agent\":[\"grpc-python/1.24.1 grpc-c/8.0.0 (manylinux; chttp2; ganges)\"],\"X-Forwarded-Host\":[\"localhost:8001/negar\"],\"X-Forwarded-Port\":[\"8001/negar\"],\"X-Forwarded-Proto\":[\"http\"],\"X-Forwarded-Server\":[\"arrow-86d675ddf8-mzhfw\"],\"X-Real-Ip\":[\"127.0.0.1\"]},\"ContentLength\":-1,\"TransferEncoding\":null,\"Host\":\"localhost:8001/negar\",\"Form\":null,\"PostForm\":null,\"MultipartForm\":null,\"Trailer\":null,\"RemoteAddr\":\"127.0.0.1:38262\",\"RequestURI\":\"/cafebazaar.ai.speech.v1.Speech/Recognize\",\"TLS\":null}"
time="2019-10-09T16:58:58Z" level=debug msg="vulcand/oxy/roundrobin/rr: Forwarding this request to URL" ForwardURL="h2c://10.233.102.144:50051" Request="{\"Method\":\"POST\",\"URL\":{\"Scheme\":\"\",\"Opaque\":\"\",\"User\":null,\"Host\":\"\",\"Path\":\"/cafebazaar.ai.speech.v1.Speech/Recognize\",\"RawPath\":\"\",\"ForceQuery\":false,\"RawQuery\":\"\",\"Fragment\":\"\"},\"Proto\":\"HTTP/2.0\",\"ProtoMajor\":2,\"ProtoMinor\":0,\"Header\":{\"Accept-Encoding\":[\"identity,gzip\"],\"Content-Type\":[\"application/grpc\"],\"Grpc-Accept-Encoding\":[\"identity,deflate,gzip\"],\"Te\":[\"trailers\"],\"User-Agent\":[\"grpc-python/1.24.1 grpc-c/8.0.0 (manylinux; chttp2; ganges)\"],\"X-Forwarded-Host\":[\"localhost:8001/negar\"],\"X-Forwarded-Port\":[\"8001/negar\"],\"X-Forwarded-Proto\":[\"http\"],\"X-Forwarded-Server\":[\"arrow-86d675ddf8-mzhfw\"],\"X-Real-Ip\":[\"127.0.0.1\"]},\"ContentLength\":-1,\"TransferEncoding\":null,\"Host\":\"localhost:8001/negar\",\"Form\":null,\"PostForm\":null,\"MultipartForm\":null,\"Trailer\":null,\"RemoteAddr\":\"127.0.0.1:38262\",\"RequestURI\":\"/cafebazaar.ai.speech.v1.Speech/Recognize\",\"TLS\":null}"
127.0.0.1 - - [09/Oct/2019:16:58:58 +0000] "POST /package.Proto/MyRPC HTTP/2.0" 504 15 "-" "-" 1 "ai-voice-negar-service-ingress-route-b0b01ca74222b075860f@kubernetescrd" "h2c://10.233.102.144:50051" 130044ms
I see that the request is forwarded (or is trying to forward) to the service, but after that, it waits about 2 minutes and prints the last line.
I tried port-forwarding my gRPC service and I got results correctly. So my service works correctly. But here we have this problem.
Also in the client I received this:
grpc._channel._Rendezvous: <_Rendezvous of RPC that terminated with:
status = StatusCode.CANCELLED
details = "Received http2 header with status: 504"
debug_error_string = "{"created":"@1570640468.416648914","description":"Received http2 :status header with non-200 OK status","file":"src/core/ext/filters/http/client/http_client_filter.cc","file_line":122,"grpc_message":"Received http2 header with status: 504","grpc_status":1,"value":"504"}"
Maybe it helps.
Very thanks.