@@ -6,15 +6,16 @@ package proxy
66import (
77 "encoding/json"
88 "fmt"
9+ "math/rand"
910 "net"
11+ "pika/codis/v2/pkg/utils"
1012 "strconv"
1113 "strings"
1214 "sync"
1315 "time"
1416
1517 "pika/codis/v2/pkg/models"
1618 "pika/codis/v2/pkg/proxy/redis"
17- "pika/codis/v2/pkg/utils"
1819 "pika/codis/v2/pkg/utils/errors"
1920 "pika/codis/v2/pkg/utils/log"
2021 "pika/codis/v2/pkg/utils/sync2/atomic2"
@@ -48,6 +49,8 @@ type Session struct {
4849 config * Config
4950 proxy * Proxy
5051
52+ rand * rand.Rand
53+
5154 authorized bool
5255}
5356
@@ -79,6 +82,7 @@ func NewSession(sock net.Conn, config *Config, proxy *Proxy) *Session {
7982 CreateUnix : time .Now ().Unix (),
8083 }
8184 s .stats .opmap = make (map [string ]* opStats , 16 )
85+ s .rand = rand .New (rand .NewSource (time .Now ().UnixNano ()))
8286 log .Infof ("session [%p] create: %s" , s , s )
8387 return s
8488}
@@ -237,31 +241,35 @@ func (s *Session) loopWriter(tasks *RequestChan) (err error) {
237241 } else {
238242 s .incrOpStats (r , resp .Type )
239243 }
244+
240245 nowTime := time .Now ().UnixNano ()
241246 duration := int64 ((nowTime - r .ReceiveTime ) / 1e3 )
242247 s .updateMaxDelay (duration , r )
243248 if fflush {
244249 s .flushOpStats (false )
245250 }
246- if duration >= s .config .SlowlogLogSlowerThan {
247- SlowCmdCount .Incr () // Atomic global variable, increment by 1 when slow log occurs.
248- //client -> proxy -> server -> porxy -> client
249- //Record the waiting time from receiving the request from the client to sending it to the backend server
250- //the waiting time from sending the request to the backend server to receiving the response from the server
251- //the waiting time from receiving the server response to sending it to the client
252- var d0 , d1 , d2 int64 = - 1 , - 1 , - 1
253- if r .SendToServerTime > 0 {
254- d0 = int64 ((r .SendToServerTime - r .ReceiveTime ) / 1e3 )
255- }
256- if r .SendToServerTime > 0 && r .ReceiveFromServerTime > 0 {
257- d1 = int64 ((r .ReceiveFromServerTime - r .SendToServerTime ) / 1e3 )
258- }
259- if r .ReceiveFromServerTime > 0 {
260- d2 = int64 ((nowTime - r .ReceiveFromServerTime ) / 1e3 )
251+ if s .config .SlowlogLogSlowerThan >= 0 {
252+ if duration >= s .config .SlowlogLogSlowerThan {
253+ SlowCmdCount .Incr ()
254+ // Atomic global variable, increment by 1 when slow log occurs.
255+ //client -> proxy -> server -> porxy -> client
256+ //Record the waiting time from receiving the request from the client to sending it to the backend server
257+ //the waiting time from sending the request to the backend server to receiving the response from the server
258+ //the waiting time from receiving the server response to sending it to the client
259+ var d0 , d1 , d2 int64 = - 1 , - 1 , - 1
260+ if r .SendToServerTime > 0 {
261+ d0 = int64 ((r .SendToServerTime - r .ReceiveTime ) / 1e3 )
262+ }
263+ if r .SendToServerTime > 0 && r .ReceiveFromServerTime > 0 {
264+ d1 = int64 ((r .ReceiveFromServerTime - r .SendToServerTime ) / 1e3 )
265+ }
266+ if r .ReceiveFromServerTime > 0 {
267+ d2 = int64 ((nowTime - r .ReceiveFromServerTime ) / 1e3 )
268+ }
269+ index := getWholeCmd (r .Multi , cmd )
270+ log .Errorf ("%s remote:%s, start_time(us):%d, duration(us): [%d, %d, %d], %d, tasksLen:%d, command:[%s]." ,
271+ 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 ]))
261272 }
262- index := getWholeCmd (r .Multi , cmd )
263- log .Errorf ("%s remote:%s, start_time(us):%d, duration(us): [%d, %d, %d], %d, tasksLen:%d, command:[%s]." ,
264- 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 ]))
265273 }
266274 return nil
267275 })
@@ -681,32 +689,67 @@ func (s *Session) handleRequestSlotsMapping(r *Request, d *Router) error {
681689 }
682690}
683691
684- func (s * Session ) incrOpTotal () {
685- s .stats .total .Incr ()
686- }
692+ func (s * Session ) getOpStats (opstr string , create bool ) * opStats {
693+ var (
694+ ok bool
695+ stat * opStats
696+ )
687697
688- func (s * Session ) getOpStats (opstr string ) * opStats {
689- e := s .stats .opmap [opstr ]
690- if e == nil {
691- e = & opStats {opstr : opstr }
692- s .stats .opmap [opstr ] = e
698+ func () {
699+ cmdstats .opmapLock .RLock ()
700+ defer cmdstats .opmapLock .RUnlock ()
701+ stat , ok = s .stats .opmap [opstr ]
702+ }()
703+ if (ok && stat != nil ) || ! create {
704+ return stat
705+ }
706+ cmdstats .opmapLock .Lock ()
707+ defer cmdstats .opmapLock .Unlock ()
708+ stat , ok = cmdstats .opmap [opstr ]
709+ if ok && stat != nil {
710+ return stat
711+ }
712+ stat = & opStats {opstr : opstr }
713+ for i := 0 ; i < IntervalNum ; i ++ {
714+ stat .delayInfo [i ] = & delayInfo {interval : IntervalMark [i ]}
693715 }
694- return e
716+ s .stats .opmap [opstr ] = stat
717+
718+ return stat
695719}
696720
697721func (s * Session ) incrOpStats (r * Request , t redis.RespType ) {
698- e := s .getOpStats (r .OpStr )
699- e .calls .Incr ()
700- e .nsecs .Add (time .Now ().UnixNano () - r .ReceiveTime )
722+ if r == nil {
723+ return
724+ }
725+ responseTime := time .Now ().UnixNano () - r .ReceiveTime
726+ var (
727+ ok bool
728+ stat * opStats
729+ )
730+ stat , ok = s .stats .opmap [r .OpStr ]
731+ if ! ok || stat == nil {
732+ stat = getOpStats (r .OpStr , true )
733+ s .stats .opmap [r .OpStr ] = stat
734+ }
735+ stat .incrOpStats (responseTime , redis .RespType (t ))
736+ stat , ok = s .stats .opmap ["ALL" ]
737+ if ! ok || stat == nil {
738+ stat = getOpStats ("ALL" , true )
739+ s .stats .opmap ["ALL" ] = stat
740+ }
741+ stat .incrOpStats (responseTime , redis .RespType (t ))
742+ stat .calls .Incr ()
743+ stat .nsecs .Add (time .Now ().UnixNano () - r .ReceiveTime )
701744 switch t {
702745 case redis .TypeError :
703- e . redis . errors . Incr ()
746+ incrOpRedisErrors ()
704747 }
705748}
706749
707750func (s * Session ) incrOpFails (r * Request , err error ) error {
708751 if r != nil {
709- e := s .getOpStats (r .OpStr )
752+ e := s .getOpStats (r .OpStr , true )
710753 e .fails .Incr ()
711754 } else {
712755 s .stats .fails .Incr ()
@@ -781,7 +824,7 @@ func (s *Session) handlePConfig(r *Request) error {
781824}
782825
783826func (s * Session ) updateMaxDelay (duration int64 , r * Request ) {
784- e := s .getOpStats (r .OpStr ) // There is no race condition in the session
827+ e := s .getOpStats (r .OpStr , true ) // There is no race condition in the session
785828 if duration > e .maxDelay .Int64 () {
786829 e .maxDelay .Set (duration )
787830 }
0 commit comments