Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 11 additions & 0 deletions backend/cmd/server/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -631,6 +631,17 @@ func registerHandlers(e *echo.Echo, cfg config.Config, db *sql.DB) (*sshinfra.SS
mux := asynq.NewServeMux()
mcpWorker := worker.NewMCPVerificationWorker(mcpVerificationRepo, cfg.WebBaseURL)
mux.HandleFunc(queue.TypeMCPVerification, mcpWorker.HandleMCPVerification)
artifactCleanupWorker := worker.NewArtifactCleanupWorker(artifactRepo, artifactStorage, minioBucket)
mux.HandleFunc(queue.TypeArtifactCleanup, artifactCleanupWorker.HandleCleanup)
scheduler := asynq.NewScheduler(asynq.RedisClientOpt{Addr: cfg.RedisAddr}, nil)
if _, err := scheduler.Register("@hourly", asynq.NewTask(queue.TypeArtifactCleanup, nil)); err != nil {
return nil, fmt.Errorf("register artifact cleanup scheduler: %w", err)
}
go func() {
if err := scheduler.Run(); err != nil {
middleware.Log().Info("asynq scheduler stopped", "error", err)

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟠 [high] scheduler.Run() 失敗時に Info ログのみでプロセスが継続する

該当箇所:

go func() {
    if err := scheduler.Run(); err != nil {
        middleware.Log().Info("asynq scheduler stopped", "error", err)
    }
}()

scheduler.Run() が起動失敗(Redis 接続不可など)した場合、Info レベルのログを出力するだけでサーバープロセスは正常稼働を続ける。その結果、@hourly の artifact cleanup タスクが一切エンキューされないが、オペレーターはエラーに気づきにくい。既存の asynqServer.Run(mux) も同様のパターンであればプロジェクトの慣習に沿っているかもしれないが、少なくとも Error レベルのログを使うべきである。

@@ -543,7 +543,7 @@ go func() {
 		if err := scheduler.Run(); err != nil {
-			middleware.Log().Info("asynq scheduler stopped", "error", err)
+			middleware.Log().Error("asynq scheduler stopped", "error", err)
 		}
 }()

code.error_handling.scheduler_goroutine_silent_stop | confidence: 0.92

}
}()
prMergeableWorker := queue.NewPRMergeableWorker(prRepo, repoRepo, gitSvc)
mux.HandleFunc(queue.TypePRMergeableCheck, prMergeableWorker.HandlePRMergeableCheck)
go func() {
Expand Down
6 changes: 6 additions & 0 deletions backend/internal/infrastructure/queue/asynq_client.go
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@ import (
const (
TypeWebhookDeliver = "webhook:deliver"
TypeMCPVerification = "mcp:verification"
TypeArtifactCleanup = "artifact:cleanup"
TypeDispatchJob = "actions:dispatch_job"
TypeCancelJob = "actions:cancel_job"
)
Expand Down Expand Up @@ -71,6 +72,11 @@ func EnqueueWebhookDelivery(ctx context.Context, client *asynq.Client, payload W
return client.EnqueueContext(ctx, task, asynq.MaxRetry(5))
}

func EnqueueArtifactCleanup(ctx context.Context, client *asynq.Client) (*asynq.TaskInfo, error) {
task := asynq.NewTask(TypeArtifactCleanup, nil)
return client.EnqueueContext(ctx, task, asynq.Queue("default"))
}

func EnqueueDispatchJob(ctx context.Context, client *asynq.Client, payload DispatchJobPayload) (*asynq.TaskInfo, error) {
data, err := json.Marshal(payload)
if err != nil {
Expand Down
57 changes: 57 additions & 0 deletions backend/internal/worker/artifact_cleanup_worker.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,57 @@
package worker

import (
"context"
"log/slog"

"github.com/hibiken/asynq"

domainrepo "github.com/open-git/backend/internal/domain/repository"
artifactusecase "github.com/open-git/backend/internal/usecase/artifact"
)

type ArtifactCleanupWorker struct {
artifactRepo domainrepo.IArtifactRepository
storage artifactusecase.ArtifactStorage
bucket string
}

func NewArtifactCleanupWorker(
repo domainrepo.IArtifactRepository,
storage artifactusecase.ArtifactStorage,
bucket string,
) *ArtifactCleanupWorker {
return &ArtifactCleanupWorker{
artifactRepo: repo,
storage: storage,
bucket: bucket,
}
}

func (w *ArtifactCleanupWorker) HandleCleanup(ctx context.Context, task *asynq.Task) error {
const batchSize = 100
for {
artifacts, err := w.artifactRepo.ListExpired(ctx, batchSize)
if err != nil {
return err
}
if len(artifacts) == 0 {
break
}

for _, artifact := range artifacts {
if err := w.storage.DeleteObject(ctx, w.bucket, artifact.StorageKey); err != nil {
slog.Error("delete artifact object", "artifact_id", artifact.ID, "error", err)
continue
}
if err := w.artifactRepo.SoftDelete(ctx, artifact.ID, artifact.OrganizationID); err != nil {
slog.Error("soft delete artifact", "artifact_id", artifact.ID, "error", err)
}
}

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟠 [high] SoftDelete 失敗時に artifact が次回バッチで再度 DeleteObject される

SoftDelete が失敗してもループを継続し、エラーを記録するだけでその artifact は soft-delete されない。次回のジョブ実行では ListExpired に同じ artifact が返り、storage.DeleteObject が再度呼ばれる。StorageKey が既に削除済みであれば 404 エラーで DeleteObject が失敗し、無限に同じ artifact が処理され続ける可能性がある。

該当箇所:

if err := w.artifactRepo.SoftDelete(ctx, artifact.ID, artifact.OrganizationID); err != nil {
    slog.Error("soft delete artifact", "artifact_id", artifact.ID, "error", err)
}

MinIO の DeleteObject べき等を前提にする設計であれば、少なくともコメントか設計メモを残すべき。べき等でない場合は二重削除を防ぐ仕組みが必要。

code.logic.softdelete_error_ignored_in_loop | confidence: 0.78

if len(artifacts) < batchSize {
break
}

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔴 [critical] SoftDelete が全件失敗すると HandleCleanup が無限ループする

外側の for ループは len(artifacts) == 0 または len(artifacts) < batchSize のときのみ終了します。SoftDelete 失敗時はログのみで処理を継続するため、期限切れレコードは DB 上で削除されず、次の反復でも同じバッチが返り続けます。

該当箇所:

	for {
		artifacts, err := w.artifactRepo.ListExpired(ctx, batchSize)
		...
		for _, artifact := range artifacts {
			...
			if err := w.artifactRepo.SoftDelete(ctx, artifact.ID, artifact.OrganizationID); err != nil {
				slog.Error("soft delete artifact", "artifact_id", artifact.ID, "error", err)
			}
		}

		if len(artifacts) < batchSize {
			break
		}
	}

batchSize(100) 件ちょうど返り、全件の SoftDelete が失敗する(DB 障害・権限エラー等)ケースでは len(artifacts) < batchSize にならず、Asynq タスクが完了せずワーカーを占有し続けます。DeleteObject が全件 continue されるケースも同様です。

@@ -48,6 +48,15 @@
 			}
 		}
 
+		deletedCount := 0
+		for _, artifact := range artifacts {
+			// track successful SoftDelete in the inner loop
+		}
+		if deletedCount == 0 && len(artifacts) > 0 {
+			return fmt.Errorf("artifact cleanup made no progress on batch of %d", len(artifacts))
+		}
+
 		if len(artifacts) < batchSize {
 			break
 		}

code.logic.infinite_loop | confidence: 0.93

}

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔴 [critical] storage.DeleteObject 失敗時に artifact が再度 ListExpired に現れ無限ループになる

storage.DeleteObject が失敗した場合は continue で SoftDelete をスキップするため、次のバッチで同じ artifact が再度 ListExpired に返される。batchSize=100 件すべてが削除失敗し続けると、len(artifacts) < batchSize の条件を満たさず外側の for {} が永遠に回り続ける。

該当箇所:

if err := w.storage.DeleteObject(ctx, w.bucket, artifact.StorageKey); err != nil {
    slog.Error("delete artifact object", "artifact_id", artifact.ID, "error", err)
    continue
}

MinIO が一時的に落ちた場合など、全件 DeleteObject 失敗 → len(artifacts) == 100 → ループ継続、という状況が容易に発生する。ワーカーが停止しない限りゴルーチンが詰まり続ける。

修正案: 内側ループでエラーが起きた artifact をスキップカウントし、1 バッチ内でエラーが一定数を超えたら早期 return するか、または ListExpired にオフセット/カーソルを持たせる。あるいは ctx.Done() チェックを先頭に入れて context キャンセルで抜けられるようにする。

@@ -44,6 +44,10 @@
+		successCount := 0
 		for _, artifact := range artifacts {
 			if err := w.storage.DeleteObject(ctx, w.bucket, artifact.StorageKey); err != nil {
 				slog.Error("delete artifact object", "artifact_id", artifact.ID, "error", err)
 				continue
 			}
 			if err := w.artifactRepo.SoftDelete(ctx, artifact.ID, artifact.OrganizationID); err != nil {
 				slog.Error("soft delete artifact", "artifact_id", artifact.ID, "error", err)
+			} else {
+				successCount++
+			}
 		}
+		if successCount == 0 {
+			break // 1件も成功しなければループを抜けて無限ループを防ぐ
+		}

code.logic.infinite_loop_on_storage_error | confidence: 0.92

return nil

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔴 [critical] SoftDelete失敗時に同一レコードが無限ループで再処理される

該当箇所:

for _, artifact := range artifacts {
    if err := w.storage.DeleteObject(ctx, w.bucket, artifact.StorageKey); err != nil {
        slog.Error("delete artifact object", "artifact_id", artifact.ID, "error", err)
        continue
    }
    if err := w.artifactRepo.SoftDelete(ctx, artifact.ID, artifact.OrganizationID); err != nil {
        slog.Error("soft delete artifact", "artifact_id", artifact.ID, "error", err)
    }
}

if len(artifacts) < batchSize {
    break
}

SoftDelete が失敗した場合、deleted_at が設定されないため当該 artifact は次の ListExpired 呼び出しでも再び取得される。バッチサイズが 100 件ちょうどの場合(len(artifacts) == batchSize)、ループを抜ける条件を満たせず、StorageKey が既に削除済みのオブジェクトに対して DeleteObject を繰り返す無限ループに陥る。最終的には context タイムアウトまでループが継続し、不必要な MinIO API コールが大量発生する。

修正案: SoftDelete 失敗時も continue し、そのアイテムをスキップするか、または処理済み件数ではなく「SoftDelete に成功した件数」でループ継続判定を行う。あるいは SoftDelete 失敗の artifact を除外したカウントをバッチ終了判定に使う。

@@ -47,6 +47,9 @@ func (w *ArtifactCleanupWorker) HandleCleanup(ctx context.Context, task *asynq.Task) error {
 			if err := w.artifactRepo.SoftDelete(ctx, artifact.ID, artifact.OrganizationID); err != nil {
 				slog.Error("soft delete artifact", "artifact_id", artifact.ID, "error", err)
+				continue
 			}
+			successCount++
 		}

code.logic.infinite_loop_on_soft_delete_failure | confidence: 0.88

}
164 changes: 164 additions & 0 deletions backend/internal/worker/artifact_cleanup_worker_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,164 @@
package worker

import (
"context"
"database/sql"
"testing"
"time"

"github.com/google/uuid"
"github.com/hibiken/asynq"
"github.com/jmoiron/sqlx"
_ "github.com/mattn/go-sqlite3"

"github.com/open-git/backend/internal/domain/entity"
infrarepo "github.com/open-git/backend/internal/infrastructure/repository"
)

const artifactCleanupTestSchema = `
CREATE TABLE organizations (
id TEXT PRIMARY KEY,
login TEXT NOT NULL,
name TEXT NOT NULL,
plan_tier TEXT NOT NULL DEFAULT 'free',
created_at TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP
);
CREATE TABLE repositories (
id TEXT PRIMARY KEY,
organization_id TEXT NOT NULL,
name TEXT NOT NULL
);
CREATE TABLE workflow_runs (
id TEXT PRIMARY KEY,
organization_id TEXT NOT NULL,
repository_id TEXT NOT NULL,
workflow TEXT NOT NULL,
status TEXT NOT NULL,
conclusion TEXT,
started_at TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP,
completed_at TIMESTAMP
);
CREATE TABLE artifacts (
id TEXT PRIMARY KEY,
organization_id TEXT NOT NULL,
repository_id TEXT NOT NULL,
workflow_run_id TEXT NOT NULL,
name TEXT NOT NULL,
storage_key TEXT NOT NULL,
size_in_bytes INTEGER NOT NULL DEFAULT 0,
status TEXT NOT NULL CHECK(status IN ('pending','uploading','completed','failed','expired')),
retention_days INTEGER NOT NULL,
created_at TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP,
expires_at TIMESTAMP NOT NULL,
deleted_at TIMESTAMP
);
CREATE UNIQUE INDEX idx_artifacts_run_name ON artifacts(workflow_run_id, name) WHERE deleted_at IS NULL;
`

func newArtifactCleanupTestDB(t *testing.T) *sqlx.DB {
t.Helper()
db, err := sql.Open("sqlite3", ":memory:")
if err != nil {
t.Fatalf("open sqlite: %v", err)
}
if _, err := db.Exec(artifactCleanupTestSchema); err != nil {
_ = db.Close()
t.Fatalf("create schema: %v", err)
}
t.Cleanup(func() { _ = db.Close() })
return sqlx.NewDb(db, "sqlite3")
}

type mockArtifactCleanupStorage struct {
deletedKeys []string
}

func (m *mockArtifactCleanupStorage) PresignedPutURL(context.Context, string, string, time.Duration) (string, error) {
return "", nil
}

func (m *mockArtifactCleanupStorage) PresignedGetURL(context.Context, string, string, time.Duration) (string, error) {
return "", nil
}

func (m *mockArtifactCleanupStorage) DeleteObject(_ context.Context, _, key string) error {
m.deletedKeys = append(m.deletedKeys, key)
return nil
}

func TestArtifactCleanupWorker_HandleCleanup(t *testing.T) {
db := newArtifactCleanupTestDB(t)
ctx := context.Background()

orgID := uuid.MustParse("11111111-1111-1111-1111-111111111111")
repoID := uuid.MustParse("33333333-3333-3333-3333-333333333333")
runID := uuid.MustParse("44444444-4444-4444-4444-444444444444")

mustExec(t, db.DB, `INSERT INTO organizations (id, login, name, plan_tier) VALUES (?, ?, ?, ?)`,
orgID.String(), "acme", "Acme", "free")
mustExec(t, db.DB, `INSERT INTO repositories (id, organization_id, name) VALUES (?, ?, ?)`,
repoID.String(), orgID.String(), "widgets")
mustExec(t, db.DB, `INSERT INTO workflow_runs (id, organization_id, repository_id, workflow, status) VALUES (?, ?, ?, ?, ?)`,
runID.String(), orgID.String(), repoID.String(), "ci.yml", "completed")

now := time.Now().UTC()
expiredKey := "org/acme/repo/widgets/runs/1/expired.zip"
futureKey := "org/acme/repo/widgets/runs/1/future.zip"

artifactRepo := infrarepo.NewArtifactRepository(db)
expiredArtifact := &entity.Artifact{
OrganizationID: orgID,
RunID: runID,
Name: "expired-artifact",
StorageKey: expiredKey,
ExpiresAt: now.Add(-1 * time.Hour),
}
futureArtifact := &entity.Artifact{
OrganizationID: orgID,
RunID: runID,
Name: "future-artifact",
StorageKey: futureKey,
ExpiresAt: now.Add(24 * time.Hour),
}
if err := artifactRepo.Create(ctx, expiredArtifact); err != nil {
t.Fatalf("Create expired artifact: %v", err)
}
if err := artifactRepo.Create(ctx, futureArtifact); err != nil {
t.Fatalf("Create future artifact: %v", err)
}
if err := artifactRepo.UpdateStatus(ctx, expiredArtifact.ID, entity.ArtifactStatusCompleted, 100); err != nil {
t.Fatalf("UpdateStatus expired artifact: %v", err)
}
if err := artifactRepo.UpdateStatus(ctx, futureArtifact.ID, entity.ArtifactStatusCompleted, 200); err != nil {
t.Fatalf("UpdateStatus future artifact: %v", err)
}

storage := &mockArtifactCleanupStorage{}
worker := NewArtifactCleanupWorker(artifactRepo, storage, "artifacts")
task := asynq.NewTask("artifact:cleanup", nil)
if err := worker.HandleCleanup(ctx, task); err != nil {
t.Fatalf("HandleCleanup returned error: %v", err)
}

var expiredDeletedAt sql.NullTime
if err := db.QueryRowContext(ctx, `SELECT deleted_at FROM artifacts WHERE id = ?`, expiredArtifact.ID.String()).
Scan(&expiredDeletedAt); err != nil {
t.Fatalf("query expired artifact deleted_at: %v", err)
}
if !expiredDeletedAt.Valid {
t.Fatal("expected expired artifact deleted_at to be set")
}

var futureDeletedAt sql.NullTime
if err := db.QueryRowContext(ctx, `SELECT deleted_at FROM artifacts WHERE id = ?`, futureArtifact.ID.String()).
Scan(&futureDeletedAt); err != nil {
t.Fatalf("query future artifact deleted_at: %v", err)
}
if futureDeletedAt.Valid {
t.Fatal("expected non-expired artifact deleted_at to remain NULL")
}

if len(storage.deletedKeys) != 1 || storage.deletedKeys[0] != expiredKey {
t.Fatalf("DeleteObject calls = %v, want [%q]", storage.deletedKeys, expiredKey)
}
}
12 changes: 12 additions & 0 deletions docker-compose.yml
Original file line number Diff line number Diff line change
Expand Up @@ -92,6 +92,18 @@ services:
retries: 3
restart: unless-stopped

createbuckets:
image: minio/mc
depends_on:
minio:
condition: service_healthy
entrypoint: >
/bin/sh -c "
mc alias set myminio http://minio:9000 $${MINIO_ROOT_USER:-minioadmin} $${MINIO_ROOT_PASSWORD:-minioadmin};
mc mb --ignore-existing myminio/artifacts;
exit 0;
"

traefik:
image: traefik:v3
command:
Expand Down
Loading