[1553] OnDeserialization not guaranteed to fire for late joiners
tracked
narazaka
I created a texture synchronization system, but faced a situation where OnDeserialization was not running randomly.
This was a random event where the result could change each time the same person rejoins, but it could tend to happen if the number of people who have joined or currently exist in the instance is large, or if there is a lot of data to be synchronized. However, this can also happen in instances where there are only two people, or instances with a small number of data (although a larger number than usual, since two or three 512x512x2bytes of data are synchronized).
The following code was used for testing. (It is a bit complicated because it is the code of an actual application.)
In the normal flow, when OnDeserialized is called,
ApplyReceiveData()
is called, and the [SyncTexture] ... ApplyReceiveColorsPartial() [ReceiveEnabled=True]
is logged.This is indicated by the following data restore and apply logs that follow after join and before OnPlayerJoined in normal.txt.
[2]
2024.12.11 01:46:07 Log - [Behaviour] All 8 bunches for SyncTextureData0 collected, now restoring.
2024.12.11 01:46:07 Log - [SyncTexture] ApplyReceiveColorsPartial() [ReceiveEnabled=True]
2024.12.11 01:46:07 Log - [SyncTextureShaderDXT] SyncTextureShaderDXTCamera.OnReceiveApplied
2024.12.11 01:46:07 Log - [Behaviour] All 8 bunches for SyncTextureData1 collected, now restoring.
2024.12.11 01:46:07 Log - [SyncTexture] ApplyReceiveColorsPartial() [ReceiveEnabled=True]
However, in the abnormal case, OnDeserialized is not called after data restoration. To solve this, the callback
TryApplyReceiveDataFromStart()
, which is called 3 seconds after Start(), calls the same process if data is found and writes logs like [SyncTexture] ... Trying to get data and found non null data!
The not-fired.txt is the log when this situation occurred, and the following data restore log is flowing before OnPlayerJoined, but
[SyncTexture] ... ApplyReceiveColorsPartial() [ReceiveEnabled=True]
that should flow when OnDeserialized is called is not flowing.[4]
2024.12.11 03:09:07 Log - [Behaviour] All 8 bunches for SyncTextureData2 collected, now restoring.
2024.12.11 03:09:07 Log - [Behaviour] All 8 bunches for SyncTextureData3 collected, now restoring.
2024.12.11 03:09:07 Log - [Behaviour] All 8 bunches for SyncTextureData4 collected, now restoring.
After OnPlayerJoined, there is a log that flows during the countermeasure callback, and the data application log is also flowing.
[5]
2024.12.11 03:09:10 Log - [SyncTextureData] (SyncTextureData36) Trying to get data but not received.
2024.12.11 03:09:10 Warning - [SyncTextureData] (SyncTextureData52) Trying to get data and found non null data!
2024.12.11 03:09:10 Log - [SyncTexture] (-1210292) ApplyReceiveColorsPartial() [ReceiveEnabled=True]
2024.12.11 03:09:10 Log - [SyncTextureShaderDXT] SyncTextureShaderDXTCamera.OnReceiveApplied
2024.12.11 03:09:10 Warning - [SyncTextureData] (SyncTextureData25) Trying to get data and found non null data!
2024.12.11 03:09:10 Log - [SyncTexture] (-892658) ApplyReceiveColorsPartial() [ReceiveEnabled=True]
From this it can be said that there are cases where OnDeserialized is not called even when data is restored.
This problem has happened in the past and VRChat is aware that it has been resolved, but it still seems to be happening.
--------------------
私はテクスチャ同期システムを作りましたが、OnDeserializationがランダムに実行されない状況に直面しました。
これは同じ人でもrejoinの度に結果が変わりうるランダムな事象でしたが、インスタンスにこれまでjoinした人数、または現在存在する人数が多いか、あるいは同期されるデータが多いと起こりやすくなる傾向がある可能性があります。しかしたった2人だけしかいないインスタンスや、データ数のすくない(とはいっても512x512x2byteのデータが2、3個同期されているので通常よりは大量ですが)インスタンスでも起こりえます。
テストに使ったのは以下のコードです。(実際のアプリケーションのコードなので少し煩雑ですが)
[1]
通常のフローではOnDeserializedが呼ばれると
ApplyReceiveData()
が呼ばれ、この先でデータを描画する時に出る[SyncTexture] ... ApplyReceiveColorsPartial() [ReceiveEnabled=True]
というログが流れます。これはnormal.txtでjoin後OnPlayerJoinedより前に以下のようにデータリストアと適用のログが続いていることに示されています。
[2]
しかし異常ケースだとOnDeserializedがデータリストア後に呼ばれません。この対策のためStart()のあと3秒後に呼ばれるコールバック
TryApplyReceiveDataFromStart()
が、もしデータが見付かった場合同様の処理を呼び、[SyncTexture] ... Trying to get data and found non null data!
といったログを書くようにしました。[3]
not-fired.txtはこの状況になった時のログで、OnPlayerJoinedの前に以下のデータリストアのログが流れていますがOnDeserializedが呼ばれると流れるはずの
[SyncTexture] ... ApplyReceiveColorsPartial() [ReceiveEnabled=True]
が流れていません。[4]
OnPlayerJoinedの後になってから対策コールバック時に流れるログが出て、データの適用ログも流れています。
[5]
このことから、データがリストアされてもOnDeserializedが呼ばれないケースが存在することが言えます。
この問題は過去にもあって、VRChatは解決済みと認識していますが、相変わらず起きているようです。
[6]]
Log In
StormRel
tracked
narazaka
StormRel It happens randomly and all manual sync objects does not sync on late join.