tracker issue : CF-4204701

select a category, or use search below
(searches all categories and all time range)

CFFTP close action results in

| View in Tracker

Status/Resolution/Reason: Closed/Withdrawn/NotABug

Reporter/Name(from Bugbase): A. B. / ()

Created: 07/01/2019

Components: Net Protocols, FTP

Versions: 2018

Failure Type:

Found In Build/Fixed In Build: 2018.0.03.314033 /

Priority/Frequency: Normal /

Locale/System: / Win 2016

Vote Count: 0

Problem Description: 
A CFM page runs the following FTP tags once a day, using the same connection, named "cbFtpConnection":

<cfftp action="open">,  <cfftp action="listdir"> and <cfftp action="getfile">

These all work as expected. After all the processing is finished, we end with

<cfftp action="close" connection="cbFtpConnection">

The close action usually works as expected. However, of recent, it results in the exception

Steps to Reproduce: 
The following code runs once daily as a scheduled task (private and sensitive information deleted):

<cfif IsDefined("url.requestTimeOut")>
    <cfset rqto = url.requestTimeOut />
    <cfset rqto = 7200 />

<cfsetting requesttimeout="#rqto#" showdebugoutput="false">

<cfquery name="qCheckRunningQueue" datasource="#application.settings.DSN#">
         , JOB_START_DATE
     WHERE JOB_NAME = <cfqueryparam cfsqltype="CF_SQL_VARCHAR" value="CheckSentCBOrders" />

