Large arrays and logging errors

[AmbiguousJoe 0]

I've been trying to nail down a bug that my script has with logging time-out errors.

The company I work for uses a system called Passport to search for and access image files. Each image has a Document ID, Title, and a bunch of meta data so that the image can be searched for. Sometimes we get a request to modify the title or meta data of 1000+ images, so I wrote a script to cycle through and update each of the requested images.

Here's a little background on what the script does.

-An excel file that contains the image's ID and meta data is read in using _ExcelReadSheetToArray()

-It opens and logs into Passport.

-A loop begins, reading the first row of the array.

-It searches for the Document ID.

-If the search times out (search page is inactive for over 10 seconds), it logs a timeout error. If the Document ID was not found, it logs a File Not Found error. The errors are simply a code that I enter into the last column of the array.

-It navigates through Passport's windows to reach the data entry screen.

-It updates the image data by submitting the info from the array.

-The array's status column, for the current row, is marked "COMPLETE"

-The first loop is now complete and the next row is read. This loop continues til the last row has been updated.

-A new Excel file is created using _ExcelWriteSheetFromArray() so that any errors can be viewed.

The problem comes in when logging time-out errors. Sometimes the error code is entered into the correct line, sometimes it's entered 1 row early. My Excel file will say that Row 620 (as an example) timed out. So, I search for it manually, and it turns out 620 was updated just fine, but line 621 hasn't been updated (So 621 was the row that actually timed out). Again, this doesn't happen all the time. Sometimes it says line 150 timed out, and when I search for it, 150 hasn't been updated, and the surrounding rows were updated as expected. From what I've seen, it's only the time-out errors that have this issue, the File Not Found errors have been recorded correctly.

Every time a function is called, I ConsoleWrite() the function name, I also ConsoleWrite() the current row each loop so I can see a log of all the actions my script has taken. Here's what just plain confuses me. According to that log, it will say that Row 620 ran the function to search for the Document ID, called the AddErrorCode function, and then moved on to row 621. Row 621 shows that all the update functions were called and everything ran smoothly... Everything in my log suggests that Row 620 had a time-out error, but manually checking shows that 621 had the timeout.

Last night I ran 1,500 rows. 6 of them reported time-out errors: the second and last errors were accurate, but the other 4 all displayed the error on the previous row. So, can anyone take a guess as to what's happening here or how to fix it? My code isn't 1 row off because that would mean all the data would be 1 row off, but the initial and completed Excel files match. I also have nothing in my code that says "$nRow - 1". Is this possibly a memory issue from handling 1000+ rows with 18 columns each? Because this is a time-out issue, which doesn't happen that often, I haven't witnessed what's actually happening when it times out.

Here's the code I use to log my errors:

Func _AddErrorCode($nRow, $sErrorCode)
ConsoleWrite("Function: AddErrorCode"&@CRLF)
     ;Sets the the status column to "*ERROR*"
     $aExcelList[$nRow][1] = "*ERROR*"

     ;If there is nothing in the Error column, add the new code.
     If $aExcelList[$nRow][17] = "" Then
          $aExcelList[$nRow][17] = $sErrorCode

     ;Else, there is already an entry in the box.
     Else

          ;Searches if this Error Code is already logged. If not, it adds the code. Prevents the same code from being added multiple times.
          If StringInStr($aExcelList[$nRow][17],$sErrorCode) = 0 Then

          ;Updates the error column by adding a comma and the new column
          $aExcelList[$nRow][17] = $aExcelList[$nRow][17]&","&$sErrorCode
     EndIf
EndFunc

[jchd 967]

The shift in row number should be somewhere else. Seems like you're barking at the wrong tree.

Use this logging to make sure:

ConsoleWrite("Function: AddErrorCode(" & $nRow & ', ' & $sErrorCode & ")" & @CRLF)

[AmbiguousJoe 0]

I added the code you suggested, and put similar reporting on my Document Search function and the other functions that call it. Hopefully this will help track down the problem.

I haven't been looking for the problem esclusively in that AddErrorCode function. I searched through the functions that were being called. All the functions receive the $nRow variable to update and pull information from the array, but the only code that modifies the variable is the loop. I'll post more information if anything turns up. I wanted to throw the question out there and see if anyone knew of any issues with large arrays. I suspect the problem is either in the Document Search function, or due to a memory issue. IT has these computers locked down so that I can't even check the speed/memory, but I've had memory issues while running programs even without a script running through thousands of entries.

[AmbiguousJoe 0]

So I increased the length of time required before a timeout error occurs, as well as adding some re-try code, which will search for the entry a second time. This bug hasn't popped up in a while, until yesterday. In addition to the extra reporting in my error function, I have the code take a screenshot so I can see what's displayed on the screen when the error occurs. I'm absolutely dumbfounded by the results:

-The error reporting is correct. The timeout occurs on the entry that it says it occured on. The screenshot backs this up: Row 638 reports a timeout and the screenshot shows a loading screen with the information from row 638.

