文章目录
  1. 1. 问题背景
  2. 2. 版本
  3. 3. 产生原因
  4. 4. 重现步骤
  5. 5. 临时解决方案

问题背景

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

除 9411 端口外其他端口也有同样的问题。

版本

Jaeger 1.22

产生原因

查看日志发现有以下路径的请求:

1
/%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

这个请求来源我们公司的安全组扫描。这个请求导致了以下错误,日志:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
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).Serve
net/http/server.go:2969 +0x36c

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

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

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

重现步骤

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

1
2
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:

1
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

或者

1
--metrics-backend=expvar

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

文章目录
  1. 1. 问题背景
  2. 2. 版本
  3. 3. 产生原因
  4. 4. 重现步骤
  5. 5. 临时解决方案