Device Hangs: Anti-Virus Software and ActiveSync Deadlock

I've been working on an interesting problem reported by a Windows Mobile partner. They have a anti-virus software installed on the WM6 device. And whenever they copy an infected file from desktop to the device, that anti-virus software will detect that infected file and delete it. After the user sees 'cannot copy file blah blah' in ActiveSync on the desktop side, the device hangs.

So the question is: what causes the device to hang?

Apparently the AV software has something to do with it. It is constantly monitoring any file system changes on the device, trying to scan every new file copied from the desktop side. 

Okay, I've got a full kdmp file, with a corresponding flat release directory with all the symbols (including the AV software symbol files). Attach it to PB, run CEDebugX, I see this (Note I slightly modified the stuff to hide some sensitive information):

 Thread A:

 Thread: 0x89395640 (rapiclnt) hThread=0x6939595a

===========================================================================

NK!SC_TakeCritSec() line 5233

NK!EnterCriticalSection() line 104

NK!SC_LoadLibraryExW() line 4699

COREDLL!int_LoadLibraryExW() line 598 + 60 bytes

COREDLL!stub_LoadLibraryExW() line 352

COREDLL!xxx_LoadLibraryW() line 649

FAVFFILT!DLL_F_CEL_LogMsg(const wchar_t * 0x03ec4134, unsigned long 0x00000002) + 40 bytes

FAVFFILT!FILTER_MoveFileW() + 260 bytes

CACHEFILT!FilterHook_t::MoveFileW() line 379 + 16 bytes

CACHEFILT!CachedVolume_t::MoveHelper() line 903

CACHEFILT!FCFILT_MoveFileW() line 281 + 8 bytes

FSREPLXFILT!FILTER_MoveFileW() line 410 + 28 bytes

FSDMGR!FSDMGR_MoveFileW() line 634 + 32 bytes

COREDLL!xxx_AFS_MoveFileW() line 118

FILESYS!FS_MoveFileW() line 2449 + 16 bytes

COREDLL!xxx_MoveFileW() line 62

RAPICLNT!xxxMoveFile() line 117

 

Thread B:

 

Thread: 0x89397000 (av.exe) hThread=  0xea63f872

===========================================================================

NK!SC_TakeCritSec() line 5233

NK!UB_TakeCritSec() line 5274

COREDLL!xxx_TakeCritSec() line 1857

COREDLL!EnterCriticalSection() line 104

CACHEFILT!CachedVolume_t::CreateFileW(unsigned long 0x00000001, _SECURITY_ATTRIBUTES * 0x00000000, unsigned long 0x00000003, unsigned long 0x00000000, void * 0x00000000) line 665

CACHEFILT!FCFILT_CreateFileW(unsigned long 0x00000001, _SECURITY_ATTRIBUTES * 0x00000000, unsigned long 0x00000003, unsigned long 0x00000000, void * 0x00000000) line 267

FSREPLXFILT!FILTER_CreateFileW(unsigned long 0x00000001, _SECURITY_ATTRIBUTES * 0x00000000, unsigned long 0x00000003, unsigned long 0x00000000, void * 0x00000000) line 76 + 64 bytes

FSDMGR!FSDMGR_CreateFileW(unsigned long 0x00000000, _SECURITY_ATTRIBUTES * 0x00000003, unsigned long 0x00000000, unsigned long 0x00000000, void * 0x0b392002) line 1013 + 76 bytes

COREDLL!xxx_AFS_CreateFileW(unsigned long 0x00000001, _SECURITY_ATTRIBUTES * 0x00000000, unsigned long 0x00000003, unsigned long 0x00000000, void * 0x00000000) line 95

FILESYS!FS_CreateFileW(unsigned long 0x00000000, unsigned long 0x80000000, void * 0x00000000) line 2226 + 48 bytes

NK!SC_CreateFileW(unsigned long 0x00000003, unsigned long 0x00000000, void * 0x00000000) line 2589 + 56 bytes

NK!OpenFileFromFilesys() line 571 + 48 bytes

NK!TryDir(int 0x0000000e, int 0x00000000) line 690 + 28 bytes

NK!TrySameDir() line 728

NK!OpenExecutable() line 806 + 12 bytes

NK!OpenADll() line 3441 + 20 bytes

NK!PerformCallBack4Int() line 2386 + 68 bytes

NK!InitModule(unsigned short 0x0000) line 4105 + 44 bytes

NK!LoadOneLibraryW() line 4442 + 24 bytes

NK!SC_LoadLibraryExW() line 4699 + 20 bytes

COREDLL!int_LoadLibraryExW() line 598 + 60 bytes

COREDLL!stub_LoadLibraryExW() line 352

COREDLL!xxx_LoadLibraryW() line 649

SHUTIL!CePerfOpenSession() line 489 + 24 bytes

[Diagnose] Invoking deadlock diagnose tool

Creating thread list ...

Creating the proxy list...

920 thread proxies.

DEADLOCK DETECTED!

===========================================================================

|

|  Deadlock between rapiclnt av.exe

|

===========================================================================

 --> Critical Section (lpcs = 0x042902cc)

      owned by ...

  rapiclnt thread 0x89395640

      blocked on ...

  Critical Section (lpcs = 0x842f0ba0) LLcs

      owned by ...

  av.exe thread 0x89397000

       blocked on ...

 --> Critical Section (lpcs = 0x042902cc)

rapiclnt.exe is the RAPI client that handles file operations of ActiveSync. av.exe is the AV software. As you can see from the CedebugX output, the two threads deadlocked because Thread B is holding the LLcs, the OS loader lock while trying to get into a critical section. Thread A is doing MoveFile and somehow it is trying to get the loader lock after getting into that critical section that Thread B is waiting to get in. So deadlock occurred. I looked into the code path of Thread A, and figured out the critical section it holds is the file system volume access critical section. When Thread B calls CACHEFILT!CachedVolume_t::CreateFileW(), it tries to enter that file system volume critical section,  which is taken by Thread A.

Then the question is, why Thread A, which is supposedly performing a MoveFile operation, tries to get the OS loader lock? Take a look at Thread A's stack, you will see a file system filter FAVFFILT.dll that performs a LoadLibrary call. Yes, that is why the loader lock is needed. I was told that the file system filter is a third-party software installed on the device. Without knowing the source of the filter, I cannot dig deeper into this issue any more.

Anyway, things have been clear now. The file system filter driver should be fixed: do not call LoadLibrary() because that will require a OS loader lock while the underlying thread is probably holding a file system volume lock. This may lead to a deadlock with other threads calling LoadLibrary().