Skip to content

Commit 903e245

Browse files
YangruiEmmaYangruiEmma
committed
debug: add log for debug discovery
1 parent e95eee3 commit 903e245

7 files changed

Lines changed: 31 additions & 14 deletions

File tree

‎client/middlewares.go‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -95,6 +95,7 @@ func newResolveMWBuilder(lbf *lbcache.BalancerFactory) endpoint.MiddlewareBuilde
9595
if remote.GetInstance() != nil {
9696
return next(ctx, request, response)
9797
}
98+
klog.CtxErrorf(ctx, "KITEX-DEBUG: start get balancer")
9899
lb, err := lbf.Get(ctx, dest)
99100
if err != nil {
100101
return kerrors.ErrServiceDiscovery.WithCause(err)
@@ -108,10 +109,13 @@ func newResolveMWBuilder(lbf *lbcache.BalancerFactory) endpoint.MiddlewareBuilde
108109
default:
109110
}
110111

112+
klog.CtxErrorf(ctx, "KITEX-DEBUG: start get picker")
111113
// we always need to get a new picker every time, because when downstream update deployment,
112114
// we may get an old picker that include all outdated instances which will cause connect always failed.
113-
picker := lb.GetPicker()
115+
picker := lb.GetPicker(ctx)
116+
klog.CtxErrorf(ctx, "KITEX-DEBUG: start get instance")
114117
ins := picker.Next(ctx, request)
118+
klog.CtxErrorf(ctx, "KITEX-DEBUG: end get instance")
115119
if ins == nil {
116120
err = kerrors.ErrNoMoreInstance.WithCause(fmt.Errorf("last error: %w", lastErr))
117121
} else {

‎pkg/loadbalance/consist.go‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -312,7 +312,7 @@ func (cb *consistBalancer) AddToDaemon() {
312312
}
313313

314314
// GetPicker implements the Loadbalancer interface.
315-
func (cb *consistBalancer) GetPicker(e discovery.Result) Picker {
315+
func (cb *consistBalancer) GetPicker(ctx context.Context, e discovery.Result) Picker {
316316
var ci *consistInfo
317317
if e.Cacheable {
318318
cii, ok := cb.cachedConsistInfo.Load(e.CacheKey)

‎pkg/loadbalance/lbcache/cache.go‎

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -163,7 +163,9 @@ func (b *BalancerFactory) Get(ctx context.Context, target rpcinfo.EndpointInfo)
163163
return val.(*Balancer), nil
164164
}
165165
val, err, _ := b.sfg.Do(desc, func() (interface{}, error) {
166+
klog.CtxErrorf(ctx, "KITEX-DEBUG: start Resolve, desc=%s", desc)
166167
res, err := b.resolver.Resolve(ctx, desc)
168+
klog.CtxErrorf(ctx, "KITEX-DEBUG: end Resolve, desc=%s", desc)
167169
if err != nil {
168170
return nil, err
169171
}
@@ -173,8 +175,11 @@ func (b *BalancerFactory) Get(ctx context.Context, target rpcinfo.EndpointInfo)
173175
target: desc,
174176
}
175177
bl.res.Store(res)
178+
klog.CtxErrorf(ctx, "KITEX-DEBUG: start getSharedTicker")
176179
bl.sharedTicker = getSharedTicker(bl, b.opts.RefreshInterval)
180+
klog.CtxErrorf(ctx, "KITEX-DEBUG: end getSharedTicker")
177181
b.cache.Store(desc, bl)
182+
klog.CtxErrorf(ctx, "KITEX-DEBUG: put balancer[desc=%s] into cache", desc)
178183
return bl, nil
179184
})
180185
if err != nil {
@@ -224,10 +229,10 @@ func (bl *Balancer) GetResult() (res discovery.Result, ok bool) {
224229
}
225230

226231
// GetPicker equal to loadbalance.Balancer without pass discovery.Result, because we cache the result
227-
func (bl *Balancer) GetPicker() loadbalance.Picker {
232+
func (bl *Balancer) GetPicker(ctx context.Context) loadbalance.Picker {
228233
atomic.StoreInt32(&bl.expire, 0)
229234
res := bl.res.Load().(discovery.Result)
230-
return bl.b.balancer.GetPicker(res)
235+
return bl.b.balancer.GetPicker(ctx, res)
231236
}
232237

233238
func (bl *Balancer) close() {

‎pkg/loadbalance/loadbalancer.go‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -29,7 +29,7 @@ type Picker interface {
2929

3030
// Loadbalancer generates pickers for the given service discovery result.
3131
type Loadbalancer interface {
32-
GetPicker(discovery.Result) Picker
32+
GetPicker(context.Context, discovery.Result) Picker
3333
Name() string // unique key
3434
}
3535

‎pkg/loadbalance/weighted_balancer.go‎

Lines changed: 8 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@
1717
package loadbalance
1818

1919
import (
20+
"context"
2021
"sync"
2122

2223
"golang.org/x/sync/singleflight"
@@ -54,24 +55,26 @@ func NewWeightedRandomBalancer() Loadbalancer {
5455
}
5556

5657
// GetPicker implements the Loadbalancer interface.
57-
func (wb *weightedBalancer) GetPicker(e discovery.Result) Picker {
58+
func (wb *weightedBalancer) GetPicker(ctx context.Context, e discovery.Result) Picker {
5859
if !e.Cacheable {
59-
picker := wb.createPicker(e)
60+
picker := wb.createPicker(ctx, e)
6061
return picker
6162
}
6263

6364
picker, ok := wb.pickerCache.Load(e.CacheKey)
6465
if !ok {
6566
picker, _, _ = wb.sfg.Do(e.CacheKey, func() (interface{}, error) {
66-
p := wb.createPicker(e)
67+
klog.CtxErrorf(ctx, "KITEX-DEBUG: start createPicker, CacheKey=%s", e.CacheKey)
68+
p := wb.createPicker(ctx, e)
69+
klog.CtxErrorf(ctx, "KITEX-DEBUG: end createPicker, CacheKey=%s", e.CacheKey)
6770
wb.pickerCache.Store(e.CacheKey, p)
6871
return p, nil
6972
})
7073
}
7174
return picker.(Picker)
7275
}
7376

74-
func (wb *weightedBalancer) createPicker(e discovery.Result) (picker Picker) {
77+
func (wb *weightedBalancer) createPicker(ctx context.Context, e discovery.Result) (picker Picker) {
7578
instances := make([]discovery.Instance, len(e.Instances)) // removed zero weight instances
7679
weightSum := 0
7780
balance := true
@@ -116,7 +119,7 @@ func (wb *weightedBalancer) Rebalance(change discovery.Change) {
116119
if !change.Result.Cacheable {
117120
return
118121
}
119-
wb.pickerCache.Store(change.Result.CacheKey, wb.createPicker(change.Result))
122+
wb.pickerCache.Store(change.Result.CacheKey, wb.createPicker(context.Background(), change.Result))
120123
}
121124

122125
// Delete implements the Rebalancer interface.

‎pkg/loadbalance/weighted_balancer_test.go‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -43,13 +43,13 @@ func TestWeightedBalancer_GetPicker(t *testing.T) {
4343
t.Run(tc.Name, func(t *testing.T) {
4444
balancer := tc.factory()
4545
// nil
46-
picker := balancer.GetPicker(discovery.Result{})
46+
picker := balancer.GetPicker(context.Background(), discovery.Result{})
4747
test.Assert(t, picker != nil)
4848
dp, ok := picker.(*DummyPicker)
4949
test.Assert(t, ok && dp != nil)
5050

5151
// invalid
52-
picker = balancer.GetPicker(discovery.Result{
52+
picker = balancer.GetPicker(context.Background(), discovery.Result{
5353
Instances: []discovery.Instance{
5454
discovery.NewInstance("tcp", "addr1", -10, nil),
5555
discovery.NewInstance("tcp", "addr2", -20, nil),
@@ -74,7 +74,7 @@ func TestWeightedBalancer_GetPicker(t *testing.T) {
7474
discovery.NewInstance("tcp", "addr2", 20, nil),
7575
discovery.NewInstance("tcp", "addr3", 30, nil),
7676
}
77-
picker = balancer.GetPicker(discovery.Result{
77+
picker = balancer.GetPicker(context.Background(), discovery.Result{
7878
Instances: insList,
7979
})
8080
test.Assert(t, picker != nil)
@@ -85,7 +85,7 @@ func TestWeightedBalancer_GetPicker(t *testing.T) {
8585
discovery.NewInstance("tcp", "addr2", 10, nil),
8686
discovery.NewInstance("tcp", "addr3", 10, nil),
8787
}
88-
picker = balancer.GetPicker(discovery.Result{
88+
picker = balancer.GetPicker(context.Background(), discovery.Result{
8989
Instances: insList,
9090
})
9191
test.Assert(t, picker != nil)

‎pkg/loadbalance/weighted_round_robin.go‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ import (
2121
"sync"
2222

2323
"github.com/bytedance/gopkg/lang/fastrand"
24+
"github.com/cloudwego/kitex/pkg/klog"
2425

2526
"github.com/cloudwego/kitex/pkg/discovery"
2627
)
@@ -76,6 +77,8 @@ type WeightedRoundRobinPicker struct {
7677

7778
// Next implements the Picker interface.
7879
func (wp *WeightedRoundRobinPicker) Next(ctx context.Context, request interface{}) (ins discovery.Instance) {
80+
klog.CtxErrorf(ctx, "KITEX-DEBUG: start Loadbalance")
81+
defer func() { klog.CtxErrorf(ctx, "KITEX-DEBUG: end Loadbalance, nodeSize=%d", len(wp.vnodes)) }()
7982
// iterator must start from 0, because we need warmup the vnode at beginning
8083
idx := wp.iterator.Next() % wp.vcapacity
8184
// fast path
@@ -97,6 +100,8 @@ func (wp *WeightedRoundRobinPicker) Next(ctx context.Context, request interface{
97100
if idx >= vtarget {
98101
vtarget = idx + 1
99102
}
103+
104+
klog.CtxErrorf(ctx, "KITEX-DEBUG: start buildVirtualWrrNodes")
100105
wp.buildVirtualWrrNodes(vtarget)
101106
return wp.vnodes[idx]
102107
}

0 commit comments

Comments
 (0)