Stuck on Updating File(s) Source Control Status.
chriszuko opened this issue · 3 comments
Unfortunately we don't have a solid repro for this yet, but it is worth mentioning this plugin can get stuck for extremely long periods of time ( 1+ hours) during a save operation when it says "Updating File(s) Source Control Status"
According to the logs its running commands on 18000+ assets... which is our entire content directory. Other than this.. there's really nothing else in the logs that shows any important info. It reports it finishes though after 0.24seconds and just keeps going doing more similar RunCommands.
It feels like what diffing used to feel like before the recent fix to make it faster.. but sometimes now on normal save operations. :/ Overall it would be nice to see a speed improvement and a possible timeout check to ensure that you don't lose work on a save operation. For now we might have to just turn this plugin off... again.. which makes me sad because I love everything else about it.
If you need any other info we can provide.. just will take time to remove NDA'd stuff from log files.
Thanks.
Here is a snippet of our logs that we found to be interesting. it looks like its running the special case operation on the entire content directory... and it takes a looong time to finish. But this seemed to happen on a rename / move operation. Its worth noting this was with gluon and with auto-refresh on... so maybe its something to do. Any insight on this is highly appreciated.
I took out our actual paths and asset names and replaced them with generic names for the sake of sharing publicly.
'''
[2020.04.22-16.59.48:455][532]LogSourceControl: RunStatus(Asset.uasset...): 2) general case for 2 file(s) in a directory (D:Project/Content/SubFolderToAsset/) [2020.04.22-16.59.48:455][532]LogSourceControl: Project/Content/SubFolderToAsset/Asset.uasset = 4:Added [2020.04.22-16.59.48:455][532]LogSourceControl: Project/Content/SubFolderToAsset/Asset_FV.uasset = 4:Added [2020.04.22-16.59.48:455][532]LogSourceControl: Error: Command 'Copy' Failed! [2020.04.22-16.59.48:892][532]LogSourceControl: GetState: ForceUpdate [2020.04.22-16.59.48:892][532]LogSourceControl: ExecuteSynchronousCommand: UpdateStatus [2020.04.22-16.59.48:911][532]LogSourceControl: status (of 0 files, ShouldCheckAllFiles=0, ShouldUpdateHistory=0, ShouldGetOpenedOnly=0, ShouldUpdateModifiedState=0) [2020.04.22-16.59.48:911][532]LogSourceControl: RunUpdateStatus: 2 file(s)/2 directory(ies) ('D:Project/Content/'...) [2020.04.22-16.59.48:911][532]LogSourceControl: RunCommand(201): 'status --compact --wkconfig --noheaders --controlledchanged --changed --localdeleted --localmoved --private --ignored "D:Project/Content/"' (148 chars, 1 files) [2020.04.22-16.59.49:456][532]LogSourceControl: RunCommand(201): 'status --compact --wkconfig --noheaders --controlledchanged --changed --localdeleted --localmoved --private --ignored "D:Project/Content/"' (in 0.543685s) output (3825 chars): [2020.04.22-16.59.49:555][532]LogSourceControl: RunStatus(D:Project/Content/): 1) special case for status of a directory containing 18626 file(s) (D:Project/Content/) [2020.04.22-16.59.52:354][532]LogSourceControl: [...] 18606 more files
'''
We identified a good reproduction case for this issue. It turns out that while right-clicking on a track in a sequence unreal is calling UUnrealEdEngine::AttemptModifiedPackageNotification() every tick, which ends up sending an UpdateStatus request for no files/no packages. At this point if you save that sequence the status query will remain visible until all of those requests are completed. This can take an extremely long time depending on your project size due these requests recursing through the entire content directory for each one.
A number of performance issues have been fixed in recent releases (esp. 1.4.12 and 1.4.13)
I am quite confident it is now fixed with 1.4.13