Skip to content

perf(recovery): optimize line reading in stack function#4466

Merged
appleboy merged 1 commit intogin-gonic:masterfrom
1911860538:stack/source
Dec 12, 2025
Merged

perf(recovery): optimize line reading in stack function#4466
appleboy merged 1 commit intogin-gonic:masterfrom
1911860538:stack/source

Conversation

@1911860538
Copy link
Copy Markdown
Contributor

@1911860538 1911860538 commented Dec 9, 2025

Optimize stack function to avoid reading entire files when generating stack traces

  • Introduce readNthLine function that reads only the specified line from a file
  • Significantly improve performance based on micro-benchmarks:
    • ~33% faster execution (115,994 ns/op → 78,139 ns/op)
    • ~94% reduction in memory usage (178,962 B/op → 10,526 B/op)
    • ~47% increase in throughput (10,278 → 15,106 iterations)
    • ~7% reduction in allocations (30 → 28 allocs/op)
  • Demonstrate real-world improvements with hey tool (100,000 panic requests, 100 concurrent connections):
    • ~31% faster total execution time (25.44s → 17.51s)
    • ~45% increase in requests/sec (3,930 → 5,711)
    • ~31% faster average response time (0.0247s → 0.0170s)
    • Improved latency distribution across all percentiles
  • Improves efficiency by minimizing I/O operations, especially for large source files
  • Maintains the same functionality while reducing resource consumption

@1911860538
Copy link
Copy Markdown
Contributor Author

Below is stack benchmark comparison:

Before

goos: darwin
goarch: amd64
pkg: github.com/gin-gonic/gin
cpu: Intel(R) Core(TM) i7-8569U CPU @ 2.80GHz
BenchmarkStack
BenchmarkStack-8   	   10278	    115994 ns/op	  178962 B/op	      30 allocs/op
PASS

Process finished with the exit code 0

After

goos: darwin
goarch: amd64
pkg: github.com/gin-gonic/gin
cpu: Intel(R) Core(TM) i7-8569U CPU @ 2.80GHz
BenchmarkStack
BenchmarkStack-8   	   15106	     78139 ns/op	   10526 B/op	      28 allocs/op
PASS

Process finished with the exit code 0

@1911860538 1911860538 marked this pull request as draft December 9, 2025 14:37
@1911860538
Copy link
Copy Markdown
Contributor Author

hey load test

recovery test code

package main

import (
	"log"
	"net/http"

	"github.com/gin-gonic/gin"
)

func main() {
	gin.SetMode(gin.ReleaseMode)

	r := gin.New()

	r.Use(gin.CustomRecoveryWithWriter(gin.DefaultErrorWriter, func(c *gin.Context, err any) {
		c.JSON(http.StatusInternalServerError, gin.H{
			"message": "internal error",
		})
	}))

	r.GET("/panic", func(c *gin.Context) {
		panic("trigger panic")
	})

	err := r.Run(":8080")
	if err != nil {
		log.Fatal(err)
	}
}

hey command

hey -n 100000 -c 100 http://localhost:8080/panic

benchmark results before optimization using hey

hey -n 100000 -c 100 http://localhost:8080/panic

Summary:
  Total:        25.4435 secs
  Slowest:      0.3380 secs
  Fastest:      0.0006 secs
  Average:      0.0247 secs
  Requests/sec: 3930.2828
  
  Total data:   2800000 bytes
  Size/request: 28 bytes

Response time histogram:
  0.001 [1]     |
  0.034 [70813] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  0.068 [19266] |■■■■■■■■■■■
  0.102 [6610]  |■■■■
  0.136 [2197]  |■
  0.169 [747]   |
  0.203 [252]   |
  0.237 [75]    |
  0.271 [26]    |
  0.304 [8]     |
  0.338 [5]     |


