Sitworld: tacmd logs summary

Version 0.50000 31 December 2015

John Alvord, IBM Corporation

jalvord@us.ibm.com

Follow on twitter

Inspiration

I recently worked a case where a suspicion arose whether some tacmd functions were causing problems at a hub TEMS. The information was available in a big collection of tacmd diagnostic trace files, like kuiras1_sysadmin_hextime-01.log. However there were thousands of them at the hub TEMS and a manual review was just too much to think about.

Background

Like many such projects I had another program to work as a template. In my Situation Audit tests, I have a regression suite and a summary program to report on all the regression tests. That had the “search a collection of files and make a list of file names” logic. Scraping through logs just needed some decisions about what to capture and I picked

1) Start Date and Time

2) userid used to authenticate the request

3) Whatever was recorded about the function

4) elapsed time estimate

5) Log Name

I simplified the logic by just working on the current directory.

Preparing for the install

Perl is usually pre-installed in Linux/Unix systems. . For Windows you may need to install from www.activestate.com or any other source. The program only uses Perl core services and no CPAN modules are needed.

tacmd summary has been tested with

This is perl 5, version 20, subversion 1 (v5.20.1) built for MSWin32-x64-multi-thread

zLinux with Perl v5.8.7

A zip file is found found kuiras1_sum.0.50000. There is one file kuiras1_sum.pl. Install it somewhere convenient.

Run Time Options

Options:

-h                           display help information

-v                           Produce some progress messages in STDERR

The report is written to kuiras1_sum.csv in the current directory.

Run command example:

perl kuiras1_sum.pl -v

Sample Report

2015/11/20 10:07:00,jga12624,[executecommand],1800,kuiras1_jga12624_564f3714-01.log,

2015/11/20 10:08:31,jga12624,[executecommand],1801,kuiras1_jga12624_564f376f-01.log,

2015/11/20 10:16:34,jga12624,[executecommand],0,kuiras1_jga12624_564f3952-01.log,

2015/11/20 10:21:36,jga12624,[executecommand],0,kuiras1_jga12624_564f3a80-01.log,

2015/11/20 10:24:07,jga12624,[executecommand],1,kuiras1_jga12624_564f3b17-01.log,

2015/11/20 10:38:11,jga12624,[executecommand],0,kuiras1_jga12624_564f3e63-01.log,

2015/11/20 10:45:49,jga12624,[executecommand],1801,kuiras1_jga12624_564f402d-01.log,

Note the report is in ascending sorted order by the start date/time. The interesting thing here is that 3 of the 7 executeCommands took about 1800 seconds to complete. That is suspiciously close to a timeout condition and might need further investigation. That function executecommand actually requires 9 SQLs and can be quite intensive.

In real usage, I correlated this data with an Unix performance capture script and found one function that sometimes caused a TEMS process size growth.

Summary

Summarize tacmd diagnostic logs.

Versions:

Here are recently published versions, In case there is a problem at one level you can always back up.

kuiras1_sum.0.50000
Initial Release

Sitworld: Table of Contents

Note: Rascal, Jr – waiting in April 2004