Files
zeekay a671dee75a State a version once
A version written into a manifest is written into every manifest that wants it,
which is how eslint came to exist in a hundred and four forms across this estate
and how a package came to resolve twice at run time. The catalog moves the number
out of the manifest: a manifest names the package, the workspace names the
version.

Four are held below their latest because the newer release cannot be used, and
the reason is recorded rather than the version alone: @noble/hashes 2 renamed
every subpath the web3 stack imports, @splinetool/runtime 2 depends on a package
that was never published, @dynamic-labs 5.4.1 the same, and react-resizable-panels
3 points its types condition at the bundle.
2026-08-29 13:46:58 -07:00

1125 lines
31 KiB
Go

//go:build integration && soak
package integration
import (
"bufio"
"context"
"database/sql"
"fmt"
"os"
"os/exec"
"os/signal"
"path/filepath"
"strconv"
"strings"
"syscall"
"testing"
"time"
)
// S3Config holds S3-specific configuration
type S3Config struct {
Endpoint string
AccessKey string
SecretKey string
Region string
ForcePathStyle bool
SkipVerify bool
SSE string
SSEKMSKeyID string
}
// TestInfo holds test state for signal handler and monitoring
type TestInfo struct {
StartTime time.Time
Duration time.Duration
RowCount int
FileCount int
DB *TestDB
cancel context.CancelFunc
}
// ErrorStats holds error categorization and counts
type ErrorStats struct {
TotalCount int
CriticalCount int
BenignCount int
RecentErrors []string
ErrorsByType map[string]int
}
func isInteractive() bool {
if fi, err := os.Stdin.Stat(); err == nil {
return fi.Mode()&os.ModeCharDevice != 0
}
return false
}
func promptYesNo(t *testing.T, prompt string, defaultYes bool) bool {
t.Helper()
switch strings.ToLower(strings.TrimSpace(os.Getenv("SOAK_AUTO_PURGE"))) {
case "y", "yes", "true", "1", "on":
t.Logf("%s yes (SOAK_AUTO_PURGE)", prompt)
return true
case "n", "no", "false", "0", "off":
t.Logf("%s no (SOAK_AUTO_PURGE)", prompt)
return false
}
if !isInteractive() {
if defaultYes {
t.Logf("%s yes (non-interactive default)", prompt)
return true
}
t.Logf("%s no (non-interactive default)", prompt)
return false
}
defPrompt := "[y/N]"
if defaultYes {
defPrompt = "[Y/n]"
}
fmt.Printf("%s %s ", prompt, defPrompt)
reader := bufio.NewReader(os.Stdin)
text, err := reader.ReadString('\n')
if err != nil {
t.Logf("Failed to read response: %v (defaulting to no)", err)
return false
}
switch strings.ToLower(strings.TrimSpace(text)) {
case "", "y", "yes":
if defaultYes || text != "" {
return true
}
return false
case "n", "no":
return false
default:
return defaultYes
}
}
func promptYesNoDefaultNo(t *testing.T, prompt string) bool {
return promptYesNo(t, prompt, false)
}
func promptYesNoDefaultYes(t *testing.T, prompt string) bool {
return promptYesNo(t, prompt, true)
}
// StartS3Container starts a self-hosted S3 container and returns the container
// ID, endpoint and data volume name.
func StartS3Container(t *testing.T) (containerID string, endpoint string, volumeName string) {
t.Helper()
containerName := fmt.Sprintf("replicate-test-s3-%d", time.Now().Unix())
volumeName = fmt.Sprintf("replicate-test-s3-data-%d", time.Now().Unix())
s3Port := "9100"
// Clean up any existing container
exec.Command("docker", "stop", containerName).Run()
exec.Command("docker", "rm", containerName).Run()
// Remove any lingering volume with the same name, then create fresh volume.
exec.Command("docker", "volume", "rm", volumeName).Run()
if out, err := exec.Command("docker", "volume", "create", volumeName).CombinedOutput(); err != nil {
t.Fatalf("Failed to create S3 volume: %v\nOutput: %s", err, string(out))
}
// Start S3 container. The image entrypoint already serves the S3 API on
// :9000 backed by /data, so no command override is required.
cmd := exec.Command("docker", "run", "-d",
"--name", containerName,
"-p", s3Port+":9000",
"-v", volumeName+":/data",
"-e", "AWS_ACCESS_KEY_ID="+s3TestAccessKey,
"-e", "AWS_SECRET_ACCESS_KEY="+s3TestSecretKey,
s3TestImage)
output, err := cmd.CombinedOutput()
if err != nil {
t.Fatalf("Failed to start S3 container: %v\nOutput: %s", err, string(output))
}
containerID = strings.TrimSpace(string(output))
endpoint = fmt.Sprintf("http://localhost:%s", s3Port)
// Wait for the S3 API to answer its health probe.
if err := waitForS3Ready(endpoint, 60*time.Second); err != nil {
t.Fatalf("S3 container failed to become ready: %v", err)
}
// Verify container is running
cmd = exec.Command("docker", "ps", "-q", "-f", "name="+containerName)
output, err = cmd.CombinedOutput()
if err != nil || len(strings.TrimSpace(string(output))) == 0 {
t.Fatalf("S3 container failed to start properly")
}
t.Logf("S3 container started: %s (endpoint: %s)", containerID[:12], endpoint)
return containerID, endpoint, volumeName
}
// StopS3Container stops and removes an S3 container
func StopS3Container(t *testing.T, containerID string, volumeName string) {
t.Helper()
if containerID == "" {
return
}
t.Logf("Stopping S3 container: %s", containerID[:12])
exec.Command("docker", "stop", containerID).Run()
exec.Command("docker", "rm", containerID).Run()
if volumeName != "" {
exec.Command("docker", "volume", "rm", volumeName).Run()
}
}
// CreateS3Bucket creates a bucket on the self-hosted S3 server.
func CreateS3Bucket(t *testing.T, containerID, bucket string) {
t.Helper()
if s3BucketExists(containerID, bucket) {
if promptYesNoDefaultYes(t, fmt.Sprintf("Bucket '%s' already exists. Purge existing objects before running soak test?", bucket)) {
t.Logf("Purging S3 bucket '%s'...", bucket)
if err := clearS3Bucket(containerID, bucket); err != nil {
t.Fatalf("Failed to purge S3 bucket: %v", err)
}
} else {
t.Logf("Skipping purge of bucket '%s'. Residual data may cause replication errors.", bucket)
}
}
cmd := awsCLI(containerID, "s3", "mb", "s3://"+bucket)
_, stdoutBuf, stderrBuf := configureCmdIO(cmd)
if err := cmd.Run(); err != nil {
output := combinedOutput(stdoutBuf, stderrBuf)
if !strings.Contains(output, "BucketAlreadyOwnedByYou") && !strings.Contains(output, "BucketAlreadyExists") {
t.Fatalf("Create bucket failed: %v Output: %s", err, output)
}
}
if err := waitForS3Bucket(containerID, bucket, 60*time.Second); err != nil {
t.Fatalf("Bucket %s not ready: %v", bucket, err)
}
if err := clearS3Bucket(containerID, bucket); err != nil {
t.Fatalf("Failed to purge S3 bucket: %v", err)
}
t.Logf("S3 bucket '%s' ready", bucket)
}
func s3BucketExists(containerID, bucket string) bool {
cmd := awsCLI(containerID, "s3", "ls", "s3://"+bucket+"/")
_, _, _ = configureCmdIO(cmd)
return cmd.Run() == nil
}
func clearS3Bucket(containerID, bucket string) error {
cmd := awsCLI(containerID, "s3", "rm", "s3://"+bucket, "--recursive")
_, stdoutBuf, stderrBuf := configureCmdIO(cmd)
if err := cmd.Run(); err != nil {
output := combinedOutput(stdoutBuf, stderrBuf)
if output != "" {
return fmt.Errorf("%w: %s", err, output)
}
return err
}
return nil
}
func waitForS3Bucket(containerID, bucket string, timeout time.Duration) error {
deadline := time.Now().Add(timeout)
for {
if s3BucketExists(containerID, bucket) {
return nil
}
if time.Now().After(deadline) {
break
}
time.Sleep(500 * time.Millisecond)
}
return fmt.Errorf("bucket %s not available", bucket)
}
// CountBucketObjects counts objects in a bucket on a container-local S3 server.
func CountBucketObjects(t *testing.T, containerID, bucket string) int {
t.Helper()
cmd := awsCLI(containerID, "s3", "ls", "s3://"+bucket+"/", "--recursive")
_, stdoutBuf, stderrBuf := configureCmdIO(cmd)
if err := cmd.Run(); err != nil {
return 0
}
output := combinedOutput(stdoutBuf, stderrBuf)
lines := strings.Split(strings.TrimSpace(output), "\n")
if len(lines) == 1 && lines[0] == "" {
return 0
}
return len(lines)
}
// CheckAWSCredentials checks if AWS credentials are set and returns bucket and region
func CheckAWSCredentials(t *testing.T) (bucket, region string) {
t.Helper()
accessKey := os.Getenv("AWS_ACCESS_KEY_ID")
secretKey := os.Getenv("AWS_SECRET_ACCESS_KEY")
bucket = os.Getenv("S3_BUCKET")
region = os.Getenv("AWS_REGION")
if accessKey == "" || secretKey == "" || bucket == "" {
t.Skip("AWS credentials not set. Set AWS_ACCESS_KEY_ID, AWS_SECRET_ACCESS_KEY, and S3_BUCKET")
}
if region == "" {
region = "us-east-1"
}
t.Logf("Using AWS S3: bucket=%s, region=%s", bucket, region)
return bucket, region
}
// TestS3Connectivity tests if we can access the S3 bucket
func TestS3Connectivity(t *testing.T, bucket string) {
t.Helper()
cmd := exec.Command("aws", "s3", "ls", "s3://"+bucket+"/")
if err := cmd.Run(); err != nil {
t.Fatalf("Failed to access S3 bucket '%s': %v\nEnsure AWS CLI is installed and credentials are valid", bucket, err)
}
t.Logf("✓ S3 bucket '%s' is accessible", bucket)
}
// CountS3Objects counts objects in an S3 path
func CountS3Objects(t *testing.T, s3URL string) int {
t.Helper()
cmd := exec.Command("aws", "s3", "ls", s3URL+"/", "--recursive")
_, stdoutBuf, stderrBuf := configureCmdIO(cmd)
if err := cmd.Run(); err != nil {
return 0
}
output := combinedOutput(stdoutBuf, stderrBuf)
lines := strings.Split(strings.TrimSpace(output), "\n")
if len(lines) == 1 && lines[0] == "" {
return 0
}
return len(lines)
}
// GetS3StorageSize gets the total storage size of an S3 path
func GetS3StorageSize(t *testing.T, s3URL string) int64 {
t.Helper()
cmd := exec.Command("aws", "s3", "ls", s3URL+"/", "--recursive", "--summarize")
_, stdoutBuf, stderrBuf := configureCmdIO(cmd)
if err := cmd.Run(); err != nil {
return 0
}
output := combinedOutput(stdoutBuf, stderrBuf)
lines := strings.Split(output, "\n")
for _, line := range lines {
if strings.Contains(line, "Total Size:") {
var size int64
fmt.Sscanf(line, "Total Size: %d", &size)
return size
}
}
return 0
}
// CreateSoakConfig creates a replicate configuration file for soak tests
func CreateSoakConfig(dbPath, replicaURL string, s3Config *S3Config, shortMode bool) string {
tempDir := filepath.Dir(dbPath)
configPath := filepath.Join(tempDir, "replicate.yml")
var config strings.Builder
snapshotInterval := "10m"
snapshotRetention := "1h"
retentionCheckInterval := "5m"
levelIntervals := []string{"30s", "1m", "5m", "15m", "30m"}
if shortMode {
snapshotInterval = "30s"
snapshotRetention = "10m"
retentionCheckInterval = "2m"
levelIntervals = []string{"15s", "30s", "1m"}
}
// Add S3 credentials if provided
if s3Config != nil && s3Config.AccessKey != "" {
config.WriteString(fmt.Sprintf("access-key-id: %s\n", s3Config.AccessKey))
config.WriteString(fmt.Sprintf("secret-access-key: %s\n", s3Config.SecretKey))
config.WriteString("\n")
}
// Aggressive snapshot settings for testing
config.WriteString("snapshot:\n")
config.WriteString(fmt.Sprintf(" interval: %s\n", snapshotInterval))
config.WriteString(fmt.Sprintf(" retention: %s\n", snapshotRetention))
config.WriteString("\n")
// Aggressive compaction levels
config.WriteString("levels:\n")
for _, interval := range levelIntervals {
config.WriteString(fmt.Sprintf(" - interval: %s\n", interval))
}
config.WriteString("\n")
// Database configuration
config.WriteString("dbs:\n")
config.WriteString(fmt.Sprintf(" - path: %s\n", filepath.ToSlash(dbPath)))
config.WriteString(" checkpoint-interval: 1m\n")
config.WriteString(" min-checkpoint-page-count: 100\n")
config.WriteString(" truncate-page-n: 5000\n")
config.WriteString("\n")
config.WriteString(" replica:\n")
config.WriteString(fmt.Sprintf(" url: %s\n", replicaURL))
// Add S3-specific settings if provided (same indent level as url:)
if s3Config != nil {
if s3Config.Endpoint != "" {
config.WriteString(fmt.Sprintf(" endpoint: %s\n", s3Config.Endpoint))
}
if s3Config.Region != "" {
config.WriteString(fmt.Sprintf(" region: %s\n", s3Config.Region))
}
if s3Config.ForcePathStyle {
config.WriteString(" force-path-style: true\n")
}
if s3Config.SkipVerify {
config.WriteString(" skip-verify: true\n")
}
if s3Config.SSE != "" {
config.WriteString(fmt.Sprintf(" sse: %s\n", s3Config.SSE))
}
if s3Config.SSEKMSKeyID != "" {
config.WriteString(fmt.Sprintf(" sse-kms-key-id: %s\n", s3Config.SSEKMSKeyID))
}
config.WriteString(fmt.Sprintf(" retention-check-interval: %s\n", retentionCheckInterval))
}
if err := os.WriteFile(configPath, []byte(config.String()), 0644); err != nil {
panic(fmt.Sprintf("Failed to create config file: %v", err))
}
return configPath
}
// setupSignalHandler sets up SIGINT/SIGTERM handler with confirmation
func setupSignalHandler(t *testing.T, cancel context.CancelFunc, testInfo *TestInfo) {
t.Helper()
sigChan := make(chan os.Signal, 1)
signal.Notify(sigChan, syscall.SIGINT, syscall.SIGTERM)
go func() {
firstInterrupt := true
for sig := range sigChan {
if firstInterrupt {
firstInterrupt = false
t.Logf("")
t.Logf("━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━")
t.Logf("⚠ Interrupt signal received (%v)", sig)
t.Logf("━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━")
t.Logf("")
elapsed := time.Since(testInfo.StartTime)
remaining := testInfo.Duration - elapsed
pct := float64(elapsed) / float64(testInfo.Duration) * 100
t.Logf("Test Progress:")
t.Logf(" Elapsed: %v (%.0f%% complete)", elapsed.Round(time.Second), pct)
t.Logf(" Remaining: %v", remaining.Round(time.Second))
t.Logf(" Data collected: %d rows, %d replica files", testInfo.RowCount, testInfo.FileCount)
t.Logf("")
t.Logf("Press Ctrl+C again within 5 seconds to confirm shutdown.")
t.Logf("Otherwise, test will continue...")
t.Logf("")
// Wait 5 seconds for second interrupt
timeout := time.NewTimer(5 * time.Second)
select {
case <-sigChan:
// Second interrupt - confirmed shutdown
timeout.Stop()
t.Logf("Shutdown confirmed. Initiating graceful cleanup...")
cancel() // Cancel context to stop test
performGracefulShutdown(t, testInfo)
return
case <-timeout.C:
// Timeout - continue test
t.Logf("No confirmation received. Continuing test...")
t.Logf("━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━")
t.Logf("")
firstInterrupt = true
}
} else {
// Second interrupt received
t.Logf("Shutdown confirmed. Initiating graceful cleanup...")
cancel()
performGracefulShutdown(t, testInfo)
return
}
}
}()
t.Cleanup(func() {
signal.Stop(sigChan)
close(sigChan)
})
}
// performGracefulShutdown performs cleanup on early termination
func performGracefulShutdown(t *testing.T, testInfo *TestInfo) {
t.Helper()
if testInfo.cancel != nil {
testInfo.cancel()
}
t.Log("")
t.Log("================================================")
t.Log("Graceful Shutdown - Early Termination")
t.Log("================================================")
t.Log("")
elapsed := time.Since(testInfo.StartTime)
// Stop Replicate gracefully
t.Log("Stopping Replicate...")
if err := testInfo.DB.StopReplicate(); err != nil {
t.Logf("Warning: Error stopping Replicate: %v", err)
} else {
t.Log("✓ Replicate stopped")
}
// Wait for pending operations
t.Log("Waiting for pending operations to complete...")
time.Sleep(2 * time.Second)
// Show partial results
t.Log("")
t.Log("Partial Test Results:")
t.Logf(" Test duration: %v (%.0f%% of planned %v)",
elapsed.Round(time.Second),
float64(elapsed)/float64(testInfo.Duration)*100,
testInfo.Duration.Round(time.Minute))
if dbSize, err := testInfo.DB.GetDatabaseSize(); err == nil {
t.Logf(" Database size: %.2f MB", float64(dbSize)/(1024*1024))
}
if rowCount, err := testInfo.DB.GetRowCount("load_test"); err == nil {
t.Logf(" Rows inserted: %d", rowCount)
if elapsed.Seconds() > 0 {
rate := float64(rowCount) / elapsed.Seconds()
t.Logf(" Average write rate: %.1f rows/second", rate)
}
}
if fileCount, err := testInfo.DB.GetReplicaFileCount(); err == nil {
t.Logf(" Replica LTX files: %d", fileCount)
}
// Run abbreviated analysis
t.Log("")
t.Log("Analyzing partial test data...")
analysis := AnalyzeSoakTest(t, testInfo.DB, elapsed)
t.Log("")
t.Log("What Was Validated (Partial):")
if analysis.SnapshotCount > 0 {
t.Logf(" ✓ Snapshots: %d generated", analysis.SnapshotCount)
}
if analysis.TotalCompactions > 0 {
t.Logf(" ✓ Compactions: %d completed", analysis.TotalCompactions)
}
if analysis.DatabaseRows > 0 {
t.Logf(" ✓ Data written: %d rows", analysis.DatabaseRows)
}
// Check for errors
errors, _ := testInfo.DB.CheckForErrors()
t.Logf(" Critical errors: %d", len(errors))
// Show where data is preserved
t.Log("")
t.Log("Test artifacts preserved at:")
t.Logf(" %s", testInfo.DB.TempDir)
if logPath, err := testInfo.DB.GetReplicateLog(); err == nil {
t.Logf(" Log: %s", logPath)
}
t.Log("")
t.Log("Test terminated early by user.")
t.Log("================================================")
// Mark test as failed (early termination)
t.Fail()
}
// getErrorStats categorizes and counts errors
func getErrorStats(db *TestDB) ErrorStats {
errors, _ := db.CheckForErrors()
stats := ErrorStats{
TotalCount: len(errors),
ErrorsByType: make(map[string]int),
}
for _, errLine := range errors {
switch {
case strings.Contains(errLine, "connection refused"):
stats.BenignCount++
stats.ErrorsByType["connection refused"]++
case strings.Contains(errLine, "context canceled"):
stats.BenignCount++
stats.ErrorsByType["context canceled"]++
case strings.Contains(errLine, "db not ready"):
stats.BenignCount++
stats.ErrorsByType["db not ready"]++
case strings.Contains(errLine, "nonsequential page numbers"):
stats.CriticalCount++
stats.ErrorsByType["nonsequential page numbers"]++
if len(stats.RecentErrors) < 5 {
stats.RecentErrors = append(stats.RecentErrors, errLine)
}
case strings.Contains(errLine, "compaction gap"):
stats.CriticalCount++
stats.ErrorsByType["compaction gap"]++
if len(stats.RecentErrors) < 5 {
stats.RecentErrors = append(stats.RecentErrors, errLine)
}
default:
stats.CriticalCount++
if len(stats.RecentErrors) < 5 {
stats.RecentErrors = append(stats.RecentErrors, errLine)
}
switch {
case strings.Contains(errLine, "timeout"):
stats.ErrorsByType["timeout"]++
case strings.Contains(errLine, "compaction failed"):
stats.ErrorsByType["compaction failed"]++
default:
stats.ErrorsByType["other"]++
}
}
}
return stats
}
// printProgress displays progress bar with error status
func printProgress(t *testing.T, elapsed, total time.Duration, errorStats ErrorStats) {
t.Helper()
if total <= 0 {
total = time.Second
}
if elapsed < 0 {
elapsed = 0
}
pct := float64(elapsed) / float64(total) * 100
if pct > 100 {
pct = 100
} else if pct < 0 {
pct = 0
}
remaining := total - elapsed
if remaining < 0 {
remaining = 0
}
// Progress bar
barWidth := 40
filled := 0
if total.Seconds() > 0 {
ratio := elapsed.Seconds() / total.Seconds()
if ratio < 0 {
ratio = 0
} else if ratio > 1 {
ratio = 1
}
filled = int(float64(barWidth) * ratio)
}
if filled > barWidth {
filled = barWidth
}
if filled < 0 {
filled = 0
}
bar := strings.Repeat("█", filled) + strings.Repeat("░", barWidth-filled)
// Status indicator
status := "✓"
if errorStats.CriticalCount > 0 {
status = "⚠"
}
t.Logf("%s Progress: [%s] %.0f%% | %v elapsed | %v remaining | Errors: %d/%d",
status, bar, pct,
elapsed.Round(time.Minute), remaining.Round(time.Minute),
errorStats.CriticalCount, errorStats.TotalCount)
}
// printErrorDetails displays detailed error information
func printErrorDetails(t *testing.T, errorStats ErrorStats) {
t.Helper()
t.Log("")
t.Log("⚠ Error Status:")
t.Logf(" Total: %d (%d critical, %d benign)", errorStats.TotalCount, errorStats.CriticalCount, errorStats.BenignCount)
// Group critical errors by type
if errorStats.CriticalCount > 0 {
t.Log(" Critical errors:")
for errorType, count := range errorStats.ErrorsByType {
if count > 0 {
t.Logf(" • %q (%d)", errorType, count)
}
}
// Show recent errors
if len(errorStats.RecentErrors) > 0 {
t.Log("")
t.Log(" Recent errors:")
for _, errLine := range errorStats.RecentErrors {
// Extract just the error message
if idx := strings.Index(errLine, "error="); idx != -1 {
msg := errLine[idx+7:]
if len(msg) > 80 {
msg = msg[:80] + "..."
}
t.Logf(" %s", msg)
}
}
}
}
// Show benign errors if present
if errorStats.BenignCount > 0 {
t.Log("")
t.Logf(" Benign errors: %d", errorStats.BenignCount)
}
}
// shouldAbortTest checks if test should auto-abort due to critical issues
func shouldAbortTest(errorStats ErrorStats, fileCount int, elapsed time.Duration) (bool, string) {
// Abort if critical error threshold exceeded after extended runtime
if elapsed > 10*time.Minute && errorStats.CriticalCount > 100 {
return true, fmt.Sprintf("Critical error threshold exceeded (%d errors)", errorStats.CriticalCount)
}
// Abort if replication completely stopped (0 files after 10 minutes)
if elapsed > 10*time.Minute && fileCount == 0 {
return true, "Replication not working (0 files created after 10 minutes)"
}
// Abort if error rate is increasing rapidly (>1 error/minute)
if errorStats.CriticalCount > 0 && elapsed > 30*time.Minute {
minutes := elapsed.Minutes()
if minutes > 0 {
errorRate := float64(errorStats.CriticalCount) / minutes
if errorRate > 2.0 {
return true, fmt.Sprintf("Error rate too high (%.1f errors/minute)", errorRate)
}
}
}
return false, ""
}
// MonitorSoakTest monitors a soak test, calling metricsFunc every 60 seconds
func MonitorSoakTest(t *testing.T, db *TestDB, ctx context.Context, info *TestInfo, refresh func(), logFunc func()) {
t.Helper()
if info == nil {
info = &TestInfo{}
}
ticker := time.NewTicker(60 * time.Second)
defer ticker.Stop()
lastCritical := -1
lastTotal := -1
lastProgress := -1.0
for {
select {
case <-ctx.Done():
if refresh != nil {
refresh()
}
if info != nil {
// Show final progress snapshot
errorStats := getErrorStats(db)
if lastProgress < 0 || lastProgress < 100 || errorStats.CriticalCount != lastCritical || errorStats.TotalCount != lastTotal {
printProgress(t, info.Duration, info.Duration, errorStats)
t.Logf("━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━")
t.Logf("[%s] Status Report", time.Now().Format("15:04:05"))
t.Logf("━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━")
if logFunc != nil {
logFunc()
}
if errorStats.CriticalCount > 0 {
printErrorDetails(t, errorStats)
}
}
}
t.Log("Monitoring stopped: test duration completed")
return
case <-ticker.C:
if refresh != nil {
refresh()
}
elapsed := time.Since(info.StartTime)
if elapsed < 0 {
elapsed = 0
}
errorStats := getErrorStats(db)
if shouldAbort, reason := shouldAbortTest(errorStats, info.FileCount, elapsed); shouldAbort {
t.Logf("")
t.Logf("⚠ AUTO-ABORTING TEST: %s", reason)
if info.cancel != nil {
info.cancel()
}
t.Fail()
return
}
totalDuration := info.Duration
if totalDuration <= 0 {
totalDuration = time.Second
}
progress := elapsed.Seconds() / totalDuration.Seconds() * 100
if progress < 0 {
progress = 0
} else if progress > 100 {
progress = 100
}
shouldLog := false
if lastCritical == -1 && lastTotal == -1 {
shouldLog = true
}
if !shouldLog && (errorStats.CriticalCount != lastCritical || errorStats.TotalCount != lastTotal) {
shouldLog = true
}
if !shouldLog && (lastProgress < 0 || progress >= lastProgress+5 || progress >= 100) {
shouldLog = true
}
if !shouldLog {
continue
}
lastCritical = errorStats.CriticalCount
lastTotal = errorStats.TotalCount
lastProgress = progress
printProgress(t, elapsed, info.Duration, errorStats)
t.Logf("━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━")
t.Logf("[%s] Status Report", time.Now().Format("15:04:05"))
t.Logf("━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━")
if logFunc != nil {
logFunc()
}
if errorStats.CriticalCount > 0 {
printErrorDetails(t, errorStats)
}
t.Log("")
}
}
}
// LogSoakMetrics logs basic soak test metrics
func LogSoakMetrics(t *testing.T, db *TestDB, testName string) {
t.Helper()
// Database size
if dbSize, err := db.GetDatabaseSize(); err == nil {
t.Logf(" Database size: %.2f MB", float64(dbSize)/(1024*1024))
}
// WAL size
walPath := db.Path + "-wal"
if info, err := os.Stat(walPath); err == nil {
t.Logf(" WAL size: %.2f MB", float64(info.Size())/(1024*1024))
}
// Row count
if count, err := db.GetRowCount("load_test"); err == nil {
t.Logf(" Rows: %d", count)
} else if count, err := db.GetRowCount("test_table_0"); err == nil {
t.Logf(" Rows: %d", count)
}
// Replica stats
if fileCount, err := db.GetReplicaFileCount(); err == nil {
t.Logf(" Replica LTX files: %d", fileCount)
}
// Error check
if errors, err := db.CheckForErrors(); err == nil && len(errors) > 0 {
t.Logf(" ⚠ Critical errors detected: %d", len(errors))
if len(errors) <= 2 {
for _, errLine := range errors {
t.Logf(" %s", errLine)
}
}
}
}
// SoakTestAnalysis holds detailed soak test metrics
type SoakTestAnalysis struct {
CompactionsByLevel map[int]int
TotalCompactions int
SnapshotCount int
CheckpointCount int
TotalFilesCreated int
FinalFileCount int
MinTxID string
MaxTxID string
DatabaseRows int64
MinRowID int64
MaxRowID int64
DatabaseSizeMB float64
Duration time.Duration
}
// AnalyzeSoakTest analyzes test results from logs and database
func AnalyzeSoakTest(t *testing.T, db *TestDB, duration time.Duration) *SoakTestAnalysis {
t.Helper()
analysis := &SoakTestAnalysis{
CompactionsByLevel: make(map[int]int),
Duration: duration,
}
// Get database stats
if count, err := db.GetRowCount("load_test"); err == nil {
analysis.DatabaseRows = int64(count)
}
if dbSize, err := db.GetDatabaseSize(); err == nil {
analysis.DatabaseSizeMB = float64(dbSize) / (1024 * 1024)
}
// Get row ID range
sqlDB, err := sql.Open("sqlite", db.Path)
if err == nil {
defer sqlDB.Close()
sqlDB.QueryRow("SELECT MIN(id), MAX(id) FROM load_test").Scan(&analysis.MinRowID, &analysis.MaxRowID)
}
// Get final file count
if count, err := db.GetReplicaFileCount(); err == nil {
analysis.FinalFileCount = count
}
// Parse replicate log
logPath, _ := db.GetReplicateLog()
if logPath != "" {
parseLog(logPath, analysis)
}
return analysis
}
func parseLog(logPath string, analysis *SoakTestAnalysis) {
file, err := os.Open(logPath)
if err != nil {
return
}
defer file.Close()
scanner := bufio.NewScanner(file)
var firstTxID, lastTxID string
for scanner.Scan() {
line := scanner.Text()
if strings.Contains(line, "compaction complete") {
analysis.TotalCompactions++
// Extract level
if idx := strings.Index(line, "level="); idx != -1 {
levelStr := line[idx+6:]
if spaceIdx := strings.Index(levelStr, " "); spaceIdx != -1 {
levelStr = levelStr[:spaceIdx]
}
if level, err := strconv.Atoi(levelStr); err == nil {
analysis.CompactionsByLevel[level]++
}
}
// Extract transaction IDs
if idx := strings.Index(line, "txid.min="); idx != -1 {
txMin := line[idx+9 : idx+25]
if firstTxID == "" {
firstTxID = txMin
}
}
if idx := strings.Index(line, "txid.max="); idx != -1 {
txMax := line[idx+9 : idx+25]
lastTxID = txMax
}
}
if strings.Contains(line, "snapshot complete") {
analysis.SnapshotCount++
}
if strings.Contains(line, "checkpoint complete") {
analysis.CheckpointCount++
}
}
analysis.MinTxID = firstTxID
analysis.MaxTxID = lastTxID
// Count all LTX files ever created (from txid range)
if analysis.MaxTxID != "" {
if maxID, err := strconv.ParseInt(analysis.MaxTxID, 16, 64); err == nil {
analysis.TotalFilesCreated = int(maxID)
}
}
}
// PrintSoakTestAnalysis prints detailed analysis and plain English summary
func PrintSoakTestAnalysis(t *testing.T, analysis *SoakTestAnalysis) {
t.Helper()
t.Log("")
t.Log("================================================")
t.Log("Detailed Test Metrics")
t.Log("================================================")
t.Log("")
// Compaction breakdown
t.Log("Compaction Activity:")
t.Logf(" Total compactions: %d", analysis.TotalCompactions)
levels := []int{1, 2, 3, 4, 5}
for _, level := range levels {
if count := analysis.CompactionsByLevel[level]; count > 0 {
t.Logf(" Level %d: %d compactions", level, count)
}
}
t.Log("")
// File operations
t.Log("File Operations:")
t.Logf(" Total LTX files created: %d", analysis.TotalFilesCreated)
if analysis.TotalFilesCreated > 0 {
t.Logf(" Final file count: %d (%.1f%% reduction)",
analysis.FinalFileCount,
100.0*float64(analysis.TotalFilesCreated-analysis.FinalFileCount)/float64(analysis.TotalFilesCreated))
}
t.Logf(" Snapshots generated: %d", analysis.SnapshotCount)
if analysis.CheckpointCount > 0 {
t.Logf(" Checkpoints: %d", analysis.CheckpointCount)
}
t.Log("")
// Database activity
t.Log("Database Activity:")
t.Logf(" Total rows: %d", analysis.DatabaseRows)
t.Logf(" Row ID range: %d → %d", analysis.MinRowID, analysis.MaxRowID)
gapCount := (analysis.MaxRowID - analysis.MinRowID + 1) - analysis.DatabaseRows
if gapCount == 0 {
t.Log(" Row continuity: ✓ No gaps (perfect)")
} else {
t.Logf(" Row continuity: %d gaps detected", gapCount)
}
t.Logf(" Final database size: %.2f MB", analysis.DatabaseSizeMB)
if analysis.Duration.Seconds() > 0 {
avgRate := float64(analysis.DatabaseRows) / analysis.Duration.Seconds()
t.Logf(" Average write rate: %.1f rows/second", avgRate)
}
t.Log("")
// Transaction range
if analysis.MinTxID != "" && analysis.MaxTxID != "" {
t.Log("Replication Range:")
t.Logf(" First transaction: %s", analysis.MinTxID)
t.Logf(" Last transaction: %s", analysis.MaxTxID)
t.Log("")
}
// Plain English summary
t.Log("================================================")
t.Log("What This Test Validated")
t.Log("================================================")
t.Log("")
t.Logf("✓ Long-term Stability")
t.Logf(" Replicate ran flawlessly for %v under sustained load", analysis.Duration.Round(time.Minute))
t.Log("")
t.Log("✓ Snapshot Generation")
t.Logf(" %d snapshots created successfully", analysis.SnapshotCount)
t.Log("")
t.Log("✓ Compaction Efficiency")
if analysis.TotalFilesCreated > 0 {
reductionPct := 100.0 * float64(analysis.TotalFilesCreated-analysis.FinalFileCount) / float64(analysis.TotalFilesCreated)
t.Logf(" Reduced %d files to %d (%.0f%% reduction through compaction)",
analysis.TotalFilesCreated, analysis.FinalFileCount, reductionPct)
}
t.Log("")
if analysis.DatabaseSizeMB > 1000 {
t.Log("✓ Large Database Handling")
t.Logf(" Successfully replicated %.1f GB database", analysis.DatabaseSizeMB/1024)
t.Log("")
}
t.Log("✓ Restoration Capability")
t.Log(" Full restore from replica completed successfully")
t.Log("")
t.Log("✓ Data Integrity")
t.Log(" SQLite integrity check confirmed no corruption")
if gapCount == 0 {
t.Log(" All rows present with perfect continuity")
}
t.Log("")
}