Posts Tagged Debugging

SSIS Debugging: Find in Files, Naming Conventions, and a Problem Solved!

I recently inherited several complex SSIS packages that are now being promoted from the development environment (ALPHA) to testing (BETA). There was one lingering issue though that took me a few hours to figure out.

We’ve implemented custom logging and auditing in the packages. In the Alpha environment, we set up Agent jobs to run groups of related tasks. For some odd reason, a log entry was being inserted into our audit table that was from a previous job step and not from the one we expected.

To give a simplified example: There are 3 SSIS packages being called by 3 job steps. Each loads a CSV file into a staging area for dimension processing. Step 1 reports that file A was processed. Step 2 reports on file B, and step 3 on file C. The step 3 job was reporting that file A was processed, but that it was the step 3 job that did it.

This wasn’t noticed until recently for several reasons, but primarily because we generally don’t rely on this particular log entry to determine if our files have been staged. So no one looks at it. In fact, this log entry merely serves as a bracket in the log table for other log entries posted in the same job. Nevertheless, I wanted to fix it.

So, where was the problem? All the logging is done using an Execute SQL Task. Every task checked out OK. The correct variables were being used in all cases. I was about ready to blame SSIS or corruption in the package when I stumbled upon a valuable clue: The name of the exact SQL Task Causing the problem!

I found the pesky task by doing a “Find in Files” search (BIDS -> Edit -> Find and Replace -> Find in Files) on the exact message being inserted into my audit table. You can use regular expressions and wildcards in this dialog so I was sure to find at least a clue. It turned out though that my exact search found the phrase; it was in a task named “Execute SQL Task”.

Red Flag!

I meticulously went through each package last month and renamed each and every task using the naming conventions posted on Jamie Thomson’s blog. This is a great best-practice and I certainly advise all SSIS developers to use this (or similar) convention. Anyway, the developers before me did a fairly good job of renaming tasks so they had meaningful names, but it was nearly impossible to look into sysdtslog90 or our custom audit tables and identify what kind of task the record was referring to. So I felt that while these packages were still in development, it was worth the few days effort to make these changes. All I did was add the suggested prefix before each task and renamed a few that I thought needed better descriptive names (sometimes shortening them in the process).

I know for sure that I didn’t miss any! Right?

Well, yes. I did. And so did the developers before me. When the package was being developed, the developers used cut & paste to move similar tasks from an existing package into this one. Then, a series of Sequence containers and Loop containers were added and tasks were moved around. A Sequence container was sized over the troublesome “Execute SQL Task” – to be forever (almost) lost in the Control Flow maze. I first saw it in the Package Explorer view and then went back to the Control Flow to see where it had gone. The task ran an SQL statement that updated the audit table.

Advice

Take care when using cut & paste to move items from one package to another. Not only could you run into some simple problems like the one detailed here, you could also forget to update a variable or an expression – producing odd or destructive results on your database. For us, this was just a simple audit log entry with zero business impact. Are there other cases buried in the packages? Need to check right now…

Also, use the naming convention best practice as discussed by Jamie. There are a lot of great reasons to do so (ease in development, debugging, readability).

I have never been in the habit of using the “Find in Files” function. But it sure saved me here. If you haven’t been using it in your packages, then give it a try!

Tags: , , , ,

No Comments

Errors Eating My TEXTMERGE

A few days ago I decided to refactor a 6-year old data integration program I wrote in VFP7 (or was it VFP6?) that moves data from a legacy tax system to an operational data warehouse for reporting (SQL Server). The program was self-contained (could be run as a compiled exe from the command line or through the IDE). To make a long story short, I decided to up the code to VFP9 and add some TRY/CATCH statements and additional parameter checking.

The code in this program makes heavy use of TEXTMERGE, utilizing the “” and “\” commands.

I wrote a few test cases to exercise my new error handling. What I discovered was that some of my logging stopped working after I added a few TRY…CATCH blocks. Hugh? Here’s a sample:

SET TEXTMERGE ON
SET TEXTMERGE TO test ADDITIVE NOSHOW 
hello
TRY
    USE xxx
CATCH TO oErr
    Error: <<oErr.Message>>
ENDTRY
world
SET TEXTMERGE TO
MODIFY FILE test.txt

If you run the above, you only see “hello” printed in the file test.txt:

hello

I went back to my original code without any TRY/CATCH blocks and to my surprise, got the same result. Only ‘hello’ printed. But WAIT… I’m running in VFP9 SP1.

When I run the original code in VFP7:

