h1or4dme8/osu-lazer
1
0
Fork 0
mirror of https://github.com/ppy/osu.git synced 2025-01-21 08:52:54 +08:00
Code Issues Releases Wiki Activity

Add logging around current channel changes and join requests

Browse Source 
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
```
This commit is contained in:
Dean Herbert 2022-06-28 13:58:35 +09:00
parent 364d0f0517
commit c1075d113f
2 changed files with 26 additions and 6 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
osu.Game.Tests/Visual/Online/TestSceneChatOverlay.cs
View File

@ -472,8 +472,8 @@ namespace osu.Game.Tests.Visual.Online
}); });
AddStep("Select channel 1", () => clickDrawable(getChannelListItem(testChannel1))); AddStep("Select channel 1", () => clickDrawable(getChannelListItem(testChannel1)));
waitForChannel1Visible(); waitForChannel1Visible();
AddStep("Press document next keys", () => InputManager.Keys(PlatformAction.DocumentNext)); AddStep("Press document next keys", () => InputManager.Keys(PlatformAction.DocumentNext));
waitForChannel2Visible(); waitForChannel2Visible();

30
osu.Game/Online/Chat/ChannelManager.cs
View File

@ -133,12 +133,14 @@ namespace osu.Game.Online.Chat
?? JoinChannel(new Channel(user)); ?? JoinChannel(new Channel(user));
} }
private void currentChannelChanged(ValueChangedEvent<Channel> e) private void currentChannelChanged(ValueChangedEvent<Channel> channel)
{ {
bool isSelectorChannel = e.NewValue is ChannelListing.ChannelListingChannel; bool isSelectorChannel = channel.NewValue is ChannelListing.ChannelListingChannel;
if (!isSelectorChannel) if (!isSelectorChannel)
JoinChannel(e.NewValue); JoinChannel(channel.NewValue);
Logger.Log($"Current channel changed to {channel.NewValue}");
} }
/// <summary> /// <summary>
@ -447,9 +449,17 @@ namespace osu.Game.Online.Chat
return channel; return channel;
case ChannelType.PM: case ChannelType.PM:
Logger.Log($"Attempting to join PM channel {channel}");
var createRequest = new CreateChannelRequest(channel); var createRequest = new CreateChannelRequest(channel);
createRequest.Failure += e =>
{
Logger.Log($"Failed to join PM channel {channel} ({e.Message})");
};
createRequest.Success += resChannel => createRequest.Success += resChannel =>
{ {
Logger.Log($"Joined PM channel {channel} ({resChannel.ChannelID})");
if (resChannel.ChannelID.HasValue) if (resChannel.ChannelID.HasValue)
{ {
channel.Id = resChannel.ChannelID.Value; channel.Id = resChannel.ChannelID.Value;
@ -463,9 +473,19 @@ namespace osu.Game.Online.Chat
break; break;
default: default:
Logger.Log($"Attempting to join public channel {channel}");
var req = new JoinChannelRequest(channel); var req = new JoinChannelRequest(channel);
req.Success += () => joinChannel(channel, fetchInitialMessages); req.Success += () =>
req.Failure += _ => LeaveChannel(channel); {
Logger.Log($"Joined public channel {channel}");
joinChannel(channel, fetchInitialMessages);
};
req.Failure += e =>
{
Logger.Log($"Failed to join public channel {channel} ({e.Message})");
LeaveChannel(channel);
};
api.Queue(req); api.Queue(req);
return channel; return channel;
} }