Problem when sending messages with CFMAIL: SpoolLockTimeoutException

[Leeesher-5payEA]

Hi all,

We're running CFMX 7 7,0,2,142559 on Windows 2003 Server, and have been experiencing the dreaded 'SpoollockTimeoutException' error.

An exception occurred when setting up mail server parameters.

This exception was caused by: coldfusion.mail.MailSessionException: An exception occurred when setting up mail server parameters..

coldfusion.mail.MailSpooler$SpoolLockTimeoutException: A timeout occurred while waiting for the lock on the mail spool directory.

The only "fix" has been to restart the ColdFusion service. Sometimes this resolves the problem for months at a time, othertimes it pops back up in just a matter of hours.

I've tracked this issue using the sysinternals.com Process Monitor, and the output when the problem exists is as follows:

3:15:55.8811675 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en_US.properties  
PATH NOT FOUND   

3:15:55.8815296 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\gateway\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en_US.properties  
PATH NOT FOUND   

3:15:55.8818991 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\wwwroot\WEB-INF\cfform\jars\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en_US.properties  
PATH NOT FOUND   

3:15:55.8821369 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\java\classes\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en_US.properties  
PATH NOT FOUND   

3:15:55.8825311 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\servers\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en_US.properties  
PATH NOT FOUND   

3:15:55.8827757 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en_US.properties  
PATH NOT FOUND   

3:15:55.8831468 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en_US.properties  
PATH NOT FOUND   

3:15:55.8833873 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\servers\coldfusion\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en_US.properties  
PATH NOT FOUND   

3:15:55.8836527 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\wwwroot\WEB-INF\classes\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en_US.properties  
PATH NOT FOUND   

3:15:55.8841173 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\servers\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en_US.properties  
PATH NOT FOUND   

3:15:55.8843907 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en_US.properties  
PATH NOT FOUND   

3:15:55.8855256 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en.properties  
PATH NOT FOUND   

3:15:55.8858246 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\gateway\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en.properties  
PATH NOT FOUND   

3:15:55.8862405 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\wwwroot\WEB-INF\cfform\jars\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en.properties  
PATH NOT FOUND   

3:15:55.8864974 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\java\classes\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en.properties  
PATH NOT FOUND   

3:15:55.8869156 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\servers\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en.properties  
PATH NOT FOUND   

3:15:55.8873517 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en.properties  
PATH NOT FOUND   

3:15:55.8877510 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en.properties  
PATH NOT FOUND   

3:15:55.8880435 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\servers\coldfusion\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en.properties  
PATH NOT FOUND   

3:15:55.8883848 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\wwwroot\WEB-INF\classes\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en.properties  
PATH NOT FOUND   

3:15:55.8887977 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\servers\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en.properties  
PATH NOT FOUND   

3:15:55.8890417 PM    jrun.exe    996    QueryOpen  
X:\CFusionMX7\runtime\lib\coldfusion\mail\MailSpooler.SpoolLockTimeoutException_en.properties  
PATH NOT FOUND

Under normal circumstances it looks like this:

4:09:17.8085747 PM    jrun.exe    5916    QueryOpen  
X:\CFusionMX7\Mail\Spool    SUCCESS    CreationTime: 1/5/2010 1:15:00
PM, LastAccessTime: 1/14/2010 4:09:02 PM, LastWriteTime: 1/14/2010
4:09:02 PM, ChangeTime: 1/14/2010 4:09:02 PM, AllocationSize: 0,
EndOfFile: 0, FileAttributes: D

4:09:17.8089456 PM    jrun.exe    5916    CreateFile  
X:\CFusionMX7\Mail\Spool    SUCCESS    Desired Access: Read Data/List
Directory, Synchronize, Disposition: Open, Options: Directory,
Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write,
Delete, AllocationSize: n/a, OpenResult: Opened

4:09:17.8090310 PM    jrun.exe    5916    QueryDirectory    X:\CFusionMX7\Mail\Spool\*    SUCCESS    Filter: *, 1: .

4:09:17.8090999 PM    jrun.exe    5916    QueryDirectory    X:\CFusionMX7\Mail\Spool    SUCCESS    0: ..

4:09:17.8091327 PM    jrun.exe    5916    QueryDirectory    X:\CFusionMX7\Mail\Spool    NO MORE FILES   

4:09:17.8091535 PM    jrun.exe    5916    CloseFile    X:\CFusionMX7\Mail\Spool    SUCCESS   

4:09:23.1199809 PM    jrun.exe    5916    CreateFile  
X:\CFusionMX7\Mail\Spool\Mail18933.cfmail    SUCCESS    Desired Access:
Generic Read/Write, Disposition: Create, Options: Synchronous IO
Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write,
AllocationSize: 0, OpenResult: Created

4:09:23.1202524 PM    jrun.exe    5916    CloseFile    X:\CFusionMX7\Mail\Spool\Mail18933.cfmail    SUCCESS   

4:09:23.1207683 PM    jrun.exe    5916    CreateFile  
X:\CFusionMX7\Mail\Spool\Mail18933.cfmail    SUCCESS    Desired Access:
Generic Write, Read Attributes, Disposition: OverwriteIf, Options:
Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode:
Read, Write, AllocationSize: 0, OpenResult: Overwritten

