408 Request Time-out

Mar 11, 2010 at 9:47 PM

hi, I used IIRF yester. everything works fine except I download report filed from our web application. It always show 408 Request Time-out. there is the log:

Thu Mar 11 14:25:35 -  7748 - ProxyRequest: WinHttpReadData 799
Thu Mar 11 14:25:35 -  7748 - ProxyRequest: WinHttpReadData nRead= 799
Thu Mar 11 14:25:35 -  7748 - ProxyRequest: WinHttpReadData 3564
Thu Mar 11 14:25:35 -  7748 - ProxyRequest: WinHttpReadData nRead= 3564
Thu Mar 11 14:25:35 -  7748 - ProxyRequest: contentChunks(2) contentTotalBytes(4363)
Thu Mar 11 14:25:35 -  7748 - ReleaseArrayWchar: pw=    0x01D65908
Thu Mar 11 14:25:35 -  7748 - ReleaseArrayWchar: pw[0]= 0x01D658E8
Thu Mar 11 14:25:35 -  7748 - DoRewrites: Proxy complete: 2 chunks, 4363 bytes'
Thu Mar 11 14:25:35 -  7748 - HttpFilterProc: SF_NOTIFY_LOG
Thu Mar 11 14:25:35 -  7748 - ReleaseOrExpireSiteConfig: site '/LM/W3SVC/635579975/Root' (era=0) (rc=0) (Expired=0) (ptr=0x01D640A8)...
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - Cached: DLL_THREAD_DETACH
Thu Mar 11 14:35:10 -  3064 - IsIniFileUpdated: C:\Inetpub\wwwroot\Sequel6\Iirf.ini NO
Thu Mar 11 14:35:10 -  3064 - GetSiteConfig: Obtain  site '/LM/W3SVC/635579975/Root' (era=0) (rc=1) (Expired=0) (ptr=0x01D640A8)...
Thu Mar 11 14:35:10 -  3064 - HttpFilterProc: SF_NOTIFY_URL_MAP
Thu Mar 11 14:35:10 -  3064 - HttpFilterProc: cfg= 0x01D640A8
Thu Mar 11 14:35:10 -  3064 - HttpFilterProc: SF_NOTIFY_AUTH_COMPLETE
Thu Mar 11 14:35:10 -  3064 - DoRewrites
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_AutoFree: getting 'url'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_AutoFree: 128 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_AutoFree: result ''
Thu Mar 11 14:35:10 -  3064 - GetHeader_AutoFree: getting 'url'
Thu Mar 11 14:35:10 -  3064 - GetHeader_AutoFree: 29 bytes   ptr:0x00100D30
Thu Mar 11 14:35:10 -  3064 - GetHeader_AutoFree: 'url' = '/sss/SourceCodeMailMerge.dwm'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_AutoFree: getting 'QUERY_STRING'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_AutoFree: 1 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_AutoFree: result ''
Thu Mar 11 14:35:10 -  3064 - GetHeader_AutoFree: getting 'method'
Thu Mar 11 14:35:10 -  3064 - GetHeader_AutoFree: 5 bytes   ptr:0x00100E40
Thu Mar 11 14:35:10 -  3064 - GetHeader_AutoFree: 'method' = 'POST'
Thu Mar 11 14:35:10 -  3064 - DoRewrites: New Url, before decoding: '/sss/SourceCodeMailMerge.dwm'
Thu Mar 11 14:35:10 -  3064 - DoRewrites: Url (no decoding): '/sss/SourceCodeMailMerge.dwm'
Thu Mar 11 14:35:10 -  3064 - EvaluateRules: depth=0
Thu Mar 11 14:35:10 -  3064 - EvaluateRules: Rule 1 : 2 matches
Thu Mar 11 14:35:10 -  3064 - GetServerVariable: getting 'HTTP_HOST'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable: 27 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable: result 'sequel6.publish2profit.com'
Thu Mar 11 14:35:10 -  3064 - ReplaceServerVariables: VariableName='HTTP_HOST' Value='sequel6.publish2profit.com'
Thu Mar 11 14:35:10 -  3064 - ReplaceServerVariables: in='%{HTTP_HOST}' out='sequel6.publish2profit.com'
Thu Mar 11 14:35:10 -  3064 - EvalCondition: ts1 'sequel6.publish2profit.com'
Thu Mar 11 14:35:10 -  3064 - GenerateReplacementString: result 'sequel6.publish2profit.com'
Thu Mar 11 14:35:10 -  3064 - EvalCondition: checking 'sequel6.publish2profit.com' against pattern '^sequel6\.publish2profit\.com$'
Thu Mar 11 14:35:10 -  3064 - EvalCondition: match result: 1 (match)
Thu Mar 11 14:35:10 -  3064 - EvalCondition: Cond %{HTTP_HOST} ^sequel6\.publish2profit\.com$ => TRUE
Thu Mar 11 14:35:10 -  3064 - EvalConditionList: rule 1, TRUE, Rule will apply
Thu Mar 11 14:35:10 -  3064 - ReplaceServerVariables: in='http://172.16.0.108/$1' out='http://172.16.0.108/$1'
Thu Mar 11 14:35:10 -  3064 - GenerateReplacementString: result 'http://172.16.0.108/sss/SourceCodeMailMerge.dwm'
Thu Mar 11 14:35:10 -  3064 - EvaluateRules: Result (length 47): http://172.16.0.108/sss/SourceCodeMailMerge.dwm
Thu Mar 11 14:35:10 -  3064 - EvaluateRules: returning 999
Thu Mar 11 14:35:10 -  3064 - DoRewrites: Proxy to: 'http://172.16.0.108/sss/SourceCodeMailMerge.dwm'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_AutoFree: getting 'REQUEST_METHOD'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_AutoFree: 5 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_AutoFree: result 'POST'
Thu Mar 11 14:35:10 -  3064 - ProxyRequest: http://172.16.0.108/sss/SourceCodeMailMerge.dwm
Thu Mar 11 14:35:10 -  3064 - DoRewrites: requires rewrite to: '/proxy.iirf?path=/LM/W3SVC/635579975/Root&url=http://172.16.0.108/sss/SourceCodeMailMerge.dwm'
Thu Mar 11 14:35:10 -  3064 - HttpFilterProc: SF_NOTIFY_URL_MAP
Thu Mar 11 14:35:10 -  3064 - HttpFilterProc: cfg= 0x01D640A8
Thu Mar 11 14:35:10 -  3064 - HttpFilterProc: SF_NOTIFY_URL_MAP
Thu Mar 11 14:35:10 -  3064 - HttpFilterProc: cfg= 0x01D640A8
Thu Mar 11 14:35:10 -  3064 - GetSiteConfig_FromPath: Obtain  site '/LM/W3SVC/635579975/Root' (era=0) (rc=2) (Expired=0) (ptr=0x01D640A8)...
Thu Mar 11 14:35:10 -  3064 - HttpExtensionProc: Proxy to 'http://172.16.0.108/sss/SourceCodeMailMerge.dwm'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: getting 'REQUEST_METHOD'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: 5 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: result 'POST'
Thu Mar 11 14:35:10 -  3064 - ProxyPostRequest: http://172.16.0.108/sss/SourceCodeMailMerge.dwm
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: getting 'CONTENT_TYPE'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: 34 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: result 'application/x-www-form-urlencoded'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: getting 'HTTP_USER_AGENT'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: Buffer not large enough.
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: 278 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: result 'Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1) ;  Embedded Web Browser from: http://bsalsa.com/; CIBA; .NET CLR 2.0.50727; aff-kingsoft-ciba; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; .NET CLR 1.1.4322)'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: getting 'REMOTE_ADDR'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: 15 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: result '206.75.200.126'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: getting 'LOCAL_ADDR'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: 13 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: result '172.16.0.106'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: getting 'HTTP_REFERER'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: 88 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: result 'http://sequel6.publish2profit.com/sss/SourceCodeMailMerge.dwm?SID=1344742829-1223592080'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: getting 'HTTP_ACCEPT'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: Buffer not large enough.
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: 268 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: result 'image/gif, image/jpeg, image/pjpeg, image/pjpeg, application/x-shockwave-flash, application/vnd.ms-excel, application/vnd.ms-powerpoint, application/msword, application/x-ms-application, application/x-ms-xbap, application/vnd.ms-xpsdocument, application/xaml+xml, */*'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: getting 'HTTP_ACCEPT_ENCODING'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: 14 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: result 'gzip, deflate'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: getting 'HTTP_ACCEPT_LANGUAGE'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: 18 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: result 'en-us,zh-CN;q=0.5'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: getting 'HTTP_COOKIE'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: Buffer not large enough.
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: 207 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: result 'SaveLogin=true; Username=sm; PublisherId=BiZBash; __utma=33045695.423650821.1262621388.1268261763.1268326384.45; __utmz=33045695.1262621388.1.1.utmccn=(direct)|utmcsr=(direct)|utmcmd=(none); __utmc=33045695'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: getting 'HTTP_X_FORWARDED_FOR'
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: does not exist (HTTP_X_FORWARDED_FOR)
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: 128 bytes
Thu Mar 11 14:35:10 -  3064 - GetServerVariable_EX: result 'HTTP_X_FORWARDED_FOR'
Thu Mar 11 14:35:10 -  3064 - ProxyPostRequest: url(http://172.16.0.108/sss/SourceCodeMailMerge.dwm)
Thu Mar 11 14:35:10 -  3064 - ProxyPostRequest: host(172.16.0.108)  path+query(/sss/SourceCodeMailMerge.dwm)
Thu Mar 11 14:35:10 -  3064 - ProxyPostRequest: varAccept 0x01D687A0 (image/gif, image/jpeg, image/pjpeg, image/pjpeg, application/x-shockwave-flash, application/vnd.ms-excel, application/vnd.ms-powerpoint, application/msword, application/x-ms-application, application/x-ms-xbap, application/vnd.ms-xpsdocument, application/xaml+xml, */*)
Thu Mar 11 14:35:10 -  3064 - ProxyPostRequest: WinHttpConnect 172.16.0.108 80
Thu Mar 11 14:35:10 -  3064 - ProxyPostRequest: WinHttpOpenRequest POST /sss/SourceCodeMailMerge.dwm
Thu Mar 11 14:35:10 -  3064 - ProxyPostRequest: WinHttpAddRequestHeaders
Thu Mar 11 14:35:10 -  3064 - ProxyPostRequest: WinHttpSendRequest  totalLength(3502)
Thu Mar 11 14:35:10 -  3064 - ProxyPostRequest: WinHttpReceiveResponse
Thu Mar 11 14:35:40 -  3064 - SetProxyResponseHeaders: starting status 10408
Thu Mar 11 14:35:40 -  3064 - SetProxyResponseHeaders: status TIMEOUT?
Thu Mar 11 14:35:40 -  3064 - SetProxyResponseHeaders: status string '408 Request Time-out'
Thu Mar 11 14:35:40 -  3064 - ProxyPostRequest: HSE_REQ_SEND_RESPONSE_HEADER_EX szStatus 408 Request Time-out
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw=    0x01F60620
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[0]= 0x01D66EB8
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[1]= 0x01F605D0
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[2]= 0x01D66C48
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[3]= 0x01D64BF0
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[4]= 0x01D65600
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[5]= 0x01D64C18
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[6]= 0x01D671F8
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[7]= 0x01D682A8
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[8]= 0x01D64C58
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[9]= 0x01D66E80
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[10]= 0x01D68728
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[11]= 0x01D658B0
Thu Mar 11 14:35:40 -  3064 - ReleaseArrayWchar: pw[12]= 0x01D64490
Thu Mar 11 14:35:40 -  3064 - HttpExtensionProc: done
Thu Mar 11 14:35:40 -  3064 - HttpFilterProc: SF_NOTIFY_LOG
Thu Mar 11 14:35:40 -  3064 - ReleaseOrExpireSiteConfig: site '/LM/W3SVC/635579975/Root' (era=0) (rc=0) (Expired=0) (ptr=0x01D640A8)...

 

Coordinator
Mar 12, 2010 at 12:13 AM

How long does that particular URL (the mailmerge report) take?  If it takes longer than 30 seconds, it will exceed a default timeout in IIRF.

You can use the ProxyTimeouts directive to set the timeouts for a proxy request.  Check the documentation for how to use the directive.

The lines you saw - "Buffer not large enough" - is not an error.  That's just a diagnostic message and it indicates normal operation.