Prometheus 导致 Jaeger API 请求超时 timeout 的故障

问题背景

使用 Jaeger 的 9411 端口（用于兼容 Zipkin 的端口）提交调用链的 span 信息，Jaeger 服务运行一段时候后，9411 端口上的请求就会全部超时，必须重启后才能恢复。

同样的问题后来我也尝试了其他端口，也有同样的问题。

版本

Jaeger 1.22

产生原因

查看日志发现有来源下面路径的请求：

/%C0%AE%C0%AE/%C0%AE%C0%AE/%C0%AE%C0%AE/%C0%AE%C0%AE/%C0%AE%C0%AE/%C0%AE%C0%AE/%C0%AE%C0%AE/%C0%AE%C0%AE/%C0%AE%C0%AE/%C0%AE%C0%AE/etc/profile

这个请求来源我们这边的安全组扫描。这个请求导致了以下错误：

2021/04/18 04:10:51 http: panic serving xx.xx.xx.xx:xxxx: label value "/\xc0\xae\xc0\xae/\xc0\xae\xc0\xae/\xc0\xae\xc0\xae/\xc0\xae\xc0\xae/\xc0\xae\xc0\xae/\xc0\xae\xc0\xae/\xc0\xae\xc0\xae/\xc0\xae\xc0\xae/\xc0\xae\xc0\xae/\xc0\xae\xc0\xae/etc/profile" is not valid UTF-8
goroutine 35495 [running]:
net/http.(*conn).serve.func1(0xc0004a2640)net/http/server.go:1801 +0x147
panic(0x1392360, 0xc00093cae0)runtime/panic.go:975 +0x47a
github.com/prometheus/client_golang/prometheus.(*HistogramVec).WithLabelValues(0xc000182e28, 0xc000947560, 0x3, 0x3, 0xc000947500, 0xc000947560)github.com/prometheus/client_golang@v1.5.1/prometheus/histogram.go:489 +0xda
github.com/uber/jaeger-lib/metrics/prometheus.(*Factory).Timer(0xc00044a140, 0x15b70ed, 0x15, 0xc0009474d0, 0x15bbfcd, 0x19, 0x0, 0x0, 0x0, 0x1512b80, ...)github.com/uber/jaeger-lib@v2.4.0+incompatible/metrics/prometheus/factory.go:181 +0x2ce
github.com/uber/jaeger-lib/metrics/fork.(*Factory).Timer(0xc0001934a0, 0x15b70ed, 0x15, 0xc0009474d0, 0x15bbfcd, 0x19, 0x0, 0x0, 0x0, 0xc0005299f5, ...)github.com/uber/jaeger-lib@v2.4.0+incompatible/metrics/fork/fork.go:48 +0x65
github.com/jaegertracing/jaeger/pkg/httpmetrics.buildTimer(...)github.com/jaegertracing/jaeger/pkg/httpmetrics/metrics.go:111
github.com/jaegertracing/jaeger/pkg/httpmetrics.(*requestDurations).record(0xc000535e60, 0xc000042240, 0x3, 0xc0004a1580, 0x3e, 0xc0002bde6d, 0x3, 0x40b0)github.com/jaegertracing/jaeger/pkg/httpmetrics/metrics.go:101 +0x465
github.com/jaegertracing/jaeger/pkg/httpmetrics.Wrap.func1(0x1e1c2c0, 0xc0009447e0, 0xc000937000)github.com/jaegertracing/jaeger/pkg/httpmetrics/metrics.go:63 +0x1fe
net/http.HandlerFunc.ServeHTTP(0xc00000cf60, 0x1e1c2c0, 0xc0009447e0, 0xc000937000)net/http/server.go:2042 +0x44
github.com/rs/cors.(*Cors).Handler.func1(0x1e1c2c0, 0xc0009447e0, 0xc000937000)github.com/rs/cors@v1.7.0/cors.go:219 +0x1b9
net/http.HandlerFunc.ServeHTTP(0xc00000cf80, 0x1e1c2c0, 0xc0009447e0, 0xc000937000)net/http/server.go:2042 +0x44
net/http.serverHandler.ServeHTTP(0xc0002a0460, 0x1e1c2c0, 0xc0009447e0, 0xc000937000)net/http/server.go:2843 +0xa3
net/http.(*conn).serve(0xc0004a2640, 0x1e225c0, 0xc000125140)net/http/server.go:1925 +0x8ad
created by net/http.(*Server).Servenet/http/server.go:2969 +0x36c

这个错误一旦出现，就会导致所有的其他请求全部超时，只有重启才能恢复。

从日志上看，这个问题貌似和 Prometheus 监控有关。由于 URL 路径比较特殊，导致没办法转换成 Prometheus 的 Label。

当然是 Jaeger 本身的 BUG，即时这个请求出错也不应该影响到其他请求。

重现步骤

下面是一个简单的重现流程：

docker run -d -e COLLECTOR_ZIPKIN_HOST_PORT=:9411 -p 5775:5775/udp -p 6831:6831/udp -p 6832:6832/udp -p 5778:5778 -p 16686:16686 -p 14268:14268 -p 14250:14250 -p 9411:9411 jaegertracing/all-in-one:1.22
curl http://localhost:9411/%C0%AE%C0%AE

再次对 9411 端口进行其他请求，都会 timeout。

临时解决方案

在官方修复这个 BUG 前，临时解决方案是将监控设置为 expvar 来禁用 Prometheus：

docker run -d -e COLLECTOR_ZIPKIN_HOST_PORT=:9411 -e METRICS_BACKEND=expvar -p 5775:5775/udp -p 6831:6831/udp -p 6832:6832/udp -p 5778:5778 -p 16686:16686 -p 14268:14268 -p 14250:14250 -p 9411:9411 jaegertracing/all-in-one:1.22

或者

--metrics-backend=expvar

由于我对 Go 语言不熟悉自己没办法修复，已向官方提了 issue：
https://github.com/jaegertracing/jaeger/issues/2944