ON ERROR Error: <<MESSAGE()>>
SET TEXTMERGE ON
SET TEXTMERGE TO test ADDITIVE NOSHOW 
hello
USE xxx
world
SET TEXTMERGE TO
ON ERROR
MODIFY FILE test.txt

I get the expected output:

hello
Error: 'xxx.dbf' does not exist.
world

It appears as if program errors are killing my TEXTMERGE in VFP9 SP1. I’ll have to try this out on my laptop with VFP9 SP2 to see if it magically got fixed.

To get around the problem in VFP9, you can put the line “SET TEXTMERGE TO test ADDITIVE NOSHOW” in the CATCH block above just before the “” command. If an error occurs, you remind TEXTMERGE that it needs to keep working. Perhaps it figures it needs some time off.

Recommendations

Unless someone has some insight or additional thoughts, I would suggest searching through your source code for cases where you are using TEXTMERGE with TRY/CATCH/FINALLY blocks. If so, insert the SET TEXTMERGE TO … line in your CATCH block. Alternately, you could use STRTOFILE() to append logging information to a file. This is the final approach I took in this program.

STRTOFILE("hello"+CHR(13),"test.txt",1)
TRY
    USE xxx.dbf
CATCH TO oErr
    STRTOFILE("Error: " + oErr.Message+CHR(13),"test.txt",1)
ENDTRY
STRTOFILE("world"+CHR(13),"test.txt",1)
MODIFY FILE test.txt

I hope this helps someone, or maybe someone who knows more about this particular issue can help me!

Tags: ,

No Comments

VFP gotcha with _TALLY, RECCOUNT, DELETED, and an INDEX

Update: FYI, this is a known “issue” and works this way by default. See comments for more details.

Maybe I’m missing something (and I hope I am). The following condition exists in VFP7 through to VFP9SP1 (and maybe earlier than 7). I don’t remember ever reading anything about it either.

This one is hard to explain (and believe), so you may need to run the example code to see what I mean. And right off the bat: This issue has nothing to do with the RECCOUNT/_TALLY results we all know about regarding deleted records (RECCOUNT always returns the number of rows in the table regardless of the SET DELETED setting). No, this issue has something to do with an index and the current setting of DELETED. When an index is set on a column involved in a WHERE clause of an SQL statement, RECCOUNT will return the total number of records from the ‘FROM’ table instead of the results from the cursor when SET DELETED is OFF! It seems as though the resulting cursor has a bunch of deleted records (the scrollbar in the browse window only goes half-way up (if you know what I mean)), but they can’t be accessed regardless of the SET DELETED setting.

The problem is with code like this:

SET DELETED OFF
SELECT sometable
SET INDEX ON somefield   &amp;&amp; can exist in a CDX too
SELECT * FROM sometable WHERE somefield = somevalue INTO CURSOR crTemp
? RECCOUNT('crTemp')   &amp;&amp; wrong! RECCOUNT returns the wrong reccount!
? _TALLY               &amp;&amp; correct results

Here’s a complete example, using a table called ‘name_list’, which has a column for name c(30) and some deleted records. In the first example, the table name_list does NOT have an index on ‘name’. RECCOUNT and _TALLY return expected results.

USE name_list IN 0 EXCL 
 
SET DELETED OFF
 
SELECT name FROM name_list WHERE name&gt;='H' INTO CURSOR crName
? "WITH DELE OFF:  "
?? _TALLY              &amp;&amp; 81,019
?? RECCOUNT('crName')  &amp;&amp; 81,019
 
SET DELETED ON
 
SELECT name FROM name_list WHERE name&gt;='H' INTO CURSOR crName
? "WITH DELE ON: "
?? _TALLY              &amp;&amp; 80,951
?? RECCOUNT('crName')  &amp;&amp; 80,951

Now, add an index to the name column and be amazed:

USE name_list IN 0 EXCL
INDEX ON name TAG name
 
SET DELETED OFF
 
SELECT name FROM name_list WHERE name&gt;='H' INTO CURSOR crName
? "WITH DELE OFF:  "
?? _TALLY              &amp;&amp; 81,019
?? RECCOUNT('crName')  &amp;&amp; 126,607 -- the actual number of records in name_list!?!
 
SET DELETED ON
 
SELECT name FROM name_list WHERE name&gt;='H' INTO CURSOR crName
? "WITH DELE ON: "
?? _TALLY              &amp;&amp; 80,951
?? RECCOUNT('crName')  &amp;&amp; 80,951

