From 3d2f970f04f735167b6a5338548f05d715a0a39a Mon Sep 17 00:00:00 2001 From: mleku Date: Sat, 13 Sep 2025 20:49:25 +0100 Subject: [PATCH] added profiler tooling to enable automated generation of profile reports --- profiler/analyze.sh | 16 +- profiler/reports/profile-analysis.txt | 237 +++++++++++++----- .../next-orly-alloc_results.txt | 190 -------------- .../next-orly-cpu_results.txt | 190 -------------- .../next-orly-mem_results.txt | 190 -------------- .../aggregate_report.txt | 68 ++--- .../next-orly-alloc_results.txt | 190 ++++++++++++++ .../next-orly-cpu_results.txt | 190 ++++++++++++++ .../next-orly-mem_results.txt | 190 ++++++++++++++ 9 files changed, 784 insertions(+), 677 deletions(-) delete mode 100644 profiler/reports/run_20250913_114010/next-orly-alloc_results.txt delete mode 100644 profiler/reports/run_20250913_114010/next-orly-cpu_results.txt delete mode 100644 profiler/reports/run_20250913_114010/next-orly-mem_results.txt rename profiler/reports/{run_20250913_114010 => run_20250913_150837}/aggregate_report.txt (59%) create mode 100644 profiler/reports/run_20250913_150837/next-orly-alloc_results.txt create mode 100644 profiler/reports/run_20250913_150837/next-orly-cpu_results.txt create mode 100644 profiler/reports/run_20250913_150837/next-orly-mem_results.txt diff --git a/profiler/analyze.sh b/profiler/analyze.sh index fef6d64..71a58e0 100644 --- a/profiler/analyze.sh +++ b/profiler/analyze.sh @@ -43,8 +43,8 @@ if [[ -z "$ALLOC_FILE" ]]; then echo "[analyze] WARNING: Alloc profile not found echo if [[ -n "$CPU_FILE" && -s "$CPU_FILE" ]]; then - echo "-- CPU Hotspots (top by flat CPU) --" - go tool pprof -top -nodecount=15 "$BIN" "$CPU_FILE" 2>/dev/null | sed '1,2d' + echo "-- CPU Functions (full list by flat CPU) --" + go tool pprof -top -nodecount=0 "$BIN" "$CPU_FILE" 2>/dev/null | sed '1,2d' echo else echo "CPU profile: not available" @@ -52,8 +52,8 @@ if [[ -z "$ALLOC_FILE" ]]; then echo "[analyze] WARNING: Alloc profile not found fi if [[ -n "$MEM_FILE" && -s "$MEM_FILE" ]]; then - echo "-- Memory (In-Use Space) Hotspots --" - go tool pprof -top -sample_index=inuse_space -nodecount=15 "$BIN" "$MEM_FILE" 2>/dev/null | sed '1,2d' + echo "-- Memory (In-Use Space) Functions (full list) --" + go tool pprof -top -sample_index=inuse_space -nodecount=0 "$BIN" "$MEM_FILE" 2>/dev/null | sed '1,2d' echo else echo "Memory (in-use) profile: not available" @@ -61,11 +61,11 @@ if [[ -z "$ALLOC_FILE" ]]; then echo "[analyze] WARNING: Alloc profile not found fi if [[ -n "$ALLOC_FILE" && -s "$ALLOC_FILE" ]]; then - echo "-- Allocations (Total Alloc Space) Hotspots --" - go tool pprof -top -sample_index=alloc_space -nodecount=15 "$BIN" "$ALLOC_FILE" 2>/dev/null | sed '1,2d' + echo "-- Allocations (Total Alloc Space) Functions (full list) --" + go tool pprof -top -sample_index=alloc_space -nodecount=0 "$BIN" "$ALLOC_FILE" 2>/dev/null | sed '1,2d' echo - echo "-- Allocation Frequency (Alloc Objects) --" - go tool pprof -top -sample_index=alloc_objects -nodecount=15 "$BIN" "$ALLOC_FILE" 2>/dev/null | sed '1,2d' + echo "-- Allocation Frequency (Alloc Objects) Functions (full list) --" + go tool pprof -top -sample_index=alloc_objects -nodecount=0 "$BIN" "$ALLOC_FILE" 2>/dev/null | sed '1,2d' echo else echo "Allocation profile: not available" diff --git a/profiler/reports/profile-analysis.txt b/profiler/reports/profile-analysis.txt index fedfa12..2f67e3a 100644 --- a/profiler/reports/profile-analysis.txt +++ b/profiler/reports/profile-analysis.txt @@ -1,81 +1,188 @@ ==== next.orly.dev Profiling Analysis ==== -Sat Sep 13 11:46:40 UTC 2025 +Sat Sep 13 15:15:09 UTC 2025 --- CPU Hotspots (top by flat CPU) -- +-- CPU Functions (full list by flat CPU) -- Type: cpu -Time: Sep 13, 2025 at 11:39am (UTC) -Duration: 400.39s, Total samples = 2620ms ( 0.65%) -Showing nodes accounting for 1950ms, 74.43% of 2620ms total -Dropped 58 nodes (cum <= 13.10ms) -Showing top 15 nodes out of 78 +Time: Sep 13, 2025 at 3:08pm (UTC) +Duration: 401.93s, Total samples = 2.67s ( 0.66%) +Showing nodes accounting for 2.48s, 92.88% of 2.67s total +Dropped 51 nodes (cum <= 0.01s) flat flat% sum% cum cum% - 870ms 33.21% 33.21% 870ms 33.21% internal/runtime/syscall.Syscall6 - 220ms 8.40% 41.60% 220ms 8.40% runtime.futex - 210ms 8.02% 49.62% 400ms 15.27% runtime.stealWork - 160ms 6.11% 55.73% 160ms 6.11% runtime.write1 - 70ms 2.67% 58.40% 70ms 2.67% runtime.nanotime1 - 60ms 2.29% 60.69% 60ms 2.29% runtime.pMask.read (inline) - 50ms 1.91% 62.60% 380ms 14.50% github.com/dgraph-io/badger/v4.(*levelsController).runCompactor - 50ms 1.91% 64.50% 50ms 1.91% runtime.(*randomEnum).next (inline) - 50ms 1.91% 66.41% 1980ms 75.57% runtime.findRunnable - 40ms 1.53% 67.94% 40ms 1.53% runtime.memclrNoHeapPointers - 40ms 1.53% 69.47% 930ms 35.50% runtime.netpoll - 40ms 1.53% 70.99% 150ms 5.73% runtime.selectgo - 30ms 1.15% 72.14% 860ms 32.82% internal/runtime/syscall.EpollWait - 30ms 1.15% 73.28% 40ms 1.53% runtime.(*mcache).prepareForSweep - 30ms 1.15% 74.43% 30ms 1.15% runtime.cheaprand (inline) + 0.78s 29.21% 29.21% 0.78s 29.21% internal/runtime/syscall.Syscall6 + 0.27s 10.11% 39.33% 0.27s 10.11% runtime.futex + 0.12s 4.49% 43.82% 0.12s 4.49% runtime.write1 + 0.11s 4.12% 47.94% 0.34s 12.73% runtime.stealWork + 0.09s 3.37% 51.31% 0.09s 3.37% runtime.read + 0.08s 3.00% 54.31% 1.94s 72.66% runtime.findRunnable + 0.08s 3.00% 57.30% 0.08s 3.00% runtime.pMask.read (inline) + 0.05s 1.87% 59.18% 0.06s 2.25% runtime.sellock + 0.05s 1.87% 61.05% 0.05s 1.87% runtime.unlock2 + 0.04s 1.50% 62.55% 0.43s 16.10% github.com/dgraph-io/badger/v4.(*levelsController).runCompactor + 0.04s 1.50% 64.04% 0.89s 33.33% runtime.netpoll + 0.04s 1.50% 65.54% 0.16s 5.99% runtime.selectgo + 0.03s 1.12% 66.67% 0.04s 1.50% github.com/dgraph-io/ristretto/v2/z.(*Closer).HasBeenClosed (inline) + 0.03s 1.12% 67.79% 0.03s 1.12% internal/runtime/atomic.(*Uint32).CompareAndSwap (inline) + 0.03s 1.12% 68.91% 0.04s 1.50% runtime.mallocgcSmallNoscan + 0.03s 1.12% 70.04% 0.03s 1.12% runtime.pMask.set (inline) + 0.03s 1.12% 71.16% 0.03s 1.12% runtime.releaseSudog + 0.03s 1.12% 72.28% 0.03s 1.12% sync/atomic.(*Int32).Add (inline) + 0.02s 0.75% 73.03% 0.02s 0.75% github.com/dgraph-io/badger/v4.(*compactStatus).delSize + 0.02s 0.75% 73.78% 0.08s 3.00% github.com/dgraph-io/badger/v4.(*levelsController).levelTargets + 0.02s 0.75% 74.53% 0.20s 7.49% github.com/dgraph-io/badger/v4.(*levelsController).pickCompactLevels + 0.02s 0.75% 75.28% 0.02s 0.75% internal/reflectlite.unpackEface (inline) + 0.02s 0.75% 76.03% 0.02s 0.75% internal/runtime/atomic.(*Uint32).Load (inline) + 0.02s 0.75% 76.78% 0.04s 1.50% runtime.(*mcache).prepareForSweep + 0.02s 0.75% 77.53% 0.02s 0.75% runtime.(*randomEnum).next (inline) + 0.02s 0.75% 78.28% 0.03s 1.12% runtime.casgstatus + 0.02s 0.75% 79.03% 0.03s 1.12% runtime.checkRunqsNoP + 0.02s 0.75% 79.78% 0.02s 0.75% runtime.execute + 0.02s 0.75% 80.52% 0.19s 7.12% runtime.futexsleep + 0.02s 0.75% 81.27% 0.02s 0.75% runtime.lock2 + 0.02s 0.75% 82.02% 0.02s 0.75% runtime.nanotime1 + 0.02s 0.75% 82.77% 0.02s 0.75% runtime.nextFreeFast (inline) + 0.02s 0.75% 83.52% 0.02s 0.75% runtime.pidleput + 0.02s 0.75% 84.27% 0.02s 0.75% runtime.runqget (inline) + 0.02s 0.75% 85.02% 2.10s 78.65% runtime.schedule + 0.02s 0.75% 85.77% 0.02s 0.75% runtime.traceEnabled (inline) + 0.02s 0.75% 86.52% 0.03s 1.12% time.Now + 0.02s 0.75% 87.27% 0.03s 1.12% time.Time.Add + 0.01s 0.37% 87.64% 0.04s 1.50% github.com/dgraph-io/badger/v4.(*levelHandler).getTotalSize + 0.01s 0.37% 88.01% 0.76s 28.46% internal/runtime/syscall.EpollWait + 0.01s 0.37% 88.39% 0.14s 5.24% runtime.(*timer).unlockAndRun + 0.01s 0.37% 88.76% 0.03s 1.12% runtime.(*waitq).dequeue (inline) + 0.01s 0.37% 89.14% 0.07s 2.62% runtime.acquirep + 0.01s 0.37% 89.51% 0.04s 1.50% runtime.checkTimersNoP + 0.01s 0.37% 89.89% 0.02s 0.75% runtime.mallocgcSmallScanNoHeader + 0.01s 0.37% 90.26% 0.02s 0.75% runtime.markroot + 0.01s 0.37% 90.64% 2.12s 79.40% runtime.mcall + 0.01s 0.37% 91.01% 2.11s 79.03% runtime.park_m + 0.01s 0.37% 91.39% 0.02s 0.75% runtime.traceAcquire (inline) + 0.01s 0.37% 91.76% 0.12s 4.49% runtime.wakep + 0.01s 0.37% 92.13% 0.13s 4.87% runtime.write + 0.01s 0.37% 92.51% 0.03s 1.12% sort.Slice + 0.01s 0.37% 92.88% 0.13s 4.87% time.sendTime + 0 0% 92.88% 0.02s 0.75% github.com/dgraph-io/badger/v4.(*DB).openMemTable + 0 0% 92.88% 0.02s 0.75% github.com/dgraph-io/badger/v4.(*DB).openMemTables + 0 0% 92.88% 0.20s 7.49% github.com/dgraph-io/badger/v4.(*levelsController).runCompactor.func3 + 0 0% 92.88% 0.02s 0.75% github.com/dgraph-io/badger/v4.(*logFile).Truncate + 0 0% 92.88% 0.03s 1.12% github.com/dgraph-io/badger/v4.Open + 0 0% 92.88% 0.02s 0.75% github.com/dgraph-io/ristretto/v2/z.(*MmapFile).Truncate + 0 0% 92.88% 0.02s 0.75% internal/poll.(*FD).Ftruncate + 0 0% 92.88% 0.02s 0.75% internal/poll.(*FD).Ftruncate.func1 (inline) + 0 0% 92.88% 0.02s 0.75% internal/poll.ignoringEINTR (inline) + 0 0% 92.88% 0.02s 0.75% internal/reflectlite.ValueOf (inline) + 0 0% 92.88% 0.03s 1.12% main.main + 0 0% 92.88% 0.03s 1.12% next.orly.dev/pkg/database.New + 0 0% 92.88% 0.02s 0.75% os.(*File).Truncate + 0 0% 92.88% 0.17s 6.37% runtime.(*timers).check + 0 0% 92.88% 0.14s 5.24% runtime.(*timers).run + 0 0% 92.88% 0.06s 2.25% runtime.chansend + 0 0% 92.88% 0.02s 0.75% runtime.convTslice + 0 0% 92.88% 0.10s 3.75% runtime.futexwakeup + 0 0% 92.88% 0.02s 0.75% runtime.gcBgMarkWorker + 0 0% 92.88% 0.02s 0.75% runtime.gcBgMarkWorker.func2 + 0 0% 92.88% 0.02s 0.75% runtime.gcDrain + 0 0% 92.88% 0.02s 0.75% runtime.gcDrainMarkWorkerDedicated (inline) + 0 0% 92.88% 0.03s 1.12% runtime.goready (inline) + 0 0% 92.88% 0.02s 0.75% runtime.lock (inline) + 0 0% 92.88% 0.02s 0.75% runtime.lockWithRank (inline) + 0 0% 92.88% 0.19s 7.12% runtime.mPark (inline) + 0 0% 92.88% 0.03s 1.12% runtime.main + 0 0% 92.88% 0.05s 1.87% runtime.makeslice + 0 0% 92.88% 0.07s 2.62% runtime.mallocgc + 0 0% 92.88% 0.13s 4.87% runtime.netpollBreak + 0 0% 92.88% 0.19s 7.12% runtime.notesleep + 0 0% 92.88% 0.10s 3.75% runtime.notewakeup + 0 0% 92.88% 0.04s 1.50% runtime.pidleget + 0 0% 92.88% 0.03s 1.12% runtime.ready + 0 0% 92.88% 0.12s 4.49% runtime.resetspinning + 0 0% 92.88% 0.06s 2.25% runtime.selectnbsend + 0 0% 92.88% 0.03s 1.12% runtime.send + 0 0% 92.88% 0.03s 1.12% runtime.send.goready.func1 + 0 0% 92.88% 0.10s 3.75% runtime.startm + 0 0% 92.88% 0.21s 7.87% runtime.stopm + 0 0% 92.88% 0.03s 1.12% runtime.systemstack + 0 0% 92.88% 0.05s 1.87% runtime.unlock (inline) + 0 0% 92.88% 0.05s 1.87% runtime.unlockWithRank (inline) + 0 0% 92.88% 0.02s 0.75% sync.(*RWMutex).RLock (inline) + 0 0% 92.88% 0.02s 0.75% syscall.Ftruncate + 0 0% 92.88% 0.03s 1.12% syscall.RawSyscall6 + 0 0% 92.88% 0.03s 1.12% syscall.Syscall --- Memory (In-Use Space) Hotspots -- +-- Memory (In-Use Space) Functions (full list) -- Type: inuse_space -Time: Sep 13, 2025 at 11:46am (UTC) -Showing nodes accounting for 85209.25kB, 99.24% of 85865.58kB total -Dropped 112 nodes (cum <= 429.33kB) +Time: Sep 13, 2025 at 3:15pm (UTC) +Showing nodes accounting for 85209.25kB, 99.24% of 85860.37kB total +Dropped 121 nodes (cum <= 429.30kB) flat flat% sum% cum cum% - 85200kB 99.22% 99.22% 85200kB 99.22% github.com/dgraph-io/badger/v4/skl.newArena (inline) - 9.25kB 0.011% 99.24% 85654.66kB 99.75% github.com/dgraph-io/badger/v4.Open - 0 0% 99.24% 85200kB 99.22% github.com/dgraph-io/badger/v4.(*DB).newMemTable - 0 0% 99.24% 85200kB 99.22% github.com/dgraph-io/badger/v4.(*DB).openMemTable - 0 0% 99.24% 85200kB 99.22% github.com/dgraph-io/badger/v4/skl.NewSkiplist - 0 0% 99.24% 85654.66kB 99.75% main.main - 0 0% 99.24% 85654.66kB 99.75% next.orly.dev/pkg/database.New - 0 0% 99.24% 85654.66kB 99.75% runtime.main + 85200kB 99.23% 99.23% 85200kB 99.23% github.com/dgraph-io/badger/v4/skl.newArena (inline) + 9.25kB 0.011% 99.24% 85632.26kB 99.73% github.com/dgraph-io/badger/v4.Open + 0 0% 99.24% 85200kB 99.23% github.com/dgraph-io/badger/v4.(*DB).newMemTable + 0 0% 99.24% 85200kB 99.23% github.com/dgraph-io/badger/v4.(*DB).openMemTable + 0 0% 99.24% 85200kB 99.23% github.com/dgraph-io/badger/v4/skl.NewSkiplist + 0 0% 99.24% 85632.26kB 99.73% main.main + 0 0% 99.24% 85632.26kB 99.73% next.orly.dev/pkg/database.New + 0 0% 99.24% 85632.26kB 99.73% runtime.main --- Allocations (Total Alloc Space) Hotspots -- +-- Allocations (Total Alloc Space) Functions (full list) -- Type: alloc_space -Time: Sep 13, 2025 at 11:46am (UTC) -Showing nodes accounting for 83.20MB, 100% of 83.21MB total -Dropped 26 nodes (cum <= 0.42MB) +Time: Sep 13, 2025 at 3:15pm (UTC) +Showing nodes accounting for 87.20MB, 100% of 87.21MB total +Dropped 15 nodes (cum <= 0.44MB) flat flat% sum% cum cum% - 83.20MB 100% 100% 83.20MB 100% github.com/dgraph-io/badger/v4/skl.newArena (inline) - 0 0% 100% 83.20MB 100% github.com/dgraph-io/badger/v4.(*DB).newMemTable - 0 0% 100% 83.20MB 100% github.com/dgraph-io/badger/v4.(*DB).openMemTable - 0 0% 100% 83.20MB 100% github.com/dgraph-io/badger/v4.Open - 0 0% 100% 83.20MB 100% github.com/dgraph-io/badger/v4/skl.NewSkiplist - 0 0% 100% 83.20MB 100% main.main - 0 0% 100% 83.20MB 100% next.orly.dev/pkg/database.New - 0 0% 100% 83.20MB 100% runtime.main + 83.20MB 95.40% 95.40% 83.20MB 95.40% github.com/dgraph-io/badger/v4/skl.newArena (inline) + 4MB 4.59% 100% 4MB 4.59% github.com/dgraph-io/ristretto/v2/z.Calloc (inline) + 0 0% 100% 4MB 4.59% github.com/dgraph-io/badger/v4.(*DB).flushMemtable + 0 0% 100% 4MB 4.59% github.com/dgraph-io/badger/v4.(*DB).handleMemTableFlush + 0 0% 100% 83.20MB 95.40% github.com/dgraph-io/badger/v4.(*DB).newMemTable + 0 0% 100% 83.20MB 95.40% github.com/dgraph-io/badger/v4.(*DB).openMemTable + 0 0% 100% 83.20MB 95.40% github.com/dgraph-io/badger/v4.Open + 0 0% 100% 4MB 4.59% github.com/dgraph-io/badger/v4.Open.func5 + 0 0% 100% 4MB 4.59% github.com/dgraph-io/badger/v4.buildL0Table + 0 0% 100% 83.20MB 95.40% github.com/dgraph-io/badger/v4/skl.NewSkiplist + 0 0% 100% 4MB 4.59% github.com/dgraph-io/badger/v4/table.NewTableBuilder + 0 0% 100% 4MB 4.59% github.com/dgraph-io/ristretto/v2/z.(*AllocatorPool).Get + 0 0% 100% 4MB 4.59% github.com/dgraph-io/ristretto/v2/z.NewAllocator + 0 0% 100% 83.20MB 95.40% main.main + 0 0% 100% 83.20MB 95.40% next.orly.dev/pkg/database.New + 0 0% 100% 83.20MB 95.40% runtime.main --- Allocation Frequency (Alloc Objects) -- +-- Allocation Frequency (Alloc Objects) Functions (full list) -- Type: alloc_objects -Time: Sep 13, 2025 at 11:46am (UTC) -Showing nodes accounting for 7, 100% of 7 total -Showing top 15 nodes out of 34 +Time: Sep 13, 2025 at 3:15pm (UTC) +Showing nodes accounting for 6, 100% of 6 total flat flat% sum% cum cum% - 2 28.57% 28.57% 2 28.57% regexp/syntax.(*parser).newRegexp (inline) - 1 14.29% 42.86% 1 14.29% github.com/dgraph-io/badger/v4.(*levelsController).levelTargets - 1 14.29% 57.14% 1 14.29% github.com/dgraph-io/badger/v4/skl.newArena (inline) - 1 14.29% 71.43% 1 14.29% github.com/pkg/profile.Start - 1 14.29% 85.71% 1 14.29% github.com/pkg/profile.Start.func11 - 1 14.29% 100% 1 14.29% runtime.allocm - 0 0% 100% 1 14.29% github.com/dgraph-io/badger/v4.(*DB).newMemTable - 0 0% 100% 1 14.29% github.com/dgraph-io/badger/v4.(*DB).openMemTable - 0 0% 100% 1 14.29% github.com/dgraph-io/badger/v4.(*levelsController).pickCompactLevels - 0 0% 100% 1 14.29% github.com/dgraph-io/badger/v4.(*levelsController).runCompactor - 0 0% 100% 1 14.29% github.com/dgraph-io/badger/v4.(*levelsController).runCompactor.func3 - 0 0% 100% 1 14.29% github.com/dgraph-io/badger/v4.Open - 0 0% 100% 1 14.29% github.com/dgraph-io/badger/v4/skl.NewSkiplist - 0 0% 100% 2 28.57% github.com/google/pprof/profile.init - 0 0% 100% 2 28.57% main.main + 1 16.67% 16.67% 1 16.67% github.com/dgraph-io/badger/v4/skl.newArena (inline) + 1 16.67% 33.33% 1 16.67% github.com/dgraph-io/ristretto/v2/z.Calloc (inline) + 1 16.67% 50.00% 1 16.67% github.com/pkg/profile.Start + 1 16.67% 66.67% 1 16.67% github.com/pkg/profile.Start.func11 + 1 16.67% 83.33% 1 16.67% runtime.allocm + 1 16.67% 100% 1 16.67% runtime.procresize + 0 0% 100% 1 16.67% github.com/dgraph-io/badger/v4.(*DB).flushMemtable + 0 0% 100% 1 16.67% github.com/dgraph-io/badger/v4.(*DB).handleMemTableFlush + 0 0% 100% 1 16.67% github.com/dgraph-io/badger/v4.(*DB).newMemTable + 0 0% 100% 1 16.67% github.com/dgraph-io/badger/v4.(*DB).openMemTable + 0 0% 100% 1 16.67% github.com/dgraph-io/badger/v4.Open + 0 0% 100% 1 16.67% github.com/dgraph-io/badger/v4.Open.func5 + 0 0% 100% 1 16.67% github.com/dgraph-io/badger/v4.buildL0Table + 0 0% 100% 1 16.67% github.com/dgraph-io/badger/v4/skl.NewSkiplist + 0 0% 100% 1 16.67% github.com/dgraph-io/badger/v4/table.NewTableBuilder + 0 0% 100% 1 16.67% github.com/dgraph-io/ristretto/v2/z.(*AllocatorPool).Get + 0 0% 100% 1 16.67% github.com/dgraph-io/ristretto/v2/z.NewAllocator + 0 0% 100% 2 33.33% main.main + 0 0% 100% 1 16.67% next.orly.dev/pkg/database.New + 0 0% 100% 2 33.33% runtime.main + 0 0% 100% 1 16.67% runtime.mstart + 0 0% 100% 1 16.67% runtime.mstart0 + 0 0% 100% 1 16.67% runtime.mstart1 + 0 0% 100% 1 16.67% runtime.newm + 0 0% 100% 1 16.67% runtime.resetspinning + 0 0% 100% 1 16.67% runtime.schedule + 0 0% 100% 1 16.67% runtime.startTheWorld.func1 + 0 0% 100% 1 16.67% runtime.startTheWorldWithSema + 0 0% 100% 1 16.67% runtime.startm + 0 0% 100% 1 16.67% runtime.systemstack + 0 0% 100% 1 16.67% runtime.wakep Notes: - CPU section identifies functions using the most CPU time. diff --git a/profiler/reports/run_20250913_114010/next-orly-alloc_results.txt b/profiler/reports/run_20250913_114010/next-orly-alloc_results.txt deleted file mode 100644 index 623d01a..0000000 --- a/profiler/reports/run_20250913_114010/next-orly-alloc_results.txt +++ /dev/null @@ -1,190 +0,0 @@ -Starting Nostr Relay Benchmark -Data Directory: /tmp/benchmark_next-orly-alloc_8 -Events: 5000, Workers: 4, Duration: 30s -20250913114427235918 INF /tmp/benchmark_next-orly-alloc_8: All 0 tables opened in 0s -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/levels.go:161 /build/pkg/database/logger.go:57 -20250913114427236368 INF /tmp/benchmark_next-orly-alloc_8: Discard stats nextEmptySlot: 0 -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/discard.go:55 /build/pkg/database/logger.go:57 -20250913114427236420 INF /tmp/benchmark_next-orly-alloc_8: Set nextTxnTs to 0 -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:358 /build/pkg/database/logger.go:57 -20250913114427237054 INF (*types.Uint32)(0xc0000100f0)({ - value: (uint32) 1 -}) - /build/pkg/database/migrations.go:65 -20250913114427237113 INF migrating to version 1... /build/pkg/database/migrations.go:79 - -=== Starting test round 1/2 === - -=== Peak Throughput Test === -Events saved: 5000/5000 (100.0%) -Duration: 339.941208ms -Events/sec: 14708.43 -Avg latency: 264.237µs -P90 latency: 347.802µs -P95 latency: 383.139µs -P99 latency: 447.141µs -Bottom 10% Avg latency: 399.688µs - -=== Burst Pattern Test === -Burst completed: 500 events in 496.639004ms -Burst completed: 500 events in 395.431081ms -Burst completed: 500 events in 411.025866ms -Burst completed: 500 events in 419.57678ms -Burst completed: 500 events in 489.269517ms -Burst completed: 500 events in 428.035789ms -Burst completed: 500 events in 476.345049ms -Burst completed: 500 events in 515.739514ms -Burst completed: 500 events in 414.702914ms -Burst completed: 500 events in 440.760343ms -Burst test completed: 5000 events in 9.501434093s -Events/sec: 526.24 - -=== Mixed Read/Write Test === -Pre-populating database for read tests... -Mixed test completed: 2500 writes, 2500 reads in 23.63556576s -Combined ops/sec: 211.55 - -Pausing 10s before next round... - -=== Starting test round 2/2 === - -=== Peak Throughput Test === -Events saved: 5000/5000 (100.0%) -Duration: 413.941287ms -Events/sec: 12079.01 -Avg latency: 323.873µs -P90 latency: 436.851µs -P95 latency: 488.881µs -P99 latency: 650.429µs -Bottom 10% Avg latency: 522.984µs - -=== Burst Pattern Test === -Burst completed: 500 events in 271.506837ms -Burst completed: 500 events in 361.931625ms -Burst completed: 500 events in 381.160975ms -Burst completed: 500 events in 310.403881ms -Burst completed: 500 events in 388.695936ms -Burst completed: 500 events in 323.300662ms -Burst completed: 500 events in 249.590375ms -Burst completed: 500 events in 318.935421ms -Burst completed: 500 events in 361.329644ms -Burst completed: 500 events in 474.806655ms -Burst test completed: 5000 events in 8.457868323s -Events/sec: 591.17 - -=== Mixed Read/Write Test === -Pre-populating database for read tests... -Mixed test completed: 2500 writes, 2152 reads in 30.024551334s -Combined ops/sec: 154.94 - -================================================================================ -BENCHMARK REPORT -================================================================================ - -Test: Peak Throughput -Duration: 339.941208ms -Total Events: 5000 -Events/sec: 14708.43 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 142 MB -Avg Latency: 264.237µs -P90 Latency: 347.802µs -P95 Latency: 383.139µs -P99 Latency: 447.141µs -Bottom 10% Avg Latency: 399.688µs ----------------------------------------- - -Test: Burst Pattern -Duration: 9.501434093s -Total Events: 5000 -Events/sec: 526.24 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 192 MB -Avg Latency: 182.339µs -P90 Latency: 240.387µs -P95 Latency: 270.195µs -P99 Latency: 333.575µs -Bottom 10% Avg Latency: 284.192µs ----------------------------------------- - -Test: Mixed Read/Write -Duration: 23.63556576s -Total Events: 5000 -Events/sec: 211.55 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 199 MB -Avg Latency: 4.300403ms -P90 Latency: 8.510786ms -P95 Latency: 10.117687ms -P99 Latency: 12.490155ms -Bottom 10% Avg Latency: 10.404696ms ----------------------------------------- - -Test: Peak Throughput -Duration: 413.941287ms -Total Events: 5000 -Events/sec: 12079.01 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 134 MB -Avg Latency: 323.873µs -P90 Latency: 436.851µs -P95 Latency: 488.881µs -P99 Latency: 650.429µs -Bottom 10% Avg Latency: 522.984µs ----------------------------------------- - -Test: Burst Pattern -Duration: 8.457868323s -Total Events: 5000 -Events/sec: 591.17 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 185 MB -Avg Latency: 213.464µs -P90 Latency: 290.884µs -P95 Latency: 333.555µs -P99 Latency: 446.27µs -Bottom 10% Avg Latency: 360.86µs ----------------------------------------- - -Test: Mixed Read/Write -Duration: 30.024551334s -Total Events: 4652 -Events/sec: 154.94 -Success Rate: 93.0% -Concurrent Workers: 4 -Memory Used: 137 MB -Avg Latency: 8.164383ms -P90 Latency: 17.857487ms -P95 Latency: 19.02409ms -P99 Latency: 21.306135ms -Bottom 10% Avg Latency: 19.344124ms ----------------------------------------- - -Report saved to: /tmp/benchmark_next-orly-alloc_8/benchmark_report.txt -AsciiDoc report saved to: /tmp/benchmark_next-orly-alloc_8/benchmark_report.adoc -20250913114629624246 INF /tmp/benchmark_next-orly-alloc_8: Lifetime L0 stalled for: 0s -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:536 /build/pkg/database/logger.go:57 -20250913114629944720 INF /tmp/benchmark_next-orly-alloc_8: -Level 0 [ ]: NumTables: 00. Size: 0 B of 0 B. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 64 MiB -Level 1 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 2 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 3 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 4 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 5 [B]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 6 [ ]: NumTables: 01. Size: 22 MiB of 22 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 4.0 MiB -Level Done -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:615 /build/pkg/database/logger.go:57 -20250913114629946593 INF /tmp/benchmark_next-orly-alloc_8: database closed /build/pkg/database/database.go:134 - -RELAY_NAME: next-orly-alloc -RELAY_URL: ws://next-orly-alloc:8080 -TEST_TIMESTAMP: 2025-09-13T11:46:29+00:00 -BENCHMARK_CONFIG: - Events: 5000 - Workers: 4 - Duration: 30s diff --git a/profiler/reports/run_20250913_114010/next-orly-cpu_results.txt b/profiler/reports/run_20250913_114010/next-orly-cpu_results.txt deleted file mode 100644 index 1fb465d..0000000 --- a/profiler/reports/run_20250913_114010/next-orly-cpu_results.txt +++ /dev/null @@ -1,190 +0,0 @@ -Starting Nostr Relay Benchmark -Data Directory: /tmp/benchmark_next-orly-cpu_8 -Events: 5000, Workers: 4, Duration: 30s -20250913114010336003 INF /tmp/benchmark_next-orly-cpu_8: All 0 tables opened in 0s -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/levels.go:161 /build/pkg/database/logger.go:57 -20250913114010336560 INF /tmp/benchmark_next-orly-cpu_8: Discard stats nextEmptySlot: 0 -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/discard.go:55 /build/pkg/database/logger.go:57 -20250913114010336587 INF /tmp/benchmark_next-orly-cpu_8: Set nextTxnTs to 0 -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:358 /build/pkg/database/logger.go:57 -20250913114010336810 INF (*types.Uint32)(0xc00001084c)({ - value: (uint32) 1 -}) - /build/pkg/database/migrations.go:65 -20250913114010336840 INF migrating to version 1... /build/pkg/database/migrations.go:79 - -=== Starting test round 1/2 === - -=== Peak Throughput Test === -Events saved: 5000/5000 (100.0%) -Duration: 363.618589ms -Events/sec: 13750.67 -Avg latency: 283.533µs -P90 latency: 378.941µs -P95 latency: 413.136µs -P99 latency: 527.123µs -Bottom 10% Avg latency: 455.08µs - -=== Burst Pattern Test === -Burst completed: 500 events in 383.290907ms -Burst completed: 500 events in 379.055138ms -Burst completed: 500 events in 344.482762ms -Burst completed: 500 events in 304.126389ms -Burst completed: 500 events in 274.619763ms -Burst completed: 500 events in 322.887417ms -Burst completed: 500 events in 277.199103ms -Burst completed: 500 events in 425.906745ms -Burst completed: 500 events in 471.907615ms -Burst completed: 500 events in 444.002409ms -Burst test completed: 5000 events in 8.641128603s -Events/sec: 578.63 - -=== Mixed Read/Write Test === -Pre-populating database for read tests... -Mixed test completed: 2500 writes, 2500 reads in 23.666052402s -Combined ops/sec: 211.27 - -Pausing 10s before next round... - -=== Starting test round 2/2 === - -=== Peak Throughput Test === -Events saved: 5000/5000 (100.0%) -Duration: 379.673375ms -Events/sec: 13169.21 -Avg latency: 297.243µs -P90 latency: 393.52µs -P95 latency: 426.161µs -P99 latency: 508.367µs -Bottom 10% Avg latency: 445.997µs - -=== Burst Pattern Test === -Burst completed: 500 events in 375.562676ms -Burst completed: 500 events in 379.688521ms -Burst completed: 500 events in 339.807492ms -Burst completed: 500 events in 407.502127ms -Burst completed: 500 events in 347.61805ms -Burst completed: 500 events in 338.215243ms -Burst completed: 500 events in 420.579964ms -Burst completed: 500 events in 339.263061ms -Burst completed: 500 events in 318.379922ms -Burst completed: 500 events in 300.546668ms -Burst test completed: 5000 events in 8.580483954s -Events/sec: 582.72 - -=== Mixed Read/Write Test === -Pre-populating database for read tests... -Mixed test completed: 2500 writes, 2094 reads in 30.014099513s -Combined ops/sec: 153.06 - -================================================================================ -BENCHMARK REPORT -================================================================================ - -Test: Peak Throughput -Duration: 363.618589ms -Total Events: 5000 -Events/sec: 13750.67 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 143 MB -Avg Latency: 283.533µs -P90 Latency: 378.941µs -P95 Latency: 413.136µs -P99 Latency: 527.123µs -Bottom 10% Avg Latency: 455.08µs ----------------------------------------- - -Test: Burst Pattern -Duration: 8.641128603s -Total Events: 5000 -Events/sec: 578.63 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 193 MB -Avg Latency: 214.446µs -P90 Latency: 286.796µs -P95 Latency: 335.028µs -P99 Latency: 615.301µs -Bottom 10% Avg Latency: 421.658µs ----------------------------------------- - -Test: Mixed Read/Write -Duration: 23.666052402s -Total Events: 5000 -Events/sec: 211.27 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 102 MB -Avg Latency: 4.328995ms -P90 Latency: 8.541367ms -P95 Latency: 10.080396ms -P99 Latency: 12.597948ms -Bottom 10% Avg Latency: 10.363345ms ----------------------------------------- - -Test: Peak Throughput -Duration: 379.673375ms -Total Events: 5000 -Events/sec: 13169.21 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 119 MB -Avg Latency: 297.243µs -P90 Latency: 393.52µs -P95 Latency: 426.161µs -P99 Latency: 508.367µs -Bottom 10% Avg Latency: 445.997µs ----------------------------------------- - -Test: Burst Pattern -Duration: 8.580483954s -Total Events: 5000 -Events/sec: 582.72 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 171 MB -Avg Latency: 202.362µs -P90 Latency: 263.111µs -P95 Latency: 296.545µs -P99 Latency: 359.544µs -Bottom 10% Avg Latency: 307.91µs ----------------------------------------- - -Test: Mixed Read/Write -Duration: 30.014099513s -Total Events: 4594 -Events/sec: 153.06 -Success Rate: 91.9% -Concurrent Workers: 4 -Memory Used: 138 MB -Avg Latency: 8.407338ms -P90 Latency: 17.892951ms -P95 Latency: 21.106647ms -P99 Latency: 26.270739ms -Bottom 10% Avg Latency: 21.626824ms ----------------------------------------- - -Report saved to: /tmp/benchmark_next-orly-cpu_8/benchmark_report.txt -AsciiDoc report saved to: /tmp/benchmark_next-orly-cpu_8/benchmark_report.adoc -20250913114211995528 INF /tmp/benchmark_next-orly-cpu_8: Lifetime L0 stalled for: 0s -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:536 /build/pkg/database/logger.go:57 -20250913114212319238 INF /tmp/benchmark_next-orly-cpu_8: -Level 0 [ ]: NumTables: 00. Size: 0 B of 0 B. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 64 MiB -Level 1 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 2 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 3 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 4 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 5 [B]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 6 [ ]: NumTables: 01. Size: 22 MiB of 22 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 4.0 MiB -Level Done -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:615 /build/pkg/database/logger.go:57 -20250913114212321065 INF /tmp/benchmark_next-orly-cpu_8: database closed /build/pkg/database/database.go:134 - -RELAY_NAME: next-orly-cpu -RELAY_URL: ws://next-orly-cpu:8080 -TEST_TIMESTAMP: 2025-09-13T11:42:12+00:00 -BENCHMARK_CONFIG: - Events: 5000 - Workers: 4 - Duration: 30s diff --git a/profiler/reports/run_20250913_114010/next-orly-mem_results.txt b/profiler/reports/run_20250913_114010/next-orly-mem_results.txt deleted file mode 100644 index d30a133..0000000 --- a/profiler/reports/run_20250913_114010/next-orly-mem_results.txt +++ /dev/null @@ -1,190 +0,0 @@ -Starting Nostr Relay Benchmark -Data Directory: /tmp/benchmark_next-orly-mem_8 -Events: 5000, Workers: 4, Duration: 30s -20250913114217371197 INF /tmp/benchmark_next-orly-mem_8: All 0 tables opened in 0s -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/levels.go:161 /build/pkg/database/logger.go:57 -20250913114217371717 INF /tmp/benchmark_next-orly-mem_8: Discard stats nextEmptySlot: 0 -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/discard.go:55 /build/pkg/database/logger.go:57 -20250913114217371747 INF /tmp/benchmark_next-orly-mem_8: Set nextTxnTs to 0 -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:358 /build/pkg/database/logger.go:57 -20250913114217372014 INF (*types.Uint32)(0xc0000100fc)({ - value: (uint32) 1 -}) - /build/pkg/database/migrations.go:65 -20250913114217372100 INF migrating to version 1... /build/pkg/database/migrations.go:79 - -=== Starting test round 1/2 === - -=== Peak Throughput Test === -Events saved: 5000/5000 (100.0%) -Duration: 353.88923ms -Events/sec: 14128.71 -Avg latency: 273.836µs -P90 latency: 365.325µs -P95 latency: 397.186µs -P99 latency: 469.604µs -Bottom 10% Avg latency: 417.518µs - -=== Burst Pattern Test === -Burst completed: 500 events in 375.971522ms -Burst completed: 500 events in 446.782317ms -Burst completed: 500 events in 470.554433ms -Burst completed: 500 events in 491.456408ms -Burst completed: 500 events in 468.172794ms -Burst completed: 500 events in 408.391929ms -Burst completed: 500 events in 447.580014ms -Burst completed: 500 events in 457.169251ms -Burst completed: 500 events in 479.515284ms -Burst completed: 500 events in 474.094546ms -Burst test completed: 5000 events in 9.534688959s -Events/sec: 524.40 - -=== Mixed Read/Write Test === -Pre-populating database for read tests... -Mixed test completed: 2500 writes, 2500 reads in 25.54544997s -Combined ops/sec: 195.73 - -Pausing 10s before next round... - -=== Starting test round 2/2 === - -=== Peak Throughput Test === -Events saved: 5000/5000 (100.0%) -Duration: 369.402349ms -Events/sec: 13535.38 -Avg latency: 289.113µs -P90 latency: 379.151µs -P95 latency: 412.575µs -P99 latency: 486.947µs -Bottom 10% Avg latency: 429.135µs - -=== Burst Pattern Test === -Burst completed: 500 events in 388.47726ms -Burst completed: 500 events in 367.258061ms -Burst completed: 500 events in 443.655199ms -Burst completed: 500 events in 364.303548ms -Burst completed: 500 events in 306.776349ms -Burst completed: 500 events in 305.273459ms -Burst completed: 500 events in 379.233497ms -Burst completed: 500 events in 377.586001ms -Burst completed: 500 events in 369.113691ms -Burst completed: 500 events in 333.996551ms -Burst test completed: 5000 events in 8.649351111s -Events/sec: 578.08 - -=== Mixed Read/Write Test === -Pre-populating database for read tests... -Mixed test completed: 2500 writes, 1996 reads in 30.025357572s -Combined ops/sec: 149.74 - -================================================================================ -BENCHMARK REPORT -================================================================================ - -Test: Peak Throughput -Duration: 353.88923ms -Total Events: 5000 -Events/sec: 14128.71 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 143 MB -Avg Latency: 273.836µs -P90 Latency: 365.325µs -P95 Latency: 397.186µs -P99 Latency: 469.604µs -Bottom 10% Avg Latency: 417.518µs ----------------------------------------- - -Test: Burst Pattern -Duration: 9.534688959s -Total Events: 5000 -Events/sec: 524.40 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 192 MB -Avg Latency: 179.076µs -P90 Latency: 231.24µs -P95 Latency: 255.006µs -P99 Latency: 303.558µs -Bottom 10% Avg Latency: 269.293µs ----------------------------------------- - -Test: Mixed Read/Write -Duration: 25.54544997s -Total Events: 5000 -Events/sec: 195.73 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 114 MB -Avg Latency: 5.044988ms -P90 Latency: 10.156837ms -P95 Latency: 11.501888ms -P99 Latency: 14.645443ms -Bottom 10% Avg Latency: 11.993477ms ----------------------------------------- - -Test: Peak Throughput -Duration: 369.402349ms -Total Events: 5000 -Events/sec: 13535.38 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 132 MB -Avg Latency: 289.113µs -P90 Latency: 379.151µs -P95 Latency: 412.575µs -P99 Latency: 486.947µs -Bottom 10% Avg Latency: 429.135µs ----------------------------------------- - -Test: Burst Pattern -Duration: 8.649351111s -Total Events: 5000 -Events/sec: 578.08 -Success Rate: 100.0% -Concurrent Workers: 4 -Memory Used: 183 MB -Avg Latency: 201.741µs -P90 Latency: 263.752µs -P95 Latency: 297.136µs -P99 Latency: 358.212µs -Bottom 10% Avg Latency: 310.062µs ----------------------------------------- - -Test: Mixed Read/Write -Duration: 30.025357572s -Total Events: 4496 -Events/sec: 149.74 -Success Rate: 89.9% -Concurrent Workers: 4 -Memory Used: 173 MB -Avg Latency: 8.802374ms -P90 Latency: 19.907605ms -P95 Latency: 22.490193ms -P99 Latency: 26.079898ms -Bottom 10% Avg Latency: 22.803343ms ----------------------------------------- - -Report saved to: /tmp/benchmark_next-orly-mem_8/benchmark_report.txt -AsciiDoc report saved to: /tmp/benchmark_next-orly-mem_8/benchmark_report.adoc -20250913114421864166 INF /tmp/benchmark_next-orly-mem_8: Lifetime L0 stalled for: 0s -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:536 /build/pkg/database/logger.go:57 -20250913114422185339 INF /tmp/benchmark_next-orly-mem_8: -Level 0 [ ]: NumTables: 00. Size: 0 B of 0 B. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 64 MiB -Level 1 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 2 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 3 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 4 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 5 [B]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB -Level 6 [ ]: NumTables: 01. Size: 22 MiB of 22 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 4.0 MiB -Level Done -/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:615 /build/pkg/database/logger.go:57 -20250913114422187124 INF /tmp/benchmark_next-orly-mem_8: database closed /build/pkg/database/database.go:134 - -RELAY_NAME: next-orly-mem -RELAY_URL: ws://next-orly-mem:8080 -TEST_TIMESTAMP: 2025-09-13T11:44:22+00:00 -BENCHMARK_CONFIG: - Events: 5000 - Workers: 4 - Duration: 30s diff --git a/profiler/reports/run_20250913_114010/aggregate_report.txt b/profiler/reports/run_20250913_150837/aggregate_report.txt similarity index 59% rename from profiler/reports/run_20250913_114010/aggregate_report.txt rename to profiler/reports/run_20250913_150837/aggregate_report.txt index 9fe0a4a..0cf7c57 100644 --- a/profiler/reports/run_20250913_114010/aggregate_report.txt +++ b/profiler/reports/run_20250913_150837/aggregate_report.txt @@ -1,7 +1,7 @@ ================================================================ NOSTR RELAY BENCHMARK AGGREGATE REPORT ================================================================ -Generated: 2025-09-13T11:46:34+00:00 +Generated: 2025-09-13T15:15:03+00:00 Benchmark Configuration: Events per test: 5000 Concurrent workers: 4 @@ -16,50 +16,50 @@ SUMMARY BY RELAY Relay: next-orly-cpu ---------------------------------------- Status: COMPLETED -Events/sec: 13750.67 -Events/sec: 578.63 -Events/sec: 13169.21 +Events/sec: 14586.66 +Events/sec: 523.16 +Events/sec: 13427.76 Success Rate: 100.0% Success Rate: 100.0% Success Rate: 100.0% -Avg Latency: 283.533µs -Bottom 10% Avg Latency: 455.08µs -Avg Latency: 214.446µs -P95 Latency: 413.136µs -P95 Latency: 335.028µs -P95 Latency: 10.080396ms +Avg Latency: 266.404µs +Bottom 10% Avg Latency: 404.279µs +Avg Latency: 181.633µs +P95 Latency: 386.835µs +P95 Latency: 258.311µs +P95 Latency: 9.420264ms Relay: next-orly-mem ---------------------------------------- Status: COMPLETED -Events/sec: 14128.71 -Events/sec: 524.40 -Events/sec: 13535.38 +Events/sec: 14400.62 +Events/sec: 517.16 +Events/sec: 13744.06 Success Rate: 100.0% Success Rate: 100.0% Success Rate: 100.0% -Avg Latency: 273.836µs -Bottom 10% Avg Latency: 417.518µs -Avg Latency: 179.076µs -P95 Latency: 397.186µs -P95 Latency: 255.006µs -P95 Latency: 11.501888ms +Avg Latency: 269.084µs +Bottom 10% Avg Latency: 409.33µs +Avg Latency: 178.033µs +P95 Latency: 390.313µs +P95 Latency: 255.165µs +P95 Latency: 9.733877ms Relay: next-orly-alloc ---------------------------------------- Status: COMPLETED -Events/sec: 14708.43 -Events/sec: 526.24 -Events/sec: 12079.01 +Events/sec: 14727.35 +Events/sec: 534.10 +Events/sec: 13931.93 Success Rate: 100.0% Success Rate: 100.0% Success Rate: 100.0% -Avg Latency: 264.237µs -Bottom 10% Avg Latency: 399.688µs -Avg Latency: 182.339µs -P95 Latency: 383.139µs -P95 Latency: 270.195µs -P95 Latency: 10.117687ms +Avg Latency: 264.477µs +Bottom 10% Avg Latency: 400.393µs +Avg Latency: 183.763µs +P95 Latency: 382.538µs +P95 Latency: 269.453µs +P95 Latency: 10.855199ms ================================================================ @@ -67,9 +67,9 @@ DETAILED RESULTS ================================================================ Individual relay reports are available in: - - /reports/run_20250913_114010/next-orly-alloc_results.txt - - /reports/run_20250913_114010/next-orly-cpu_results.txt - - /reports/run_20250913_114010/next-orly-mem_results.txt + - /reports/run_20250913_150837/next-orly-alloc_results.txt + - /reports/run_20250913_150837/next-orly-cpu_results.txt + - /reports/run_20250913_150837/next-orly-mem_results.txt ================================================================ BENCHMARK COMPARISON TABLE @@ -77,9 +77,9 @@ BENCHMARK COMPARISON TABLE Relay Status Peak Tput/s Avg Latency Success Rate ---- ------ ----------- ----------- ------------ -next-orly-cpu OK 13750.67 283.533µs 100.0% -next-orly-mem OK 14128.71 273.836µs 100.0% -next-orly-alloc OK 14708.43 264.237µs 100.0% +next-orly-cpu OK 14586.66 266.404µs 100.0% +next-orly-mem OK 14400.62 269.084µs 100.0% +next-orly-alloc OK 14727.35 264.477µs 100.0% ================================================================ End of Report diff --git a/profiler/reports/run_20250913_150837/next-orly-alloc_results.txt b/profiler/reports/run_20250913_150837/next-orly-alloc_results.txt new file mode 100644 index 0000000..7040f10 --- /dev/null +++ b/profiler/reports/run_20250913_150837/next-orly-alloc_results.txt @@ -0,0 +1,190 @@ +Starting Nostr Relay Benchmark +Data Directory: /tmp/benchmark_next-orly-alloc_8 +Events: 5000, Workers: 4, Duration: 30s +20250913151255068694 INF /tmp/benchmark_next-orly-alloc_8: All 0 tables opened in 0s +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/levels.go:161 /build/pkg/database/logger.go:57 +20250913151255069225 INF /tmp/benchmark_next-orly-alloc_8: Discard stats nextEmptySlot: 0 +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/discard.go:55 /build/pkg/database/logger.go:57 +20250913151255069261 INF /tmp/benchmark_next-orly-alloc_8: Set nextTxnTs to 0 +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:358 /build/pkg/database/logger.go:57 +20250913151255069538 INF (*types.Uint32)(0xc00001010c)({ + value: (uint32) 1 +}) + /build/pkg/database/migrations.go:65 +20250913151255069681 INF migrating to version 1... /build/pkg/database/migrations.go:79 + +=== Starting test round 1/2 === + +=== Peak Throughput Test === +Events saved: 5000/5000 (100.0%) +Duration: 339.504298ms +Events/sec: 14727.35 +Avg latency: 264.477µs +P90 latency: 350.647µs +P95 latency: 382.538µs +P99 latency: 448.954µs +Bottom 10% Avg latency: 400.393µs + +=== Burst Pattern Test === +Burst completed: 500 events in 479.359678ms +Burst completed: 500 events in 425.596145ms +Burst completed: 500 events in 446.109496ms +Burst completed: 500 events in 378.033475ms +Burst completed: 500 events in 391.065418ms +Burst completed: 500 events in 409.089993ms +Burst completed: 500 events in 495.220448ms +Burst completed: 500 events in 493.489266ms +Burst completed: 500 events in 410.468883ms +Burst completed: 500 events in 418.819105ms +Burst test completed: 5000 events in 9.361610197s +Events/sec: 534.10 + +=== Mixed Read/Write Test === +Pre-populating database for read tests... +Mixed test completed: 2500 writes, 2500 reads in 24.078024733s +Combined ops/sec: 207.66 + +Pausing 10s before next round... + +=== Starting test round 2/2 === + +=== Peak Throughput Test === +Events saved: 5000/5000 (100.0%) +Duration: 358.887842ms +Events/sec: 13931.93 +Avg latency: 280.856µs +P90 latency: 366.297µs +P95 latency: 394.952µs +P99 latency: 451.52µs +Bottom 10% Avg latency: 409.325µs + +=== Burst Pattern Test === +Burst completed: 500 events in 362.96011ms +Burst completed: 500 events in 416.140454ms +Burst completed: 500 events in 448.460564ms +Burst completed: 500 events in 474.76808ms +Burst completed: 500 events in 447.434655ms +Burst completed: 500 events in 427.462963ms +Burst completed: 500 events in 413.117609ms +Burst completed: 500 events in 442.349391ms +Burst completed: 500 events in 464.157823ms +Burst completed: 500 events in 472.898161ms +Burst test completed: 5000 events in 9.381865696s +Events/sec: 532.94 + +=== Mixed Read/Write Test === +Pre-populating database for read tests... +Mixed test completed: 2500 writes, 2122 reads in 30.021046357s +Combined ops/sec: 153.96 + +================================================================================ +BENCHMARK REPORT +================================================================================ + +Test: Peak Throughput +Duration: 339.504298ms +Total Events: 5000 +Events/sec: 14727.35 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 142 MB +Avg Latency: 264.477µs +P90 Latency: 350.647µs +P95 Latency: 382.538µs +P99 Latency: 448.954µs +Bottom 10% Avg Latency: 400.393µs +---------------------------------------- + +Test: Burst Pattern +Duration: 9.361610197s +Total Events: 5000 +Events/sec: 534.10 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 192 MB +Avg Latency: 183.763µs +P90 Latency: 236.69µs +P95 Latency: 269.453µs +P99 Latency: 328.425µs +Bottom 10% Avg Latency: 284.22µs +---------------------------------------- + +Test: Mixed Read/Write +Duration: 24.078024733s +Total Events: 5000 +Events/sec: 207.66 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 105 MB +Avg Latency: 4.442571ms +P90 Latency: 8.682425ms +P95 Latency: 10.855199ms +P99 Latency: 12.949977ms +Bottom 10% Avg Latency: 10.754668ms +---------------------------------------- + +Test: Peak Throughput +Duration: 358.887842ms +Total Events: 5000 +Events/sec: 13931.93 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 122 MB +Avg Latency: 280.856µs +P90 Latency: 366.297µs +P95 Latency: 394.952µs +P99 Latency: 451.52µs +Bottom 10% Avg Latency: 409.325µs +---------------------------------------- + +Test: Burst Pattern +Duration: 9.381865696s +Total Events: 5000 +Events/sec: 532.94 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 175 MB +Avg Latency: 186.501µs +P90 Latency: 237.853µs +P95 Latency: 269.192µs +P99 Latency: 336.811µs +Bottom 10% Avg Latency: 287.769µs +---------------------------------------- + +Test: Mixed Read/Write +Duration: 30.021046357s +Total Events: 4622 +Events/sec: 153.96 +Success Rate: 92.4% +Concurrent Workers: 4 +Memory Used: 129 MB +Avg Latency: 8.281607ms +P90 Latency: 17.758024ms +P95 Latency: 19.206379ms +P99 Latency: 24.13486ms +Bottom 10% Avg Latency: 20.330644ms +---------------------------------------- + +Report saved to: /tmp/benchmark_next-orly-alloc_8/benchmark_report.txt +AsciiDoc report saved to: /tmp/benchmark_next-orly-alloc_8/benchmark_report.adoc +20250913151458624980 INF /tmp/benchmark_next-orly-alloc_8: Lifetime L0 stalled for: 0s +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:536 /build/pkg/database/logger.go:57 +20250913151458946409 INF /tmp/benchmark_next-orly-alloc_8: +Level 0 [ ]: NumTables: 00. Size: 0 B of 0 B. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 64 MiB +Level 1 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 2 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 3 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 4 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 5 [B]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 6 [ ]: NumTables: 01. Size: 22 MiB of 22 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 4.0 MiB +Level Done +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:615 /build/pkg/database/logger.go:57 +20250913151458948689 INF /tmp/benchmark_next-orly-alloc_8: database closed /build/pkg/database/database.go:134 + +RELAY_NAME: next-orly-alloc +RELAY_URL: ws://next-orly-alloc:8080 +TEST_TIMESTAMP: 2025-09-13T15:14:58+00:00 +BENCHMARK_CONFIG: + Events: 5000 + Workers: 4 + Duration: 30s diff --git a/profiler/reports/run_20250913_150837/next-orly-cpu_results.txt b/profiler/reports/run_20250913_150837/next-orly-cpu_results.txt new file mode 100644 index 0000000..c61142d --- /dev/null +++ b/profiler/reports/run_20250913_150837/next-orly-cpu_results.txt @@ -0,0 +1,190 @@ +Starting Nostr Relay Benchmark +Data Directory: /tmp/benchmark_next-orly-cpu_8 +Events: 5000, Workers: 4, Duration: 30s +20250913150837785506 INF /tmp/benchmark_next-orly-cpu_8: All 0 tables opened in 0s +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/levels.go:161 /build/pkg/database/logger.go:57 +20250913150837785985 INF /tmp/benchmark_next-orly-cpu_8: Discard stats nextEmptySlot: 0 +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/discard.go:55 /build/pkg/database/logger.go:57 +20250913150837786066 INF /tmp/benchmark_next-orly-cpu_8: Set nextTxnTs to 0 +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:358 /build/pkg/database/logger.go:57 +20250913150837786329 INF (*types.Uint32)(0xc0002b1cac)({ + value: (uint32) 1 +}) + /build/pkg/database/migrations.go:65 +20250913150837786374 INF migrating to version 1... /build/pkg/database/migrations.go:79 + +=== Starting test round 1/2 === + +=== Peak Throughput Test === +Events saved: 5000/5000 (100.0%) +Duration: 342.779064ms +Events/sec: 14586.66 +Avg latency: 266.404µs +P90 latency: 354.213µs +P95 latency: 386.835µs +P99 latency: 459.934µs +Bottom 10% Avg latency: 404.279µs + +=== Burst Pattern Test === +Burst completed: 500 events in 423.591594ms +Burst completed: 500 events in 454.585716ms +Burst completed: 500 events in 486.007191ms +Burst completed: 500 events in 503.830553ms +Burst completed: 500 events in 433.97967ms +Burst completed: 500 events in 427.591978ms +Burst completed: 500 events in 500.38276ms +Burst completed: 500 events in 489.161258ms +Burst completed: 500 events in 474.350023ms +Burst completed: 500 events in 350.911595ms +Burst test completed: 5000 events in 9.557316818s +Events/sec: 523.16 + +=== Mixed Read/Write Test === +Pre-populating database for read tests... +Mixed test completed: 2500 writes, 2500 reads in 24.103605311s +Combined ops/sec: 207.44 + +Pausing 10s before next round... + +=== Starting test round 2/2 === + +=== Peak Throughput Test === +Events saved: 5000/5000 (100.0%) +Duration: 372.362841ms +Events/sec: 13427.76 +Avg latency: 291.441µs +P90 latency: 380.663µs +P95 latency: 417.233µs +P99 latency: 494.64µs +Bottom 10% Avg latency: 434.725µs + +=== Burst Pattern Test === +Burst completed: 500 events in 417.269185ms +Burst completed: 500 events in 468.354112ms +Burst completed: 500 events in 443.231977ms +Burst completed: 500 events in 435.358047ms +Burst completed: 500 events in 380.799007ms +Burst completed: 500 events in 322.904743ms +Burst completed: 500 events in 354.234969ms +Burst completed: 500 events in 390.690665ms +Burst completed: 500 events in 392.317202ms +Burst completed: 500 events in 467.071067ms +Burst test completed: 5000 events in 9.085471121s +Events/sec: 550.33 + +=== Mixed Read/Write Test === +Pre-populating database for read tests... +Mixed test completed: 2500 writes, 2067 reads in 30.027760725s +Combined ops/sec: 152.09 + +================================================================================ +BENCHMARK REPORT +================================================================================ + +Test: Peak Throughput +Duration: 342.779064ms +Total Events: 5000 +Events/sec: 14586.66 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 142 MB +Avg Latency: 266.404µs +P90 Latency: 354.213µs +P95 Latency: 386.835µs +P99 Latency: 459.934µs +Bottom 10% Avg Latency: 404.279µs +---------------------------------------- + +Test: Burst Pattern +Duration: 9.557316818s +Total Events: 5000 +Events/sec: 523.16 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 192 MB +Avg Latency: 181.633µs +P90 Latency: 225.639µs +P95 Latency: 258.311µs +P99 Latency: 332.341µs +Bottom 10% Avg Latency: 277.625µs +---------------------------------------- + +Test: Mixed Read/Write +Duration: 24.103605311s +Total Events: 5000 +Events/sec: 207.44 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 108 MB +Avg Latency: 4.472533ms +P90 Latency: 8.862063ms +P95 Latency: 9.420264ms +P99 Latency: 12.991173ms +Bottom 10% Avg Latency: 10.293802ms +---------------------------------------- + +Test: Peak Throughput +Duration: 372.362841ms +Total Events: 5000 +Events/sec: 13427.76 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 125 MB +Avg Latency: 291.441µs +P90 Latency: 380.663µs +P95 Latency: 417.233µs +P99 Latency: 494.64µs +Bottom 10% Avg Latency: 434.725µs +---------------------------------------- + +Test: Burst Pattern +Duration: 9.085471121s +Total Events: 5000 +Events/sec: 550.33 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 177 MB +Avg Latency: 191.41µs +P90 Latency: 247.551µs +P95 Latency: 282.246µs +P99 Latency: 336.099µs +Bottom 10% Avg Latency: 290.757µs +---------------------------------------- + +Test: Mixed Read/Write +Duration: 30.027760725s +Total Events: 4567 +Events/sec: 152.09 +Success Rate: 91.3% +Concurrent Workers: 4 +Memory Used: 173 MB +Avg Latency: 8.526682ms +P90 Latency: 18.686774ms +P95 Latency: 21.052665ms +P99 Latency: 24.581304ms +Bottom 10% Avg Latency: 21.498913ms +---------------------------------------- + +Report saved to: /tmp/benchmark_next-orly-cpu_8/benchmark_report.txt +AsciiDoc report saved to: /tmp/benchmark_next-orly-cpu_8/benchmark_report.adoc +20250913151041289202 INF /tmp/benchmark_next-orly-cpu_8: Lifetime L0 stalled for: 0s +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:536 /build/pkg/database/logger.go:57 +20250913151041613609 INF /tmp/benchmark_next-orly-cpu_8: +Level 0 [ ]: NumTables: 00. Size: 0 B of 0 B. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 64 MiB +Level 1 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 2 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 3 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 4 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 5 [B]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 6 [ ]: NumTables: 01. Size: 22 MiB of 22 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 4.0 MiB +Level Done +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:615 /build/pkg/database/logger.go:57 +20250913151041615724 INF /tmp/benchmark_next-orly-cpu_8: database closed /build/pkg/database/database.go:134 + +RELAY_NAME: next-orly-cpu +RELAY_URL: ws://next-orly-cpu:8080 +TEST_TIMESTAMP: 2025-09-13T15:10:41+00:00 +BENCHMARK_CONFIG: + Events: 5000 + Workers: 4 + Duration: 30s diff --git a/profiler/reports/run_20250913_150837/next-orly-mem_results.txt b/profiler/reports/run_20250913_150837/next-orly-mem_results.txt new file mode 100644 index 0000000..6c773ac --- /dev/null +++ b/profiler/reports/run_20250913_150837/next-orly-mem_results.txt @@ -0,0 +1,190 @@ +Starting Nostr Relay Benchmark +Data Directory: /tmp/benchmark_next-orly-mem_8 +Events: 5000, Workers: 4, Duration: 30s +20250913151046664505 INF /tmp/benchmark_next-orly-mem_8: All 0 tables opened in 0s +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/levels.go:161 /build/pkg/database/logger.go:57 +20250913151046665322 INF /tmp/benchmark_next-orly-mem_8: Discard stats nextEmptySlot: 0 +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/discard.go:55 /build/pkg/database/logger.go:57 +20250913151046665358 INF /tmp/benchmark_next-orly-mem_8: Set nextTxnTs to 0 +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:358 /build/pkg/database/logger.go:57 +20250913151046665590 INF (*types.Uint32)(0xc00013fc1c)({ + value: (uint32) 1 +}) + /build/pkg/database/migrations.go:65 +20250913151046665622 INF migrating to version 1... /build/pkg/database/migrations.go:79 + +=== Starting test round 1/2 === + +=== Peak Throughput Test === +Events saved: 5000/5000 (100.0%) +Duration: 347.207269ms +Events/sec: 14400.62 +Avg latency: 269.084µs +P90 latency: 358.252µs +P95 latency: 390.313µs +P99 latency: 459.745µs +Bottom 10% Avg latency: 409.33µs + +=== Burst Pattern Test === +Burst completed: 500 events in 372.815911ms +Burst completed: 500 events in 385.472929ms +Burst completed: 500 events in 493.886155ms +Burst completed: 500 events in 499.001539ms +Burst completed: 500 events in 495.383911ms +Burst completed: 500 events in 463.681787ms +Burst completed: 500 events in 474.409848ms +Burst completed: 500 events in 507.35297ms +Burst completed: 500 events in 487.725706ms +Burst completed: 500 events in 473.3812ms +Burst test completed: 5000 events in 9.668130847s +Events/sec: 517.16 + +=== Mixed Read/Write Test === +Pre-populating database for read tests... +Mixed test completed: 2500 writes, 2500 reads in 23.457777521s +Combined ops/sec: 213.15 + +Pausing 10s before next round... + +=== Starting test round 2/2 === + +=== Peak Throughput Test === +Events saved: 5000/5000 (100.0%) +Duration: 363.793593ms +Events/sec: 13744.06 +Avg latency: 284.695µs +P90 latency: 372.509µs +P95 latency: 405.031µs +P99 latency: 461.949µs +Bottom 10% Avg latency: 418.636µs + +=== Burst Pattern Test === +Burst completed: 500 events in 468.131728ms +Burst completed: 500 events in 466.05048ms +Burst completed: 500 events in 348.112373ms +Burst completed: 500 events in 399.633064ms +Burst completed: 500 events in 442.046507ms +Burst completed: 500 events in 381.168926ms +Burst completed: 500 events in 362.016406ms +Burst completed: 500 events in 379.297871ms +Burst completed: 500 events in 457.958442ms +Burst completed: 500 events in 455.557676ms +Burst test completed: 5000 events in 9.174541855s +Events/sec: 544.99 + +=== Mixed Read/Write Test === +Pre-populating database for read tests... +Mixed test completed: 2500 writes, 2146 reads in 30.008115864s +Combined ops/sec: 154.82 + +================================================================================ +BENCHMARK REPORT +================================================================================ + +Test: Peak Throughput +Duration: 347.207269ms +Total Events: 5000 +Events/sec: 14400.62 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 143 MB +Avg Latency: 269.084µs +P90 Latency: 358.252µs +P95 Latency: 390.313µs +P99 Latency: 459.745µs +Bottom 10% Avg Latency: 409.33µs +---------------------------------------- + +Test: Burst Pattern +Duration: 9.668130847s +Total Events: 5000 +Events/sec: 517.16 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 192 MB +Avg Latency: 178.033µs +P90 Latency: 225.098µs +P95 Latency: 255.165µs +P99 Latency: 318.015µs +Bottom 10% Avg Latency: 267.252µs +---------------------------------------- + +Test: Mixed Read/Write +Duration: 23.457777521s +Total Events: 5000 +Events/sec: 213.15 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 103 MB +Avg Latency: 4.235413ms +P90 Latency: 8.39945ms +P95 Latency: 9.733877ms +P99 Latency: 12.359344ms +Bottom 10% Avg Latency: 10.173821ms +---------------------------------------- + +Test: Peak Throughput +Duration: 363.793593ms +Total Events: 5000 +Events/sec: 13744.06 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 121 MB +Avg Latency: 284.695µs +P90 Latency: 372.509µs +P95 Latency: 405.031µs +P99 Latency: 461.949µs +Bottom 10% Avg Latency: 418.636µs +---------------------------------------- + +Test: Burst Pattern +Duration: 9.174541855s +Total Events: 5000 +Events/sec: 544.99 +Success Rate: 100.0% +Concurrent Workers: 4 +Memory Used: 174 MB +Avg Latency: 188.886µs +P90 Latency: 242.201µs +P95 Latency: 270.475µs +P99 Latency: 331.521µs +Bottom 10% Avg Latency: 287.008µs +---------------------------------------- + +Test: Mixed Read/Write +Duration: 30.008115864s +Total Events: 4646 +Events/sec: 154.82 +Success Rate: 92.9% +Concurrent Workers: 4 +Memory Used: 184 MB +Avg Latency: 8.147241ms +P90 Latency: 17.076493ms +P95 Latency: 17.970006ms +P99 Latency: 24.424806ms +Bottom 10% Avg Latency: 19.866973ms +---------------------------------------- + +Report saved to: /tmp/benchmark_next-orly-mem_8/benchmark_report.txt +AsciiDoc report saved to: /tmp/benchmark_next-orly-mem_8/benchmark_report.adoc +20250913151249700098 INF /tmp/benchmark_next-orly-mem_8: Lifetime L0 stalled for: 0s +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:536 /build/pkg/database/logger.go:57 +20250913151250019024 INF /tmp/benchmark_next-orly-mem_8: +Level 0 [ ]: NumTables: 00. Size: 0 B of 0 B. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 64 MiB +Level 1 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 2 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 3 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 4 [ ]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 5 [B]: NumTables: 00. Size: 0 B of 10 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 2.0 MiB +Level 6 [ ]: NumTables: 01. Size: 22 MiB of 22 MiB. Score: 0.00->0.00 StaleData: 0 B Target FileSize: 4.0 MiB +Level Done +/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.8.0/db.go:615 /build/pkg/database/logger.go:57 +20250913151250021227 INF /tmp/benchmark_next-orly-mem_8: database closed /build/pkg/database/database.go:134 + +RELAY_NAME: next-orly-mem +RELAY_URL: ws://next-orly-mem:8080 +TEST_TIMESTAMP: 2025-09-13T15:12:50+00:00 +BENCHMARK_CONFIG: + Events: 5000 + Workers: 4 + Duration: 30s