scheduler: add debug log #907

Connor1996 · 2018-01-09T04:00:32Z

this pr:

add some debug log in balance-leader and balance-region scheduler
add a log api for pd-ctl to set log level

siddontang · 2018-01-09T04:34:54Z

server/schedulers/balance_leader.go

@@ -74,6 +75,8 @@ func (l *balanceLeaderScheduler) Schedule(cluster schedule.Cluster, opInfluence

 	source := cluster.GetStore(region.Leader.GetStoreId())
 	target := cluster.GetStore(newLeader.GetStoreId())
+	log.Debugf("source store is %v", source)


please combine two logs into one, add scheduler name .

add [region xxx] xxx

ok, but I think it's not necessary to add scheduler name, cause log will print file name

siddontang · 2018-01-09T04:35:00Z

server/schedulers/utils.go

@@ -39,6 +39,8 @@ func scheduleTransferLeader(cluster schedule.Cluster, schedulerName string, s sc

 	mostLeaderStore := s.SelectSource(cluster, stores, filters...)
 	leastLeaderStore := s.SelectTarget(cluster, stores, filters...)
+	log.Debugf("mostLeaderStore is %v", mostLeaderStore)


siddontang · 2018-01-09T04:35:33Z

server/schedulers/utils.go

@@ -63,7 +67,7 @@ func scheduleTransferLeader(cluster schedule.Cluster, schedulerName string, s sc
 			region, peer = scheduleRemoveLeader(cluster, schedulerName, mostLeaderStore.GetId(), s)
 		}
 	}
-
+	log.Debugf("transfer leader select %v to be new leader for region %v", peer, region)


[region xxx] do ...

disksing · 2018-01-09T07:49:53Z

server/api/debug.go

+		return
+	}
+
+	level := "info"


I think it's better to set log level by string. If original level is "warning" or "error", we will not able to recover after debug.

disksing · 2018-01-09T07:50:59Z

server/schedule/filters.go