Latency distribution:
  10% in 0.0013 secs
  25% in 0.0025 secs
  50% in 0.0063 secs
  75% in 0.0375 secs
  90% in 0.0678 secs
  95% in 0.0901 secs
  99% in 0.1391 secs

Details (average, fastest, slowest):
  DNS+dialup:   0.0000 secs, 0.0006 secs, 0.3380 secs
  DNS-lookup:   0.0000 secs, 0.0000 secs, 0.0087 secs
  req write:    0.0000 secs, 0.0000 secs, 0.0049 secs
  resp wait:    0.0246 secs, 0.0005 secs, 0.3380 secs
  resp read:    0.0000 secs, 0.0000 secs, 0.0101 secs

Status code distribution:
  [500] 100000 responses

benchmark results after optimization using hey

hey -n 100000 -c 100 http://localhost:8080/panic

Summary:
  Total:        17.5100 secs
  Slowest:      0.3669 secs
  Fastest:      0.0004 secs
  Average:      0.0170 secs
  Requests/sec: 5711.0322
  
  Total data:   2800000 bytes
  Size/request: 28 bytes

Response time histogram:
  0.000 [1]     |
  0.037 [81980] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  0.074 [12141] |■■■■■■
  0.110 [3550]  |■■
  0.147 [1593]  |■
  0.184 [481]   |
  0.220 [172]   |
  0.257 [53]    |
  0.294 [20]    |
  0.330 [4]     |
  0.367 [5]     |


Latency distribution:
  10% in 0.0010 secs
  25% in 0.0017 secs
  50% in 0.0036 secs
  75% in 0.0091 secs
  90% in 0.0610 secs
  95% in 0.0795 secs
  99% in 0.1377 secs

Details (average, fastest, slowest):
  DNS+dialup:   0.0000 secs, 0.0004 secs, 0.3669 secs
  DNS-lookup:   0.0000 secs, 0.0000 secs, 0.0080 secs
  req write:    0.0000 secs, 0.0000 secs, 0.0056 secs
  resp wait:    0.0169 secs, 0.0004 secs, 0.3669 secs
  resp read:    0.0000 secs, 0.0000 secs, 0.0196 secs

Status code distribution:
  [500] 100000 responses

@codecov
Copy link
Copy Markdown

codecov Bot commented Dec 9, 2025

Codecov Report

❌ Patch coverage is 95.23810% with 1 line in your changes missing coverage. Please review.
✅ Project coverage is 98.92%. Comparing base (3dc1cd6) to head (1226362).
⚠️ Report is 225 commits behind head on master.

Files with missing lines Patch % Lines
recovery.go 95.23% 1 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##           master    #4466      +/-   ##
==========================================
- Coverage   99.21%   98.92%   -0.29%     
==========================================
  Files          42       44       +2     
  Lines        3182     2986     -196     
==========================================
- Hits         3157     2954     -203     
- Misses         17       20       +3     
- Partials        8       12       +4     
Flag Coverage Δ
?
--ldflags="-checklinkname=0" -tags sonic 98.85% <95.23%> (?)
-tags go_json 98.78% <95.23%> (?)
-tags nomsgpack 98.84% <95.23%> (?)
go-1.18 ?
go-1.19 ?
go-1.20 ?
go-1.21 ?
go-1.24 98.86% <95.23%> (?)
go-1.25 98.92% <95.23%> (?)
macos-latest 98.92% <95.23%> (-0.29%) ⬇️
ubuntu-latest 98.86% <95.23%> (-0.36%) ⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@1911860538
Copy link
Copy Markdown
Contributor Author

@1911860538 1911860538 marked this pull request as ready for review December 9, 2025 14:46
@1911860538
Copy link
Copy Markdown
Contributor Author

@appleboy Please help to review this.

@appleboy appleboy added this to the v1.12 milestone Dec 12, 2025
@appleboy appleboy merged commit 64a6ed9 into gin-gonic:master Dec 12, 2025
25 of 27 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants