Some Active Sessions show as Worlds in the browser

shadowpanther commented 8 months ago

Describe the bug?

While looking at the Active Sessions tab of the World Browser, some shown sessions don't show user count and the hosting user, but show world creator instead. When I click to get the world info, the popup shows it's a session and shows the host and the users in session.

To Reproduce

Look at the Active Worlds tab in World Browser. Notice after some time the lack of user count indicator and the Host line changes to By line.

Expected behavior

Active sessions show as sessions, not as worlds that have no sessions of them,

Screenshots

Resonite Version Number

2023.10.13.743

What Platforms does this occur on?

Windows

What headset if any do you use?

No response

Log Files

VIXEN - 2023.10.13.743 - 2023-10-14 17_35_20.log

Additional Context

~~My guess is the sessions shown this way might be the ones where more than one session of the same public world is open.~~ Checked again, and it seems even the unique session of one world is sometimes shown this way.

Reporters

Shadow Panther

shadowpanther commented 8 months ago

There's also an opposite effect sometimes, when the session shows in the list, but the session info is empty:

Gawdl3y commented 8 months ago

I've noticed this as well. Additionally, sometimes when clicking one of these, the session details (player count, players present, etc.) show up properly only for a second or two before switching to the world details as if there is no session.

kazu0617 commented 7 months ago

This bug causes people trying to get in on a daily basis to lose track of the sessions they're meant to be in, resulting in the development of a number of specialized tools. In effect, I have to say that now the world browser "not working, broken" (In fact, I almost always use a dedicated Join tool when my mentor calls for directions.).

This is an important issue.

Nytra commented 7 months ago

The bug where the session shows in the list but upon clicking shows no session info is extremely annoying, because at this point the only way you have to join such a session is via the contacts list, but only if you are contacts with anyone in that session.

Nytra commented 7 months ago

I have a feeling about what causes the second problem in this issue: "session shows in the list, but the session info is empty"

~I think it happens if you host a session of a world. Somehow I think that session info gets cached. Then later if you try to click on a active session of that same world in the browser it tries to use the previously cached session that you hosted which no longer exists, which results in no session being shown, and it falling back to showing just the world instead. It even persists after restarting Resonite which suggests that the no-longer-existing session is being cached in the local database or in the cloud. However this is just a hypothesis and it would need to be tested more.~

I now believe it happens for any world that you have visited (ie. any world that shows "(visited)" in the corner of the thumbnail). These are worlds that have been recorded in the local database as visited.

Nytra commented 7 months ago

I have found that if you untick MergeSessionsByWorldId in the WorldListManager component it fixes the problem of "session shows in the list, but the session info is empty"

akiRAM3 commented 7 months ago

This issue is still ongoing. Like Nytra, I have to use contact list to join my friend's session in my daily basis.

And, when it comes to JP Tutorial World, where multiple sessions tends to occur, it is very inconvinient to noticing/tracking sessions built by new people who are not in my contact list due to this bug.

e1ght3 commented 6 months ago

I would like to see this fixed as soon as possible, as it is a hindrance to new encounters when sessions do not display properly during normal operation.

skywindkitsune commented 6 months ago

This could be related to issue #739 sometimes when you login to resonite you do not register as online automatically causing the world browser to not display the session as an active session.

shadowpanther commented 6 months ago

@skywindkitsune the missing session in Active sessions happens even if the contact shows as online, and I can join that same session from the Contacts tab. It's only in the world browser that the problem happens.

Frooxius commented 6 months ago

I'll try to look into this soon.

Frooxius commented 4 months ago

I'm looking into this, but there's not a super good spot to start for this that I can see.

Are there any patterns to this behavior? E.g.:

Does this happen only with sessions that have been running for a while (order of hours)? Or does it also affect relatively fresh sessions (less than half an hour)?
Does it affect any session access level or just specific ones? (Public, Contacts, Contacts+...)
Does this seem to affect all users equally? E.g. if this occurs for particular session, will multiple people be affected at the same time? Or would some users see the session without an issue, while others have an issue?
If you restart the client, does the issue persist for the same session?

iamgreaser commented 4 months ago

The only pattern at the moment that I can see is that at least one of the two versions of the bug is pretty much guaranteed to happen. Right now I'm getting the variant where a world on the active sessions list looks like it has no sessions but if you click on it then there is a session active.

AND JUST LIKE THAT I managed to get the other variant to occur. Look at the JP Tutorial World in the session browser and leave it on that for a minute or so. That one tends to have issues. The exact text you're looking for is JP チュートリアルワールド Resonite .

Nytra commented 4 months ago

@Frooxius I don't have concrete data, but just from my experience with this I think it affects all sessions that have corresponding worlds, it seems to happen regardless of uptime or session access level, and I think it's a local problem so if person A sees the session disappear then person B might still be able to see it.

I can replicate it just by opening Active Sessions and watching it for under a minute, you will see sessions which are worlds begin to show only the world, and it can be fixed by refreshing the world browser (so clicking to some other tabs in the world browser and then back to Active Sessions). Restarting the client will 'fix' it in the same way as refreshing the browser I think, but then the sessions will start disappearing again.

Just for additional info:

I managed to 'fix' this in a mod by adding some code to the end of WorldItem.OnWorldIDSessionsChanged which calls the WorldItem.ForceUpdate method.

private void OnWorldIdSessionsChanged(IReadOnlyList<SessionInfo> sessions)
{
    RunSynchronously(delegate
    {
        UpdateData(sessions);
    });

        // Next part is the code I added
        RunSynchronously(delegate
    {
        ForceUpdate();
    });
}

I think part of the problem is that the sessions list that is getting provided into the UpdateData method is not containing the right sessions here for some reason, but calling ForceUpdate after it which gets a whole new sessions list is a way around it.

Frooxius commented 4 months ago

Thanks for the additional info and context! I'll see if I can figure something out. I tried watching the sessions for a bit too, but it didn't occur.

It almost sounds like some data is expiring in some way or something like that, but I'm not sure. If that was the case I don't think ForceUpdate would work, so it might be that the data is not including the correct list of things.

shiftyscales commented 4 months ago

From 2024.1.29.1304:

Add diagnostic for session info disappearing (for issue #164) -- If you notice sessons becoming worlds when they shouldn't, please take a note of the name of the world and send the logs

Frooxius commented 4 months ago

Thanks! I was about to post that! Yes, please keep a lookout for this happening and then nab the logs and the name of the world so I can match up that to the log.

This doesn't fix the issue, but will give me more data to work with.

Nytra commented 4 months ago

@Frooxius I think I have an idea of what is actually causing this. Forgive the screenshot of decompiled code:

Screenshot 2024-01-29 231242

This is in SkyFrost.Base.SessionsManager.RunSessionUpdated method.

You can see that the code calls item2(list3) where item2 is FrooxEngine.WorldItem.OnWorldIdSessionsChanged and list3 is the sessions list for that world ID.

Then after the for loop it immediately calls Pool.Return(ref list3); which clears the sessions list. This means that the sessions list is empty so when the synchronous action (which runs at the end of the update) in OnWorldIdSessionsChanged tries to read from it there will be no sessions in there.

ProbablePrime commented 4 months ago

I'm unable to locate your exact code in our source, this is probably decompiling mangling.

I found the area though and the Pool use there is temporary, and is used to setup event listeners, It is not the main session list...list. So I do not think it is related.

Nytra commented 4 months ago

Well I patched the DLL to remove that call to Pool.Return and the bug no longer happens, so I think it is related. This is however not the proper solution because it will result in memory leaks over time.

XDelta commented 4 months ago

Spotted this occur on 'Optimizone' which has several sessions of the world being hosted. Occurred while I was looking at the 'contacts sessions' page and had opened up to the large info screen on the sessions available of that world.

Relevant log lines below


12:49:29 AM.853 (125 FPS)   SessionInfo. Id: S-U-Raid-Server-Legends:OptimizoneMelody, Name: Optimizone: Melody, Host: Optimizone, CorrespondingWorldId: U-Raidriar796:R-f97cabfa-16c5-4d60-a371-25c0a50dbf42, URLs: lnl-nat://f4145623eceb433d90dd08e947cc0fc9/S-U-Raid-Server-Legends:OptimizoneMelody, IsExpired: False
12:49:29 AM.853 (125 FPS)   SessionInfo. Id: S-U-Raid-Server-Legends:OptimizoneNorland, Name: Optimizone: Norland, Host: Optimizone, CorrespondingWorldId: U-Raidriar796:R-f97cabfa-16c5-4d60-a371-25c0a50dbf42, URLs: lnl-nat://f4145623eceb433d90dd08e947cc0fc9/S-U-Raid-Server-Legends:OptimizoneNorland, IsExpired: False
12:49:29 AM.853 (125 FPS)   SessionInfo. Id: S-U-Raid-Server-Legends:OptimizoneRusset, Name: Optimizone: Russet, Host: Optimizone, CorrespondingWorldId: U-Raidriar796:R-f97cabfa-16c5-4d60-a371-25c0a50dbf42, URLs: lnl-nat://f4145623eceb433d90dd08e947cc0fc9/S-U-Raid-Server-Legends:OptimizoneRusset, IsExpired: False
12:49:29 AM.853 (125 FPS)   SessionInfo. Id: S-U-Raid-Server-Legends:OptimizoneYukon, Name: Optimizone: Yukon, Host: Optimizone, CorrespondingWorldId: U-Raidriar796:R-f97cabfa-16c5-4d60-a371-25c0a50dbf42, URLs: lnl-nat://f4145623eceb433d90dd08e947cc0fc9/S-U-Raid-Server-Legends:OptimizoneYukon, IsExpired: False
12:49:29 AM.853 (125 FPS)   SessionInfo. Id: S-U-Raid-Server-Legends:OptimizoneJewel, Name: Optimizone: Jewel, Host: Optimizone, CorrespondingWorldId: U-Raidriar796:R-f97cabfa-16c5-4d60-a371-25c0a50dbf42, URLs: lnl-nat://5ade3b968ba74298b186f508ca90c192/S-U-Raid-Server-Legends:OptimizoneJewel, IsExpired: False
12:49:31 AM.122 (126 FPS)   Session updated, forcing status update
12:49:31 AM.424 (126 FPS)   Session updated, forcing status update
12:49:31 AM.824 (140 FPS)   Session updated, forcing status update
12:49:32 AM.024 (146 FPS)   Session updated, forcing status update
12:49:37 AM.533 (143 FPS)   Session updated, forcing status update
12:49:37 AM.834 (143 FPS)   Session updated, forcing status update
12:49:38 AM.336 (141 FPS)   Session updated, forcing status update
12:49:39 AM.238 (144 FPS)   Session updated, forcing status update
12:49:40 AM.740 (144 FPS)   Session updated, forcing status update
12:49:41 AM.240 (144 FPS)   Session updated, forcing status update
12:49:42 AM.341 (144 FPS)   Session updated, forcing status update
12:49:42 AM.934 (144 FPS)   Session count became zero for U-Raidriar796:R-f97cabfa-16c5-4d60-a371-25c0a50dbf42 Optimizone

  at System.Environment.get_StackTrace () [0x00000] in <9577ac7a62ef43179789031239ba8798>:0 
  at Elements.Core.UniLog.Log (System.String message, System.Boolean stackTrace) [0x00000] in <80229d1197cf49d988a8b637774ba61f>:0 
  at FrooxEngine.WorldItem.UpdateData (System.Collections.Generic.IReadOnlyList`1[T] sessions, System.Boolean notifyManager) [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.WorldItem+<>c__DisplayClass19_0.<OnWorldIdSessionsChanged>b__0 () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.World.RunSynchronousActions () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.World.NextRefreshStage () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.World.Refresh () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.WorldManager.UpdateStep () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.WorldManager.RunUpdateLoop () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.Engine.UpdateStep () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.Engine.RunUpdateLoop () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at UnityFrooxEngineRunner.FrooxEngineRunner.UpdateFrooxEngine () [0x00000] in <5e585788751a4bbabeeadefebaee83eb>:0 
  at UnityFrooxEngineRunner.FrooxEngineRunner.Update () [0x00000] in <5e585788751a4bbabeeadefebaee83eb>:0 
12:49:42 AM.934 (144 FPS)   Session count became zero for U-Raidriar796:R-f97cabfa-16c5-4d60-a371-25c0a50dbf42 Optimizone

  at System.Environment.get_StackTrace () [0x00000] in <9577ac7a62ef43179789031239ba8798>:0 
  at Elements.Core.UniLog.Log (System.String message, System.Boolean stackTrace) [0x00000] in <80229d1197cf49d988a8b637774ba61f>:0 
  at FrooxEngine.WorldItem.UpdateData (System.Collections.Generic.IReadOnlyList`1[T] sessions, System.Boolean notifyManager) [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.WorldItem+<>c__DisplayClass19_0.<OnWorldIdSessionsChanged>b__0 () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.World.RunSynchronousActions () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.World.NextRefreshStage () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.World.Refresh () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.WorldManager.UpdateStep () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.WorldManager.RunUpdateLoop () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.Engine.UpdateStep () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.Engine.RunUpdateLoop () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at UnityFrooxEngineRunner.FrooxEngineRunner.UpdateFrooxEngine () [0x00000] in <5e585788751a4bbabeeadefebaee83eb>:0 
  at UnityFrooxEngineRunner.FrooxEngineRunner.Update () [0x00000] in <5e585788751a4bbabeeadefebaee83eb>:0 ```

Additional thing I noticed is it seems to occur more on worlds with multiple sessions open of it, although it definitely still occurs on worlds with a single instance open. Seems like whatever happens on any of the sessions will then hide all of them.

XDelta commented 4 months ago

Another separate occurance (on a world with one one open session)


  1:03:17 AM.834 (140 FPS)  SessionInfo. Id: S-44b4a8e7-ffbd-4269-b124-4b204baf17ed, Name: NeoRoid HUB WIP, Host: K-Pere, CorrespondingWorldId: U-KPere:R-e6481372-7844-4b90-b0fc-0bea4b87f095, URLs: res-steam://76561198079034428/2/S-44b4a8e7-ffbd-4269-b124-4b204baf17ed, lnl-nat://5ade3b968ba74298b186f508ca90c192/S-44b4a8e7-ffbd-4269-b124-4b204baf17ed, IsExpired: False
  1:03:17 AM.945 (140 FPS)  Session updated, forcing status update
  1:04:59 AM.091 (130 FPS)  Session updated, forcing status update
  1:05:06 AM.024 (136 FPS)  Session count became zero for U-KPere:R-e6481372-7844-4b90-b0fc-0bea4b87f095 NeoRoid HUB WIP

  at System.Environment.get_StackTrace () [0x00000] in <9577ac7a62ef43179789031239ba8798>:0 
  at Elements.Core.UniLog.Log (System.String message, System.Boolean stackTrace) [0x00000] in <80229d1197cf49d988a8b637774ba61f>:0 
  at FrooxEngine.WorldItem.UpdateData (System.Collections.Generic.IReadOnlyList`1[T] sessions, System.Boolean notifyManager) [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.WorldItem+<>c__DisplayClass19_0.<OnWorldIdSessionsChanged>b__0 () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.World.RunSynchronousActions () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.World.NextRefreshStage () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.World.Refresh () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.WorldManager.UpdateStep () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.WorldManager.RunUpdateLoop () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.Engine.UpdateStep () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at FrooxEngine.Engine.RunUpdateLoop () [0x00000] in <41c49157bb9444ac92cd54b5749246e7>:0 
  at UnityFrooxEngineRunner.FrooxEngineRunner.UpdateFrooxEngine () [0x00000] in <5e585788751a4bbabeeadefebaee83eb>:0 
  at UnityFrooxEngineRunner.FrooxEngineRunner.Update () [0x00000] in <5e585788751a4bbabeeadefebaee83eb>:0 ```

Frooxius commented 4 months ago

Thanks for all the info! Yes, I think I know why this is happening now, the lists are not being used right away, they are being returned to the pool (which clears them right after call finishes).

We'll just eat the cost of a little extra GC pressure (it shouldn't be much overall) and just allocate them fresh, which should fix this.

Frooxius commented 4 months ago

Okay I think this should be fixed now in 2024.1.30.731!

Thanks for all the help everyone! If this still occurs, we'll reopen, but I'm going to close it for now.

Yellow-Dog-Man / Resonite-Issues