Skip to content

queue: Flaky test TestLevelQueue #15776

Closed
@silverwind

Description

@silverwind

Can reproduce this locally somewhat rarely. CI failure example:

$ while true; do go test -count=1 -run TestLevelQueue ./modules/queue; done
ok    code.gitea.io/gitea/modules/queue 0.457s
ok    code.gitea.io/gitea/modules/queue 0.452s
ok    code.gitea.io/gitea/modules/queue 0.445s
2021/05/07 19:46:40 ...les/queue/manager.go:134:Add() [T] Queue Manager registered: queue-1 (QID: 1)
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:96:Run() [D] level:  Starting
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:104:Run() [T] level:  Waiting til closed
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:147:readToChan() [T] level : Task found: &queue.testData{TestString:"A", TestInt:1}
2021/05/07 19:46:40 .../queue/workerpool.go:251:commonRegisterWorkers() [T] WorkerPool: 1 (for queue-1) adding 1 workers with group id: 1
2021/05/07 19:46:40 .../queue/workerpool.go:93:zeroBoost() [W] WorkerPool: 1 (for queue-1) has zero workers - adding 5 temporary workers for 5m0s
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:147:readToChan() [T] level : Task found: &queue.testData{TestString:"B", TestInt:2}
2021/05/07 19:46:40 .../queue/workerpool.go:420:doWork() [T] Handling: 1 data, [0xc00065edf8]
2021/05/07 19:46:40 .../queue/workerpool.go:420:doWork() [T] Handling: 1 data, [0xc00000ed98]
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:156:Shutdown() [T] level:  Shutting down
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:164:Shutdown() [D] level:  Shutdown
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:106:Run() [T] level:  Waiting til done
2021/05/07 19:46:40 .../queue/workerpool.go:396:doWork() [T] Worker shutting down
2021/05/07 19:46:40 .../queue/workerpool.go:396:doWork() [T] Worker shutting down
2021/05/07 19:46:40 .../queue/workerpool.go:396:doWork() [T] Worker shutting down
2021/05/07 19:46:40 .../queue/workerpool.go:396:doWork() [T] Worker shutting down
2021/05/07 19:46:40 .../queue/workerpool.go:396:doWork() [T] Worker shutting down
2021/05/07 19:46:40 .../queue/workerpool.go:396:doWork() [T] Worker shutting down
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:109:Run() [T] level:  Waiting til cleaned
2021/05/07 19:46:40 .../queue/workerpool.go:309:CleanUp() [T] WorkerPool: 1 CleanUp
2021/05/07 19:46:40 .../queue/workerpool.go:321:CleanUp() [T] WorkerPool: 1 CleanUp Done
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:174:Terminate() [T] level:  Terminating
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:156:Shutdown() [T] level:  Shutting down
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:164:Shutdown() [D] level:  Shutdown
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:186:Terminate() [D] level:  Closing with 2 tasks left in queue
2021/05/07 19:46:40 ...ue/queue_bytefifo.go:191:Terminate() [D] level:  Terminated
2021/05/07 19:46:41 ...les/queue/manager.go:134:Add() [T] Queue Manager registered: queue-2 (QID: 2)
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:96:Run() [D] level:  Starting
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:104:Run() [T] level:  Waiting til closed
2021/05/07 19:46:41 .../queue/workerpool.go:251:commonRegisterWorkers() [T] WorkerPool: 2 (for queue-2) adding 1 workers with group id: 1
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:147:readToChan() [T] level : Task found: &queue.testData{TestString:"A", TestInt:1}
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:147:readToChan() [T] level : Task found: &queue.testData{TestString:"B", TestInt:2}
2021/05/07 19:46:41 .../queue/workerpool.go:412:doWork() [T] Handling: 2 data, [0xc000d085d0 0xc000d08708]
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:156:Shutdown() [T] level:  Shutting down
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:164:Shutdown() [D] level:  Shutdown
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:156:Shutdown() [T] level:  Shutting down
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:164:Shutdown() [D] level:  Shutdown
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:174:Terminate() [T] level:  Terminating
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:156:Shutdown() [T] level:  Shutting down
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:106:Run() [T] level:  Waiting til done
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:164:Shutdown() [D] level:  Shutdown
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:174:Terminate() [T] level:  Terminating
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:156:Shutdown() [T] level:  Shutting down
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:164:Shutdown() [D] level:  Shutdown
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:186:Terminate() [D] level:  Closing with 0 tasks left in queue
2021/05/07 19:46:41 ...ue/queue_bytefifo.go:191:Terminate() [D] level:  Terminated
--- FAIL: TestLevelQueue (0.70s)
    queue_disk_test.go:21:
          Error Trace:  queue_disk_test.go:21
                              workerpool.go:421
                              workerpool.go:276
                              asm_amd64.s:1371
          Error:        Should be true
          Test:         TestLevelQueue
    queue_disk_test.go:21:
          Error Trace:  queue_disk_test.go:21
                              workerpool.go:421
                              workerpool.go:276
                              asm_amd64.s:1371
          Error:        Should be true
          Test:         TestLevelQueue
    queue_disk_test.go:73:
          Error Trace:  queue_disk_test.go:73
          Error:        Not equal:
                        expected: "A"
                        actual  : "B"

                        Diff:
                        --- Expected
                        +++ Actual
                        @@ -1 +1 @@
                        -A
                        +B
          Test:         TestLevelQueue
    queue_disk_test.go:74:
          Error Trace:  queue_disk_test.go:74
          Error:        Not equal:
                        expected: 1
                        actual  : 2
          Test:         TestLevelQueue
    queue_disk_test.go:77:
          Error Trace:  queue_disk_test.go:77
          Error:        Not equal:
                        expected: "B"
                        actual  : "A"

                        Diff:
                        --- Expected
                        +++ Actual
                        @@ -1 +1 @@
                        -B
                        +A
          Test:         TestLevelQueue
    queue_disk_test.go:78:
          Error Trace:  queue_disk_test.go:78
          Error:        Not equal:
                        expected: 2
                        actual  : 1
          Test:         TestLevelQueue
FAIL
FAIL  code.gitea.io/gitea/modules/queue 0.781s
FAIL
ok    code.gitea.io/gitea/modules/queue 0.444s
ok    code.gitea.io/gitea/modules/queue 0.485s
ok    code.gitea.io/gitea/modules/queue 0.450s
ok    code.gitea.io/gitea/modules/queue 0.449s
ok    code.gitea.io/gitea/modules/queue 0.448s
ok    code.gitea.io/gitea/modules/queue 0.445s
ok    code.gitea.io/gitea/modules/queue 0.445s
ok    code.gitea.io/gitea/modules/queue 0.442s
ok    code.gitea.io/gitea/modules/queue 0.449s

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions