お世話になっております。
Unreal Engine 5.8において、アセットエディタのタブを閉じた際にエディタが数秒間停止する現象を確認しております。
本現象は、新規作成したテンプレートプロジェクトでも再現しており、UE5.7.4では同様の現象は確認できておりません。
現象発生時には、以下のファイルに対する保存処理で警告が繰り返し出力されます。
Saved/Config/WindowsEditor/EditorPerProjectUserSettings.ini
ログ上では、以下のような MoveFileの失敗が約0.5秒間隔で複数回発生し、その間エディタが停止している状態となります。
MoveFile was unable to move '...EditorPerProjectUserSettingsXXXXXXXX.tmp' to '.../EditorPerProjectUserSettings.ini' (Error Code 183), retrying in .5s...
原因調査のため、SaveConfigFileWrapper()に以下のように診断ログを追加しました。
static std::atomic<uint64> GConfigTestSaveSequence { 0 };
static std::atomic<int32> GConfigTestActiveSaveCount { 0 };
static bool SaveConfigFileWrapper(const TCHAR* IniFile, const FString& Contents)
{
TRACE_CPUPROFILER_EVENT_SCOPE(SaveConfigFileWrapper);
const uint64 SaveSequence = ++GConfigTestSaveSequence;
const int32 ActiveSaveCount = ++GConfigTestActiveSaveCount;
const uint32 ThreadId = FPlatformTLS::GetCurrentThreadId();
const bool bTargetFile = FCString::Stristr(IniFile, TEXT("EditorPerProjectUserSettings.ini")) != nullptr;
if (bTargetFile)
{
UE_LOG(LogConfig, Warning, TEXT("[ConfigTest] BEGIN Seq=%llu Thread=%u Active=%d File=%s"), SaveSequence, ThreadId, ActiveSaveCount, IniFile);
if (ActiveSaveCount > 1)
{
UE_LOG(LogConfig, Error, TEXT("[ConfigTest] OVERLAP DETECTED Seq=%llu Thread=%u Active=%d"), SaveSequence, ThreadId, ActiveSaveCount);
}
}
// let anyone that needs to save it, do so (counting how many did)
int32 SavedCount = 0;
FCoreDelegates::TSPreSaveConfigFileDelegate().Broadcast(IniFile, Contents, SavedCount);
if (bTargetFile)
{
UE_LOG(LogConfig, Warning, TEXT("[ConfigTest] AFTER_PRESAVE Seq=%llu Thread=%u Active=%d SavedCount=%d"), SaveSequence, ThreadId, GConfigTestActiveSaveCount.load(), SavedCount);
}
// save if the delegate didn't, or it did and we don't want to skip the normal save
bool bLocalWriteSucceeded = false;
if (SavedCount == 0 || GSkipSaveIfPreSaveSucceeded == false)
{
if (FConfigFile::WriteTempFileThenMove())
{
const FString BaseFilename = FPaths::GetBaseFilename(IniFile);
const FString TempFilename = FPaths::CreateTempFilename(*FPaths::ProjectSavedDir(), *BaseFilename.Left(32));
if (bTargetFile)
{
UE_LOG(LogConfig, Warning, TEXT("[ConfigTest] TEMP Seq=%llu Thread=%u Temp=%s Dest=%s"), SaveSequence, ThreadId, *TempFilename, IniFile);
}
bLocalWriteSucceeded = FFileHelper::SaveStringToFile(Contents, *TempFilename, FFileHelper::EEncodingOptions::ForceUTF8WithoutBOM);
if (bTargetFile)
{
UE_LOG(LogConfig, Warning, TEXT("[ConfigTest] TEMP_WRITE Seq=%llu Thread=%u Result=%d"), SaveSequence, ThreadId, bLocalWriteSucceeded ? 1 : 0);
}
if (bLocalWriteSucceeded)
{
if (bTargetFile)
{
UE_LOG(LogConfig, Warning, TEXT("[ConfigTest] MOVE_BEGIN Seq=%llu Thread=%u Active=%d DestExists=%d Temp=%s Dest=%s"), SaveSequence, ThreadId, GConfigTestActiveSaveCount.load(), IFileManager::Get().FileExists(IniFile) ? 1 : 0, *TempFilename, IniFile);
}
if (!IFileManager::Get().Move(IniFile, *TempFilename))
{
if (bTargetFile)
{
UE_LOG(LogConfig, Warning, TEXT("[ConfigTest] MOVE_END Seq=%llu Thread=%u Result=0 DestExists=%d TempExists=%d"), SaveSequence, ThreadId, IFileManager::Get().FileExists(IniFile) ? 1 : 0, IFileManager::Get().FileExists(*TempFilename) ? 1 : 0);
}
IFileManager::Get().Delete(*TempFilename);
bLocalWriteSucceeded = false;
}
else if (bTargetFile)
{
UE_LOG(LogConfig, Warning, TEXT("[ConfigTest] MOVE_END Seq=%llu Thread=%u Result=1 DestExists=%d TempExists=%d"), SaveSequence, ThreadId, IFileManager::Get().FileExists(IniFile) ? 1 : 0, IFileManager::Get().FileExists(*TempFilename) ? 1 : 0);
}
}
}
else
{
bLocalWriteSucceeded = FFileHelper::SaveStringToFile(Contents, IniFile, FFileHelper::EEncodingOptions::ForceUTF8WithoutBOM);
}
}
const int32 RemainingSaveCount = --GConfigTestActiveSaveCount;
if (bTargetFile)
{
UE_LOG(LogConfig, Warning, TEXT("[ConfigTest] END Seq=%llu Thread=%u Active=%d Result=%d"), SaveSequence, ThreadId, RemainingSaveCount, (SavedCount > 0 || bLocalWriteSucceeded) ? 1 : 0);
}
// success is based on a delegate or file write working (or both)
return SavedCount > 0 || bLocalWriteSucceeded;
}
結果、同一のEditorPerProjectUserSettings.iniに対して、異なるスレッドから同時に保存処理が実行されていることを確認しました。
例として、以下のように "Active=2"となるタイミングが存在します。
[ConfigTest] BEGIN Seq=32 Thread=47804 Active=1
[ConfigTest] MOVE_BEGIN Seq=32 Thread=47804 Active=1 DestExists=1
[ConfigTest] BEGIN Seq=33 Thread=42340 Active=2
[ConfigTest] OVERLAP DETECTED Seq=33 Thread=42340 Active=2
[ConfigTest] MOVE_BEGIN Seq=33 Thread=42340 Active=2 DestExists=0
[ConfigTest] MOVE_END Seq=32 Thread=47804 Result=1
その直後、もう一方のスレッドによるファイル移動処理で Windows エラーコード 183（ERROR_ALREADY_EXISTS）が発生しています。
UE5.7.4 と UE5.8 のソースを比較したところ、SaveConfigFileWrapper()における「一時ファイルへ書き込み後、IFileManager::Move()で置換する」基本的な処理は両バージョンに存在していました。
一方、UE5.8 ではコンフィグシステム周辺にスレッドセーフ関連の変更が追加されていますが、SaveConfigFileWrapper()の最終的な物理ファイル保存処理には、同一出力先ファイルに対する排他制御が見当たりませんでした。
切り分けのため、SaveConfigFileWrapper()全体を FCriticalSection で排他したところ、以下を確認しております。
- エディタの数秒間の停止が解消
- 同一 ini に対する同時保存が発生しなくなった
- MoveFileのエラーコード 183 が発生しなくなった
- 全てのファイル移動処理が正常終了
以上から、同一のコンフィグファイルに対する保存処理が複数スレッドから同時に実行されることで、IFileManager::Move()の置換処理が競合している可能性が高いと考えております。
恐れ入りますが、以下についてご確認いただけますでしょうか。
- UE5.8 において、同一 ini ファイルに対してSaveConfigFileWrapper()が複数スレッドから同時実行されることは想定された動作でしょうか。
- 同一出力先ファイルに対するコンフィグ保存処理について、ファイル単位での排他制御は不要な設計となっておりますでしょうか。
- 本現象は UE5.8 の既知不具合として認識されていますでしょうか。
関連する不具合や修正予定がございましたら、ご教示いただけますと幸いです。
お手数をおかけいたしますが、ご確認のほどよろしくお願いいたします。