-Even though the timeout occured, all the information for that entry was updated, as if there weren't any problems..

-My console shows that upon timeout of Row 638, the function was exited, and the next entry in the list begins the search process (intended). The console shows that the next entry (639) was searched for, updated, and every step ran without any problems.

-Row 639 (the entry after the error), which reported no errors and appears to have run just fine, has not been altered whatsoever... it's as if there was a timeout on that entry.

-The final result is that Row 638 is reported as a timeout even though it's been updated. Row 639 has not been updated, but it's reported that everything was run successfully.

My first thought was that the timed out entry was eventually loaded while the script attempted to load Row 639. This would cause the the script to enter information from row 639 into the entry from row 638... but no, all the information from Row 638 was entered correctly. At this point, I'm clueless. This scripts runs thousands of entries each night, and I'm unable to monitor what's happening exactly at the moment of timeout, other than the single screenshot taken when an error occurs. This particular bug is frustating because its reporting that an entry was updated correctly, when nothing was actually changed. Incorrect data in the db is not a good thing.

Anyone have any ideas? I don't expect anyone to debug my code for me, just trying to understand where my logic went wrong. Here's the code from my search function. The error is sent within this code:

expandcollapse popup

;Populates the search fields on the TIMC010 panel and searches for the document
;$nMode variable: 0 = First time the function has been called         1 = Function called recursively, indicating a timeout on the first attempt.
Func _PopulatePassportSearch($nRow, $nMode = 0) ;Receives a row number so that Passport data can be populated
ConsoleWrite("Function: PopulatePassportSearch"&@CRLF)
Local $nLoopCount = 0

WinActivate("TIM") ;Activates the Passport window.
WinMove("TIM", "",1659,229,900,730) ;Resizes the Passport window in case it was previously opened or resized.
Sleep(250) ;Sleeps for 0.25 seconds

_PopulateRequiredFields($nRow) ;Fills out Search info into the appropriate fields.

MouseClick("left",2330,355, 1) ;Clicks the Execute button, which begins the seach.

;Loops until the search is completed. The search is complete when the "TIMCO1W" window is loaded, or the color of the status field changes.
While(PixelGetColor(1785,365) <> 13353643 Or WinExists("TIMC01W") = 1)

     If $nLoopCount >= 4 Then ;If the search loop has been running for 2 seconds or more.

          if PixelGetColor(1690, 288) = 0 Then ;Check if there's a No Document Found message
               ConsoleWrite("Document was not found, skipping this document."&@CRLF)
               _AddErrorCode($nRow, "DIDFNF")
               Return 1 ;Breaks out of function and notifies other functions of error.
          EndIf

          If $nLoopCount >= 20 Then ;If the loop has run 20 or more times (10 seconds) and the document has not been found
               ConsoleWrite("Document took too long to load, taking appropriate action."&@CRLF)

               If $nMode = 0 Then ;If this is the first time the function has been run, attempt a second try.
                    ConsoleWrite("DID not found on first attempt. Re-starting function after 5 seconds."&@CRLF)
                    Sleep(5000) ;Sleeps for 5 seconds before attempting a second try.
                    $nErrorCheck = _PopulatePassportSearch($nRow, 1) ;Checks for errors on the 2nd attempt. The results will be returned to the calling function.
                    Return $nErrorCheck ;Exits out of this function so the next steps are not duplicated.

               ElseIf $nMode = 1 Then ;If a second call resulted in a timeout.
                    ConsoleWrite("DID was not found after a second attempt. Marking as a timed out entry."&@CRLF)
                    _AddErrorCode($nRow, "DIDTO", 2) ;Logs the timeout error. The 2 indicates that this entry can be re-tried at the end of the script.
                    Return 1 ;Returns an error, which will be returned by the original call in the next statement.

               EndIf
          EndIf
     EndIf

     Sleep(500) ;Sleeps for 0.5 seconds

     If WinExists("TIMC01W") = 1 Then ;If the DID Selection page is opened (search completed)
          MouseClick("left",1680,395, 2) ;Double-clicks on the first entry.
          WinWaitActive("TIMC010","",60) ;Waits up to 60 seconds for the info page to load. This is verified in the next function.
     EndIf

     If WinExists("TIMC010") = 0 Then ;If the search window gets closed, or is navigated away from, call recursively.
          $nErrorCheck = _PopulatePassportSearch($nRow) ;Function calls itself, restarting all search steps.
          Return $nErrorCheck ;prevents looping continuously after a page has been lost due to lag/closing
     EndIf

     $nLoopCount = $nLoopCount + 1 ;Tracks the number of times the loop has been run

WEnd ;End of the search wait loop.
EndFunc ;==>PopulatePassportSearch

The bug only occurs on time-out errors, and only occasionally. I realize the problem may be somewhere outside of the Search function, and outside of the error reporting function, but I honestly wouldn't know where to look: After the search function is called, either the information for that row is entered, or the next entry in the list is searched for.