TudbuT/forgejo
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions 1

fail test when log.Error is called

Browse source 
except for some specific messages (to make the test pass for now)
This commit is contained in:
oliverpool 2024-03-14 14:45:41 +01:00
parent af0bb6e68a
commit e43c6cd9df
5 changed files with 206 additions and 35 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

10
.deadcode-out
View file

@ -271,13 +271,19 @@ package "code.gitea.io/gitea/modules/sync"
package "code.gitea.io/gitea/modules/testlogger"
func (*testLoggerWriterCloser).pushT
func (*testLoggerWriterCloser).Write
func (*testLoggerWriterCloser).Log
func (*testLoggerWriterCloser).recordError
func (*testLoggerWriterCloser).printMsg
func (*testLoggerWriterCloser).popT
func (*testLoggerWriterCloser).Close
func (*testLoggerWriterCloser).Reset
func PrintCurrentTest
func Printf
func NewTestLoggerWriter
func (*TestLogEventWriter).Base
func (*TestLogEventWriter).GetLevel
func (*TestLogEventWriter).GetWriterName
func (*TestLogEventWriter).GetWriterType
func (*TestLogEventWriter).Run
package "code.gitea.io/gitea/modules/timeutil"
func GetExecutableModTime

4
models/migrations/base/tests.go
View file

