Stats.DB Index Repo[425] hangs

[somera]

Description

Just saw, that the job hangs.

gitea-diagnosis-20230722-235117.zip

Gitea Version

1.20.1

Can you reproduce the bug on the Gitea demo site?

Yes

Log Gist

No response

Screenshots

No response

Git Version

2.25.1

Operating System

Ubuntu 20.04.6

How are you running Gitea?

Precompiled gitea-1.20.1-linux-amd64

Database

PostgreSQL

[somera]

I restarted my gitea to "fix" this.

[techknowlogick]

Thanks for the report @somera, could you confirm that repo with ID 425 in your DB is https://github.com/google/material-design-icons ? I'm cloning it now to poke at it in my instance.

[wxiaoguang]

Just a guess, maybe it's related to this problem (I have left some comments in the "code/indexer.go")

This issue's stacktrace:

1 @ 0x440bb6 0x47132c 0x47130c 0x4903ec 0xaa6a5d 0x54833f 0x548f2f 0x549374 0x54974b 0xd60af8 0xdb063b 0x1e56bf8 0x1e576f2 0x1e58a9d 0x1e5b16e 0x1e58729 0x475381
# labels: {"graceful-lifecycle":"with-shutdown", "pid":"64bc45a1", "ppid":"", "process-description":"Stats.DB Index Repo[425]", "process-type":"normal"}
#	0x47130b	sync.runtime_notifyListWait+0x12b							/usr/local/go/src/runtime/sema.go:527
#	0x4903eb	sync.(*Cond).Wait+0x8b									/usr/local/go/src/sync/cond.go:70
#	0xaa6a5c	github.com/djherbis/nio/v3.(*PipeReader).Read+0x19c					/go/pkg/mod/github.com/djherbis/nio/v3@v3.0.1/sync.go:106
#	0x54833e	bufio.(*Reader).fill+0xfe								/usr/local/go/src/bufio/bufio.go:106
#	0x548f2e	bufio.(*Reader).ReadSlice+0x2e								/usr/local/go/src/bufio/bufio.go:372
#	0x549373	bufio.(*Reader).collectFragments+0x73							/usr/local/go/src/bufio/bufio.go:447
#	0x54974a	bufio.(*Reader).ReadString+0x2a								/usr/local/go/src/bufio/bufio.go:494
#	0xd60af7	code.gitea.io/gitea/modules/git.ReadBatchLine+0x37					/source/modules/git/batch_reader.go:149
#	0xdb063a	code.gitea.io/gitea/modules/git.(*Repository).GetLanguageStats+0x111a			/source/modules/git/repo_language_stats_nogogit.go:153
#	0x1e56bf7	code.gitea.io/gitea/modules/indexer/stats.(*DBIndexer).Index+0x5b7			/source/modules/indexer/stats/db.go:64
#	0x1e576f1	code.gitea.io/gitea/modules/indexer/stats.handler+0x71					/source/modules/indexer/stats/queue.go:22
#	0x1e58a9c	code.gitea.io/gitea/modules/queue.NewWorkerPoolQueueWithContext[...].func1+0x9c		/source/modules/queue/workerqueue.go:246
#	0x1e5b16d	code.gitea.io/gitea/modules/queue.(*WorkerPoolQueue[...]).doWorkerHandle+0x16d		/source/modules/queue/workergroup.go:98
#	0x1e58728	code.gitea.io/gitea/modules/queue.(*WorkerPoolQueue[...]).doStartNewWorker.func1+0x308	/source/modules/queue/workergroup.go:162

Previous comment:

[somera]

Thanks for the report @somera, could you confirm that repo with ID 425 in your DB is https://github.com/google/material-design-icons ? I'm cloning it now to poke at it in my instance.

Yes, this repo is in my DB.

[somera]

1.20.2: hangs for 2 hours now.

gitea-diagnosis-20230731-181943.zip

[wxiaoguang]

Still the same problem as above: stats.(*DBIndexer).Index -> GetLanguageStats -> git.ReadBatchLine ....

I have tried writing some different tests but I still can't reproduce it on my side, no idea yet .....

[somera]

I think this happens, when the mirror and stats tasks run at the same time. But i'm not sure, that this is the reason.

[somera]

And I found

2023/07/31 16:10:59 ...it/repo_attribute.go:306:func2() [E] Unable to open checker for 6745d95590b1a5593888b6c402401fc3db75fbdb. Error: failed to run attr-check. Error: context deadline exceeded
Stderr:
        /source/modules/git/repo_attribute.go:306 (0xd8e2e1)
        /usr/local/go/src/runtime/asm_amd64.s:1598 (0x475380)
                goexit: BYTE    $0x90   // NOP

[somera]

And I see, this is the same repo id -> 425.

[somera]

I removed the mirror.

The issue can be closed or you fix this: #26064 (comment)

[wxiaoguang]

I think it is a really serious bug, so it could be kept open until it gets resolved ......

ps: the repo contains a lot of small files (580937) , https://github.com/google/material-design-icons

[wxiaoguang]

As a workaround:

;; repo indexer units, the items to index, could be `sources`, `forks`, `mirrors`, `templates` or any combination of them separated by a comma.
;; If empty then it defaults to `sources` only, as if you'd like to disable fully please see REPO_INDEXER_ENABLED.
;REPO_INDEXER_REPO_TYPES = sources,forks,mirrors,templates

I think it could help you to avoid indexing such large repo

[wxiaoguang]

After more trails, I figured out the problem. It looks like a Golang's framework's bug flaw (although it has been documented but not obvious ....).

Demo code:

func TestCommand(t *testing.T) {
	ctx, cancel := context.WithCancel(context.Background())
	defer cancel()

	cmd := exec.CommandContext(ctx, "cat")
	rStdin, wStdin := io.Pipe()
	rStdout, wStdout := io.Pipe() // nio.Pipe(buffer.New(32 * 1024))
	cmd.Stdin = rStdin
	cmd.Stdout = wStdout
	written := 0
	read := 0
	stopWriting := atomic.Bool{}
	go func() {
		for !stopWriting.Load() {
			line := strings.Repeat("a", 5+rand.Intn(100)) + "\n"
			for i := 0; i < len(line); i++ {
				_, _ = wStdin.Write([]byte{line[i]})
			}
			written++
			time.Sleep(50 * time.Microsecond)
		}
	}()
	go func() {
		bio := bufio.NewReader(rStdout)
		for {
			_, _ = bio.ReadString('\n')
			read++
		}
	}()

	go func() {
		time.Sleep(1000 * time.Millisecond)
		t.Logf("now written: %d, read: %d, stop writing", written, read)
		stopWriting.Store(true) // with this line, if the "writing" is stopped ahead, the cmd.Run()/Wait() gets stuck forever
		t.Logf("cancel context (kill process) ...")
		cancel()
	}()

	err := cmd.Run()
	assert.Error(t, err)
	t.Logf("done. written: %d, read: %d", written, read)
}

Update: Hmm .... OK, actually, not Golang's bug, it's a Golang's design flaw ..... the Stdin/Stdout should not be used that way.