(Created and edited by Charlie Arehart, with additional content provided by Bill Shelton.)

If you didn't know, FusionReactor creates great logs which can be very helpful in analyzing what's going on within your CF (or other J2EE server) environment. Of course, when logs have lots of data, it can be a challenge pulling out meaningful information. There's a great free tool that can help with that, and this page helps explain how to take maximum advantage of it, and it points out specific features enabled in FusionReactor that help make it easy to use the tool with the FusionReactor logs (though it can be used with any logs).

This concept was first introduced in the Fusionreactor mailing list in early Mar 08, and it would be worth your time to go read thread that first: http://groups.google.com/group/fusionreactor/browse_thread/thread/f04a0a1a11f32d9f. As background, there are several useful logs in FR, which details each request, each query, all crash protection events, and a log that tracks resource utilization every 5 seconds. These can be very powerful, but analyzing them can be challenging.

The thread discusses the free Log Parser (http://www.microsoft.com/downloads/details.aspx?FamilyID=890cd06b-abf8-4c25-91b2-f8d975cf8c07&displaylang=en), a command-line tool from Microsoft, which enables you to process FusionReactor (and other) log files using SQL syntax.

But this Google Group page is focused on how to use it with FR specifically. Significant for FR users is that in FR 3, Intergral now provides a set of "header" files which are perfect for use with LP. There's one for each of the log file, and the header file identifies for its corresponding log file the column names. (You can also find more about each log file in the corresponding page of the FR help.)

This page serves as a repository for variants of LP SQL statements created to be used with FR, as offered by different FR users. These are just examples: there are many variations possible. For instance, many of these are set to provides results as a tabular report. It's possible as well to create charts and graphs, or store the results in a database, and much more. It's also possible to read multiple log files (of the same type) at once, as shown in some examples below. It's also possible to store the SELECT statements in a separate file to be reused within the tool, passing in arguments for variation. These features aren't demonstrated here.

In the FR mailing list thread above, there's a link to an article written by fellow FusionReactor user Charlie Arehart, introducing Log Parser and discussing using it from a CF perspective. You'll want to read that too to get most from the tool, and it points to additional resources for learning still more.

Note that there are slight differences between the log files created in FusionReactor 3.0.1 versus 3.0, and significant differences in the logs created in the older FR 2. See the bottom of this page for more info.

Please add new contributions to the bottom of the page.

Contributions from Charlie Arehart:

* List top 10 instances where there were 10 or more requests running at once, per the resource-0 log (which tracks the most recent resource log entries)

logparser "select top 10 * from resource-0.log where reqsrunning > 10 order by reqsrunning desc" -i:tsv -iheaderfile:resource-headers.txt -iseparator:space -nsep:1 -fixedsep:on -itsformat:"yyyy-MM-dd" -headerrow:off -rtp:-1

* List top 10 requests whose execution time exceeded 10 seconds, per the request-0 log (which tracks the most recent request log entries)

logparser "select top 10 * from request-0.log where exectime > 10000 order by exectime desc" -i:tsv -iheaderfile:request-headers.txt -iseparator:space -nsep:1 -fixedsep:on -itsformat:"yyyy-MM-dd" -headerrow:off -rtp:-1

* List top 10 queries whose total time exceeded 10 seconds, per the jdbc-0 log (which tracks the most recent jdbc log entries)

logparser "select top 10 * from jdbc-0.log where totaltime > 10000 and logtype='METRIC' order by totaltime desc" -i:tsv -iheaderfile:jdbc-headers.txt -iseparator:space -nsep:1 -fixedsep:on -itsformat:"yyyy-MM-dd" -headerrow:off -rtp:-1

(Note that you must enable JDBC logging in FusionReactor, which is not enabled by default. If you get this error, 'Error: WHERE clause: Semantic Error: content field "10000" doesn't match type of left-operand "totaltime"', that's the problem.

Also, when querying the JDBC log, note that there is a logtype column whose value is 'METRIC' for entries that track the end of a query's processing. It's important to add that to the WHERE clause, otherwise you may find entries for other logtype values, the records for which are added when the notifyAfter and/or remindAfter arguments are added to the JDBC URL as FR configuraiton options.)

* List URLs which have been executed more than 100 times, in order by the most hits, per day (and accounting for different request methods), across all request logs (not just the most recent)

logparser "select date, count(*) as hits, requrl, reqmethod from request-*.log where reqstatus='COMPLETED' group by date, requrl, reqmethod having hits > 100 order by date, hits desc" -i:tsv -iheaderfile:request-headers.txt -iseparator:space -nsep:1 -fixedsep:on -itsformat:"yyyy-MM-dd" -headerrow:off -rtp:-1

(Note that for tracking number of request executions, it's critical to recognize that FR's request log tracks an entry for both the start and end of a request, so for the request above, you want to look only at completed requests: and reqstatus='COMPLETED'.)

* List URLs whose average exectime is > 10 seconds, in order by slowest avg time, per day (and accounting for different request methods), across all request logs, with cols right-aligned 

logparser "select date, requrl, reqmethod, avg(exectime) as avgtime(ms) from request-*.log group by date, requrl, reqmethod having avgtime(ms) > 10000 order by date, avgtime(ms) desc" -i:tsv -iheaderfile:request-headers.txt -iseparator:space -nsep:1 -fixedsep:on -itsformat:"yyyy-MM-dd" -headerrow:off -rtp:-1 -ralign:on

(Note: the rest of the examples here also refer to all the FR log files (0-5, by default), not just the most recent (0) 

* List URLs with any requests where exectime > 10 secs, showing avg/min/max time, in order by number of executions per day  (and accounting for different request methods), across all request logs, with cols right-aligned 

logparser "select date, count(*) as hits, requrl, reqmethod, avg(exectime), min(exectime), max(exectime) from request-*.log where exectime > 10000 group by date, requrl, reqmethod order by date, hits desc" -i:tsv -iheaderfile:request-headers.txt -iseparator:space -nsep:1 -fixedsep:on -itsformat:"yyyy-MM-dd" -headerrow:off -rtp:-1 -ralign:on 

* List above for yesterday only

logparser "select date, count(*) as hits, requrl, reqmethod, avg(exectime), min(exectime), max(exectime) from request-*.log where exectime > 10000 and date=to_Date(SUB(to_localtime(SYSTEM_TIMESTAMP()),TIMESTAMP('2','d'))) group by date, requrl, reqmethod order by date, hits desc" -i:tsv -iheaderfile:request-headers.txt -iseparator:space -nsep:1 -fixedsep:on -itsformat:"yyyy-MM-dd" -headerrow:off -rtp:-1 -ralign:on 

(Note: to look at just today, change the value '2' in the TIMESTAMP() function to '1'. For the day before yesterday, make it '3', and so on. The to_localtime function must be used because the system_timestamp function will by default return the current date/time in UTC form, but the FR log dates are instead in local time.)

* List above for past 8 hours only

* List requests that exceed 2 minutes during past 8 hours

logparser "select date,time,requrl,reqmethod,exectime from request-*.log where date = to_Date(SUB(to_localtime(SYSTEM_TIMESTAMP()),TIMESTAMP('1','d'))) and substr(time,0,8) > to_string(SUB(to_localtime(SYSTEM_TIMESTAMP()),TIMESTAMP('8','h')),'hh:mm:ss') and exectime > 100000 order by date, time desc" -i:tsv -iheaderfile:request-headers.txt -iseparator:space -nsep:1 -fixedsep:on -itsformat:"yyyy-MM-dd" -headerrow:off -rtp:-1 -ralign:on

* List URLs with any requests where bytes >80k, showing avg/min/max bytes, in order by number of executions per day  (and accounting for different request methods), across all request logs, with cols right-aligned

logparser "select date, count(*) as hits, requrl, reqmethod, avg(bytes), min(bytes), max(bytes) from request-*.log where bytes > 80000 group by date, requrl, reqmethod order by date, hits desc" -i:tsv -iheaderfile:request-headers.txt -iseparator:space -nsep:1 -fixedsep:on -itsformat:"yyyy-MM-dd" -headerrow:off -rtp:-1 -ralign:on

* List URLs with any requests where jdbctotaltime (sum of all queries in a request) > 2 secs, showing avg/min/max jdbctotaltime, in order by number of executions per day  (and accounting for different request methods), across all request logs, with cols right-aligned

logparser "select date, count(*) as hits, requrl, reqmethod, avg(jdbctotaltime), min(jdbctotaltime), max(jdbctotaltime) from request-*.log where jdbctotaltime > 2000 group by date, requrl, reqmethod order by date, hits desc" -i:tsv -iheaderfile:request-headers.txt -iseparator:space -nsep:1 -fixedsep:on -itsformat:"yyyy-MM-dd" -headerrow:off -rtp:-1 -ralign:on

Contributions from Bill Shelton:

* * *

logparser "select top 1000 date, time, requrl, querystring, div(exectime,1000) as et, div(jdbctotaltime,1000) as jdbcet, statuscode into mylog.csv from request-0.log order by et desc" -i:TSV -iSeparator:space -iHeaderFile:request-headers.txt -o:csv 

 * * *

Here's a command I used for some postmortem this week. It gets 65000 rows from the crashprotection-n.log and puts it into a csv file that I can open and play around with in Excel. Note that Excel allows a max of 65000 (plus change) rows.

Note, you might need to scroll right to get full line of logparser command.

logparser file:cp_summary_daterange_csv.sqlsrc=crashprotection-0.log+dest=crash_test_dummy.csv+start\\0752008-03-17+end\\0752008-03-18 -i:TSV -iSeparator:space -iHeaderFile:crashprotection-headers.txt -o:csv

Note the file command-line option and the http url-like syntax for parameters. The %start% param is the start of a date range and the %end% is the end of the date range. 

The cp_summary_daterange_csv.sql sql file looks like this:

select top 65000 date,time,mempct,clientip,exectime,cptype,action,requrl,querystring 
  into %dest%
  from %src%
where date between '%start%' and '%end%'
order by date,time,mempct,exectime desc

Note that the %src% param can use a network location; I just happen to have copied locally for analysis. Likewise, the %dest% param can be somewhere else, too.

* * *

 Uploading FusionReactor log file data to a SQL Server database

LogParser "SELECT * INTO RequestLog FROM \\myserver\FusionReactor\instance\myinstance.name\log\request-*.log" -i:TSV -iSeparator:space -iheaderfile:request-headers.txt -iCheckPoint:request-log-checkpoint.lpc -o:SQL -server:MySqlServer  -database:MyFusionReactorDb -createTable:Off -headerRow:off -transactionRowCount:1000

 The INTO RequestLog indicates the table name. The credentials are the account under which LogParser is running, or the user logged in. In this example, LogParser will not attempt to create the table, but you can set the -createTable: option to ON and LogParser will attempt to create the table. The -iCheckpoint:file-name instructs LogParser not to re-scan all the log files on subsequent reads. This is very handy!

Ant Task Wrapper for LogParser (FR + Ant + LogParser = Frantic)

This is a hack I put together last year (2008), but it's what I use at work when they run frantically into my office and want to know why something is coming to a halt. It generates canned reports and allows you to do some adhoc queries. If you know your way around Ant, this should seem familiar and you can easily build in some lower level automation.

Notes:

If you'd like offer your own LP commands, feel free to edit this document (assuming you're a member of the FusionReactor Google Group), adding new items at the bottom of the info above. If you're a member and find you can't edit this file, you may want to confirm that you are logged into groups.google.com using the same address with which you receive the FR group emails.

If you're using FR 2, there is now also a page for using Log Parserwith FR 2: http://groups.google.com/group/fusionreactor/web/log-parser-files-for-fr-2 .

If you're using FR 3.0.1, the -headers.txt files have been updated to reflect the slight changes (primarily, an addition of a srvstartts column, and a change in the value of the version column form 3 to 4.) Just be aware that you may still have some data in your logs from when you were running 3.0, which could cause errors with the examples below. If you get such errors, look carefully at your logs to see if you have entries with the version column set to 3. If so, you may want to remove them into their own log. To do so, stop CF (or your J2EE server) and copy the log file in question and give it a new name, then open that file to remove the new entries, and open the original FR log file to remove the older entries. This way you can still analyze the old log files, though you'll need to find or create headers.txt files to correspond to that old format (or maybe someone still running 3.0 can post that versions header files here).