The Case of the Locked File

February 27, 2017

Recently, we were seeing increasing numbers of warning messages appearing from Unreal Engine when compiling shaders… not really a very serious error – but one that concerned us all the same… the warnings all looked something like this:-

Error deleting file: [FILENAME] (Error Code 0)

That message was originating from FFileManagerGeneric::Delete() in FileManagerGeneric.cpp:-

if( EvenReadOnly )
{
  GetLowLevel().SetReadOnly( Filename, false );
}
if( !GetLowLevel().DeleteFile( Filename ) )
{
  if (!Quiet)
  {
    UE_LOG( LogFileManager, Warning, TEXT( "Error deleting file: %s (Error Code %i)" ), Filename, FPlatformMisc::GetLastError() );
  }
  return false;
}

Here’s the funny thing … if we set a breakpoint in Delete() and stepped through the function, no matter how many times we did it, we could never get the problem to happen. So we did a little more investigation to get to the bottom of the problem.

The files being deleted were always temporary files … you know, the ones with temporary GUID-style names. The engine would’ve just written the files, done a little processing with them – and then wanted to delete them so that they wouldn’t fill your HDD space. On checking the code, everything looked fine – file handles were opened and closed correctly (with no errors), the engine definitely wasn’t keeping hold of anything .. so why then couldn’t we delete them?

The clue came from that the problem never happened if we stepped over the Delete() function in the debugger. Instead of that, I tried something else: adding a 0.5 second stall at the top of Delete(). Sure enough, with that in place, the problem went away: however, I’d now slowed the editor down – compiling 5000 shaders would now take 2500 seconds (~42 minutes) longer than it did before. So this wasn’t really an acceptable fix…

Thinking about this some more… it was apparent that there was an external process that was, for some reason, grabbing hold of our temporary files – but only for a short period of time. What kind of nasty piece of bytes would do that? Then it struck me: a virus killer. Of course, it made perfect sense – we were writing thousands of files to the HDD… Virus killers are of course hooked up to the file system so that they’re notified immediately when something new appears on your HDD. A quick test, disabling the real-time virus scanning feature and removing the 0.5 second pause we’d added, showed that this was in fact the case. Again, though, we couldn’t just ask all our clients to disable their virus killers to fix this warning…! So we came to the third and final solution…

We created a new function, DeleteFileWithRetries(), that would keep retrying the file delete until it succeeded, up to a maximum period of 2 seconds, with a pause of 0.01 seconds in between:-

const uint32 MaxRetries = 200; // 200 retries should take no more than ~2 seconds
bool FFileManagerGeneric::DeleteFileWithRetries(const TCHAR* Filename, const uint32 MaxRetries)
{
   bool bDeletedOutput = GetLowLevel().DeleteFile(Filename);
   for (uint32 RetryIdx = 0; RetryIdx < MaxRetries && !bDeletedOutput; RetryIdx++)
   {
      FPlatformProcess::Sleep(0.01f);
      bDeletedOutput = GetLowLevel().DeleteFile(Filename);
   }
   if (!bDeletedOutput)
   {
      UE_LOG(LogFileManager, Error, TEXT("Error deleting file '%s'."), Filename);
   }
   return bDeletedOutput;
}

We then changed Delete() to use this instead of DeleteFile():-

if( !DeleteFileWithRetries(Filename, MaxRetries) )
{
  if (!Quiet)
  {
    UE_LOG( LogFileManager, Warning, TEXT( "Error deleting file: %s (Error Code %i)" ), Filename, FPlatformMisc::GetLastError() );
  }
  return false;
}

And, finally, we also changed the Move() function to use this as well – since that function could’ve suffered from the same problem in its call to DeleteFile()… here’s the version seen in 4.15:-

bool FFileManagerGeneric::Move( const TCHAR* Dest, const TCHAR* Src, bool Replace, bool EvenIfReadOnly, bool Attributes, bool bDoNotRetryOrError )
{
   MakeDirectory( *FPaths::GetPath(Dest), true );
   // Retry on failure, unless the file wasn't there anyway.
   if( GetLowLevel().FileExists( Dest ) && !GetLowLevel().DeleteFile( Dest ) && !bDoNotRetryOrError )
   {
      // If the delete failed, throw a warning but retry before we throw an error
      UE_LOG( LogFileManager, Warning, TEXT( "DeleteFile was unable to delete '%s', retrying in .5s..." ), Dest );

      // Wait just a little bit( i.e. a totally arbitrary amount )...
      FPlatformProcess::Sleep( 0.5f );

      // Try again
      if( !GetLowLevel().DeleteFile( Dest ) )
      {
         UE_LOG( LogFileManager, Error, TEXT( "Error deleting file '%s'." ), Dest );
         return false;
      }
      else
      {
         UE_LOG( LogFileManager, Warning, TEXT( "DeleteFile recovered during retry!" ) );
      }
   }

   if( !GetLowLevel().MoveFile( Dest, Src ) )

They actually already have a retry in the above – but they only retry once, waiting half a second before doing that … it’s ok, it might work, but our solution is better

bool FFileManagerGeneric::Move( const TCHAR* Dest, const TCHAR* Src, bool Replace, bool EvenIfReadOnly, bool Attributes, bool bDoNotRetryOrError )
{
   MakeDirectory( *FPaths::GetPath(Dest), true );
   if( GetLowLevel().FileExists( Dest ) )
   {
      if (!DeleteFileWithRetries(Dest, bDoNotRetryOrError?0:MaxRetries))
      {
         return false;
      }
   }

   if( !GetLowLevel().MoveFile( Dest, Src ) )

Much shorter, more likely to fix the problem – and should certainly be much faster (as we shouldn’t usually need to wait anything like 0.5 seconds for the file delete to work).

And there you have it … a neat little fix for an “issue” that we can’t really call a bug. A misunderstanding, perhaps, to assume that other processes wouldn’t be interested in files that we’re creating on a user’s HDD… except that this is, of course, exactly what a virus killer is interested in.

Credit(s): Robert Troughton (Coconut Lizard)
Status: Currently unfixed in 4.15