@@ -31,6 +32,7 @@ type Filter interface {
 func FilterSource(opt Options, store *core.StoreInfo, filters []Filter) bool {
 	for _, filter := range filters {
 		if filter.FilterSource(opt, store) {
+			log.Debugf("[filter %T] filtes store %v from source", filter, store)


filtes -> filters.

siddontang · 2018-01-09T08:00:00Z

server/api/debug.go

+	if debug {
+		level = "debug"
+	}
+	h.svr.SetLogLevel(level)


I worry the data race here. Changing log level is not thread safe?

server reads cfg.Log only when initing logger, and setloglevel is not an operation with high frequency. Even if it causes write-write-conflict, it seems that it does not matter here.

siddontang · 2018-01-09T08:02:10Z

please attach [region %d] at the beginning of the log if there is.

disksing · 2018-01-09T09:55:15Z

server/schedulers/balance_leader.go

@@ -74,6 +75,7 @@ func (l *balanceLeaderScheduler) Schedule(cluster schedule.Cluster, opInfluence

 	source := cluster.GetStore(region.Leader.GetStoreId())
 	target := cluster.GetStore(newLeader.GetStoreId())
+	log.Debugf("source store is %v, target store is %v", source, target)


log store id should be enough.

disksing · 2018-01-09T09:55:24Z

server/schedulers/balance_region.go

@@ -117,6 +118,7 @@ func (s *balanceRegionScheduler) transferPeer(cluster schedule.Cluster, region *

 	target := cluster.GetStore(newPeer.GetStoreId())
 	avgScore := cluster.GetStoresAverageScore(core.RegionKind)
+	log.Debugf("source store is %v, target store is %v", source, target)


log store id should be enough.

siddontang · 2018-01-09T11:43:18Z

server/schedule/filters.go

@@ -31,6 +32,7 @@ type Filter interface {
 func FilterSource(opt Options, store *core.StoreInfo, filters []Filter) bool {
 	for _, filter := range filters {
 		if filter.FilterSource(opt, store) {
+			log.Debugf("[filter %T] filters store %v from source", filter, store)


%T will output all the fields of the filter, is it ok here?

no, it outputs like "*schedule.excludedFilter"

siddontang · 2018-01-09T11:43:34Z

server/schedulers/balance_leader.go

@@ -74,6 +75,7 @@ func (l *balanceLeaderScheduler) Schedule(cluster schedule.Cluster, opInfluence

 	source := cluster.GetStore(region.Leader.GetStoreId())
 	target := cluster.GetStore(newLeader.GetStoreId())
+	log.Debugf("source store id is %v, target store id is %v", source.GetId(), target.GetId())


siddontang · 2018-01-09T11:43:43Z

server/schedulers/balance_region.go

@@ -117,6 +118,7 @@ func (s *balanceRegionScheduler) transferPeer(cluster schedule.Cluster, region *

 	target := cluster.GetStore(newPeer.GetStoreId())
 	avgScore := cluster.GetStoresAverageScore(core.RegionKind)
+	log.Debugf("source store id is %v, target store id is %v", source.GetId(), target.GetId())


siddontang · 2018-01-09T11:44:03Z

server/schedulers/utils.go

@@ -39,6 +39,7 @@ func scheduleTransferLeader(cluster schedule.Cluster, schedulerName string, s sc

 	mostLeaderStore := s.SelectSource(cluster, stores, filters...)
 	leastLeaderStore := s.SelectTarget(cluster, stores, filters...)
+	log.Debugf("[%v] mostLeaderStore is %v, leastLeaderStore is %v", schedulerName, mostLeaderStore, leastLeaderStore)


nolouch · 2018-01-10T03:10:39Z

server/schedulers/utils.go

+	if region == nil {
+		log.Debugf("[%v] select no region", schedulerName)
+	} else {
+		log.Debugf("[region %v][%v] select %v to be new leader", schedulerName, region.GetId(), peer)


I guess the parameter does not correspond.

oh, I mistake the order

nolouch · 2018-01-10T03:15:13Z

server/schedulers/utils.go

@@ -183,6 +190,7 @@ func shouldBalance(source, target *core.StoreInfo, avgScore float64, kind core.R
 	sourceSizeDiff := (sourceScore - avgScore) * source.ResourceWeight(kind)
 	targetSizeDiff := (avgScore - targetScore) * target.ResourceWeight(kind)

+	log.Debugf("size diff is %v and region size is %v", math.Min(sourceSizeDiff, targetSizeDiff), float64(region.ApproximateSize)*tolerantRatio)


region size -> tolerable size？better to indicate region id.

siddontang · 2018-01-10T07:33:02Z

LGTM

nolouch

LGTM

* scheduler: add debug log (#907)

add debug log

b34289e

siddontang reviewed Jan 9, 2018

View reviewed changes

Connor1996 added 2 commits January 9, 2018 12:58

fix ci

0a2255a

tiny change

a3b2e5b

Connor1996 requested review from nolouch and disksing January 9, 2018 05:35

fix test

3ec9aba

disksing reviewed Jan 9, 2018

View reviewed changes

siddontang reviewed Jan 9, 2018

View reviewed changes

Connor1996 added 2 commits January 9, 2018 16:06

set log level

9f92af1

address comment

9b7754e

disksing reviewed Jan 9, 2018

View reviewed changes

address comment

bd4b5a8

Connor1996 force-pushed the debug-log branch from 1837740 to bd4b5a8 Compare January 9, 2018 11:12

siddontang reviewed Jan 9, 2018

View reviewed changes

address comment

0858b95

nolouch reviewed Jan 10, 2018

View reviewed changes

Connor1996 added 2 commits January 10, 2018 14:15

address comment

ff975d6

Merge branch 'master' into debug-log

e61ef23

Merge branch 'master' into debug-log

3bc9446

nolouch approved these changes Jan 10, 2018

View reviewed changes

Merge branch 'master' into debug-log

452c693

disksing merged commit f3a22e2 into tikv:master Jan 10, 2018

Connor1996 deleted the debug-log branch January 15, 2018 03:07

Connor1996 added a commit to Connor1996/pd that referenced this pull request Jan 15, 2018

scheduler: add debug log (tikv#907)

655c909

Connor1996 added a commit that referenced this pull request Jan 15, 2018

scheduler: add debug log (#907) (#917)

1a878c9

* scheduler: add debug log (#907)

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

scheduler: add debug log #907

scheduler: add debug log #907

Connor1996 commented Jan 9, 2018 •

edited

Loading

siddontang Jan 9, 2018

siddontang Jan 9, 2018

Connor1996 Jan 9, 2018

siddontang Jan 9, 2018

siddontang Jan 9, 2018

disksing Jan 9, 2018

disksing Jan 9, 2018

siddontang Jan 9, 2018

Connor1996 Jan 9, 2018

siddontang commented Jan 9, 2018

disksing Jan 9, 2018

disksing Jan 9, 2018

siddontang Jan 9, 2018

Connor1996 Jan 10, 2018

siddontang Jan 9, 2018

siddontang Jan 9, 2018

siddontang Jan 9, 2018

nolouch Jan 10, 2018

Connor1996 Jan 10, 2018

nolouch Jan 10, 2018

siddontang commented Jan 10, 2018

nolouch left a comment

scheduler: add debug log #907

scheduler: add debug log #907

Conversation

Connor1996 commented Jan 9, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

siddontang commented Jan 9, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

siddontang commented Jan 10, 2018

nolouch left a comment

Choose a reason for hiding this comment

Connor1996 commented Jan 9, 2018 •

edited

Loading