8 Replies Latest reply on Nov 7, 2013 7:49 PM by mcahren

    Import Script Failing Sporadically

    mcahren

      The script ran fine for a year, then it began failing sporadically.  I suspect it's related to a DB timeout or network issue, but I can't pinpoint the issue.  I added some basic logging and error trapping, but it isn't enough to go on.  Any ideas on how to continue troubleshooting?

       

       

      Function FDM_JDE_Connect(strLoc, lngCatKey, dblPerKey, strWorkTableName)

      ' ------------------------------------------------------------------------------

      ' Date         Person         Modification

      ' -----------  -------------  ------------------------------------------------

      ' 20131024     Jeff McAhren   Cleaned up code, added logging

      '

      ' ------------------------------------------------------------------------------

       

        Dim cnSS      ' Integration Connection

        Dim strSQL ' SQL statement for V_HFM_LOAD

        Dim rs     ' v_HFM_LOAD Recordset

        Dim rsAppend ' tTB table append rs object

        Dim strMonth

        Dim strYear

        Dim strJDEMonthCol

        Dim r

       

        WriteLog "~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~"

        WriteLog "FDM_JDE_Connect Starting"

        WriteLog "strLoc = " & strLoc

        WriteLog "lngCatKey = " & lngCatKey

        WriteLog "dblPerKey = " & dblPerKey

        WriteLog "strWorkTableName = " & strWorkTableName

       

        Set cnSS = CreateObject("ADODB.Connection")

        Set rs = CreateObject("ADODB.Recordset")

        Set rsAppend = DW.DataAccess.farsTableAppend(strWorkTableName)

       

        'Connect to the Integration database

        cnSS.open "Provider=SQLOLEDB.1;Password=mypassword;Persist Security Info=True;User ID=myuser;Initial Catalog=mydatabase;Data Source=mydb;"

        WriteLog "Connected to Integration Database; Err = " & Err & " - " & Err.Description

       

       

        strMonth = RIGHT("0" & Month(RES.PstrPer),2)

        strJDEMonthCol="GBAN" & strMonth

        strYear = Year(RES.PstrPer)

       

        strSQL = "SELECT DATAVIEW, YEAR, PERIOD, ENTITY, ACCOUNT, CUSTOM1, CUSTOM2, CUSTOM3, CUSTOM4, AMOUNT " &_

        "FROM V_HFM_LOAD WHERE PERIOD = " & strMonth & " and (YEAR = " & strYear & " or YEAR = '')"

       

        rs.Open strSQL, cnSS

        WriteLog "rs recordset opened; Err = " & Err & " - " & Err.Description

       

        'Check for data

        If rs.bof And rs.eof Then

        RES.PlngActionType = 2

        RES.PstrActionValue = "No Records to load!"

        WriteLog "No records to load, exiting function; Err = " & Err & " - " & Err.Description

        Exit Function

        End If

       

        'Loop through records and append to tTB table in location's DB, use records returned from the strSQL query

        If Not rs.bof And Not rs.eof Then

        WriteLog "Entering do/while loop; Err = " & Err & " - " & Err.Description

        Do While Not rs.eof

        r = r + 1

        rsAppend.AddNew

        If err <> 0 Then WriteLog "*** ERROR EXECUTING ADDNEW - RECORD: " & r & " - Error: " & err  & " - " & Err.Description

        rsAppend.Fields("PartitionKey") = RES.PlngLocKey

        rsAppend.Fields("CatKey") = RES.PlngCatKey

        rsAppend.Fields("PeriodKey") = RES.PdtePerKey

        rsAppend.Fields("DataView") = rs.fields("DATAVIEW").Value

        rsAppend.Fields("CalcAcctType") = 9

        rsAppend.Fields("Amount") = rs.fields("AMOUNT").Value

        rsAppend.Fields("Desc1") = rs.fields("ACCOUNT").Value

        rsAppend.Fields("Account") = rs.fields("ACCOUNT").Value

        rsAppend.Fields("Entity") = rs.fields("ENTITY").Value

        rsAppend.Fields("ICP") = "[ICP None]"

        rsAppend.Fields("UD1") = rs.fields("CUSTOM1").Value

        rsAppend.Fields("UD2") = rs.fields("CUSTOM2").Value

        rsAppend.Fields("UD3") = rs.fields("CUSTOM3").Value

        rsAppend.Fields("UD4") = rs.fields("CUSTOM4").Value

        rsAppend.Update

        If err <> 0 Then WriteLog "*** ERROR EXECUTING UPDATE - RECORD: " & r & " - Error: " & err  & " - " & Err.Description

        If r / 10000 = Int(r / 10000) Then WriteLog "Status Update Record: " & r

        rs.movenext

        If err <> 0 Then WriteLog "*** ERROR EXECUTING MOVENEXT - RECORD: " & r & " - Error: " & err  & " - " & Err.Description

        Loop

        WriteLog "Exiting do/while loop; recordcount = " & r & "; Err = " & Err & Err.Description

        End If

       

        rs.close

        rsAppend.close

       

        WriteLog "Recordsets closed, exiting function; Err = " & Err & Err.Description

       

        'Assign Return value

        FDM_JDE_Connect = True

       

      End Function

       

       

      Sub WriteLog(LogMessage)

          Dim objLogFile

          Dim FSO

          Set fso = CreateObject("Scripting.FileSystemObject")

          Set objLogFile = fso.OpenTextFile("d:\scripts\HFM\FDM_JDE_Connect.log", 8, True) '8=ForAppending

          objLogFile.Writeline (Now() & ": " & LogMessage)

          objLogFile.Close

          Set objLogFile = Nothing

      End Sub

        • 1. Re: Import Script Failing Sporadically
          mcahren

          This is what the script log output looks like when the process is successful.  It is successful about a third of the time.

           

          10/27/2013 7:09:16 PM: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

          10/27/2013 7:09:16 PM: FDM_JDE_Connect Starting

          10/27/2013 7:09:16 PM: strLoc = JDE

          10/27/2013 7:09:16 PM: lngCatKey = 13

          10/27/2013 7:09:16 PM: dblPerKey = 41486

          10/27/2013 7:09:16 PM: strWorkTableName = tWsys_jd546857642214

          10/27/2013 7:09:16 PM: Connected to EA Database; Err = 0

          10/27/2013 7:09:24 PM: rs recordset opened; Err = 0

          10/27/2013 7:09:24 PM: Entering do/while loop; Err = 0

          10/27/2013 7:09:56 PM: Status Update Record: 10000

          10/27/2013 7:10:28 PM: Status Update Record: 20000

          10/27/2013 7:11:04 PM: Status Update Record: 30000

          10/27/2013 7:11:27 PM: Status Update Record: 40000

          10/27/2013 7:11:54 PM: Status Update Record: 50000

          10/27/2013 7:12:20 PM: Status Update Record: 60000

          10/27/2013 7:12:46 PM: Status Update Record: 70000

          10/27/2013 7:13:01 PM: Exiting do/while loop; recordcount = 74968; Err = 0

          10/27/2013 7:13:01 PM: Recordsets closed, exiting function; Err = 0

           

          This is what it looks like when the process fails:

          10/28/2013 7:07:18 AM: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

          10/28/2013 7:07:18 AM: FDM_JDE_Connect Starting

          10/28/2013 7:07:18 AM: strLoc = JDE

          10/28/2013 7:07:18 AM: lngCatKey = 13

          10/28/2013 7:07:18 AM: dblPerKey = 41486

          10/28/2013 7:07:18 AM: strWorkTableName = tWsys_jd533655084031

          10/28/2013 7:07:18 AM: Connected to EA Database; Err = 0

          10/28/2013 7:07:27 AM: rs recordset opened; Err = 0

          10/28/2013 7:07:27 AM: Entering do/while loop; Err = 0

           

           

          A couple times, it has gotten a little further, in this example, it failed somewhere between records 30,000 and 40,000:

          10/27/2013 10:10:23 AM: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

          10/27/2013 10:10:23 AM: FDM_JDE_Connect Starting

          10/27/2013 10:10:23 AM: strLoc = JDE

          10/27/2013 10:10:23 AM: lngCatKey = 13

          10/27/2013 10:10:23 AM: dblPerKey = 41486

          10/27/2013 10:10:23 AM: strWorkTableName = tWsys_jd543659887769

          10/27/2013 10:10:23 AM: Connected to EA Database; Err = 0

          10/27/2013 10:10:31 AM: rs recordset opened; Err = 0

          10/27/2013 10:10:31 AM: Entering do/while loop; Err = 0

          10/27/2013 10:11:10 AM: Status Update Record: 10000

          10/27/2013 10:11:30 AM: Status Update Record: 20000

          10/27/2013 10:11:50 AM: Status Update Record: 30000

           

          So I tinkered with debug logging a bit more, I have verified that the recordset loop always updates *some* records, but it dies somewhere before it finishes.  It never raises any errors while executing the ADDNEW, UPDATE, or MOVENEXT ADO commands.

           

          Any ideas would be appreciated..

          • 2. Re: Import Script Failing Sporadically
            mcahren

            Oh, and there is this:

             

            ** Begin FDM Runtime Error Log Entry [2013-10-28 16:07:18] **

            -------------------------------------------------------------

            ERROR:

            Code............................................. -2147467259

            Description...................................... File [07^JDE^Actual^Jul - 2013^RR.txt] Caused Error: (Query timeout expired At line: 99) <=== LINE 99 is the "LOOP" Statement

            Procedure........................................ clsBatchLoader.mFileCollectionProcess

            Component........................................ upsWBatchLoaderDM

            Version.......................................... 1112

            Thread........................................... 5844

             

             

            IDENTIFICATION:

            User............................................. sys_jde_load

            Computer Name.................................... MyServer

            App Name......................................... BBCFDM

            Client App....................................... WebClient

             

             

            CONNECTION:

            Provider......................................... SQLOLEDB

            Data Server...................................... MyDBServer

            Database Name.................................... BBCFDM

            Trusted Connect.................................. False

            Connect Status.. Connection Open

             

             

            GLOBALS:

            Location......................................... JDE

            Location ID...................................... 749

            Location Seg..................................... 3

            Category......................................... ACTUAL

            Category ID...................................... 13

            Period........................................... Jul - 2013

            Period ID........................................ 7/31/2013

            POV Local........................................ False

            Language......................................... 1033

            User Level....................................... 1

            All Partitions................................... True

            Is Auditor....................................... False

            • 3. Re: Import Script Failing Sporadically
              SH_INT

              The first thing you need to do is switch the vbscript error handling mechanism on by putting On Error Resume Next as the first line of your script. Without this statement as soon as an error is encountered the script will exit and you will never get to the lines of code that output the Err objects information.

              • 4. Re: Import Script Failing Sporadically
                mcahren

                Crikey, I can't believe I missed that!  Line added, and now waiting for a failed execution...

                 

                Thank you!

                • 5. Re: Import Script Failing Sporadically
                  mcahren

                  The process failed, I pasted the log below.  It looks like it's a query timeout on the RS recordset, which is the source, and is pulling from a SQL view. 

                   

                  The SQL view completes in ~10 seconds in SQL Server Management Studio. 

                   

                  My thoughts:

                   

                  1.  The process always seems to get started, some records are always inserted from the source to the work table, but why is it timing out?  If it has any records, doesn't it have all records?

                  2.  Re #1, maybe it doesn't have all records, and it's failing while waiting for the next batch?  Maybe I can use some sort of ADO parameter or cursor type that will pull the entire recordset down before beginning the loop (if you can't tell, I don't have a lot of experience with this sort of issue).

                   

                   

                   

                   

                   

                  10/30/2013 1:05:53 PM: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

                  10/30/2013 1:05:53 PM: FDM_JDE_Connect Starting

                  10/30/2013 1:05:53 PM: strLoc = JDE

                  10/30/2013 1:05:53 PM: lngCatKey = 13

                  10/30/2013 1:05:53 PM: dblPerKey = 41486

                  10/30/2013 1:05:53 PM: strWorkTableName = tWsys_jd690854247263

                  10/30/2013 1:05:53 PM: Connected to EA Database; Err = 0 -

                  10/30/2013 1:06:01 PM: rs recordset opened; Err = 0 -

                  10/30/2013 1:06:01 PM: Entering do/while loop; Err = 0 -

                  10/30/2013 1:07:02 PM: *** ERROR EXECUTING MOVENEXT - RECORD: 82 - Error: -2147467259 - Query timeout expired

                  10/30/2013 1:07:02 PM: Exiting do/while loop; recordcount = 82; Err = -2147467259 - Query timeout expired

                  10/30/2013 1:07:02 PM: Recordsets closed, exiting function; Err = -2147467259 - Query timeout expired

                  • 6. Re: Import Script Failing Sporadically
                    mcahren

                    Any suggestions?  This is still broken.

                    • 7. Re: Import Script Failing Sporadically
                      SH_INT

                      Have you tried increasing the CommandTimeout property of the Connection. It defaults to 30 secs try increasing it to 120

                      • 8. Re: Import Script Failing Sporadically
                        mcahren

                        I just threw that in there, but I think that timeout is for opening the connection, isn't it?  Hopefully it works!

                         

                        More thinking out loud...  the problem occurs whether the cursor is the default of read-write & server side, -and- when the cursor is client side & static & read only (recent script additions).  In that second cursor scenario, I'm guessing that the entire recordset is delivered to the client, and the database isn't involved when moving through said recordset.... ???  This is why I'm confused why the error is occurring on the rs.MoveNext. 


                        Thinking out loud part three:  Instead of looping through 75000 records, and inserting them into another table one by one, why can't I do something like the following, which seems 1000x more efficient anyway?  (I'm torn on this approach, however, because it's masking the problems instead of solving the underlying problem)

                         

                        Insert into hyp_fdm.dbo.[worktable] select [bunch of fields, literals, concatenations, etc.] from mydatabase.dbo.v_hfm_load