Ephemeral Runner deletion causing logs to not get submitted #36632
Description
Description
This PR causes ephemeral runners to be set as deleted as soon as the task completes.
However sometimes this is before the runner has sent all the log data.
This causes retrieval of the runner in interceptor.go#L37 to sometimes fail to get the runner from the database (as it looks like the orm implicitly adds a WHERE deleted=0 clause), resulting in nil result for runner from actions_model.GetRunnerByUUID(ctx, uuid), returning early and causing UpdateLog in runner.go#L245 to not get called.
The error in the logs is generic
2026/02/15 03:35:10 HTTPRequest [I] router: completed POST /api/actions/runner.v1.RunnerService/UpdateLog for x.x.x.x:52216, 500 Internal Server Error in 62634.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)
When this occurs it usually happens on the last log submission which has NoMore=true set, signalling the end of the logging. Without this being received, no log gets output to disk, and there are gaps in gitea/actions_log with no file/folder created where logs were not finalised. In some instances the deletion is early enough that actual log data is not received and is missing in the UI.
It looks like setting the runner as deleted should either have some kind of timeout, or be aware there are outstanding logs to be received, and then perhaps pend the deletion till either NoMore=true is received, or a timeout occurs.
Alternatively the database query could use Unscoped() to allow getting the 'deleted' runner, so that the log entry request can be processed. Although this doesn't feel right.
Here is some logging data that shows the issue.
Working Run
gitea | 2026/02/15 03:33:18 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="a451337f-9805-477b-800f-5ff1bc87f736" TaskId=537 Index=0 Rows=0 NoMore=false
gitea | 2026/02/15 03:33:25 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="a451337f-9805-477b-800f-5ff1bc87f736" TaskId=537 Index=0 Rows=6 NoMore=false
gitea | 2026/02/15 03:33:27 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="a451337f-9805-477b-800f-5ff1bc87f736" TaskId=537 Index=6 Rows=0 NoMore=false
gitea | 2026/02/15 03:33:29 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="a451337f-9805-477b-800f-5ff1bc87f736" TaskId=537 Index=6 Rows=0 NoMore=false
gitea | 2026/02/15 03:33:30 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="a451337f-9805-477b-800f-5ff1bc87f736" TaskId=537 Index=6 Rows=0 NoMore=false
gitea | 2026/02/15 03:33:32 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="a451337f-9805-477b-800f-5ff1bc87f736" TaskId=537 Index=6 Rows=75 NoMore=false
gitea | 2026/02/15 03:33:33 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="a451337f-9805-477b-800f-5ff1bc87f736" TaskId=537 Index=81 Rows=52 NoMore=true
gitea | 2026/02/15 03:33:34 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="a451337f-9805-477b-800f-5ff1bc87f736" TaskId=537 Index=133 Rows=0 NoMore=true
Broken Run
gitea | 2026/02/15 03:33:57 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="4aa05f23-a296-4abe-b635-60b4e9117995" TaskId=538 Index=0 Rows=0 NoMore=false
gitea | 2026/02/15 03:33:58 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="4aa05f23-a296-4abe-b635-60b4e9117995" TaskId=538 Index=0 Rows=6 NoMore=false
gitea | 2026/02/15 03:34:00 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="4aa05f23-a296-4abe-b635-60b4e9117995" TaskId=538 Index=6 Rows=0 NoMore=false
gitea | 2026/02/15 03:34:01 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="4aa05f23-a296-4abe-b635-60b4e9117995" TaskId=538 Index=6 Rows=0 NoMore=false
gitea | 2026/02/15 03:34:04 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="4aa05f23-a296-4abe-b635-60b4e9117995" TaskId=538 Index=6 Rows=0 NoMore=false
gitea | 2026/02/15 03:34:06 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="4aa05f23-a296-4abe-b635-60b4e9117995" TaskId=538 Index=6 Rows=16 NoMore=false
gitea | 2026/02/15 03:34:07 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="4aa05f23-a296-4abe-b635-60b4e9117995" TaskId=538 Index=22 Rows=66 NoMore=false
gitea | 2026/02/15 03:34:08 .../runner/interceptor.go:39:init.1.1() [E] MYDEBUG withRunner: UpdateLog uuid="4aa05f23-a296-4abe-b635-60b4e9117995" TaskId=538 Index=88 Rows=45 NoMore=true
gitea | 2026/02/15 03:34:08 .../runner/interceptor.go:45:init.1.1() [E] MYDEBUG withRunner: unregistered runner uuid="4aa05f23-a296-4abe-b635-60b4e9117995" method=UpdateLog
gitea | 2026/02/15 03:34:48 .../runner/interceptor.go:47:init.1.1() [E] MYDEBUG withRunner: TaskId=538 Index=88 Rows=45 NoMore=true
With the following modifications to interceptor.go for the debug logs above.
import (
....
runnerv1 "code.gitea.io/actions-proto-go/runner/v1"
)
...
var withRunner = connect.WithInterceptors(connect.UnaryInterceptorFunc(func(unaryFunc connect.UnaryFunc) connect.UnaryFunc {
return func(ctx context.Context, request connect.AnyRequest) (connect.AnyResponse, error) {
methodName := getMethodName(request)
if methodName == "Register" {
return unaryFunc(ctx, request)
}
uuid := request.Header().Get(uuidHeaderKey)
token := request.Header().Get(tokenHeaderKey)
if msg, ok := request.Any().(*runnerv1.UpdateLogRequest); ok {
log.Error("MYDEBUG withRunner: UpdateLog uuid=%q TaskId=%d Index=%d Rows=%d NoMore=%v", uuid, msg.TaskId, msg.Index, len(msg.Rows), msg.NoMore)
}
runner, err := actions_model.GetRunnerByUUID(ctx, uuid)
if err != nil {
if errors.Is(err, util.ErrNotExist) {
log.Error("MYDEBUG withRunner: unregistered runner uuid=%q method=%s", uuid, methodName)
if msg, ok := request.Any().(*runnerv1.UpdateLogRequest); ok {
log.Error("MYDEBUG withRunner: TaskId=%d Index=%d Rows=%d NoMore=%v", msg.TaskId, msg.Index, len(msg.Rows), msg.NoMore)
}
return nil, status.Error(codes.Unauthenticated, "unregistered runner")
}
return nil, status.Error(codes.Internal, err.Error())
}
if subtle.ConstantTimeCompare([]byte(runner.TokenHash), []byte(auth_model.HashToken(token, runner.TokenSalt))) != 1 {
return nil, status.Error(codes.Unauthenticated, "unregistered runner")
}
cols := []string{"last_online"}
runner.LastOnline = timeutil.TimeStampNow()
if methodName == "UpdateTask" || methodName == "UpdateLog" {
runner.LastActive = timeutil.TimeStampNow()
cols = append(cols, "last_active")
}
if err := actions_model.UpdateRunner(ctx, runner, cols...); err != nil {
log.Error("can't update runner status: %v", err)
}
ctx = context.WithValue(ctx, runnerCtxKey{}, runner)
return unaryFunc(ctx, request)
}
}))
func getMethodName(req connect.AnyRequest) string {
splits := strings.Split(req.Spec().Procedure, "/")
if len(splits) > 0 {
return splits[len(splits)-1]
}
return ""
}
type runnerCtxKey struct{}
func GetRunner(ctx context.Context) *actions_model.ActionRunner {
if v := ctx.Value(runnerCtxKey{}); v != nil {
if r, ok := v.(*actions_model.ActionRunner); ok {
return r
}
}
return nil
}
Other possibly related issues are
Gitea Version
1.25.4
Can you reproduce the bug on the Gitea demo site?
No
Log Gist
No response
Screenshots
No response
Git Version
No response
Operating System
No response
How are you running Gitea?
the official docker image, with source built gitea executable to debug this issue.
Database
None