1
0
mirror of https://github.com/ppy/osu.git synced 2024-11-18 16:32:55 +08:00
osu-lazer/osu.Game/Online/Chat
Dean Herbert c1075d113f Add logging around current channel changes and join requests
Tracking down a flaky test
(https://teamcity.ppy.sh/buildConfiguration/Osu_Build/553?hideProblemsFromDependencies=false&expandBuildTestsSection=true&hideTestsFromDependencies=false):

```csharp
TearDown : System.TimeoutException : "PM Channel 1 displayed" timed out
--TearDown
   at osu.Framework.Testing.Drawables.Steps.UntilStepButton.<>c__DisplayClass11_0.<.ctor>b__0()
   at osu.Framework.Testing.Drawables.Steps.StepButton.PerformStep(Boolean userTriggered)
   at osu.Framework.Testing.TestScene.runNextStep(Action onCompletion, Action`1 onError, Func`2 stopCondition)
--- End of stack trace from previous location ---
   at osu.Framework.Testing.TestSceneTestRunner.TestRunner.RunTestBlocking(TestScene test)
   at osu.Game.Tests.Visual.OsuTestScene.OsuTestSceneTestRunner.RunTestBlocking(TestScene test) in /opt/buildagent/work/ecd860037212ac52/osu.Game/Tests/Visual/OsuTestScene.cs:line 503
   at osu.Framework.Testing.TestScene.RunTestsFromNUnit()
------- Stdout: -------
[runtime] 2022-06-27 23:18:55 [verbose]: 💨 Class: TestSceneChatOverlay
[runtime] 2022-06-27 23:18:55 [verbose]: 🔶 Test:  TestKeyboardNextChannel
[runtime] 2022-06-27 23:18:55 [verbose]: Chat is now polling every 60000 ms
[runtime] 2022-06-27 23:18:55 [verbose]: 🔸 Step #1 Setup request handler
[runtime] 2022-06-27 23:18:55 [verbose]: 🔸 Step #2 Add test channels
[runtime] 2022-06-27 23:18:55 [verbose]: 🔸 Step #3 Show overlay with channels
[runtime] 2022-06-27 23:18:55 [verbose]: Unhandled Request Type: osu.Game.Online.API.Requests.CreateChannelRequest
[network] 2022-06-27 23:18:55 [verbose]: Failing request osu.Game.Online.API.Requests.CreateChannelRequest (System.InvalidOperationException: DummyAPIAccess cannot process this request.)
[runtime] 2022-06-27 23:18:55 [verbose]: Unhandled Request Type: osu.Game.Online.API.Requests.CreateChannelRequest
[network] 2022-06-27 23:18:55 [verbose]: Failing request osu.Game.Online.API.Requests.CreateChannelRequest (System.InvalidOperationException: DummyAPIAccess cannot process this request.)
[runtime] 2022-06-27 23:18:55 [verbose]: 🔸 Step #4 Select channel 1
[runtime] 2022-06-27 23:18:55 [verbose]: 🔸 Step #5 Channel 1 is visible
[runtime] 2022-06-27 23:18:55 [verbose]: 🔸 Step #6 Press document next keys
[runtime] 2022-06-27 23:18:55 [verbose]: 🔸 Step #7 Channel 2 is visible
[runtime] 2022-06-27 23:18:55 [verbose]: 🔸 Step #8 Press document next keys
[runtime] 2022-06-27 23:18:55 [verbose]: 🔸 Step #9 PM Channel 1 displayed
[network] 2022-06-27 23:18:55 [verbose]: Request to https://a.ppy.sh/587 failed with System.Net.WebException: NotFound.
[network] 2022-06-27 23:18:55 [verbose]: Request to https://a.ppy.sh/503 failed with System.Net.WebException: NotFound.
[runtime] 2022-06-27 23:19:05 [verbose]: 💥 Failed (on attempt 5,550)
[runtime] 2022-06-27 23:19:05 [verbose]:  Currently loading components (0)
[runtime] 2022-06-27 23:19:05 [verbose]: 🧵 Task schedulers
[runtime] 2022-06-27 23:19:05 [verbose]: LoadComponentsAsync (standard) concurrency:4 running:0 pending:0
[runtime] 2022-06-27 23:19:05 [verbose]: LoadComponentsAsync (long load) concurrency:4 running:0 pending:0
[runtime] 2022-06-27 23:19:05 [verbose]: 🎱 Thread pool
[runtime] 2022-06-27 23:19:05 [verbose]: worker:          min 1      max 32,767 available 32,766
[runtime] 2022-06-27 23:19:05 [verbose]: completion:      min 1      max 1,000  available 1,000
[runtime] 2022-06-27 23:19:05 [debug]: Focus on "ChatTextBox" no longer valid as a result of unfocusIfNoLongerValid.
[runtime] 2022-06-27 23:19:05 [debug]: Focus changed from ChatTextBox to nothing.
```

This kind of logging should be helpful:

```csharp
[runtime] 2022-06-28 04:59:57 [verbose]: 🔸 Step #5 Channel 1 is visible
[runtime] 2022-06-28 04:59:57 [verbose]: 🔸 Step #6 Press document next keys
[runtime] 2022-06-28 04:59:57 [verbose]: Current channel changed to #channel-2
[runtime] 2022-06-28 04:59:57 [debug]: Pressed (DocumentNext) handled by TestSceneChatOverlay+TestChatOverlay.
[runtime] 2022-06-28 04:59:57 [debug]: KeyDownEvent(PageDown, False) handled by ManualInputManager+LocalPlatformActionContainer.
[runtime] 2022-06-28 04:59:57 [verbose]: 🔸 Step #7 Channel 2 is visible
[runtime] 2022-06-28 04:59:57 [verbose]: 🔸 Step #8 Press document next keys
[runtime] 2022-06-28 04:59:57 [verbose]: Current channel changed to test user 685
[runtime] 2022-06-28 04:59:57 [debug]: Pressed (DocumentNext) handled by TestSceneChatOverlay+TestChatOverlay.
[runtime] 2022-06-28 04:59:57 [debug]: KeyDownEvent(PageDown, False) handled by ManualInputManager+LocalPlatformActionContainer.
[runtime] 2022-06-28 04:59:57 [verbose]: 🔸 Step #9 PM Channel 1 displayed
[runtime] 2022-06-28 04:59:57 [verbose]: 🔸 Step #10 Press document next keys
[runtime] 2022-06-28 04:59:57 [verbose]: Current channel changed to test user 218
```
2022-06-28 14:00:30 +09:00
..
Channel.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
ChannelManager.cs Add logging around current channel changes and join requests 2022-06-28 14:00:30 +09:00
ChannelType.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
DrawableLinkCompiler.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
ErrorMessage.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
ExternalLinkOpener.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
IChannelPostTarget.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
InfoMessage.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
LocalEchoMessage.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
LocalMessage.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
Message.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
MessageFormatter.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
MessageNotifier.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
NowPlayingCommand.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00
StandAloneChatDisplay.cs Automated #nullable processing 2022-06-17 16:37:17 +09:00