Skip to content

Commit fc55eaa

Browse files
244372610244372610
committed
feat: beautify scheduler log
Signed-off-by: santong <[email protected]>
1 parent 023f18f commit fc55eaa

File tree

8 files changed

+81
-87
lines changed

8 files changed

+81
-87
lines changed

‎scheduler/core/events.go‎

Lines changed: 16 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -79,13 +79,11 @@ func (e startReportPieceResultEvent) apply(s *state) {
7979
span := trace.SpanFromContext(e.ctx)
8080
parent := e.peer.GetParent()
8181
if parent != nil {
82-
logger.WithTaskAndPeerID(e.peer.Task.TaskID,
83-
e.peer.PeerID).Warnf("startReportPieceResultEvent: no need schedule parent because peer already had parent %s", e.peer.GetParent().PeerID)
82+
e.peer.Log().Warnf("startReportPieceResultEvent: no need schedule parent because peer already had parent %s", e.peer.GetParent().PeerID)
8483
return
8584
}
8685
if e.peer.Task.IsBackSourcePeer(e.peer.PeerID) {
87-
logger.WithTaskAndPeerID(e.peer.Task.TaskID,
88-
e.peer.PeerID).Info("startReportPieceResultEvent: no need schedule parent because peer is back source peer")
86+
e.peer.Log().Info("startReportPieceResultEvent: no need schedule parent because peer is back source peer")
8987
s.waitScheduleParentPeerQueue.Done(e.peer)
9088
return
9189
}
@@ -100,13 +98,12 @@ func (e startReportPieceResultEvent) apply(s *state) {
10098
}
10199
return
102100
}
103-
logger.WithTaskAndPeerID(e.peer.Task.TaskID,
104-
e.peer.PeerID).Warnf("startReportPieceResultEvent: no parent node is currently available，reschedule it later")
101+
e.peer.Log().Warnf("startReportPieceResultEvent: no parent node is currently available，reschedule it later")
105102
s.waitScheduleParentPeerQueue.AddAfter(e.peer, time.Second)
106103
return
107104
}
108105
if err := e.peer.SendSchedulePacket(constructSuccessPeerPacket(e.peer, parent, candidates)); err != nil {
109-
logger.WithTaskAndPeerID(e.peer.Task.TaskID, e.peer.PeerID).Warnf("send schedule packet to peer %s failed: %v", e.peer.PeerID, err)
106+
e.peer.Log().Warnf("send schedule packet to peer %s failed: %v", e.peer.PeerID, err)
110107
}
111108
}
112109

