Skip to content

Commit 49f235b

Browse files
authored
feat: log clock calls, traps, time advancement (#16)
fixes #13 Adds logging of traps, calls, and advancing the clock like: ``` === CONT Test_MultipleTraps mock.go:438: Mock Clock - Trap Now(..., [0]) mock.go:438: Mock Clock - Trap Now(..., [1]) mock.go:200: Mock Clock - Now([0 1]) call, matched 2 traps mock_test.go:340: Mock Clock - Advance(1s) mock_test.go:350: Mock Clock - Advance(1s) mock.go:200: Mock Clock - Now([end]) call, matched 0 traps ``` This should make it easier to debug a variety of issues, including not setting the trap before the call happens.
1 parent d87ad1f commit 49f235b

File tree

1 file changed

+67
-0
lines changed

1 file changed

+67
-0
lines changed

mock.go

Lines changed: 67 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -197,6 +197,7 @@ func (m *Mock) matchCallLocked(c *apiCall) {
197197
traps = append(traps, t)
198198
}
199199
}
200+
m.tb.Logf("Mock Clock - %s call, matched %d traps", c, len(traps))
200201
if len(traps) == 0 {
201202
return
202203
}
@@ -260,6 +261,7 @@ func (m *Mock) Advance(d time.Duration) AdvanceWaiter {
260261
m.tb.Helper()
261262
w := AdvanceWaiter{tb: m.tb, ch: make(chan struct{})}
262263
m.mu.Lock()
264+
m.tb.Logf("Mock Clock - Advance(%s)", d)
263265
fin := m.cur.Add(d)
264266
// nextTime.IsZero implies no events scheduled.
265267
if m.nextTime.IsZero() || fin.Before(m.nextTime) {
@@ -307,6 +309,7 @@ func (m *Mock) Set(t time.Time) AdvanceWaiter {
307309
m.tb.Helper()
308310
w := AdvanceWaiter{tb: m.tb, ch: make(chan struct{})}
309311
m.mu.Lock()
312+
m.tb.Logf("Mock Clock - Set(%s)", t)
310313
if t.Before(m.cur) {
311314
defer close(w.ch)
312315
defer m.mu.Unlock()
@@ -343,6 +346,7 @@ func (m *Mock) Set(t time.Time) AdvanceWaiter {
343346
// wait for the timer/tick event(s) to finish.
344347
func (m *Mock) AdvanceNext() (time.Duration, AdvanceWaiter) {
345348
m.mu.Lock()
349+
m.tb.Logf("Mock Clock - AdvanceNext()")
346350
m.tb.Helper()
347351
w := AdvanceWaiter{tb: m.tb, ch: make(chan struct{})}
348352
if m.nextTime.IsZero() {
@@ -431,6 +435,7 @@ func (m *Mock) Trap() Trapper {
431435
func (m *Mock) newTrap(fn clockFunction, tags []string) *Trap {
432436
m.mu.Lock()
433437
defer m.mu.Unlock()
438+
m.tb.Logf("Mock Clock - Trap %s(..., %v)", fn, tags)
434439
tr := &Trap{
435440
fn: fn,
436441
tags: tags,
@@ -557,6 +562,37 @@ const (
557562
clockFunctionUntil
558563
)
559564

565+
func (c clockFunction) String() string {
566+
switch c {
567+
case clockFunctionNewTimer:
568+
return "NewTimer"
569+
case clockFunctionAfterFunc:
570+
return "AfterFunc"
571+
case clockFunctionTimerStop:
572+
return "Timer.Stop"
573+
case clockFunctionTimerReset:
574+
return "Timer.Reset"
575+
case clockFunctionTickerFunc:
576+
return "TickerFunc"
577+
case clockFunctionTickerFuncWait:
578+
return "TickerFunc.Wait"
579+
case clockFunctionNewTicker:
580+
return "NewTicker"
581+
case clockFunctionTickerReset:
582+
return "Ticker.Reset"
583+
case clockFunctionTickerStop:
584+
return "Ticker.Stop"
585+
case clockFunctionNow:
586+
return "Now"
587+
case clockFunctionSince:
588+
return "Since"
589+
case clockFunctionUntil:
590+
return "Until"
591+
default:
592+
return "?????"
593+
}
594+
}
595+
560596
type callArg func(c *apiCall)
561597

562598
// apiCall represents a single call to one of the Clock APIs.
@@ -570,6 +606,37 @@ type apiCall struct {
570606
complete chan struct{}
571607
}
572608

609+
func (a *apiCall) String() string {
610+
switch a.fn {
611+
case clockFunctionNewTimer:
612+
return fmt.Sprintf("NewTimer(%s, %v)", a.Duration, a.Tags)
613+
case clockFunctionAfterFunc:
614+
return fmt.Sprintf("AfterFunc(%s, <fn>, %v)", a.Duration, a.Tags)
615+
case clockFunctionTimerStop:
616+
return fmt.Sprintf("Timer.Stop(%v)", a.Tags)
617+
case clockFunctionTimerReset:
618+
return fmt.Sprintf("Timer.Reset(%s, %v)", a.Duration, a.Tags)
619+
case clockFunctionTickerFunc:
620+
return fmt.Sprintf("TickerFunc(<ctx>, %s, <fn>, %s)", a.Duration, a.Tags)
621+
case clockFunctionTickerFuncWait:
622+
return fmt.Sprintf("TickerFunc.Wait(%v)", a.Tags)
623+
case clockFunctionNewTicker:
624+
return fmt.Sprintf("NewTicker(%s, %v)", a.Duration, a.Tags)
625+
case clockFunctionTickerReset:
626+
return fmt.Sprintf("Ticker.Reset(%s, %v)", a.Duration, a.Tags)
627+
case clockFunctionTickerStop:
628+
return fmt.Sprintf("Ticker.Stop(%v)", a.Tags)
629+
case clockFunctionNow:
630+
return fmt.Sprintf("Now(%v)", a.Tags)
631+
case clockFunctionSince:
632+
return fmt.Sprintf("Since(%s, %v)", a.Time, a.Tags)
633+
case clockFunctionUntil:
634+
return fmt.Sprintf("Until(%s, %v)", a.Time, a.Tags)
635+
default:
636+
return "?????"
637+
}
638+
}
639+
573640
// Call represents an apiCall that has been trapped.
574641
type Call struct {
575642
Time time.Time

0 commit comments

Comments
 (0)