In the above example, it doesn’t matter if the index is set to name (SET ORDER TO name) or not! Just the fact that the index exists throws off RECCOUNT(). If you do a count on crName with DELETED OFF, you get the expected results:

USE name_list IN 0 EXCL
INDEX ON name TAG name
 
SET DELETED OFF
 
SELECT name FROM name_list WHERE name&gt;='H' INTO CURSOR crName
? "WITH DELE OFF:  "
?? _TALLY              &amp;&amp; 81,019
?? RECCOUNT('crName')  &amp;&amp; 126,607 -- the actual number of records in name_list!?!
COUNT TO ln
?? ln                  &amp;&amp; 81,019

The moral is not to use RECCOUNT() to get the total number of records from
an SQL statement. Always use _TALLY. But unfortunately, this undocumented behavior has certainly crept into someone’s code somewhere. Consider a situation where you want to test to see if the SQL returns any records. You might do something like this:

SELECT * FROM sometable WHERE somefield = somevalue INTO CURSOR crTemp
IF RECCOUNT() &gt; 0
  ...
ENDIF

This code is fatal if in fact there happens to be an index on somefield and SET DELETED is OFF! If anyone has some insight, I’d love to hear it…

Tags: ,

6 Comments

An Introduction to the Coverage Profiler Application

Visual FoxPro (starting in version 7) comes with a built-in tool called the Coverage Profiler Application. This tool is designed to both cover (log information about each line of code run during program execution) and profile (produce useful information about the lines of code that are run) source code. The primary use for this tool is to detect code bottlenecks (which lines of code are taking too long to execute) and to locate lines of code not executed. These two functions of the Coverage Profiler are worth their weight in gold.

Sometimes I get the feeling that software performance is an afterthought during the development cycle. The code must work first. If time permits, then it is customary to go back and fine tune the source for performance. But reality (which many of you are living in) soon sets in, and time just doesn’t permit for this type of engineering. Of course, if performance is absolutely horrible then that must be addressed, but a half a second here or a quarter second there isn’t going to stir any milkshakes.

But coverage logs can really help. Consider a process (like saving a record) that zips along on a development machine, but crawls on an older test machine built some time before iPods came out. Having some knowledge of the coverage profiler can not only identify the problem, but can also help you solve it. You can identify the trouble spots in the call stack right down to the line of code causing the problem. Each problem you encounter will be different from the last, but identifying the problem will be the same.

The other major benefit of this tool is seeing which lines of code did not run. For testing purposes, this ability can really go a long way in flexing a new function or in testing a ‘fixed’ bug. It can show you where test cases are falling short, and allow you to write updated scripts that touch each line of code. It will also expose unnecessary blocks of code that an eager developer might have thought necessary (Developers: when was the last time you added an OTHERWISE statement to a DO CASE that you knew would never run? Of course, this practice is a good idea for clarity and readability, but perhaps a comment or ASSERT would be sufficient?).

What’s more is that the source code for these tools (coverage and profiler applications) is included with VFP. The Fox Development team has always encouraged its users to modify and enhance these tools to suit individual needs. Unfortunately I have not seen too many enhancements online over the years from other developers. Maybe the core functionality is good enough? I think so. But Perhaps I’ll think of something to build and put it here on this blog…

Tags: , ,

3 Comments

Handling Errors in Visual FoxPro

There is no question that having a custom error handler working behind the scenes in your Visual FoxPro Application is not only a good thing, but essential for good, stable production systems. Oftentimes, these custom error handlers are nothing more than a generic message alerting the user that a problem has occurred. Good designs will then dump the error details to a file or table for later analysis. While this method is a good first step, so much more can be done. Consider the following:

1. Instead of a generic message, write code to work with certain predictable errors. In my code, I like to trap errors such as “E1, File Does not exist”, “E6, Too many files open”, “E1001, Feature is not available”, “E2012 Cannot call SetFocus error”, and “E2028 API call caused an exception”. In these cases, special messages alert the user to what is going on, while code behind the scenes tries to handle the problem. For some errors, a simple RETRY or RETURN works well (like for error code 1001). For others, more work (error code 1) needs to be done.

2. Dumping the error contents to a file or table is a nice idea, but what if the user never tells you they received an error? Without you knowing, you can’t fix it. In a perfect environment, you could email a copy of the error details to the development staff automatically through FoxPro. Messages can also be posted (via XML and web services) to an Internet support site. Simply including tech support’s phone and fax number on the error message may give the operator a little more incentive as well. In the end, no method is foolproof. The important thing to remember is that no one likes an error, and more importantly, no one likes to get the same error over and over.

