gitea doctor --run output is sometime truncated

[silentcodeg]

Description

Steps to reproduce:

• docker run --name gitea -p 3000:3000 -e GITEA__security__INSTALL_LOCK=true -d gitea/gitea:1.16.8-rootless
• docker exec gitea gitea admin user create --admin --username root --password admin1234 --email root@example.com
• docker exec gitea mkdir /var/lib/gitea/data/log
• go to the web interface to create a test repository, with an initial README.md file
• docker exec gitea mv /var/lib/gitea/git/repositories/root/test.git /var/lib/gitea/git/repositories/root/other.git
• docker exec gitea gitea doctor --run hooks

What is expected?

$ docker exec gitea gitea doctor --run hooks
[1] Check if hook files are up-to-date and executable
 - [W] old hook file /var/lib/gitea/git/repositories/root/test.git/hooks/pre-receive does not exist
 - [W] hooks directory /var/lib/gitea/git/repositories/root/test.git/hooks/pre-receive.d does not exist
 - [W] new hook file /var/lib/gitea/git/repositories/root/test.git/hooks/pre-receive.d/gitea does not exist
 - [W] old hook file /var/lib/gitea/git/repositories/root/test.git/hooks/update does not exist
 - [W] hooks directory /var/lib/gitea/git/repositories/root/test.git/hooks/update.d does not exist
 - [W] new hook file /var/lib/gitea/git/repositories/root/test.git/hooks/update.d/gitea does not exist
 - [W] old hook file /var/lib/gitea/git/repositories/root/test.git/hooks/post-receive does not exist
 - [W] hooks directory /var/lib/gitea/git/repositories/root/test.git/hooks/post-receive.d does not exist
 - [W] new hook file /var/lib/gitea/git/repositories/root/test.git/hooks/post-receive.d/gitea does not exist
OK

What actually happens?

The output is truncated, the line with OK is never shown and other lines are truncated randomly:

$ docker exec gitea gitea doctor --run hooks
[1] Check if hook files are up-to-date and executable
 - [W] old hook file /var/lib/gitea/git/repositories/root/test.git/hooks/pre-receive does not exist

Gitea Version

1.16.8

Can you reproduce the bug on the Gitea demo site?

No

Log Gist

No response

Screenshots

No response

Git Version

Operating System

How are you running Gitea?

Database

SQLite

[wxiaoguang]

Just a guess, the doctor logger writes to Stdout, and in its Flush it does nothing, then the content is still in the buffer ....

[Gusted]

TL;DR It's resolved in #19982

To give some more info to this issue, while debugging I noticed that at a certain point message are just lost, they don't appear where they should be going. So my terminal crying of debug statements, I found the point where messages prefer to be in the void than being printed.

gitea/modules/log/event.go

Line 103 in f0ce547

case l.queue <- event:

is the last codepath where all message will still be present, from there on, sometimes message just don't appear up again, therefor

gitea/modules/log/event.go

Line 330 in f0ce547

case event, ok := <-m.queue:

is the start of the codepath whereby not all messages would be present. I'm not really sure of why some messages are somewhere in the void, but I did found out that this particular log had a huge buffer and reducing that to a non-buffer, the issue completely disappeared.

If you would like to waste your time(Please note that not all SENDING will be RECEIVED due to log levels etc.):

diff --git a/modules/log/event.go b/modules/log/event.go
index f66ecd179..0afb4e6bc 100644
--- a/modules/log/event.go
+++ b/modules/log/event.go
@@ -328,6 +328,7 @@ func (m *MultiChannelledLog) Start() {
                                m.level = INFO
                        }
                case event, ok := <-m.queue:
+                       fmt.Printf("RECEIVING: %t, %#v\n", ok, *event)
                        if !ok {
                                m.closeLoggers()
                                return
@@ -359,6 +360,7 @@ func (m *MultiChannelledLog) Start() {
 
 // LogEvent logs an event to this MultiChannelledLog
 func (m *MultiChannelledLog) LogEvent(event *Event) error {
+       fmt.Printf("SENDING: %#v\n", *event)
        select {
        case m.queue <- event:
                return nil