Log the start-up checkpoint's figures under their own names (closes #117)

Initialize scanned the row of PRAGMA wal_checkpoint(TRUNCATE), which is
the busy flag, the frames in the WAL and the frames copied, into
wal_pages, checkpointed and moved; and a completed TRUNCATE reads 0 for
both counts. The line now logs busy, wal_frames and checkpointed_frames,
plus wal_bytes, the WAL file's size, which New reads before it opens the
database because the open writes a frame to the WAL. The line is a
warning when busy is 1. Tests open a database a second time while the
first stays open, with and without a read open on the first, and check
the line's level and figures.

Model: opus-5-5

internal/database/database.go

@@ -169,6 +169,20 @@ func New(cfg *config.Config, logger *logger.Logger) (*Database, error) {
 		return nil, fmt.Errorf("failed to create database directory: %w", err)
 	}
 
+	// The size of the WAL file the previous run left, which Initialize logs
+	// with the start-up checkpoint. It is read before the database is opened,
+	// because opening it writes a frame to the WAL. There is no WAL file when
+	// the database is new or the last run closed the database, which deletes
+	// it.
+	var walBytes int64
+
+	wal, err := os.Stat(dbPath + walFileSuffix)
+	if err == nil {
+		walBytes = wal.Size()
+	} else if !errors.Is(err, os.ErrNotExist) {
+		logger.Warn("Failed to read the WAL file's size on startup", "error", err)
+	}
+
 	// Per-connection SQLite settings go in the DSN so every pooled connection
 	// gets them, not just the one that runs the Initialize pragmas. _txlock=
 	// immediate makes every transaction take the write lock at BEGIN. Without it
@@ -229,7 +243,7 @@ func New(cfg *config.Config, logger *logger.Logger) (*Database, error) {
 		counts: &liveCounts{},
 	}
 
-	err = database.Initialize()
+	err = database.Initialize(walBytes)
 	if err != nil {
 		return nil, fmt.Errorf("failed to initialize database: %w", err)
 	}
@@ -245,8 +259,16 @@ func New(cfg *config.Config, logger *logger.Logger) (*Database, error) {
 	return database, nil
 }
 
-// Initialize creates the database schema if it doesn't exist.
-func (d *Database) Initialize() error {
+// The messages Initialize logs the start-up WAL checkpoint with.
+const (
+	startupCheckpointMessage           = "WAL checkpoint on startup"
+	startupCheckpointIncompleteMessage = "WAL checkpoint on startup incomplete"
+)
+
+// Initialize creates the database schema if it doesn't exist. walBytes is the
+// size of the WAL file the previous run left, which New reads before it opens
+// the database.
+func (d *Database) Initialize(walBytes int64) error {
 	// Set SQLite pragmas for performance. Per-connection settings (cache_size,
 	// synchronous, busy_timeout, journal_mode) live in the DSN, and New sets the
 	// writing connection's cache_size; temp_store is left at its default so
@@ -266,19 +288,33 @@ func (d *Database) Initialize() error {
 		}
 	}
 
-	// Run WAL checkpoint on startup to consolidate any existing WAL
-	var walPages, checkpointedPages, movedPages int
+	// The start-up checkpoint copies the WAL a previous run left into the
+	// database file and empties the WAL file; its frame counts then read 0,
+	// so walBytes is logged with them.
+	var busy, walFrames, checkpointedFrames int
 
 	err := d.writer.QueryRowContext(context.Background(),
 		"PRAGMA wal_checkpoint(TRUNCATE)",
-	).Scan(&walPages, &checkpointedPages, &movedPages)
-	if err != nil {
+	).Scan(&busy, &walFrames, &checkpointedFrames)
+
+	switch {
+	case err != nil:
 		d.logger.Warn("Failed to checkpoint WAL on startup", "error", err)
-	} else {
-		d.logger.Info("WAL checkpoint on startup",
-			"wal_pages", walPages,
-			"checkpointed", checkpointedPages,
-			"moved", movedPages,
+	case busy != 0:
+		// Another process using the database kept the checkpoint from
+		// copying or emptying all of the WAL.
+		d.logger.Warn(startupCheckpointIncompleteMessage,
+			"wal_bytes", walBytes,
+			"busy", busy,
+			"wal_frames", walFrames,
+			"checkpointed_frames", checkpointedFrames,
+		)
+	default:
+		d.logger.Info(startupCheckpointMessage,
+			"wal_bytes", walBytes,
+			"busy", busy,
+			"wal_frames", walFrames,
+			"checkpointed_frames", checkpointedFrames,
 		)
 	}