Nando @ Aria Media

( learning Clojure ColdFusion Lucee Javascript jQuery Angular CSS Linux Apache HTML5 & etc )

Debugging Technique CFML Development

| Comments

I learned a debugging techique from Sean Corfield recently that I think is well worth sharing more widely. It works just as well for Lucee, Railo or Adobe Coldfusion. Here’s what he reccommends:

For ease of debugging any problems that may occur, I strongly recommend you always keep a Terminal / Console window open containing a tail of the console output from your CFML server. If you’re using Lucee or a Railo installation based on Tomcat, you’ll want to find the catalina.out log file and tail that. If you’re using ColdFusion 11, even tho’ it is notionally based on Tomcat, it’s completely non-standard and you’ll want to tail cfusion/logs/coldfusion-out.log.

To “tail”, in this case, means to show the newly added contents of a log file in real time. To get this to work, I open Terminal on my Mac and issue the following commands:

… for my local CF11 install:

 tail -f /Applications/ColdFusion11/cfusion/logs/coldfusion-out.log

and for my local Lucee install:

  tail -f ~/tomcat/logs/catalina.out

You will of course need to change those paths to match the directory under which your applications are installed.

To get out of tail mode and back to the command line, hit CTRL-C.

What I see when I do this is the last 10 lines of the log file, to start with. Anytime an additional line is added to the log file, it immediately appears in the console display in real time.

Now what I can do in my code is send output to these log files. An example should explain it sufficiently. I just used this technique to debug a the following service function, where I wanted to ensure that dateTo UTC was being set as needed:

    public query function findRawAudit( string entity, numeric userId, date dateFrom, date dateTo, numeric timeZoneOffset ) {
        var stdout = createObject( "java", "java.lang.System" ).out;

        ...

        if ( structKeyExists(arguments, 'dateTo') ) {
            sql &= "#newLine#" & "and timestamp < :dateTo";
            //  adjust dateFrom to account for time zone difference between server and user
            var dateToUTC = DateAdd( 'h', -arguments.timeZoneOffset, arguments.dateTo );
            // we add a day to dateTo to arrive at an effectiveEndDateTime, namely midnight of the endDate
            // so that the endDate is inclusive, as users would very likely expect
            dateToUTC = dateAdd( 'd', 1, dateToUTC );
            stdout.println( "dateToUTC : #dateToUTC #" );
            structInsert(params, "dateTo", { value: dateToUTC, cfsqltype: "cf_sql_timestamp" } );
        }
        ...
    }

Note the lines var stdout = createObject( "java", "java.lang.System" ).out; and stdout.println( "dateToUTC : #dateToUTC #" ); which creates an instance of java.lang.System.out and prints a line to the log file.

Immediately upon running this code dateToUTC : {ts '2015-06-16 22:00:00'} appeared in my tail output, which is what I expected. The bug was elsewhere, . I find this very useful. It’s simple and effective, and it works in the same way across ACF, Lucee and Railo. I don’t have to fiddle around with an admin setting to turn on trace output, check if trace output is enabled, remember the syntax used for cftrace / trace, and I can use it directly on a production server in a pinch in case of need.

Of course, you can tail any log file necessary, or use WriteLog() if you prefer. WriteLog() does the exact same thing as stdout.println(), and it’s easier to remember. So taking the above example, I could also use

1
WriteLog( "dateToUTC : #dateToUTC #" );

or

1
WriteLog( "dateToUTC : "  & dateToUTC );

Comments