util: Add new blocked timer utility

This adds a new *BlockedTimer struct which can be used to run a function
or a printf after a short duration. It can be cancelled early. A short
blog post about the topic is available here:

https://purpleidea.com/blog/2023/05/26/blocked-select-logging-in-golang/

util/bt.go

@@ -0,0 +1,111 @@
+// Mgmt
+// Copyright (C) 2013-2023+ James Shubin and the project contributors
+// Written by James Shubin <james@shubin.ca> and the project contributors
+//
+// This program is free software: you can redistribute it and/or modify
+// it under the terms of the GNU General Public License as published by
+// the Free Software Foundation, either version 3 of the License, or
+// (at your option) any later version.
+//
+// This program is distributed in the hope that it will be useful,
+// but WITHOUT ANY WARRANTY; without even the implied warranty of
+// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+// GNU General Public License for more details.
+//
+// You should have received a copy of the GNU General Public License
+// along with this program.  If not, see <http://www.gnu.org/licenses/>.
+
+package util
+
+import (
+	"context"
+	"fmt"
+	"sync"
+	"time"
+)
+
+// BlockedTimer is a helper facility for printing log messages when you have a
+// possible deadlock. Alternatively, it can run an arbitrary function instead.
+// It does this by starting a timer, and if that timer isn't cancelled soon
+// enough, it executes the task. This is usually most useful before a select
+// statement which should ordinarily unblock rather quickly. It's helpful to
+// avoid unnecessary "waiting for select" log messages being constantly printed,
+// but should those block for longer, you'd definitely like to know where to
+// look first. This is safe for concurrent use. Multiple invocations of Printf
+// or Run are permitted. They each have their own separate countdown timers, but
+// are all cancelled when Cancel is run. It is safe to call Cancel multiple
+// times. If Cancel is called before Printf or Run, then those will never run. A
+// BlockedTimer must not be copied after first use.
+type BlockedTimer struct {
+	// Duration specifies how long we should wait before we run (or print)
+	// the function or message. The counter starts when that respective
+	// function is run. For an easier method, specify the Seconds parameter
+	// instead.
+	Duration time.Duration
+
+	// Seconds works exactly as Duration does, except it can be used as a
+	// shorter method to accomplish the same thing. If this value is zero,
+	// then Duration is used instead.
+	Seconds int
+
+	ctx       context.Context
+	cancel    func()
+	cancelled bool
+	mutex     sync.Mutex
+}
+
+// Printf will print as expected when the timer expires if Cancel isn't run
+// first. This can be used multiple times.
+func (obj *BlockedTimer) Printf(format string, v ...interface{}) {
+	f := func() {
+		// safe Logf in case f.String contains %? chars...
+		s := fmt.Sprintf(format, v...)
+		fmt.Printf("%s", s)
+	}
+	obj.Run(f)
+}
+
+// Run will run the passed function as expected when the timer expires if Cancel
+// isn't run first. This can be used multiple times.
+func (obj *BlockedTimer) Run(f func()) {
+	obj.mutex.Lock()
+	defer obj.mutex.Unlock()
+
+	if obj.cancelled { // we already cancelled
+		return
+	}
+
+	if obj.cancel == nil { // only do it once
+		obj.ctx, obj.cancel = context.WithCancel(context.Background())
+	}
+
+	d := time.Duration(obj.Seconds) * time.Second
+	if obj.Seconds == 0 {
+		d = obj.Duration
+	}
+
+	go func() {
+		select {
+		case <-time.After(d):
+			// print!
+		case <-obj.ctx.Done():
+			// cancel the print
+			return
+		}
+		f() // run it
+	}()
+}
+
+// Cancel cancels the execution of any Run or Printf functions. It is safe to
+// call it multiple times. It is important to call this at least once (on defer
+// for example) if you've used either Printf or Run, because otherwise you will
+// leak goroutines.
+func (obj *BlockedTimer) Cancel() {
+	obj.mutex.Lock()
+	defer obj.mutex.Unlock()
+	obj.cancelled = true
+	if obj.cancel == nil { // race! never let it run
+		return
+	}
+	obj.cancel()
+}

util/bt_test.go

@@ -0,0 +1,123 @@
+// Mgmt
+// Copyright (C) 2013-2023+ James Shubin and the project contributors
+// Written by James Shubin <james@shubin.ca> and the project contributors
+//
+// This program is free software: you can redistribute it and/or modify
+// it under the terms of the GNU General Public License as published by
+// the Free Software Foundation, either version 3 of the License, or
+// (at your option) any later version.
+//
+// This program is distributed in the hope that it will be useful,
+// but WITHOUT ANY WARRANTY; without even the implied warranty of
+// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+// GNU General Public License for more details.
+//
+// You should have received a copy of the GNU General Public License
+// along with this program.  If not, see <http://www.gnu.org/licenses/>.
+
+//go:build !root
+
+package util
+
+import (
+	"testing"
+	"time"
+)
+
+func TestBlockedTimer1(t *testing.T) {
+	bt := &BlockedTimer{Seconds: 1}
+	defer bt.Cancel()
+	ch := make(chan struct{})
+	bt.Run(func() { close(ch) })
+	select {
+	case <-time.After(time.Duration(3) * time.Second):
+		t.Errorf("the timer was too slow")
+	case <-ch:
+	}
+}
+
+func TestBlockedTimer2(t *testing.T) {
+	bt := &BlockedTimer{Seconds: 3}
+	defer bt.Cancel()
+	ch := make(chan struct{})
+	bt.Run(func() { close(ch) })
+	select {
+	case <-time.After(time.Duration(1) * time.Second):
+	case <-ch:
+		t.Errorf("the timer was too fast")
+	}
+}
+
+func TestBlockedTimer3(t *testing.T) {
+	bt := &BlockedTimer{Seconds: 2}
+	defer bt.Cancel()
+	ch := make(chan struct{})
+	bt.Run(func() { close(ch) })
+	select {
+	case <-time.After(time.Duration(1) * time.Second):
+	}
+	bt.Cancel()
+	select {
+	case <-time.After(time.Duration(2) * time.Second):
+	case <-ch:
+		t.Errorf("the channel should not have closed")
+	}
+}
+
+func TestBlockedTimer1b(t *testing.T) {
+	bt := BlockedTimer{Seconds: 1}
+	defer bt.Cancel()
+	ch := make(chan struct{})
+	bt.Run(func() { close(ch) })
+	select {
+	case <-time.After(time.Duration(3) * time.Second):
+		t.Errorf("the timer was too slow")
+	case <-ch:
+	}
+}
+
+func TestBlockedTimer2b(t *testing.T) {
+	bt := BlockedTimer{Seconds: 3}
+	defer bt.Cancel()
+	ch := make(chan struct{})
+	bt.Run(func() { close(ch) })
+	select {
+	case <-time.After(time.Duration(1) * time.Second):
+	case <-ch:
+		t.Errorf("the timer was too fast")
+	}
+}
+
+func TestBlockedTimer3b(t *testing.T) {
+	bt := BlockedTimer{Seconds: 3}
+	defer bt.Cancel()
+	ch := make(chan struct{})
+	bt.Run(func() { close(ch) })
+	select {
+	case <-time.After(time.Duration(1) * time.Second):
+	}
+	bt.Cancel()
+	select {
+	case <-time.After(time.Duration(2) * time.Second):
+	case <-ch:
+		t.Errorf("the channel should not have closed")
+	}
+}
+
+// just an example to see how to use AfterFunc instead of BlockedTimer
+func TestAfterFunc1(t *testing.T) {
+	ch := make(chan struct{})
+	af := time.AfterFunc(time.Duration(2)*time.Second, func() { close(ch) })
+	defer af.Stop()
+	select {
+	case <-time.After(time.Duration(1) * time.Second):
+	}
+	af.Stop()
+	af.Stop()
+	af.Stop()
+	select {
+	case <-ch:
+		t.Errorf("the timer was too fast")
+	default:
+	}
+}