Skip to content

Commit 2621dbe

Browse files
mattdhollowayCopilotomgitsads
authored
Add actions job log buffer and profiler (#866)
* add sliding window for actions logs * refactor: fix sliding * remove trim content * only use up to 1mb of memory for logs * update to tail lines in second pass * add better memory usage calculation * increase window size to 5MB * update test * update vers * undo vers change * add incremental memory tracking * use ring buffer * remove unused ctx param * remove manual GC clear * fix cca feedback * extract ring buffer logic to new package * handle log content processing errors and use correct param for maxjobloglines * fix tailing * account for if tailLines exceeds window size * add profiling thats reusable * remove profiler testing * refactor profiler: introduce safeMemoryDelta for accurate memory delta calculations * linter fixes * Update pkg/buffer/buffer.go Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com> * use flag for maxJobLogLines * add param passing for context window size * refactor: rename contextWindowSize to contentWindowSize for consistency * fix: use tailLines if bigger but only if <= 5000 * fix: limit tailLines to a maximum of 500 for log content download * Update cmd/github-mcp-server/main.go Co-authored-by: Adam Holt <omgitsads@github.com> * Update cmd/github-mcp-server/main.go Co-authored-by: Adam Holt <omgitsads@github.com> * move profiler to internal/ * update actions test with new profiler location * fix: adjust buffer size limits * make line buffer 1028kb * fix mod path * change test to use same buffer size as normal use * improve test for non-sliding window implementation to not count empty lines * make test memory measurement more accurate * remove impossible conditional --------- Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com> Co-authored-by: Adam Holt <omgitsads@github.com>
1 parent 96a705c commit 2621dbe

File tree

8 files changed

+493
-55
lines changed

8 files changed

+493
-55
lines changed

cmd/github-mcp-server/generate_docs.go

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -64,7 +64,7 @@ func generateReadmeDocs(readmePath string) error {
6464
t, _ := translations.TranslationHelper()
6565

6666
// Create toolset group with mock clients
67-
tsg := github.DefaultToolsetGroup(false, mockGetClient, mockGetGQLClient, mockGetRawClient, t)
67+
tsg := github.DefaultToolsetGroup(false, mockGetClient, mockGetGQLClient, mockGetRawClient, t, 5000)
6868

6969
// Generate toolsets documentation
7070
toolsetsDoc := generateToolsetsDoc(tsg)
@@ -302,7 +302,7 @@ func generateRemoteToolsetsDoc() string {
302302
t, _ := translations.TranslationHelper()
303303

304304
// Create toolset group with mock clients
305-
tsg := github.DefaultToolsetGroup(false, mockGetClient, mockGetGQLClient, mockGetRawClient, t)
305+
tsg := github.DefaultToolsetGroup(false, mockGetClient, mockGetGQLClient, mockGetRawClient, t, 5000)
306306

307307
// Generate table header
308308
buf.WriteString("| Name | Description | API URL | 1-Click Install (VS Code) | Read-only Link | 1-Click Read-only Install (VS Code) |\n")

cmd/github-mcp-server/main.go

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -55,6 +55,7 @@ var (
5555
ExportTranslations: viper.GetBool("export-translations"),
5656
EnableCommandLogging: viper.GetBool("enable-command-logging"),
5757
LogFilePath: viper.GetString("log-file"),
58+
ContentWindowSize: viper.GetInt("content-window-size"),
5859
}
5960
return ghmcp.RunStdioServer(stdioServerConfig)
6061
},
@@ -75,6 +76,7 @@ func init() {
7576
rootCmd.PersistentFlags().Bool("enable-command-logging", false, "When enabled, the server will log all command requests and responses to the log file")
7677
rootCmd.PersistentFlags().Bool("export-translations", false, "Save translations to a JSON file")
7778
rootCmd.PersistentFlags().String("gh-host", "", "Specify the GitHub hostname (for GitHub Enterprise etc.)")
79+
rootCmd.PersistentFlags().Int("content-window-size", 5000, "Specify the content window size")
7880

7981
// Bind flag to viper
8082
_ = viper.BindPFlag("toolsets", rootCmd.PersistentFlags().Lookup("toolsets"))
@@ -84,6 +86,7 @@ func init() {
8486
_ = viper.BindPFlag("enable-command-logging", rootCmd.PersistentFlags().Lookup("enable-command-logging"))
8587
_ = viper.BindPFlag("export-translations", rootCmd.PersistentFlags().Lookup("export-translations"))
8688
_ = viper.BindPFlag("host", rootCmd.PersistentFlags().Lookup("gh-host"))
89+
_ = viper.BindPFlag("content-window-size", rootCmd.PersistentFlags().Lookup("content-window-size"))
8790

8891
// Add subcommands
8992
rootCmd.AddCommand(stdioCmd)

internal/ghmcp/server.go

Lines changed: 15 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -47,6 +47,9 @@ type MCPServerConfig struct {
4747

4848
// Translator provides translated text for the server tooling
4949
Translator translations.TranslationHelperFunc
50+
51+
// Content window size
52+
ContentWindowSize int
5053
}
5154

5255
const stdioServerLogPrefix = "stdioserver"
@@ -132,7 +135,7 @@ func NewMCPServer(cfg MCPServerConfig) (*server.MCPServer, error) {
132135
}
133136

134137
// Create default toolsets
135-
tsg := github.DefaultToolsetGroup(cfg.ReadOnly, getClient, getGQLClient, getRawClient, cfg.Translator)
138+
tsg := github.DefaultToolsetGroup(cfg.ReadOnly, getClient, getGQLClient, getRawClient, cfg.Translator, cfg.ContentWindowSize)
136139
err = tsg.EnableToolsets(enabledToolsets)
137140

138141
if err != nil {
@@ -180,6 +183,9 @@ type StdioServerConfig struct {
180183

181184
// Path to the log file if not stderr
182185
LogFilePath string
186+
187+
// Content window size
188+
ContentWindowSize int
183189
}
184190

185191
// RunStdioServer is not concurrent safe.
@@ -191,13 +197,14 @@ func RunStdioServer(cfg StdioServerConfig) error {
191197
t, dumpTranslations := translations.TranslationHelper()
192198

193199
ghServer, err := NewMCPServer(MCPServerConfig{
194-
Version: cfg.Version,
195-
Host: cfg.Host,
196-
Token: cfg.Token,
197-
EnabledToolsets: cfg.EnabledToolsets,
198-
DynamicToolsets: cfg.DynamicToolsets,
199-
ReadOnly: cfg.ReadOnly,
200-
Translator: t,
200+
Version: cfg.Version,
201+
Host: cfg.Host,
202+
Token: cfg.Token,
203+
EnabledToolsets: cfg.EnabledToolsets,
204+
DynamicToolsets: cfg.DynamicToolsets,
205+
ReadOnly: cfg.ReadOnly,
206+
Translator: t,
207+
ContentWindowSize: cfg.ContentWindowSize,
201208
})
202209
if err != nil {
203210
return fmt.Errorf("failed to create MCP server: %w", err)

internal/profiler/profiler.go

Lines changed: 215 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,215 @@
1+
package profiler
2+
3+
import (
4+
"context"
5+
"fmt"
6+
"os"
7+
"runtime"
8+
"strconv"
9+
"time"
10+
11+
"log/slog"
12+
"math"
13+
)
14+
15+
// Profile represents performance metrics for an operation
16+
type Profile struct {
17+
Operation string `json:"operation"`
18+
Duration time.Duration `json:"duration_ns"`
19+
MemoryBefore uint64 `json:"memory_before_bytes"`
20+
MemoryAfter uint64 `json:"memory_after_bytes"`
21+
MemoryDelta int64 `json:"memory_delta_bytes"`
22+
LinesCount int `json:"lines_count,omitempty"`
23+
BytesCount int64 `json:"bytes_count,omitempty"`
24+
Timestamp time.Time `json:"timestamp"`
25+
}
26+
27+
// String returns a human-readable representation of the profile
28+
func (p *Profile) String() string {
29+
return fmt.Sprintf("[%s] %s: duration=%v, memory_delta=%+dB, lines=%d, bytes=%d",
30+
p.Timestamp.Format("15:04:05.000"),
31+
p.Operation,
32+
p.Duration,
33+
p.MemoryDelta,
34+
p.LinesCount,
35+
p.BytesCount,
36+
)
37+
}
38+
39+
func safeMemoryDelta(after, before uint64) int64 {
40+
if after > math.MaxInt64 || before > math.MaxInt64 {
41+
if after >= before {
42+
diff := after - before
43+
if diff > math.MaxInt64 {
44+
return math.MaxInt64
45+
}
46+
return int64(diff)
47+
}
48+
diff := before - after
49+
if diff > math.MaxInt64 {
50+
return -math.MaxInt64
51+
}
52+
return -int64(diff)
53+
}
54+
55+
return int64(after) - int64(before)
56+
}
57+
58+
// Profiler provides minimal performance profiling capabilities
59+
type Profiler struct {
60+
logger *slog.Logger
61+
enabled bool
62+
}
63+
64+
// New creates a new Profiler instance
65+
func New(logger *slog.Logger, enabled bool) *Profiler {
66+
return &Profiler{
67+
logger: logger,
68+
enabled: enabled,
69+
}
70+
}
71+
72+
// ProfileFunc profiles a function execution
73+
func (p *Profiler) ProfileFunc(ctx context.Context, operation string, fn func() error) (*Profile, error) {
74+
if !p.enabled {
75+
return nil, fn()
76+
}
77+
78+
profile := &Profile{
79+
Operation: operation,
80+
Timestamp: time.Now(),
81+
}
82+
83+
var memBefore runtime.MemStats
84+
runtime.ReadMemStats(&memBefore)
85+
profile.MemoryBefore = memBefore.Alloc
86+
87+
start := time.Now()
88+
err := fn()
89+
profile.Duration = time.Since(start)
90+
91+
var memAfter runtime.MemStats
92+
runtime.ReadMemStats(&memAfter)
93+
profile.MemoryAfter = memAfter.Alloc
94+
profile.MemoryDelta = safeMemoryDelta(memAfter.Alloc, memBefore.Alloc)
95+
96+
if p.logger != nil {
97+
p.logger.InfoContext(ctx, "Performance profile", "profile", profile.String())
98+
}
99+
100+
return profile, err
101+
}
102+
103+
// ProfileFuncWithMetrics profiles a function execution and captures additional metrics
104+
func (p *Profiler) ProfileFuncWithMetrics(ctx context.Context, operation string, fn func() (int, int64, error)) (*Profile, error) {
105+
if !p.enabled {
106+
_, _, err := fn()
107+
return nil, err
108+
}
109+
110+
profile := &Profile{
111+
Operation: operation,
112+
Timestamp: time.Now(),
113+
}
114+
115+
var memBefore runtime.MemStats
116+
runtime.ReadMemStats(&memBefore)
117+
profile.MemoryBefore = memBefore.Alloc
118+
119+
start := time.Now()
120+
lines, bytes, err := fn()
121+
profile.Duration = time.Since(start)
122+
profile.LinesCount = lines
123+
profile.BytesCount = bytes
124+
125+
var memAfter runtime.MemStats
126+
runtime.ReadMemStats(&memAfter)
127+
profile.MemoryAfter = memAfter.Alloc
128+
profile.MemoryDelta = safeMemoryDelta(memAfter.Alloc, memBefore.Alloc)
129+
130+
if p.logger != nil {
131+
p.logger.InfoContext(ctx, "Performance profile", "profile", profile.String())
132+
}
133+
134+
return profile, err
135+
}
136+
137+
// Start begins timing an operation and returns a function to complete the profiling
138+
func (p *Profiler) Start(ctx context.Context, operation string) func(lines int, bytes int64) *Profile {
139+
if !p.enabled {
140+
return func(int, int64) *Profile { return nil }
141+
}
142+
143+
profile := &Profile{
144+
Operation: operation,
145+
Timestamp: time.Now(),
146+
}
147+
148+
var memBefore runtime.MemStats
149+
runtime.ReadMemStats(&memBefore)
150+
profile.MemoryBefore = memBefore.Alloc
151+
152+
start := time.Now()
153+
154+
return func(lines int, bytes int64) *Profile {
155+
profile.Duration = time.Since(start)
156+
profile.LinesCount = lines
157+
profile.BytesCount = bytes
158+
159+
var memAfter runtime.MemStats
160+
runtime.ReadMemStats(&memAfter)
161+
profile.MemoryAfter = memAfter.Alloc
162+
profile.MemoryDelta = safeMemoryDelta(memAfter.Alloc, memBefore.Alloc)
163+
164+
if p.logger != nil {
165+
p.logger.InfoContext(ctx, "Performance profile", "profile", profile.String())
166+
}
167+
168+
return profile
169+
}
170+
}
171+
172+
var globalProfiler *Profiler
173+
174+
// IsProfilingEnabled checks if profiling is enabled via environment variables
175+
func IsProfilingEnabled() bool {
176+
if enabled, err := strconv.ParseBool(os.Getenv("GITHUB_MCP_PROFILING_ENABLED")); err == nil {
177+
return enabled
178+
}
179+
return false
180+
}
181+
182+
// Init initializes the global profiler
183+
func Init(logger *slog.Logger, enabled bool) {
184+
globalProfiler = New(logger, enabled)
185+
}
186+
187+
// InitFromEnv initializes the global profiler using environment variables
188+
func InitFromEnv(logger *slog.Logger) {
189+
globalProfiler = New(logger, IsProfilingEnabled())
190+
}
191+
192+
// ProfileFunc profiles a function using the global profiler
193+
func ProfileFunc(ctx context.Context, operation string, fn func() error) (*Profile, error) {
194+
if globalProfiler == nil {
195+
return nil, fn()
196+
}
197+
return globalProfiler.ProfileFunc(ctx, operation, fn)
198+
}
199+
200+
// ProfileFuncWithMetrics profiles a function with metrics using the global profiler
201+
func ProfileFuncWithMetrics(ctx context.Context, operation string, fn func() (int, int64, error)) (*Profile, error) {
202+
if globalProfiler == nil {
203+
_, _, err := fn()
204+
return nil, err
205+
}
206+
return globalProfiler.ProfileFuncWithMetrics(ctx, operation, fn)
207+
}
208+
209+
// Start begins timing using the global profiler
210+
func Start(ctx context.Context, operation string) func(int, int64) *Profile {
211+
if globalProfiler == nil {
212+
return func(int, int64) *Profile { return nil }
213+
}
214+
return globalProfiler.Start(ctx, operation)
215+
}

pkg/buffer/buffer.go

Lines changed: 69 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,69 @@
1+
package buffer
2+
3+
import (
4+
"bufio"
5+
"fmt"
6+
"net/http"
7+
"strings"
8+
)
9+
10+
// ProcessResponseAsRingBufferToEnd reads the body of an HTTP response line by line,
11+
// storing only the last maxJobLogLines lines using a ring buffer (sliding window).
12+
// This efficiently retains the most recent lines, overwriting older ones as needed.
13+
//
14+
// Parameters:
15+
//
16+
// httpResp: The HTTP response whose body will be read.
17+
// maxJobLogLines: The maximum number of log lines to retain.
18+
//
19+
// Returns:
20+
//
21+
// string: The concatenated log lines (up to maxJobLogLines), separated by newlines.
22+
// int: The total number of lines read from the response.
23+
// *http.Response: The original HTTP response.
24+
// error: Any error encountered during reading.
25+
//
26+
// The function uses a ring buffer to efficiently store only the last maxJobLogLines lines.
27+
// If the response contains more lines than maxJobLogLines, only the most recent lines are kept.
28+
func ProcessResponseAsRingBufferToEnd(httpResp *http.Response, maxJobLogLines int) (string, int, *http.Response, error) {
29+
lines := make([]string, maxJobLogLines)
30+
validLines := make([]bool, maxJobLogLines)
31+
totalLines := 0
32+
writeIndex := 0
33+
34+
scanner := bufio.NewScanner(httpResp.Body)
35+
scanner.Buffer(make([]byte, 0, 64*1024), 1024*1024)
36+
37+
for scanner.Scan() {
38+
line := scanner.Text()
39+
totalLines++
40+
41+
lines[writeIndex] = line
42+
validLines[writeIndex] = true
43+
writeIndex = (writeIndex + 1) % maxJobLogLines
44+
}
45+
46+
if err := scanner.Err(); err != nil {
47+
return "", 0, httpResp, fmt.Errorf("failed to read log content: %w", err)
48+
}
49+
50+
var result []string
51+
linesInBuffer := totalLines
52+
if linesInBuffer > maxJobLogLines {
53+
linesInBuffer = maxJobLogLines
54+
}
55+
56+
startIndex := 0
57+
if totalLines > maxJobLogLines {
58+
startIndex = writeIndex
59+
}
60+
61+
for i := 0; i < linesInBuffer; i++ {
62+
idx := (startIndex + i) % maxJobLogLines
63+
if validLines[idx] {
64+
result = append(result, lines[idx])
65+
}
66+
}
67+
68+
return strings.Join(result, "\n"), totalLines, httpResp, nil
69+
}

0 commit comments

Comments
 (0)