@@ -127,8 +124,7 @@ func (e peerDownloadPieceSuccessEvent) apply(s *state) {
127124
if e.peer.Task.IsBackSourcePeer(e.peer.PeerID) {
128125
e.peer.Task.AddPiece(e.pr.PieceInfo)
129126
if !e.peer.Task.CanSchedule() {
130-
logger.WithTaskAndPeerID(e.peer.Task.TaskID,
131-
e.peer.PeerID).Warnf("peerDownloadPieceSuccessEvent: update task status seeding")
127+
e.peer.Log().Warnf("peerDownloadPieceSuccessEvent: update task status seeding")
132128
e.peer.Task.SetStatus(supervisor.TaskStatusSeeding)
133129
}
134130
return
@@ -141,13 +137,12 @@ func (e peerDownloadPieceSuccessEvent) apply(s *state) {
141137
e.peer.ReplaceParent(parentPeer)
142138
}
143139
} else if parentPeer.IsLeave() {
144-
logger.WithTaskAndPeerID(e.peer.Task.TaskID,
145-
e.peer.PeerID).Warnf("peerDownloadPieceSuccessEvent: need reschedule parent for peer because it's parent is leave")
140+
e.peer.Log().Warnf("peerDownloadPieceSuccessEvent: need reschedule parent for peer because it's parent is leave")
146141
e.peer.ReplaceParent(nil)
147142
var hasParent bool
148143
parentPeer, candidates, hasParent = s.sched.ScheduleParent(e.peer)
149144
if !hasParent {
150-
logger.WithTaskAndPeerID(e.peer.Task.TaskID, e.peer.PeerID).Warnf("peerDownloadPieceSuccessEvent: no parent node is currently available, " +
145+
e.peer.Log().Warnf("peerDownloadPieceSuccessEvent: no parent node is currently available, " +
151146
"reschedule it later")
152147
s.waitScheduleParentPeerQueue.AddAfter(e.peer, time.Second)
153148
return
@@ -159,7 +154,7 @@ func (e peerDownloadPieceSuccessEvent) apply(s *state) {
159154
}
160155
// TODO if parentPeer is equal with oldParent, need schedule again ?
161156
if err := e.peer.SendSchedulePacket(constructSuccessPeerPacket(e.peer, parentPeer, candidates)); err != nil {
162-
logger.WithTaskAndPeerID(e.peer.Task.TaskID, e.peer.PeerID).Warnf("send schedule packet to peer %s failed: %v", e.peer.PeerID, err)
157+
e.peer.Log().Warnf("send schedule packet to peer %s failed: %v", e.peer.PeerID, err)
163158
}
164159
}
165160

@@ -201,7 +196,7 @@ func (e peerDownloadPieceFailEvent) apply(s *state) {
201196
children := s.sched.ScheduleChildren(cdnPeer)
202197
for _, child := range children {
203198
if err := child.SendSchedulePacket(constructSuccessPeerPacket(child, cdnPeer, nil)); err != nil {
204-
logger.WithTaskAndPeerID(e.peer.Task.TaskID, e.peer.PeerID).Warnf("send schedule packet to peer %s failed: %v", child.PeerID, err)
199+
e.peer.Log().Warnf("send schedule packet to peer %s failed: %v", child.PeerID, err)
205200
}
206201
}
207202
}
@@ -245,7 +240,7 @@ func (e peerDownloadSuccessEvent) apply(s *state) {
245240
children := s.sched.ScheduleChildren(e.peer)
246241
for _, child := range children {
247242
if err := child.SendSchedulePacket(constructSuccessPeerPacket(child, e.peer, nil)); err != nil {
248-
logger.WithTaskAndPeerID(e.peer.Task.TaskID, e.peer.PeerID).Warnf("send schedule packet to peer %s failed: %v", child.PeerID, err)
243+
e.peer.Log().Warnf("send schedule packet to peer %s failed: %v", child.PeerID, err)
249244
}
250245
}
251246
}
@@ -273,12 +268,12 @@ func (e peerDownloadFailEvent) apply(s *state) {
273268
child := (value).(*supervisor.Peer)
274269
parent, candidates, hasParent := s.sched.ScheduleParent(child)
275270
if !hasParent {
276-
logger.WithTaskAndPeerID(child.Task.TaskID, child.PeerID).Warnf("peerDownloadFailEvent: there is no available parent, reschedule it later")
271+
e.peer.Log().Warnf("peerDownloadFailEvent: there is no available parent, reschedule it later")
277272
s.waitScheduleParentPeerQueue.AddAfter(e.peer, time.Second)
278273
return true
279274
}
280275
if err := child.SendSchedulePacket(constructSuccessPeerPacket(child, parent, candidates)); err != nil {
281-
logger.WithTaskAndPeerID(e.peer.Task.TaskID, e.peer.PeerID).Warnf("send schedule packet to peer %s failed: %v", child.PeerID, err)
276+
e.peer.Log().Warnf("send schedule packet to peer %s failed: %v", child.PeerID, err)
282277
}
283278
return true
284279
})
@@ -302,12 +297,12 @@ func (e peerLeaveEvent) apply(s *state) {
302297
child := value.(*supervisor.Peer)
303298
parent, candidates, hasParent := s.sched.ScheduleParent(child)
304299
if !hasParent {
305-
logger.WithTaskAndPeerID(child.Task.TaskID, child.PeerID).Warnf("handlePeerLeave: there is no available parent，reschedule it later")
300+
e.peer.Log().Warnf("handlePeerLeave: there is no available parent，reschedule it later")
306301
s.waitScheduleParentPeerQueue.AddAfter(child, time.Second)
307302
return true
308303
}
309304
if err := child.SendSchedulePacket(constructSuccessPeerPacket(child, parent, candidates)); err != nil {
310-
logger.WithTaskAndPeerID(e.peer.Task.TaskID, e.peer.PeerID).Warnf("send schedule packet to peer %s failed: %v", child.PeerID, err)
305+
e.peer.Log().Warnf("send schedule packet to peer %s failed: %v", child.PeerID, err)
311306
}
312307
return true
313308
})
@@ -361,7 +356,7 @@ func reScheduleParent(peer *supervisor.Peer, s *state) {
361356
}
362357
// TODO if parentPeer is equal with oldParent, need schedule again ?
363358
if err := peer.SendSchedulePacket(constructSuccessPeerPacket(peer, parent, candidates)); err != nil {
364-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Warnf("send schedule packet to peer %s failed: %v", peer.PeerID, err)
359+
peer.Log().Warnf("send schedule packet to peer %s failed: %v", peer.PeerID, err)
365360
}
366361
}
367362

@@ -394,7 +389,7 @@ func removePeerFromCurrentTree(peer *supervisor.Peer, s *state) {
394389
children := s.sched.ScheduleChildren(parent)
395390
for _, child := range children {
396391
if err := child.SendSchedulePacket(constructSuccessPeerPacket(child, peer, nil)); err != nil {
397-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Warnf("send schedule packet to peer %s failed: %v", child.PeerID, err)
392+
peer.Log().Warnf("send schedule packet to peer %s failed: %v", child.PeerID, err)
398393
}
399394
}
400395
}

‎scheduler/core/scheduler/basic/basic_scheduler.go‎

Lines changed: 33 additions & 50 deletions
Original file line numberDiff line numberDiff line change
@@ -71,7 +71,7 @@ type Scheduler struct {
7171

7272
func (s *Scheduler) ScheduleChildren(peer *supervisor.Peer) (children []*supervisor.Peer) {
7373
if s.evaluator.IsBadNode(peer) {
74-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debug("terminate schedule children flow because peer is bad node")
74+
peer.Log().Debug("terminate schedule children flow because peer is bad node")
7575
return
7676
}
7777
freeUpload := peer.Host.GetFreeUploadLoad()
@@ -106,13 +106,13 @@ func (s *Scheduler) ScheduleChildren(peer *supervisor.Peer) (children []*supervi
106106
for _, child := range children {
107107
child.ReplaceParent(peer)
108108
}
109-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("schedule children result: %v", children)
109+
peer.Log().Debugf("schedule children result: %v", children)
110110
return
111111
}
112112

113113
func (s *Scheduler) ScheduleParent(peer *supervisor.Peer) (*supervisor.Peer, []*supervisor.Peer, bool) {
114114
//if !s.evaluator.NeedAdjustParent(peer) {
115-
// logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("stop schedule parent flow because peer is not need adjust parent", peer.PeerID)
115+
// peer.Log().Debugf("stop schedule parent flow because peer is not need adjust parent", peer.PeerID)
116116
// if peer.GetParent() == nil {
117117
// return nil, nil, false
118118
// }
@@ -126,7 +126,7 @@ func (s *Scheduler) ScheduleParent(peer *supervisor.Peer) (*supervisor.Peer, []*
126126
var evalScore []float64
127127
for _, parent := range candidateParents {
128128
score := s.evaluator.Evaluate(parent, peer)
129-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("evaluate score candidate %s is %f", parent.PeerID, score)
129+
peer.Log().Debugf("evaluate score candidate %s is %f", parent.PeerID, score)
130130
evalResult[score] = append(evalResult[score], parent)
131131
evalScore = append(evalScore, score)
132132
}
@@ -138,135 +138,118 @@ func (s *Scheduler) ScheduleParent(peer *supervisor.Peer) (*supervisor.Peer, []*
138138
if parents[0] != peer.GetParent() {
139139
peer.ReplaceParent(parents[0])
140140
}
141-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("primary parent %s is selected", parents[0].PeerID)
141+
peer.Log().Debugf("primary parent %s is selected", parents[0].PeerID)
142142
return parents[0], parents[1:], true
143143
}
144144

145145
func (s *Scheduler) selectCandidateChildren(peer *supervisor.Peer, limit int) (candidateChildren []*supervisor.Peer) {
146-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debug("start schedule children flow")
147-
defer logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("finish schedule parent flow, select num %d candidate children, "+
146+
peer.Log().Debug("start schedule children flow")
147+
defer peer.Log().Debugf("finish schedule parent flow, select num %d candidate children, "+
148148
"current task tree node count %d, back source peers: %s", len(candidateChildren), peer.Task.ListPeers().Size(), peer.Task.GetBackSourcePeers())
149149
candidateChildren = peer.Task.Pick(limit, func(candidateNode *supervisor.Peer) bool {
150150
if candidateNode == nil {
151-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("******candidate child peer is not selected because it is nil******")
151+
peer.Log().Debugf("******candidate child peer is not selected because it is nil******")
152152
return false
153153
}
154154
if candidateNode.IsDone() {
155-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("******candidate child peer %s is not selected because it has done******",
156-
candidateNode.PeerID)
155+
peer.Log().Debugf("******candidate child peer %s is not selected because it has done******", candidateNode.PeerID)
157156
return false
158157
}
159158
if candidateNode.IsLeave() {
160-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("******candidate child peer %s is not selected because it has left******",
161-
candidateNode.PeerID)
159+
peer.Log().Debugf("******candidate child peer %s is not selected because it has left******", candidateNode.PeerID)
162160
return false
163161
}
164162
if candidateNode.IsWaiting() {
165-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("******candidate child peer %s is not selected because it's status is Waiting******",
166-
candidateNode.PeerID)
163+
peer.Log().Debugf("******candidate child peer %s is not selected because it's status is Waiting******", candidateNode.PeerID)
167164
return false
168165
}
169166
if candidateNode == peer {
170-
logger.WithTaskAndPeerID(peer.Task.TaskID,
171-
peer.PeerID).Debugf("******candidate child peer %s is not selected because it and peer are the same******",
172-
candidateNode.PeerID)
167+
peer.Log().Debugf("******candidate child peer %s is not selected because it and peer are the same******", candidateNode.PeerID)
173168
return false
174169
}
175170
if candidateNode.IsAncestorOf(peer) {
176-
logger.WithTaskAndPeerID(peer.Task.TaskID,
177-
peer.PeerID).Debugf("******candidate child peer %s is not selected because peer's ancestor is candidate peer******", candidateNode.PeerID)
171+
peer.Log().Debugf("******candidate child peer %s is not selected because peer's ancestor is candidate peer******", candidateNode.PeerID)
178172
return false
179173
}
180174
if candidateNode.GetFinishedNum() >= peer.GetFinishedNum() {
181-
logger.WithTaskAndPeerID(peer.Task.TaskID,
182-
peer.PeerID).Debugf("******candidate child peer %s is not selected because it finished number of download is equal to or greater than peer's"+
183-
"******",
184-
candidateNode.PeerID)
175+
peer.Log().Debugf("******candidate child peer %s is not selected because it finished number of download is equal to or greater than peer's"+
176+
"******", candidateNode.PeerID)
185177
return false
186178
}
187179
if candidateNode.Host != nil && candidateNode.Host.CDN {
188-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("******candidate child peer %s is not selected because it is a cdn host******",
189-
candidateNode.PeerID)
180+
peer.Log().Debugf("******candidate child peer %s is not selected because it is a cdn host******", candidateNode.PeerID)
190181
return false
191182
}
192183
if !candidateNode.IsConnected() {
193-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("******candidate child peer %s is not selected because it is not connected******",
194-
candidateNode.PeerID)
184+
peer.Log().Debugf("******candidate child peer %s is not selected because it is not connected******", candidateNode.PeerID)
195185
return false
196186
}
197187
if candidateNode.GetParent() == nil {
198-
logger.WithTaskAndPeerID(peer.Task.TaskID,
199-
peer.PeerID).Debugf("******[selected]candidate child peer %s is selected because it has not parent[selected]******",
200-
candidateNode.PeerID)
188+
peer.Log().Debugf("******[selected]candidate child peer %s is selected because it has not parent[selected]******", candidateNode.PeerID)
201189
return true
202190
}
203191

204192
if candidateNode.GetParent() != nil && s.evaluator.IsBadNode(candidateNode.GetParent()) {
205-
logger.WithTaskAndPeerID(peer.Task.TaskID,
206-
peer.PeerID).Debugf("******[selected]candidate child peer %s is selected because parent's status is not health[selected]******",
193+
peer.Log().Debugf("******[selected]candidate child peer %s is selected because parent's status is not health[selected]******",
207194
candidateNode.PeerID)
208195
return true
209196
}
210-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("******[default]candidate child peer %s is selected[default]******", candidateNode.PeerID)
197+
peer.Log().Debugf("******[default]candidate child peer %s is selected[default]******", candidateNode.PeerID)
211198
return true
212199
})
213200
return
214201
}
215202

216203
func (s *Scheduler) selectCandidateParents(peer *supervisor.Peer, limit int) (candidateParents []*supervisor.Peer) {
217-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debug("start schedule parent flow")
218-
defer logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("finish schedule parent flow, select num %d candidates parents, "+
204+
peer.Log().Debug("start schedule parent flow")
205+
defer peer.Log().Debugf("finish schedule parent flow, select num %d candidates parents, "+
219206
"current task tree node count %d, back source peers: %s", len(candidateParents), peer.Task.ListPeers().Size(), peer.Task.GetBackSourcePeers())
220207
if !peer.Task.CanSchedule() {
221-
logger.WithTaskAndPeerID(peer.Task.TaskID,
222-
peer.PeerID).Debugf("++++++peer can not be scheduled because task cannot be scheduled at this time，waiting task status become seeding. "+
208+
peer.Log().Debugf("++++++peer can not be scheduled because task cannot be scheduled at this time，waiting task status become seeding. "+
223209
"it current status is %s++++++", peer.Task.GetStatus())
224210
return nil
225211
}
226212
candidateParents = peer.Task.PickReverse(limit, func(candidateNode *supervisor.Peer) bool {
227213
if candidateNode == nil {
228-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("++++++candidate parent peer is not selected because it is nil++++++")
214+
peer.Log().Debugf("++++++candidate parent peer is not selected because it is nil++++++")
229215
return false
230216
}
231217
if s.evaluator.IsBadNode(candidateNode) {
232-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("++++++candidate parent peer %s is not selected because it is badNode++++++",
218+
peer.Log().Debugf("++++++candidate parent peer %s is not selected because it is badNode++++++",
233219
candidateNode.PeerID)
234220
return false
235221
}
236222
if candidateNode.IsLeave() {
237-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("++++++candidate parent peer %s is not selected because it has already left++++++",
223+
peer.Log().Debugf("++++++candidate parent peer %s is not selected because it has already left++++++",
238224
candidateNode.PeerID)
239225
return false
240226
}
241227
if candidateNode == peer {
242-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("++++++candidate parent peer %s is not selected because it and peer are the same++++++",
228+
peer.Log().Debugf("++++++candidate parent peer %s is not selected because it and peer are the same++++++",
243229
candidateNode.PeerID)
244230
return false
245231
}
246232
if candidateNode.IsDescendantOf(peer) {
247-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("++++++candidate parent peer %s is not selected because it's ancestor is peer++++++",
233+
peer.Log().Debugf("++++++candidate parent peer %s is not selected because it's ancestor is peer++++++",
248234
candidateNode.PeerID)
249235
return false
250236
}
251237
if candidateNode.Host.GetFreeUploadLoad() <= 0 {
252-
logger.WithTaskAndPeerID(peer.Task.TaskID,
253-
peer.PeerID).Debugf("++++++candidate parent peer %s is not selected because it's free upload load equal to less than zero++++++",
238+
peer.Log().Debugf("++++++candidate parent peer %s is not selected because it's free upload load equal to less than zero++++++",
254239
candidateNode.PeerID)
255240
return false
256241
}
257242
if candidateNode.IsWaiting() {
258-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("++++++candidate parent peer %s is not selected because it's status is waiting++++++",
243+
peer.Log().Debugf("++++++candidate parent peer %s is not selected because it's status is waiting++++++",
259244
candidateNode.PeerID)
260245
return false
261246
}
262247
if candidateNode.GetFinishedNum() <= peer.GetFinishedNum() {
263-
logger.WithTaskAndPeerID(peer.Task.TaskID,
264-
peer.PeerID).Debugf("++++++candidate parent peer %s is not selected because it finished number of download is equal to or smaller than peer"+
265-
"'s++++++",
266-
candidateNode.PeerID)
248+
peer.Log().Debugf("++++++candidate parent peer %s is not selected because it finished number of download is equal to or smaller than peer's"+
249+
"++++++", candidateNode.PeerID)
267250
return false
268251
}
269-
logger.WithTaskAndPeerID(peer.Task.TaskID, peer.PeerID).Debugf("++++++[default]candidate parent peer %s is selected[default]", candidateNode.PeerID)
252+
peer.Log().Debugf("++++++[default]candidate parent peer %s is selected[default]", candidateNode.PeerID)
270253
return true
271254
})
272255
return

0 commit comments

Comments
 (0)