@ -160,6 +160,10 @@ func MainTest(m *testing.M) {
exitStatus := m.Run()
if err := testlogger.WriterCloser.Reset(); err != nil && exitStatus == 0 {
fmt.Printf("testlogger.WriterCloser.Reset: %v\n", err)
os.Exit(1)
}
if err := removeAllWithRetry(setting.RepoRootPath); err != nil {
fmt.Fprintf(os.Stderr, "os.RemoveAll: %v\n", err)
}

216
modules/testlogger/testlogger.go
View file

@ -4,8 +4,11 @@
package testlogger
import (
"bytes"
"context"
"errors"
"fmt"
"io"
"os"
"runtime"
"strings"
@ -28,52 +31,145 @@ var WriterCloser = &testLoggerWriterCloser{}
type testLoggerWriterCloser struct {
sync.RWMutex
t []testing.TB
errs []error // stack of error, parallel to the stack of testing.TB
err error // fallback if the stack is empty
}
func (w *testLoggerWriterCloser) pushT(t testing.TB) {
w.Lock()
w.t = append(w.t, t)
w.errs = append(w.errs, nil)
w.Unlock()
}
func (w *testLoggerWriterCloser) Write(p []byte) (int, error) {
func (w *testLoggerWriterCloser) Log(level log.Level, msg string) {
if len(msg) > 0 && msg[len(msg)-1] == '\n' {
msg = msg[:len(msg)-1]
}
w.printMsg(msg)
if level >= log.ERROR {
w.recordError(msg)
}
}
// list of error message which will not fail the test
// ideally this list should be empty, however ensuring that it does not grow
// is already a good first step.
var ignoredErrorMessageSuffixes = []string{
// only seen on mysql tests https://codeberg.org/forgejo/forgejo/pulls/2657#issuecomment-1693055
`table columns using inconsistent collation, they should use "utf8mb4_0900_ai_ci". Please go to admin panel Self Check page`,
// TestAPIDeleteReleaseByTagName
// action notification were a commit cannot be computed (because the commit got deleted)
`Notify() [E] an error occurred while executing the DeleteRelease actions method: gitRepo.GetCommit: object does not exist [id: refs/tags/release-tag, rel_path: ]`,
`Notify() [E] an error occurred while executing the PushCommits actions method: gitRepo.GetCommit: object does not exist [id: refs/tags/release-tag, rel_path: ]`,
// TestAPIRepoTags
`Notify() [E] an error occurred while executing the DeleteRelease actions method: gitRepo.GetCommit: object does not exist [id: refs/tags/gitea/22, rel_path: ]`,
`Notify() [E] an error occurred while executing the PushCommits actions method: gitRepo.GetCommit: object does not exist [id: refs/tags/gitea/22, rel_path: ]`,
// TestAPIDeleteTagByName
`Notify() [E] an error occurred while executing the DeleteRelease actions method: gitRepo.GetCommit: object does not exist [id: refs/tags/delete-tag, rel_path: ]`,
`Notify() [E] an error occurred while executing the PushCommits actions method: gitRepo.GetCommit: object does not exist [id: refs/tags/delete-tag, rel_path: ]`,
// TestAPIGenerateRepo
`Notify() [E] an error occurred while executing the CreateRepository actions method: gitRepo.GetCommit: object does not exist [id: , rel_path: ]`,
// TestAPIPullReview
`PullRequestReview() [E] Unsupported review webhook type`,
// TestAPIPullReviewRequest
`ToAPIPullRequest() [E] unable to resolve PR head ref`,
// TestAPILFSUpload
`Put() [E] Whilst putting LFS OID[ca978112ca1bbdcafac231b39a23dc4da786eff8147c4e72b9807785afee48bb]: Failed to copy to tmpPath: ca/97/8112ca1bbdcafac231b39a23dc4da786eff8147c4e72b9807785afee48bb Error: content size does not match`,
`[E] Error putting LFS MetaObject [ca978112ca1bbdcafac231b39a23dc4da786eff8147c4e72b9807785afee48bb] into content store. Error: content size does not match`,
`UploadHandler() [E] Upload does not match LFS MetaObject [ca978112ca1bbdcafac231b39a23dc4da786eff8147c4e72b9807785afee48bb]. Error: content size does not match`,
`Put() [E] Whilst putting LFS OID[2581dd7bbc1fe44726de4b7dd806a087a978b9c5aec0a60481259e34be09b06a]: Failed to copy to tmpPath: 25/81/dd7bbc1fe44726de4b7dd806a087a978b9c5aec0a60481259e34be09b06a Error: content hash does not match OID`,
`[E] Error putting LFS MetaObject [2581dd7bbc1fe44726de4b7dd806a087a978b9c5aec0a60481259e34be09b06a] into content store. Error: content hash does not match OID`,
`UploadHandler() [E] Upload does not match LFS MetaObject [2581dd7bbc1fe44726de4b7dd806a087a978b9c5aec0a60481259e34be09b06a]. Error: content hash does not match OID`,
`UploadHandler() [E] Upload does not match LFS MetaObject [83de2e488b89a0aa1c97496b888120a28b0c1e15463a4adb8405578c540f36d4]. Error: content size does not match`,
// TestAPILFSVerify
`getAuthenticatedMeta() [E] Unable to get LFS OID[fb8f7d8435968c4f82a726a92395be4d16f2f63116caf36c8ad35c60831ab042] Error: LFS Meta object does not exist`,
// TestAPIUpdateOrgAvatar
`UpdateAvatar() [E] UploadAvatar: image.DecodeConfig: image: unknown format`,
// TestGetAttachment
`/data/attachments/a/0/a0eebc99-9c0b-4ef8-bb6d-6bb9bd380a18: no such file or directory`,
// TestBlockUser
`BlockedUsersUnblock() [E] IsOrganization: org3 is an organization not a user`,
`BlockedUsersBlock() [E] IsOrganization: org3 is an organization not a user`,
`Action() [E] Cannot perform this action on an organization "unblock"`,
`Action() [E] Cannot perform this action on an organization "block"`,
// TestBlockActions
`/gitea-repositories/user10/repo7.git Error: no such file or directory`,
// TestE2e/explore.test.e2e
`TrString() [E] Missing translation "more_items"`,
// TestRebuildCargo
`RebuildCargoIndex() [E] RebuildIndex failed: GetRepositoryByOwnerAndName: repository does not exist [id: 0, uid: 0, owner_name: user2, name: _cargo-index]`,
}
func (w *testLoggerWriterCloser) recordError(msg string) {
for _, s := range ignoredErrorMessageSuffixes {
if strings.HasSuffix(msg, s) {
return
}
}
w.Lock()
defer w.Unlock()
err := w.err
if len(w.errs) > 0 {
err = w.errs[len(w.errs)-1]
}
err = errors.Join(err, errors.New(msg))
if len(w.errs) > 0 {
w.errs[len(w.errs)-1] = err
} else {
w.err = err
}
}
func (w *testLoggerWriterCloser) printMsg(msg string) {
// There was a data race problem: the logger system could still try to output logs after the runner is finished.
// So we must ensure that the "t" in stack is still valid.
w.RLock()
defer w.RUnlock()
var t testing.TB
if len(w.t) > 0 {
t = w.t[len(w.t)-1]
}
if len(p) > 0 && p[len(p)-1] == '\n' {
p = p[:len(p)-1]
}
if t == nil {
t := w.t[len(w.t)-1]
t.Log(msg)
} else {
// if there is no running test, the log message should be outputted to console, to avoid losing important information.
// the "???" prefix is used to match the "===" and "+++" in PrintCurrentTest
return fmt.Fprintf(os.Stdout, "??? [TestLogger] %s\n", p)
fmt.Fprintln(os.Stdout, "??? [TestLogger]", msg)
}
}
t.Log(string(p))
return len(p), nil
}
func (w *testLoggerWriterCloser) popT() {
func (w *testLoggerWriterCloser) popT() error {
w.Lock()
defer w.Unlock()
if len(w.t) > 0 {
w.t = w.t[:len(w.t)-1]
err := w.errs[len(w.errs)-1]
w.errs = w.errs[:len(w.errs)-1]
return err
}
w.Unlock()
return w.err
}
func (w *testLoggerWriterCloser) Close() error {
return nil
}
func (w *testLoggerWriterCloser) Reset() {
func (w *testLoggerWriterCloser) Reset() error {
w.Lock()
if len(w.t) > 0 {
for _, t := range w.t {
@ -84,8 +180,12 @@ func (w *testLoggerWriterCloser) Reset() {
t.Errorf("Unclosed logger writer in test: %s", t.Name())
}
w.t = nil
w.errs = nil
}
err := w.err
w.err = nil
w.Unlock()
return err
}
// PrintCurrentTest prints the current test to os.Stdout
@ -132,7 +232,10 @@ func PrintCurrentTest(t testing.TB, skip ...int) func() {
_, _ = fmt.Fprintf(os.Stdout, "+++ %s had a slow clean-up flush (took %v)\n", t.Name(), flushTook)
}
}
WriterCloser.popT()
if err := WriterCloser.popT(); err != nil {
t.Errorf("testlogger.go:recordError() FATAL ERROR: log.Error has been called: %v", err)
}
}
}
@ -146,19 +249,72 @@ func Printf(format string, args ...any) {
_, _ = fmt.Fprintf(os.Stdout, "\t"+format, args...)
}
// TestLogEventWriter is a logger which will write to the testing log
type TestLogEventWriter struct {
*log.EventWriterBaseImpl
}
// NewTestLoggerWriter creates a TestLogEventWriter as a log.LoggerProvider
func NewTestLoggerWriter(name string, mode log.WriterMode) log.EventWriter {
w := &TestLogEventWriter{}
w.EventWriterBaseImpl = log.NewEventWriterBase(name, "test-log-writer", mode)
w.OutputWriteCloser = WriterCloser
w.base = log.NewEventWriterBase(name, "test-log-writer", mode)
w.writer = WriterCloser
return w
}
// TestLogEventWriter is a logger which will write to the testing log
type TestLogEventWriter struct {
base *log.EventWriterBaseImpl
writer *testLoggerWriterCloser
}
// Base implements log.EventWriter.
func (t *TestLogEventWriter) Base() *log.EventWriterBaseImpl {
return t.base
}
// GetLevel implements log.EventWriter.
func (t *TestLogEventWriter) GetLevel() log.Level {
return t.base.GetLevel()
}
// GetWriterName implements log.EventWriter.
func (t *TestLogEventWriter) GetWriterName() string {
return t.base.GetWriterName()
}
// GetWriterType implements log.EventWriter.
func (t *TestLogEventWriter) GetWriterType() string {
return t.base.GetWriterType()
}
// Run implements log.EventWriter.
func (t *TestLogEventWriter) Run(ctx context.Context) {
for {
select {
case <-ctx.Done():
return
case event, ok := <-t.base.Queue:
if !ok {
return
}
var errorMsg string
switch msg := event.Msg.(type) {
case string:
errorMsg = msg
case []byte:
errorMsg = string(msg)
case io.WriterTo:
var buf bytes.Buffer
if _, err := msg.WriteTo(&buf); err != nil {
panic(err)
}
errorMsg = buf.String()
default:
errorMsg = fmt.Sprint(msg)
}
t.writer.Log(event.Origin.Level, errorMsg)
}
}
}
func init() {
const relFilePath = "modules/testlogger/testlogger.go"
_, filename, _, _ := runtime.Caller(0)

6
tests/e2e/e2e_test.go
View file

@ -59,8 +59,10 @@ func TestMain(m *testing.M) {
exitVal := m.Run()
testlogger.WriterCloser.Reset()
if err := testlogger.WriterCloser.Reset(); err != nil {
fmt.Printf("testlogger.WriterCloser.Reset: %v\n", err)
os.Exit(1)
}
if err = util.RemoveAll(setting.Indexer.IssuePath); err != nil {
fmt.Printf("util.RemoveAll: %v\n", err)
os.Exit(1)

5
tests/integration/integration_test.go
View file

@ -145,7 +145,10 @@ func TestMain(m *testing.M) {
// Instead, "No tests were found", last nonsense log is "According to the configuration, subsequent logs will not be printed to the console"
exitCode := m.Run()
testlogger.WriterCloser.Reset()
if err := testlogger.WriterCloser.Reset(); err != nil {
fmt.Printf("testlogger.WriterCloser.Reset: %v\n", err)
os.Exit(1)
}
if err = util.RemoveAll(setting.Indexer.IssuePath); err != nil {
fmt.Printf("util.RemoveAll: %v\n", err)