Skip to content

Commit 5fdb472

Browse files
wangshao1wangshaoyi
wangshao1
and
wangshaoyi
authored
fix slowcmd log duration error with batch command && add proxy metrics && reset proxy tp duration in 1 min (OpenAtomFoundation#3044)
Co-authored-by: wangshaoyi <[email protected]>
1 parent 1668357 commit 5fdb472

10 files changed

Lines changed: 186 additions & 68 deletions

File tree

‎codis/go.mod‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ replace google.golang.org/grpc => google.golang.org/grpc v1.29.0
88

99
require (
1010
github.com/BurntSushi/toml v0.3.1
11+
github.com/HdrHistogram/hdrhistogram-go v1.1.2
1112
github.com/docopt/docopt-go v0.0.0-20180111231733-ee0de3bc6815
1213
github.com/emirpasic/gods v1.18.1
1314
github.com/garyburd/redigo v1.6.4

‎codis/go.sum‎

Lines changed: 52 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,26 +1,41 @@
1+
dmitri.shuralyov.com/gpu/mtl v0.0.0-20190408044501-666a987793e9/go.mod h1:H6x//7gZCb22OMCxBHrMx7a5I7Hp++hsVxbQ4BYO7hU=
12
github.com/BurntSushi/toml v0.3.1 h1:WXkYYl6Yr3qBf1K79EBnL4mak0OimBfB0XUf9Vl28OQ=
23
github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03qcyfWMU=
4+
github.com/BurntSushi/xgb v0.0.0-20160522181843-27f122750802/go.mod h1:IVnqGOEym/WlBOVXweHU+Q+/VP0lqqI8lqeDx9IjBqo=
5+
github.com/HdrHistogram/hdrhistogram-go v1.1.2 h1:5IcZpTvzydCQeHzK4Ef/D5rrSqwxob0t8PQPMybUNFM=
6+
github.com/HdrHistogram/hdrhistogram-go v1.1.2/go.mod h1:yDgFjdqOqDEKOvasDdhWNXYg9BVp4O+o5f6V/ehm6Oo=
7+
github.com/ajstarks/svgo v0.0.0-20180226025133-644b8db467af/go.mod h1:K08gAheRH3/J6wwsYMMT4xOr94bZjxIelGM0+d/wbFw=
38
github.com/codegangsta/inject v0.0.0-20150114235600-33e0aa1cb7c0 h1:sDMmm+q/3+BukdIpxwO365v/Rbspp2Nt5XntgQRXq8Q=
49
github.com/codegangsta/inject v0.0.0-20150114235600-33e0aa1cb7c0/go.mod h1:4Zcjuz89kmFXt9morQgcfYZAYZ5n8WHjt81YYWIwtTM=
510
github.com/coreos/go-semver v0.3.1 h1:yi21YpKnrx1gt5R+la8n5WgS0kCrsPp33dmEyHReZr4=
611
github.com/coreos/go-semver v0.3.1/go.mod h1:irMmmIw/7yzSRPWryHsK7EYSg09caPQL03VsM8rvUec=
12+
github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E=
713
github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
814
github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
915
github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
1016
github.com/docopt/docopt-go v0.0.0-20180111231733-ee0de3bc6815 h1:bWDMxwH3px2JBh6AyO7hdCn/PkvCZXii8TGj7sbtEbQ=
1117
github.com/docopt/docopt-go v0.0.0-20180111231733-ee0de3bc6815/go.mod h1:WwZ+bS3ebgob9U8Nd0kOddGdZWjyMGR8Wziv+TBNwSE=
1218
github.com/emirpasic/gods v1.18.1 h1:FXtiHYKDGKCW2KzwZKx0iC0PQmdlorYgdFG9jPXJ1Bc=
1319
github.com/emirpasic/gods v1.18.1/go.mod h1:8tpGGwCnJ5H4r6BWwaV6OrWmMoPhUl5jm/FMNAnJvWQ=
20+
github.com/fogleman/gg v1.2.1-0.20190220221249-0403632d5b90/go.mod h1:R/bRT+9gY/C5z7JzPU0zXsXHKM4/ayA+zqcVNZzPa1k=
1421
github.com/garyburd/redigo v1.6.4 h1:LFu2R3+ZOPgSMWMOL+saa/zXRjw0ID2G8FepO53BGlg=
1522
github.com/garyburd/redigo v1.6.4/go.mod h1:rTb6epsqigu3kYKBnaF028A7Tf/Aw5s0cqA47doKKqw=
23+
github.com/go-gl/glfw v0.0.0-20190409004039-e6da0acd62b1/go.mod h1:vR7hzQXu2zJy9AVAgeJqvqgH9Q5CA+iKCZ2gyEVpxRU=
1624
github.com/go-martini/martini v0.0.0-20170121215854-22fa46961aab h1:xveKWz2iaueeTaUgdetzel+U7exyigDYBryyVfV/rZk=
1725
github.com/go-martini/martini v0.0.0-20170121215854-22fa46961aab/go.mod h1:/P9AEU963A2AYjv4d1V5eVL1CQbEJq6aCNHDDjibzu8=
26+
github.com/golang/freetype v0.0.0-20170609003504-e2365dfdc4a0/go.mod h1:E/TSTwGwJL78qG/PmXZO1EjYhfJinVAhrmmHX6Z8B9k=
27+
github.com/google/go-cmp v0.5.4/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
1828
github.com/google/go-cmp v0.5.7 h1:81/ik6ipDQS2aGcBfIN5dHDB36BwrStyeAQquSYCV4o=
1929
github.com/google/gofuzz v1.0.0/go.mod h1:dBl0BpW6vV/+mYPU4Po3pmUjxk6FQPldtuIdl/M65Eg=
2030
github.com/influxdata/influxdb v1.11.0 h1:0X+ZsbcOWc6AEi5MHee9BYqXCKmz8IZsljrRYjmV8Qg=
2131
github.com/influxdata/influxdb v1.11.0/go.mod h1:V93tJcidY0Zh0LtSONZWnXXGDyt20dtVf+Ddp4EnhaA=
2232
github.com/json-iterator/go v1.1.12 h1:PV8peI4a0ysnczrg+LtxykD8LfKY9ML6u2jnxaEnrnM=
2333
github.com/json-iterator/go v1.1.12/go.mod h1:e30LSqwooZae/UwlEbR2852Gd8hjQvJoHmT4TnhNGBo=
34+
github.com/jung-kurt/gofpdf v1.0.3-0.20190309125859-24315acbbda5/go.mod h1:7Id9E/uU8ce6rXgefFLlgrJj/GYY22cpxn+r32jIOes=
35+
github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ=
36+
github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
37+
github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY=
38+
github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE=
2439
github.com/martini-contrib/binding v0.0.0-20160701174519-05d3e151b6cf h1:6YSkbjZVghliN7zwJC/U3QQG+OVXOrij3qQ8sxfPIMg=
2540
github.com/martini-contrib/binding v0.0.0-20160701174519-05d3e151b6cf/go.mod h1:aCggxkm1kuifLw/LEQUbz91N1ZM6PhV7dz03xPQduZA=
2641
github.com/martini-contrib/gzip v0.0.0-20151124214156-6c035326b43f h1:wVDxEVZP1eiPIlHVaafUAEUDtyl6ytjHv3egJVbyfOk=
@@ -32,6 +47,8 @@ github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd h1:TRLaZ9cD/w
3247
github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd/go.mod h1:6dJC0mAP4ikYIbvyc7fijjWJddQyLn8Ig3JB5CqoB9Q=
3348
github.com/modern-go/reflect2 v1.0.2 h1:xBagoLtFs94CBntxluKeaWgTMpvLxC4ur3nMaC9Gz0M=
3449
github.com/modern-go/reflect2 v1.0.2/go.mod h1:yWuevngMOJpCy52FWWMvUC8ws7m/LJsjYzDa0/r8luk=
50+
github.com/niemeyer/pretty v0.0.0-20200227124842-a10e7caefd8e h1:fD57ERR4JtEqsWbfPhv4DMiApHyliiK5xCTNVSPiaAs=
51+
github.com/niemeyer/pretty v0.0.0-20200227124842-a10e7caefd8e/go.mod h1:zD1mROLANZcx1PVRCS0qkT7pwLkGfwJo4zjcN/Tysno=
3552
github.com/oxtoacart/bpool v0.0.0-20190530202638-03653db5a59c h1:rp5dCmg/yLR3mgFuSOe4oEnDDmGLROTvMragMUXpTQw=
3653
github.com/oxtoacart/bpool v0.0.0-20190530202638-03653db5a59c/go.mod h1:X07ZCGwUbLaax7L0S3Tw4hpejzu63ZrrQiUe6W0hcy0=
3754
github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
@@ -43,6 +60,7 @@ github.com/spinlock/jemalloc-go v0.0.0-20201010032256-e81523fb8524/go.mod h1:A/i
4360
github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
4461
github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw=
4562
github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
63+
github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
4664
github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
4765
github.com/stretchr/testify v1.8.0 h1:pSgiaMZlXftHpm5L7V1+rVB+AZJydKsMxsQBIJw4PKk=
4866
github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU=
@@ -52,12 +70,45 @@ go.etcd.io/etcd/client/pkg/v3 v3.5.7 h1:y3kf5Gbp4e4q7egZdn5T7W9TSHUvkClN6u+Rq9mE
5270
go.etcd.io/etcd/client/pkg/v3 v3.5.7/go.mod h1:o0Abi1MK86iad3YrWhgUsbGx1pmTS+hrORWc2CamuhY=
5371
go.etcd.io/etcd/client/v2 v2.305.7 h1:AELPkjNR3/igjbO7CjyF1fPuVPjrblliiKj+Y6xSGOU=
5472
go.etcd.io/etcd/client/v2 v2.305.7/go.mod h1:GQGT5Z3TBuAQGvgPfhR7VPySu/SudxmEkRq9BgzFU6s=
73+
golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
74+
golang.org/x/crypto v0.0.0-20190510104115-cbcb75029529/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI=
75+
golang.org/x/exp v0.0.0-20180321215751-8460e604b9de/go.mod h1:CJ0aWSM057203Lf6IL+f9T1iT9GByDxfZKAQTCR3kQA=
76+
golang.org/x/exp v0.0.0-20180807140117-3d87b88a115f/go.mod h1:CJ0aWSM057203Lf6IL+f9T1iT9GByDxfZKAQTCR3kQA=
77+
golang.org/x/exp v0.0.0-20190125153040-c74c464bbbf2/go.mod h1:CJ0aWSM057203Lf6IL+f9T1iT9GByDxfZKAQTCR3kQA=
78+
golang.org/x/exp v0.0.0-20190306152737-a1d7652674e8/go.mod h1:CJ0aWSM057203Lf6IL+f9T1iT9GByDxfZKAQTCR3kQA=
79+
golang.org/x/exp v0.0.0-20191030013958-a1ab85dbe136/go.mod h1:JXzH8nQsPlswgeRAPE3MuO9GYsAcnJvJ4vnMwN/5qkY=
80+
golang.org/x/exp v0.0.0-20211216164055-b2b84827b756 h1:/5Bs7sWi0i3rOVO5KnM55OwugpsD4bRW1zywKoZjbkI=
81+
golang.org/x/image v0.0.0-20180708004352-c73c2afc3b81/go.mod h1:ux5Hcp/YLpHSI86hEcLt0YII63i6oz57MZXIpbrjZUs=
82+
golang.org/x/image v0.0.0-20190227222117-0694c2d4d067/go.mod h1:kZ7UVZpmo3dzQBMxlp+ypCbDeSB+sBbTgSJuh5dn5js=
83+
golang.org/x/image v0.0.0-20190802002840-cff245a6509b/go.mod h1:FeLwcggjj3mMvU+oOTbSwawSJRM1uh48EjtB4UJZlP0=
84+
golang.org/x/mobile v0.0.0-20190719004257-d2bd2a29d028/go.mod h1:E/iHnbuqvinMTCcRqshq8CkpyQDoeVncDDYHnLhea+o=
85+
golang.org/x/mod v0.1.0/go.mod h1:0QHyrYULN0/3qlju5TqG8bIK38QM8yzMo5ekMj3DlcY=
86+
golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
87+
golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s=
5588
golang.org/x/net v0.17.0 h1:pVaXccu2ozPjCXewfr1S7xza/zcXTity9cCdXQYSjIM=
5689
golang.org/x/net v0.17.0/go.mod h1:NxSsAGuq816PNPmqtQdLE42eU2Fs7NoRIZrHJAlaCOE=
90+
golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
91+
golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
92+
golang.org/x/sys v0.0.0-20190312061237-fead79001313/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
93+
golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
94+
golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
95+
golang.org/x/tools v0.0.0-20180525024113-a5b4c53f6e8b/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
96+
golang.org/x/tools v0.0.0-20190206041539-40960b6deb8e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
97+
golang.org/x/tools v0.0.0-20191012152004-8de300cfc20a/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
98+
golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
99+
golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
100+
golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
101+
gonum.org/v1/gonum v0.0.0-20180816165407-929014505bf4/go.mod h1:Y+Yx5eoAFn32cQvJDxZx5Dpnq+c3wtXuadVZAcxbbBo=
102+
gonum.org/v1/gonum v0.8.2/go.mod h1:oe/vMfY3deqTw+1EZJhuvEW2iwGF1bW9wwu7XCu0+v0=
103+
gonum.org/v1/gonum v0.11.0 h1:f1IJhK4Km5tBJmaiJXtk/PkL4cdVX6J+tGiM187uT5E=
104+
gonum.org/v1/netlib v0.0.0-20190313105609-8cb42192e0e0/go.mod h1:wa6Ws7BG/ESfp6dHfk7C6KdzKA7wR7u/rKwOGE66zvw=
105+
gonum.org/v1/plot v0.0.0-20190515093506-e2840ee46a6b/go.mod h1:Wt8AAjI+ypCyYX3nZBvf6cAIx93T+c/OS2HFAYskSZc=
57106
gopkg.in/alexcesaro/statsd.v2 v2.0.0 h1:FXkZSCZIH17vLCO5sO2UucTHsH9pc+17F6pl3JVCwMc=
58107
gopkg.in/alexcesaro/statsd.v2 v2.0.0/go.mod h1:i0ubccKGzBVNBpdGV5MocxyA/XlLUJzA7SLonnE4drU=
59-
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=
60108
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
109+
gopkg.in/check.v1 v1.0.0-20200227125254-8fa46927fb4f h1:BLraFXnmrev5lT+xlilqcH8XK9/i0At2xKjWk4p6zsU=
110+
gopkg.in/check.v1 v1.0.0-20200227125254-8fa46927fb4f/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
61111
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
62112
gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
63113
gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
114+
rsc.io/pdf v0.1.1/go.mod h1:n8OzWcQ6Sp37PL01nO98y4iUCRdTGarVfzxY20ICaU4=

‎codis/pkg/proxy/backend.go‎

Lines changed: 5 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@ import (
1010
"strconv"
1111
"strings"
1212
"sync"
13+
"sync/atomic"
1314
"time"
1415

1516
"pika/codis/v2/pkg/proxy/redis"
@@ -84,14 +85,14 @@ func (bc *BackendConn) KeepAlive() bool {
8485
}
8586
switch bc.state.Int64() {
8687
default:
87-
m := &Request{}
88+
m := &Request{ReceiveTime: new(int64), SendToPikaTime: new(int64), ReceiveFromPikaTime: new(int64)}
8889
m.Multi = []*redis.Resp{
8990
redis.NewBulkBytes([]byte("PING")),
9091
}
9192
bc.PushBack(m)
9293

9394
case stateDataStale:
94-
m := &Request{}
95+
m := &Request{ReceiveTime: new(int64), SendToPikaTime: new(int64), ReceiveFromPikaTime: new(int64)}
9596
m.Multi = []*redis.Resp{
9697
redis.NewBulkBytes([]byte("INFO")),
9798
}
@@ -284,7 +285,7 @@ func (bc *BackendConn) loopReader(tasks <-chan *Request, c *redis.Conn, round in
284285
}()
285286
for r := range tasks {
286287
resp, err := c.Decode()
287-
r.ReceiveFromServerTime = time.Now().UnixNano()
288+
atomic.StoreInt64(r.ReceiveFromPikaTime, time.Now().UnixNano())
288289
if err != nil {
289290
return bc.setResponse(r, nil, fmt.Errorf("backend conn failure, %s", err))
290291
}
@@ -364,7 +365,7 @@ func (bc *BackendConn) loopWriter(round int) (err error) {
364365
} else {
365366
tasks <- r
366367
}
367-
r.SendToServerTime = time.Now().UnixNano()
368+
atomic.CompareAndSwapInt64(r.SendToPikaTime, 0, time.Now().UnixNano())
368369
}
369370
return nil
370371
}

‎codis/pkg/proxy/request.go‎

Lines changed: 9 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ package proxy
55

66
import (
77
"sync"
8+
"sync/atomic"
89
"unsafe"
910

1011
"pika/codis/v2/pkg/proxy/redis"
@@ -21,11 +22,11 @@ type Request struct {
2122
OpStr string
2223
OpFlag
2324

24-
Database int32
25-
ReceiveTime int64
26-
SendToServerTime int64
27-
ReceiveFromServerTime int64
28-
TasksLen int64
25+
Database int32
26+
ReceiveTime *int64
27+
SendToPikaTime *int64
28+
ReceiveFromPikaTime *int64
29+
TasksLen int64
2930

3031
*redis.Resp
3132
Err error
@@ -47,14 +48,16 @@ func (r *Request) MakeSubRequest(n int) []Request {
4748
x.Broken = r.Broken
4849
x.Database = r.Database
4950
x.ReceiveTime = r.ReceiveTime
51+
x.SendToPikaTime = r.SendToPikaTime
52+
x.ReceiveFromPikaTime = r.ReceiveFromPikaTime
5053
}
5154
return sub
5255
}
5356

5457
const GOLDEN_RATIO_PRIME_32 = 0x9e370001
5558

5659
func (r *Request) Seed16() uint {
57-
h32 := uint32(r.ReceiveTime) + uint32(uintptr(unsafe.Pointer(r)))
60+
h32 := uint32(atomic.LoadInt64(r.ReceiveTime)) + uint32(uintptr(unsafe.Pointer(r)))
5861
h32 *= GOLDEN_RATIO_PRIME_32
5962
return uint(h32 >> 16)
6063
}

‎codis/pkg/proxy/session.go‎

Lines changed: 27 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -10,13 +10,16 @@ import (
1010
"strconv"
1111
"strings"
1212
"sync"
13+
"sync/atomic"
1314
"time"
1415

1516
"pika/codis/v2/pkg/models"
1617
"pika/codis/v2/pkg/proxy/redis"
1718
"pika/codis/v2/pkg/utils/errors"
1819
"pika/codis/v2/pkg/utils/log"
1920
"pika/codis/v2/pkg/utils/sync2/atomic2"
21+
22+
"github.com/HdrHistogram/hdrhistogram-go"
2023
)
2124

2225
type Session struct {
@@ -184,7 +187,10 @@ func (s *Session) loopReader(tasks *RequestChan, d *Router) (err error) {
184187
r.Multi = multi
185188
r.Batch = &sync.WaitGroup{}
186189
r.Database = s.database
187-
r.ReceiveTime = start.UnixNano()
190+
r.ReceiveTime = new(int64)
191+
r.SendToPikaTime = new(int64)
192+
r.ReceiveFromPikaTime = new(int64)
193+
*r.ReceiveTime = time.Now().UnixNano()
188194
r.TasksLen = int64(tasksLen)
189195

190196
if err := s.handleRequest(r, d); err != nil {
@@ -230,14 +236,16 @@ func (s *Session) loopWriter(tasks *RequestChan) (err error) {
230236
if err := p.Encode(resp); err != nil {
231237
return s.incrOpFails(r, err)
232238
}
239+
nowTime := time.Now().UnixNano()
240+
receiveTime := atomic.LoadInt64(r.ReceiveTime)
241+
duration := int64((nowTime - receiveTime) / 1e3)
242+
233243
fflush := tasks.IsEmpty()
234244
if err := p.Flush(fflush); err != nil {
235245
return s.incrOpFails(r, err)
236246
} else {
237-
s.incrOpStats(r, resp.Type)
247+
s.incrOpStats(r, resp.Type, duration)
238248
}
239-
nowTime := time.Now().UnixNano()
240-
duration := int64((nowTime - r.ReceiveTime) / 1e3)
241249
s.updateMaxDelay(duration, r)
242250
if fflush {
243251
s.flushOpStats(false)
@@ -248,19 +256,22 @@ func (s *Session) loopWriter(tasks *RequestChan) (err error) {
248256
//Record the waiting time from receiving the request from the client to sending it to the backend server
249257
//the waiting time from sending the request to the backend server to receiving the response from the server
250258
//the waiting time from receiving the server response to sending it to the client
259+
sendToPikaTime := atomic.LoadInt64(r.SendToPikaTime)
260+
receiveFromPikaTime := atomic.LoadInt64(r.ReceiveFromPikaTime)
261+
251262
var d0, d1, d2 int64 = -1, -1, -1
252-
if r.SendToServerTime > 0 {
253-
d0 = int64((r.SendToServerTime - r.ReceiveTime) / 1e3)
263+
if sendToPikaTime > 0 {
264+
d0 = int64((sendToPikaTime - receiveTime) / 1e3)
254265
}
255-
if r.SendToServerTime > 0 && r.ReceiveFromServerTime > 0 {
256-
d1 = int64((r.ReceiveFromServerTime - r.SendToServerTime) / 1e3)
266+
if sendToPikaTime > 0 && receiveFromPikaTime > 0 {
267+
d1 = int64((receiveFromPikaTime - sendToPikaTime) / 1e3)
257268
}
258-
if r.ReceiveFromServerTime > 0 {
259-
d2 = int64((nowTime - r.ReceiveFromServerTime) / 1e3)
269+
if receiveFromPikaTime > 0 {
270+
d2 = int64((nowTime - receiveFromPikaTime) / 1e3)
260271
}
261272
index := getWholeCmd(r.Multi, cmd)
262-
log.Errorf("%s remote:%s, start_time(us):%d, duration(us): [%d, %d, %d], %d, tasksLen:%d, command:[%s].",
263-
time.Unix(r.ReceiveTime/1e9, 0).Format("2006-01-02 15:04:05"), s.Conn.RemoteAddr(), r.ReceiveTime/1e3, d0, d1, d2, duration, r.TasksLen, string(cmd[:index]))
273+
log.Warnf("remote:%s, duration(us): [%d, %d, %d], %d, tasksLen:%d, command:[%s].",
274+
s.Conn.RemoteAddr(), d0, d1, d2, duration, r.TasksLen, string(cmd[:index]))
264275
}
265276
return nil
266277
})
@@ -669,16 +680,17 @@ func (s *Session) incrOpTotal() {
669680
func (s *Session) getOpStats(opstr string) *opStats {
670681
e := s.stats.opmap[opstr]
671682
if e == nil {
672-
e = &opStats{opstr: opstr}
683+
e = &opStats{opstr: opstr, hist: hdrhistogram.New(1, 10000, 3)}
673684
s.stats.opmap[opstr] = e
674685
}
675686
return e
676687
}
677688

678-
func (s *Session) incrOpStats(r *Request, t redis.RespType) {
689+
func (s *Session) incrOpStats(r *Request, t redis.RespType, duration int64) {
679690
e := s.getOpStats(r.OpStr)
680691
e.calls.Incr()
681-
e.nsecs.Add(time.Now().UnixNano() - r.ReceiveTime)
692+
e.nsecs.Add(duration)
693+
e.hist.RecordValue(duration / 1e3)
682694
switch t {
683695
case redis.TypeError:
684696
e.redis.errors.Incr()

‎codis/pkg/proxy/stats.go‎

Lines changed: 15 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,8 @@ import (
1212

1313
"pika/codis/v2/pkg/utils"
1414
"pika/codis/v2/pkg/utils/sync2/atomic2"
15+
16+
hdrhistogram "github.com/HdrHistogram/hdrhistogram-go"
1517
)
1618

1719
var (
@@ -28,6 +30,7 @@ type opStats struct {
2830
errors atomic2.Int64
2931
}
3032
maxDelay atomic2.Int64
33+
hist *hdrhistogram.Histogram
3134
}
3235

3336
func (s *opStats) OpStats() *OpStats {
@@ -37,6 +40,9 @@ func (s *opStats) OpStats() *OpStats {
3740
Usecs: s.nsecs.Int64() / 1e3,
3841
Fails: s.fails.Int64(),
3942
MaxDelay: s.maxDelay.Int64(),
43+
TP99: s.hist.ValueAtPercentile(99),
44+
TP999: s.hist.ValueAtPercentile(99.9),
45+
TP9999: s.hist.ValueAtPercentile(99.99),
4046
}
4147
if o.Calls != 0 {
4248
o.UsecsPercall = o.Usecs / o.Calls
@@ -53,6 +59,9 @@ type OpStats struct {
5359
Fails int64 `json:"fails"`
5460
RedisErrType int64 `json:"redis_errtype"`
5561
MaxDelay int64 `json:"max_delay"`
62+
TP99 int64 `json:"tp99"`
63+
TP999 int64 `json:"tp999"`
64+
TP9999 int64 `json:"tp9999"`
5665
}
5766

5867
var cmdstats struct {
@@ -87,13 +96,14 @@ func init() {
8796
for {
8897
refreshPeriod := RefreshPeriod.Int64()
8998
if refreshPeriod == 0 {
90-
time.Sleep(15 * time.Second)
99+
time.Sleep(1 * time.Minute)
91100
} else {
92101
time.Sleep(time.Duration(refreshPeriod))
93102
}
94103

95104
for _, s := range cmdstats.opmap {
96105
s.maxDelay.Set(0)
106+
s.hist.Reset()
97107
}
98108
}
99109
}()
@@ -127,7 +137,7 @@ func getOpStats(opstr string, create bool) *opStats {
127137
cmdstats.Lock()
128138
s = cmdstats.opmap[opstr]
129139
if s == nil {
130-
s = &opStats{opstr: opstr}
140+
s = &opStats{opstr: opstr, hist: hdrhistogram.New(1, 10000, 3)}
131141
cmdstats.opmap[opstr] = s
132142
}
133143
cmdstats.Unlock()
@@ -191,6 +201,9 @@ func incrOpStats(e *opStats) {
191201
cmdstats.redis.errors.Add(n)
192202
}
193203

204+
s.hist.Merge(e.hist)
205+
e.hist.Reset()
206+
194207
/**
195208
Each session refreshes its own saved metrics, and there is a race condition at this time.
196209
Use the CAS method to update.

‎codis/pkg/utils/log/log.go‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -138,7 +138,7 @@ func New(writer io.Writer, prefix string) *Logger {
138138
}
139139
return &Logger{
140140
out: out,
141-
log: log.New(out, prefix, LstdFlags|Lshortfile),
141+
log: log.New(out, prefix, LstdFlags|Lshortfile|Lmicroseconds),
142142
level: LevelAll,
143143
trace: LevelError,
144144
}

‎tools/pika_exporter/discovery/codis_dashboard.go‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -50,6 +50,9 @@ type CmdInfo struct {
5050
Usecs_percall int64 `json:"usecs_percall"`
5151
Fails int64 `json:"fails"`
5252
MaxDelay int64 `json:"max_delay"`
53+
TP99 int64 `json:"tp99"`
54+
TP909 int64 `json:"tp999"`
55+
TP9999 int64 `json:"tp9999"`
5356
}
5457

5558
type ProxyOpsInfo struct {

0 commit comments

Comments
 (0)