4:09:23.1212033 PM    jrun.exe    5916    CreateFile  
X:\CFusionMX7\Mail\Spool\Mail18933.cfmail    SUCCESS    Desired Access:
None, Disposition: Open, Options: Synchronous IO Non-Alert, Attributes:
N, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult:
Opened

4:09:23.1212759 PM    jrun.exe    5916    FileSystemControl  
X:\CFusionMX7\Mail\Spool\Mail18933.cfmail    SUCCESS    Control:
FSCTL_CREATE_OR_GET_OBJECT_ID

4:09:23.1215152 PM    jrun.exe    5916    CloseFile    X:\CFusionMX7\Mail\Spool\Mail18933.cfmail    SUCCESS   

4:09:23.1225639 PM    jrun.exe    5916    WriteFile  
X:\CFusionMX7\Mail\Spool\Mail18933.cfmail    SUCCESS    Offset: 0,
Length: 718

4:09:23.1227925 PM    jrun.exe    5916    CloseFile    X:\CFusionMX7\Mail\Spool\Mail18933.cfmail    SUCCESS   

4:09:23.1232382 PM    jrun.exe    5916    CreateFile  
X:\CFusionMX7\Mail\Spool\Mail18933.cfmail    SUCCESS    Desired Access:
None, Disposition: Open, Options: Synchronous IO Non-Alert, Attributes:
N, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult:
Opened

4:09:23.1248326 PM    jrun.exe    5916    FileSystemControl  
X:\CFusionMX7\Mail\Spool\Mail18933.cfmail    SUCCESS    Control:
FSCTL_CREATE_OR_GET_OBJECT_ID

4:09:23.1250002 PM    jrun.exe    5916    CloseFile    X:\CFusionMX7\Mail\Spool\Mail18933.cfmail    SUCCESS   

The server in question has 600GB of free diskspace, so it's not a problem of low disk. This problem can occur whether we're sending 1 message or 5,000 messages. We've tried the hotfix, and it doesn't seem to change anything.

Any help is appreciated. I'm going nuts!

Leesha

[JR__Bob__Dobbs-qSBHQ2]

Have you tried installing Cumulative Hot Fix 3?

http://go.adobe.com/kb/ts_kb402465_en-us

[Leeesher-5payEA]

We have CH3 installed, as well as  hf702-71489 - http://kb2.adobe.com/cps/402/kb402001.html

When I installed  hf702-71489 I thought we had it licked, as the problem didn't occur for 3 or 4 months, but now it pops up every few days.

[Leeesher-5payEA]

*bump*

Anyone have any insight on this? We're seeing it again this afternoon.

Thanks!

[Balance]

Leesher,

Were you able to fix this? I've just begun seeing this error in my mail.log file and need to fix it ASAP.

Thanks

[jackhuang]

I am having the same problem with CF8.  Anyone can help out?  Thanks a lot.

[StevenErat]

You can override the default value of the ColdFusion spool lock timeout by

adding the argument -Dcoldfusion.spooltimeout=NNNN to your jvm.config file

on the java args line. NNN is a number in seconds. The default value is

60, but you can set it higher to what ever you want. Try 120 or even 300 if

need be. (Requires CF restart to take effect)

[JoshuaPereyda]

If my understanding is correct, that will only matter for large pieces of mail and/or large mail jobs.  I'm on CF 9 and am still having this problem, even with trivially sized messages.

The problem, from my research, can only be fixed by resetting the server (which is completely worthless from a customer service standpoint).

One way to get around it is to ALWAYS set spoolenable="false" (you can set the default in CF Admin).  This has at least worked for me, but it causes other problems you might expect from synchronous mailing.

So, practically speaking, the mail spool in CF is broken (whether or not you think so depends on how often it breaks for you and how willing your customers are to wait for it to get fixed every once in a while).  It really bugs me that this has been the case since CF 7 and there is no real fix available.

PS: I've heard people suggest using ServiceFactory to restart the MailSpoolService, but I don't know if that's worked for anybody.  Hasn't for me, but here's the code:

        <cfset sFactory = CreateObject("java","coldfusion.server.ServiceFactory")>
        <cfset MailSpoolService = sFactory.mailSpoolService>
        <cfset MailSpoolService.stop()>

[Balance]

You may want to tweak the various settings under the "Mail Spool Settings" section to see if that fixes the problem.

I think once I updated some of them the dreaded "SpoolLockTimeoutException" error went away. I say "think" because it has been a while since I last modified those settings but it has also been a while since I last saw the "SpoolLockTimeoutException" error in my mail.log file.

HTH

[Guest]

i wouldn't bother restarting the mailspoolservice as below. I tried it before and caused all sorts of instability which ended up with a restart required.

[XeeMe]

I agree with Joshua - I guess the mail spool part of CF is just not good. We have the same issue with CF9. I'm sure there are some conflicting aspects in the code that it may or may not work. I believe a good request to fix it for CF 11 : >>> http://coldfusion.uservoice.com

[jruusu]

Bump.. this problem still persists in CF10.

Not sure if a bug report has any impact on anything, but I filed one anyway; 3525473.

Br,

Jan

PS. I also saw "timeout value is negative" in mail.log, once. May or may not be relevant.