2

The Problem

The issue is that uploading a file that takes more than 30 minutes will fail in an unusual way. I've been using Google Chrome for my testing and almost exactly at the 30 minute mark (the amount uploaded does not matter, it always happens at ~1800 seconds) the upload progress will reset to "0%" and begin again.

There are no messages from the browser that anything went wrong, it just restarts the upload. (Even watching "Network" in developer tools only shows a single post request). Looking in the Event Viewer on the server doesn't turn up anything that looks unusual either. Something I did notice was that normally temporary upload files for ColdFusion go into "ColdFusion9\runtime\servers\coldfusion\SERVER-INF\temp\wwwroot-tmp" and are removed when the upload completes or is aborted. When this issue occurs, those temporary files are not removed.

The fact this happens on two systems in completely different locations and always at 1800 seconds makes me think there has got to be some default timeout setting somewhere but I just can't find the bugger.

Can anyone offer suggestions on where to look or (I know this is crazy) what is actually the cause?

Some Information

The test system configuration(s):

Windows Server 2008 Standard & Windows Web Server 2008 R2
IIS 7 & 7.5
ColdFusion 9 Standard

My form looks like:

<form name="frmUpload" method="post" enctype="multipart/form-data" action="upload.cfm?Action=Upload">
    <input type="hidden" name="Submit" value="1" />
    <input type="file" name="File" />
    <input type="submit" name="SubmitButton" value="Submit" />
</form>

My web.config looks like:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <system.webServer>
        <httpErrors existingResponse="PassThrough" />
        <urlCompression doDynamicCompression="true" />
        <defaultDocument>
            <files>
                <clear />
                <add value="login.cfm" />
                <add value="index.cfm" />
                <add value="index.htm" />
                <add value="index.html" />
            </files>
        </defaultDocument>
        <security>
            <requestFiltering>
                <requestLimits maxAllowedContentLength="2147482624" />
            </requestFiltering>
        </security>
    </system.webServer>
    <system.web>
        <httpRuntime executionTimeout="21600" maxRequestLength="2097151"/>
    </system.web>
</configuration>

When the upload restarts, the IIS logs show (note last two values "bytes-received" and "time-taken"):

2012-06-07 17:35:02 192.168.200.184 POST upload.cfm Action=Upload 443 - 192.168.1.230 Mozilla/5.0+(Windows+NT+6.1;+WOW64)+AppleWebKit/536.5+(KHTML,+like+Gecko)+Chrome/19.0.1084.52+Safari/536.5 500 0 0 1473 214483824 1800801

There are also entries in the "coldfusion-out.log" file that happen around the same time:

06/07 14:35:21 error unexpected end of part
java.io.IOException: unexpected end of part
at com.oreilly.servlet.multipart.PartInputStream.fill(PartInputStream.java:96)
at com.oreilly.servlet.multipart.PartInputStream.read(PartInputStream.java:191)
at com.oreilly.servlet.multipart.PartInputStream.read(PartInputStream.java:152)
at com.oreilly.servlet.multipart.FilePart.write(FilePart.java:257)
at com.oreilly.servlet.multipart.FilePart.writeTo(FilePart.java:215)
at coldfusion.filter.FormScope.fillForm(FormScope.java:253)
at coldfusion.filter.FusionContext.SymTab_initForRequest(FusionContext.java:377)
at coldfusion.filter.GlobalsFilter.invoke(GlobalsFilter.java:33)
at coldfusion.filter.DatasourceFilter.invoke(DatasourceFilter.java:22)
at coldfusion.filter.CachingFilter.invoke(CachingFilter.java:62)
at coldfusion.filter.RequestThrottleFilter.invoke(RequestThrottleFilter.java:126)
at coldfusion.CfmServlet.service(CfmServlet.java:200)
at coldfusion.bootstrap.BootstrapServlet.service(BootstrapServlet.java:89)
at jrun.servlet.FilterChain.doFilter(FilterChain.java:86)
at coldfusion.monitor.event.MonitoringServletFilter.doFilter(MonitoringServletFilter.java:42)
at coldfusion.bootstrap.BootstrapFilter.doFilter(BootstrapFilter.java:46)
at jrun.servlet.FilterChain.doFilter(FilterChain.java:94)
at jrun.servlet.FilterChain.service(FilterChain.java:101)
at jrun.servlet.ServletInvoker.invoke(ServletInvoker.java:106)
at jrun.servlet.JRunInvokerChain.invokeNext(JRunInvokerChain.java:42)
at jrun.servlet.JRunRequestDispatcher.invoke(JRunRequestDispatcher.java:286)
at jrun.servlet.ServletEngineService.dispatch(ServletEngineService.java:543)
at jrun.servlet.jrpp.JRunProxyService.invokeRunnable(JRunProxyService.java:203)
at jrunx.scheduler.ThreadPool$DownstreamMetrics.invokeRunnable(ThreadPool.java:320)
at jrunx.scheduler.ThreadPool$ThreadThrottle.invokeRunnable(ThreadPool.java:428)
at jrunx.scheduler.ThreadPool$UpstreamMetrics.invokeRunnable(ThreadPool.java:266)
at jrunx.scheduler.WorkerThread.run(WorkerThread.java:66)