3. Intermingle all available error handling techniques in the application. This includes TRY…CATCH…FINALLY blocks where appropriate, using form and class level error methods, and even writing bullet-proof code (checking to make sure a table isn’t already open before you USE it, for example). Spending time on this endeavors will pay dividends in the end. Good error handling doesn’t go away, once it is in place it will continue to do its work throughout the life of the application.

4. Leave ON ERROR alone! There is sometimes a need to handle certain potential error cases differently. To achieve this, developers often swap ON ERROR routines. Take this typical case:
The global ON ERROR points to some code that displays a generic message when an error occurs. In a procedure, the developer needs to try to open a table for EXCLUSIVE use. So, the developer wraps the USE…EXCLUSIVE command around a customized ON ERROR that handles the error case when a file is in use. Next, the developer sets the ON ERROR command back to the global handler.

*-- Set up global error handler
ON ERROR oApp.gobal_err_hand(ERROR()    ,;
                             MESSAGE()  ,;
                             MESSAGE(1) ,;
                             LINENO(1)  ,;
                             SYS(16)    ,;
                             SYS(2018)  ) 
 
*-- Start event processing (run the app!)
READ EVENTS                       
 
*-- function to open a table exclusively
FUNCTION open_data_exclusive()
 
    LOCAL lcOldError
    lcOldError = ON("ERROR")
 
    ON ERROR MESSAGEBOX("Can't open the file!")
    USE sometable IN 0 EXCLUSIVE
    ON ERROR &amp;lcOldError
 
RETURN USED('sometable')

This method has many flaws, but certainly gets the developer where he or she needs to be. But what if the developer forgets to switch the error handler back? What about SET COMPATIBLE? What if a different error occurs?). This method also begs the question: Why not build a single a method with a large CASE structure to handle the specific error conditions? Of course, this is the best approach. Use a single ON ERROR command at the start of the application, and then work with that handler. No switching allowed! Things are easier now in newer versions of FoxPro. TRY…CATCH…FINALLY essentially renders the ON ERROR swap totally and utterly archaic.

Another side-effect of using ON ERROR in this way is that if you’re like me, then you have a debug menu and a debug environment that will treat errors differently. When an error occurs I don’t want to get a generic message. I want the ability to suspend the application and start a debugging session. See my blog entry on the debug menu for more details!

Tags: ,

2 Comments

Debug Environment

Not to take too much time away from my series on testing applications and bullet-proofing source code, but I felt that a little time dedicated to setting up a proper debugging environment would be helpful. A developer should have a different set of tools available than the end user. These tools will give the developer the ability to stop program execution, run some utilities, start a coverage, track events, etc.

Below are the main features of a debugging environment that I find important. Because the implementation can be done in several ways, I won’t get bogged down into the details at this time. Perhaps I will address one or two of these in a future article:

1.) A global debug flag. This flag would be part of a custom application object that can be used to determine whether or not the debug features are present or absent in the current instance of the application. Setting the flag can be done in a config file, a setup table, or even via a parameter during execution. The flag should be smart enough to know if the application started from the VFP command window (or the program/do menu) or via a desktop shortcut. We want to avoid ‘feature not available’ errors; we would also like to remind the developer that he or she is trying to run debug mode from a shortcut.

2.) A custom error handler. It is highly recommended to include custom error handling at the class level (via a form, container, textbox, etc). But there should also be a global handler that can address any issues that arise otherwise. These error handlers must be smart enough to recognize when a developer is in debug mode. These methods should give the developer a means to suspend execution (perhaps by spitting out the default VFP error notification) and to save environment settings for further research.

3.) A debug menu. When in debug mode, a special menu called ‘Debug’ should be created; pop it in right after the help menu. The menu should contain some useful features, such as a SUSPEND command; window activation (Trace, Command, Data); Coverage and Event logging; ability to open log files and tables; perhaps the ability to output information about the current environment, call stack, and objects; and various custome functions and programs not available to the end user. In addition, it should be chock-full of utilities and functions that can be called when needed.

4.) There should be a built-in restore mechanism that will automatically restore key labels, menus, and the VFP environment at anytime. Coupled with this would be a mechanism to cancel the program in a clean way for the developer.

This is the bulk of what is required for a proper debugging environment. These additions could save hours during debugging sessions. Exploring them further is well worth the effort.

Tags: , ,

No Comments