Saturday, January 19, 2008

Logparser for J.D.Edwards

Those who know me know that I come from a background of developing for Microsoft platforms.  Part of my role as a solution architect for Mary Kay Supply Chain is to understand, as much as possible, about all of our applications - even those that are non-Microsoft.  Heck, most of them are applications that were originally built for other platforms and then ported to Windows. That means when debugging these applications, I tend to fall back to the basics.  Things that, as .NET developers (yes, I think of myself that way), we tend to push back into the foggy recesses of forgotten experiences: memory management, process and external libraries (dynamic and statically linked), message pumps, a plethora of other details, and just plain basic understanding of TCP/IP.  I'm not even counting Java here.  Our Java footprint is very small, but still very significant in the overall business - but at least we own the source code for the majority of that code, and if you have access to code, your done.

LogParser has been an incredibly useful support tool.  I’ve been using it, more and more, to query Windows Event logs, Registry Keys, IIS Logs, custom application logs, and of course, J.D. Edwards Application logs (there is a point to this post!).  LogParser can be used to query just about any data store out there (some take more ingenuity than others!).

In order to use LogParser, you need to download it and install it on a machine.  It can be any machine.  Once its installed, you can then deploy it by just file copying the LogParser binaries (*.exe/*.dll/*.chm).  Mary Kay standard server build has a 'tools' folder, and I have been ‘deploying’ it to there as needed.  If in doubt about how to do something, the help file is incredibly useful and concise.

Download LogParser.

In many cases, it can be used to query files across a UNC path, however, I wouldn’t recommend it across a WAN (e.g. Dallas Data Center to Shanghai Data Center).  Mary Kay has a MPLS WAN connection between Dallas and Shanghai that experiences latency of about 135ms to 500ms (depending on time of day), which means sometimes you can get away with this, others you can't.  If you log into a server in the remote data center, you can then effectively query across all UNC paths with almost no delay.   

Below are a few of the queries that I use against JDE Application Logs.  These queries make it easy to find relevant information from sometimes HUGE JDE log files.  It will scan a 100MB file in seconds.  If DEBUG=FILE, in the JDE.INI, then files can actually reach Gigabytes in size.  Most of which is 'chatter' your not interested in.  Logparser makes it simple to 'rip apart' the log files and get to the meat of what you need to know.  Some of these queries are iterative, meaning I take a rinse and repeat approach.  I've been experimenting with Powershell, and its ability to pipe the results into additional statements for processing, and think I can shorten these down to one, or two, queries.  If I do, I'll post that.

In some of the samples below, I use the our test data directory repository as a specific example of querying a UNC path.  If you have multiple servers to check, its very easy to “up arrow” and change the specific value in the path (e.g. server name).  Note, for MK employees, that folder has been fudged to protect the innocent, even though I'm ignorant enough to not understand what would be hackers could do with that information!

 

Display Kernel Type + PID


Here we quickly identify what PID is a particular kernel (jdenet_k.exe) type.  JDE uses a generic process to host application code.  Think of services.exe, or dllhost.exe.  By looking at the process, you usually can't determine WHAT is actually running in the process.  The process, or kernel, logs will host this information.  From an application developer perspective, we are predominately concerned with what are called 'call object' kernels.  This is where the business logic will be executed.  Sometimes, in the event of a serious application exception, a kernel will be 'zombied'.  Basically, you need to identify it and end the process.  JDE will automatically spin up a replacement process.

logparser "SELECT EXTRACT_FILENAME(LogFileName) AS LogFile, SUBSTR(Text, 25) AS KernelType  FROM jde_*.log WHERE Text LIKE '%Starting Kernel of Type:%' ORDER BY KernelType"  -i:TEXTLINE -rtp:-1

 

Fields Returned
•    LogFile  - Log file name (includes PID information).
•    KernelType – the type of kernel the PID belongs to.

Output
LogFile       KernelType
------------- --------------------
jde_27696.log CALL OBJECT KERNEL
jde_27608.log CALL OBJECT KERNEL
jde_4280.log  CALL OBJECT KERNEL
jde_15040.log CALL OBJECT KERNEL
jde_14036.log CALL OBJECT KERNEL
jde_8280.log  CALL OBJECT KERNEL
jde_14024.log CALL OBJECT KERNEL
jde_12752.log CALL OBJECT KERNEL
jde_8560.log  CALL OBJECT KERNEL
jde_8820.log  CALL OBJECT KERNEL
jde_10100.log QUEUE KERNEL
jde_12668.log SAW KERNEL
jde_22688.log SECURITY KERNEL
jde_716.log   SECURITY KERNEL
jde_13984.log SECURITY KERNEL
jde_2420.log  UBE SUBSYSTEM KERNEL
jde_8148.log  XML DISPATCH KERNEL
jde_5424.log  XML DISPATCH KERNEL
jde_2336.log  XML DISPATCH KERNEL
jde_27356.log XML DISPATCH KERNEL
jde_21712.log XML DISPATCH KERNEL
jde_20420.log XML DISPATCH KERNEL
jde_19676.log XML DISPATCH KERNEL
jde_11412.log XML DISPATCH KERNEL
jde_10896.log XML DISPATCH KERNEL
jde_28156.log XML DISPATCH KERNEL

 

Find “Call Stacks”

Here we are searching for the text “====>” associated with a call stack (stack dump); I’ve also used “ACCESS_VIOLATION” as a delimiter in the WHERE clause.  Once we have obtained the Index (line number)of the call stack, we can dump further information.

logparser "SELECT EXTRACT_FILENAME(LogFileName) AS LogFile, Index FROM \\shares\ART\TestResults\TestRun135\logs\JDE\SERVER01\jde_*.log WHERE TEXT LIKE '%====>%'" -i:TEXTLINE  -rtp:-1

Fields Returned
•    LogFile – Log file that contains a ‘call stack’ – or match to our WHERE clause.
•    Index – the line number matching the delimiter.

Output
LogFile                       Index
----------------------------- -----
jde_2432.log                  3119
jde_2836.log                  1898
jde_3020.log                  3080
jde_3992.log                  1937
jde_5948.log                  2405
jde_6076.log                  2822

 

Find “Call Stack Information”

Armed with the a log file that contains a call stack, and the beginning line number, we can dump out the relevant contents.  Sometimes its easier to redirect this output to a file, then view that information in notepad.  E.g. append “> callstack.txt” to the query below.  Notice that we are plugging in the value ‘3119’, which was returned from our previous query.  I use the ADD function as a simple way to indicate I want to grab the next [n] lines.

logparser "SELECT EXTRACT_FILENAME(LogFileName) AS LogFile, Index, Text FROM \\shares\ART\TestResults\TestRun135\logs\JDE\SERVER01\jde_2432.log WHERE Index BETWEEN 3119 AND ADD(3119, 15)" -i:TEXTLINE -rtp:-1

Fields Returned
•    LogFile – Log file Name.
•    Index – Line number.
•    Text – line information.

Output
LogFile      Index Text
------------ ----- -----------------------------------------------------------------------------------
jde_2432.log 3119    ====> Exception occurred with call stack:
jde_2432.log 3120  -
jde_2432.log 3121    JDECM_GetNumRecords+AE                D:\PeopleSoft\E811\DDP\system\bin32\jdekrnl.dll
jde_2432.log 3122    jdeCacheOpenCursorX+F4                D:\PeopleSoft\E811\DDP\system\bin32\jdekrnl.dll
jde_2432.log 3123    F4211SalesOrderAgreementCache+1B7     D:\PeopleSoft\E811\DDP\ART811\bin32\CDIST.dll
jde_2432.log 3124    jdeCallObjectV2+3EDE                  D:\PeopleSoft\E811\DDP\system\bin32\jdekrnl.dll
jde_2432.log 3125    jdeCallObject+36                      D:\PeopleSoft\E811\DDP\system\bin32\jdekrnl.dll
jde_2432.log 3126    VerifyAndGetLocationMaster+CEA2       D:\PeopleSoft\E811\DDP\ART811\bin32\COPBASE.dll
jde_2432.log 3127    F4111ClearDetailStack+C59             D:\PeopleSoft\E811\DDP\ART811\bin32\COPBASE.dll
jde_2432.log 3128    jdeCallObjectV2+3EDE                  D:\PeopleSoft\E811\DDP\system\bin32\jdekrnl.dll
jde_2432.log 3129    jdeCallObject+36                      D:\PeopleSoft\E811\DDP\system\bin32\jdekrnl.dll
jde_2432.log 3130    F4113FSClearWorkFile+F5               D:\PeopleSoft\E811\DDP\ART811\bin32\COPBASE.dll
jde_2432.log 3131    jdeCallObjectV2+3EDE                  D:\PeopleSoft\E811\DDP\system\bin32\jdekrnl.dll
jde_2432.log 3132    jdeCallObject+36                      D:\PeopleSoft\E811\DDP\system\bin32\jdekrnl.dll
jde_2432.log 3133    dcLINKInventoryTransfers+3863         D:\PeopleSoft\E811\DDP\ART811\bin32\CBUSPART.dll
jde_2432.log 3134  -

No comments:

Post a Comment