06/07 14:35:21 error (JRun Service: ProxyService  [jrun.servlet.jrpp.JRunProxyService@2cf889c8]) JRunPRoxyServer.invokeRunnable: 
java.lang.IllegalStateException
at jrun.servlet.JRunResponse.getWriter(JRunResponse.java:205)
at jrun.servlet.JRunResponse.sendError(JRunResponse.java:597)
at jrun.servlet.JRunRequestDispatcher.invoke(JRunRequestDispatcher.java:328)
at jrun.servlet.ServletEngineService.dispatch(ServletEngineService.java:543)
at jrun.servlet.jrpp.JRunProxyService.invokeRunnable(JRunProxyService.java:203)
at jrunx.scheduler.ThreadPool$DownstreamMetrics.invokeRunnable(ThreadPool.java:320)
at jrunx.scheduler.ThreadPool$ThreadThrottle.invokeRunnable(ThreadPool.java:428)
at jrunx.scheduler.ThreadPool$UpstreamMetrics.invokeRunnable(ThreadPool.java:266)
at jrunx.scheduler.WorkerThread.run(WorkerThread.java:66)

java.lang.IllegalStateException
at jrun.servlet.JRunResponse.getWriter(JRunResponse.java:205)
at jrun.servlet.JRunResponse.sendError(JRunResponse.java:597)
at jrun.servlet.JRunRequestDispatcher.invoke(JRunRequestDispatcher.java:328)
at jrun.servlet.ServletEngineService.dispatch(ServletEngineService.java:543)
at jrun.servlet.jrpp.JRunProxyService.invokeRunnable(JRunProxyService.java:203)
at jrunx.scheduler.ThreadPool$DownstreamMetrics.invokeRunnable(ThreadPool.java:320)
at jrunx.scheduler.ThreadPool$ThreadThrottle.invokeRunnable(ThreadPool.java:428)
at jrunx.scheduler.ThreadPool$UpstreamMetrics.invokeRunnable(ThreadPool.java:266)
at jrunx.scheduler.WorkerThread.run(WorkerThread.java:66)
btaves
  • 21
  • 2
  • It sounds like your App pool is being recycled at 30 minutes. Has your settings under the `Advanced Properties -> Recycling` been adjusted from defaults? – Zypher Jun 08 '12 at 19:52
  • @Zypher - That's a good suggestion and has gotten me before. I've already tried adjusting the application pool recycling on both servers though (currently every day at 12:00am). – btaves Jun 08 '12 at 20:12
  • Ahh, multiple servers? Are you going through a load balencer? – Zypher Jun 08 '12 at 20:38
  • @Zypher - No, I'm just using two servers to establish that it's not an issue specific to the first machine. The problem first manifested on the Server 2008 Standard machine and I reproduced it on the Web Server 2008 R2 machine. – btaves Jun 08 '12 at 21:21
  • Any firewalls/routers/etc in between the server and the workstation? – Zypher Jun 08 '12 at 22:03
  • @Zypher - The two servers are in totally different locations: Seattle and Dallas. They do both have firewalls between them and the internet but the datacenter techs tell me there is nothing in the firewall that would cut the connection after 30 minutes – btaves Jun 08 '12 at 23:12
  • tried a different browser? – TristanK Jun 09 '12 at 06:12
  • @TristanK - Just tried again in FF 13.0 and it also restarts the upload at 30 minutes. – btaves Jun 12 '12 at 21:47
  • It's a IIS security option, see this answer here : http://stackoverflow.com/questions/11226392/when-upload-larger-file-getting-this-errorerror-404-file-or-directory-not-fo/11238544#11238544 – Allie Jun 14 '14 at 14:24

0 Answers0