<cfif qCheckRunningQueue.recordCount neq 0>
    <cfmail from="" to="," subject="Failed to start: #qCheckRunningQueue.job_name[1]#" type="html">
        De job #qCheckRunningQueue.job_name[1]# is al eerder gestart op #qCheckRunningQueue.job_start_date[1]#.

    <cfthrow message = "Failed to start: #qCheckRunningQueue.job_name[1]#" />
    <cfquery name="qInsertJobIntoRunningQueue" datasource="#application.settings.DSN#">
                  ( JOB_NAME
                  , TIME_OUT
           VALUES (
                    <cfqueryparam cfsqltype="CF_SQL_VARCHAR" value="CheckSentCBOrders" />
                  , <cfqueryparam cfsqltype="CF_SQL_INTEGER" value="#rqto#" />

    <cfset cbFtpConnection = "" />
    <cfftp action="open" retrycount="2" stoponerror="true" server="" username="*********"  password="*********" connection="cbFtpConnection" />

    <cfftp action="listdir" directory="/out" name="ftpContent" connection="cbFtpConnection" passive="true" />

    <cfif ftpContent.recordCount neq 0>
    <!---Sort results on date --->
        <cfquery name="ftpContentSorted" dbtype="query">
            SELECT *
              FROM ftpContent
             ORDER BY LastModified

        <cfloop query="ftpContentSorted">
            <cfif Find(".uit",[ftpContentSorted.currentRow])>
                <cfftp action="getfile" localfile="#GetTempDirectory()#/[ftpContentSorted.currentRow]#" remotefile="/out/[ftpContentSorted.currentRow]#" connection="cbFtpConnection" transfermode="ascii" passive="true" failIfExists="false" />
                <cffile action="read" file="#GetTempDirectory()#/[ftpContentSorted.currentRow]#" variable="localFile" >
         			<cfset application.objectStoreWrapper.uploadToFileStorage(targetFileLocation="files/dev/CB_UIT/",[ftpContentSorted.currentRow],[ftpContentSorted.currentRow]) />

                <cfset fileRows = ListToArray(localFile,"#chr(13)##chr(10)#") />

                <cfset recordFound = false />
                <cfset isNewOrder = false />
                <cfset errorFound = false />
                <cfset errorMessage = "" />
                <cfset orderId = "" />
                <cfset sentDate = DateFormat(Now(), "YYYY-MM-DD") />

                <cfset fileRows_length = ArrayLen(fileRows) />

                <cfloop from="1" to="#fileRows_length#" index="i">
                    <cfif Find("##00010", fileRows[i]) neq 0>
                        <cfset sentDatePos = Find("##0004", fileRows[i]) />
                        <cfset nextPos = Find("##", fileRows[i], sentDatePos+5)-(sentDatePos+5) />
                        <cfset sentDate = Mid(fileRows[i], sentDatePos+5, nextPos) />
                        <cfset sentDate = Left(sentDate, 4) & "-" & Mid(sentDate, 5, 2) & "-" & Right(sentDate, 2) />
                    <cfelseif Find("##00014", fileRows[i]) neq 0>
                        <cfset recordFound = true />

                        <cfset orderReferencePos = Find("##0403", fileRows[i]) />
                        <cfset nextPos = Find("##", fileRows[i], orderReferencePos+5)-(orderReferencePos+5) />
                        <cfset orderId = Mid(fileRows[i], orderReferencePos+5, nextPos) />

                        <cfif Left(orderId, 1) eq "6" and Len(orderId) eq 8 and IsNumeric(orderId)>
                            <cfset isNewOrder = true />
                            Order: <cfoutput>#orderId#</cfoutput><br/>

                            <cfset eanPos = Find("##0200", fileRows[i]) />
                            <cfset nextPos = Find("##", fileRows[i], eanPos+5)-(eanPos+5) />
                            <cfset ean = Mid(fileRows[i], eanPos+5, nextPos) />
                            - EAN: <cfoutput>#ean#</cfoutput><br/>

                            <cfset amountPos = Find("##0430", fileRows[i]) />
                            <cfset nextPos = Find("##", fileRows[i], amountPos+5)-(amountPos+5) />
                            <cfif nextPos eq -(amountPos+5)>
                                <cfset nextPos = Len(fileRows[i]) - (amountPos+5) - 1 />
                            <cfset amount = Trim(Mid(fileRows[i], amountPos+5, nextPos)) />
                            - Aantal geleverd: <cfoutput>#amount#</cfoutput><br/>

                            <cfset tntPos = Find("##0462", fileRows[i]) />
                            <cfif tntPos neq 0>
                                <cfset nextPos = Find("##", fileRows[i], tntPos+5)-(tntPos+5) />
                                <cfif nextPos eq -(tntPos+5)>
                                    <cfset nextPos = Len(fileRows[i]) - (tntPos+5) - 1 />
                                <cfset tnt = Trim(Mid(fileRows[i], tntPos+5, nextPos)) />
                                <cfset tnt = "" />
                            - Track & trace code: <cfoutput>#tnt#</cfoutput><br/>

                            <cfsavecontent variable="xmlFilter">
                                        <filter FilterId="orderId">
                                            <field FieldId="ProfitOrderNummer" OperatorType="1">#orderId#</field>
                                            <field FieldId="ean" OperatorType="1">#ean#</field>

                            <cfset findOrderResult = application.profitService.GetConnector("devVerkooporderregels", xmlFilter) />

                            <cfif StructKeyExists(findOrderResult.Envelope.Body.GetDataResponse.GetDataResult.AfasGetConnector, "devVerkooporderregels")>
                                <cfsavecontent variable="xmlData">
                                        <FbSales xmlns:xsi="">
                                                <!--- private xml content --->

                                <cfset updateResult = application.profitService.updateConnector("FbSales", xmlData) />

                                Profit orderline modified!<br/>

                                <cfsavecontent variable="xmlData">
                                        <FbDeliveryNote xmlns:xsi="">
                                                <!--- private xml content --->

                                <cfset result = application.profitService.updateConnector("FbDeliveryNote", xmlData) />

                                Profit delivery added!<br/>
                                Profit order NOT found!!!<br/>

                            Oude order of directe order via CB Online: <cfoutput>#orderId#</cfoutput><br/>
                            GEEN ACTIE!<br/>

     <!--- the line \scheduled\finance\CheckSentCBOrders.cfm:213 in the stacktrace-->
    <cfftp action="close" connection="cbFtpConnection" />

Actual Result: The code is a CFM that runs once daily as a scheduled task. It does what we expect it to do, with one exception: the last line (FTP close) throws an FTPConnectionClosedException on some days. See attached stacktrace.

Expected Result:
No FTPConnectionClosedException exception, especially as that is what the tag <cfftp  action="close"> is supposed to do.

Any Workarounds:
None known



I am withdrawing this ticket. I think I found the cause of the FTPConnectionClosedException. Even though the error message says "An error occurred during the FTP CLOSE operation", it is apparent that the tag <cfftp action="close"> has nothing to do with the error's root cause. I discovered the following: In the CFM page shown here, the tag <cfftp action="open"> creates an FTP connection, cbFtpConnection. As the tag uses no timeout attribute, ColdFusion's default value, 30 seconds, is in effect. After that point the tags <cfftp action="listdir"> and <cfftp action="getfile"> reuse the connection cbFtpConnection within in a loop. However, the loop contains 2 calls to the function application.profitService.updateConnector(). It so happens that a cfhttp call is included somewhere in the function calls. The cfhttp tag has no timeout attribute. So the cfhttp call may take up to 7200 seconds, the request-timeout limit of the current page (The request-timeout limit in the ColdFusion Administrator is 120 seconds). The 7200 seconds far exceeds the 30 second timeout for the FTP connection. There is therefore every chance that the FTP server will find the connection idle and close it.
Comment by A. B.
30987 | July 04, 2019 12:50:47 PM GMT
@A.BAKIGĀ  Thanks for confirming. We will close this bug.
Comment by Dattanand M.
31020 | July 15, 2019 04:43:17 AM GMT