ibm-netrexx

Re: jEdit performance problem - blame it on "options trace2"

Classic

List

Threaded

1 message

kenner

Re: jEdit performance problem - blame it on "options trace2"

This is with debug turned on in every method from the jEdit Netrexx log.

C:\Program Files\Java\jre7\bin\javaw.exe -cp .;C:\Users\KEKLEIN\REXX\NetRexx\jEdit\jars\NetRexxC.jar;C:\Program Files\Java\jdk1.7.0_05\lib\tools.jar;C:\Users\KEKLEIN\REXX\NetRexx\jEdit\jedit.jar Filter_Date rmf.report.rolledup.txt

arg ===> rmf.report.rolledup.txt

Fri May 17 13:27:15 EDT 2013

Current time: 1368811635213

Elapsed time: 0

Processing rmf.report.rolledup.txt...

Processed another 100 records.

Elapsed time: 0

Processed another 100 records.

Elapsed time: 0

Processed another 100 records.

Elapsed time: 1

Processed another 100 records.

Elapsed time: 2

Processed another 100 records.

Elapsed time: 3

500 lines written

Elapsed time: 3

=> Finished <=

This is with debug turned off in every method.

arg ===> rmf.report.rolledup.txt

Fri May 17 13:26:05 EDT 2013

Current time: 1368811565862

Elapsed time: 0

Processing rmf.report.rolledup.txt...

Processed another 100 records.

Elapsed time: 0

Processed another 100 records.

Elapsed time: 0

Processed another 100 records.

Elapsed time: 0

Processed another 100 records.

Elapsed time: 0

Processed another 100 records.

Elapsed time: 0

500 lines written

Elapsed time: 0

=> Finished <=

AHA!

With the debug turned on and options trace2:

arg ===> rmf.report.rolledup.txt

Fri May 17 14:04:51 EDT 2013

Current time: 1368813891996

Elapsed time: 0

Processing rmf.report.rolledup.txt...

Processed another 100 records.

Elapsed time: 0.098

Processed another 100 records.

Elapsed time: 0.45

Processed another 100 records.

Elapsed time: 1.025

300 lines written

Elapsed time: 1.03

=> Finished <=

With the debug still turned on and options trace1:

129 *=* numeric digits 9

>>> "9"

130 *=* delta=delta.format(null,3)

>>> "3"

>v> delta "0.008"

131 *=* -- delta=(delta+totalMinutes) %1

132 *=* return delta

>>> "0.008"

>>> "Elapsed time: 0.008"

Elapsed time: 0.008

46 *=* exit

=> Finished <=

/* This is a sample file input and output program, showing how to open,

check, and process text files, and handle exceptions.

Note the use of the Reader and Writer classes, which convert your

local computer's 'code page' (character encoding) to Unicode during

reading and back again during writing. */

options verbose4 trace1 logo

import java.util.Date

import java.text.

import java.text.DateFormat

import java.text.SimpleDateFormat

class Filter_Date

properties inheritable static

Start_Time = long

inhandle=BufferedReader

outhandle=OutputStreamWriter

linesep=System.getProperty('line.separator') -- be platform-neutral

fin = string

letterNum = 0

Debug_Level = 100

trace methods

method main(arg=String[]) static public

if Debug_Level > 90 then trace var fin Delta fName fileName

if Debug_Level > 50 then trace results

if arg.length = 0 then do

say '# Please specify input file.'

exit 1

end

fin = arg[0]

loop letterNum = 1 by 1 to arg.length - 1

fin = fin || arg[letterNum]

end

say "arg ===>" fin

-- parse arg fin -- get the arguments: input and output files

if fin='' then do

say '# Please specify input file.'

exit 1

end

Start_Time = reset()

Filter_Date(fin)

method Filter_Date(fName)

if Debug_Level > 30 then trace results

FileHandles(fName)

FileScanned()

say "Elapsed time:" elapsed()

exit

/* Open and check the files */

Method FileHandles(fileName)

if Debug_Level > 30 then trace results

say "Current time:" Start_Time

say "Elapsed time:" elapsed()

infile=File(fileName)

instream=FileInputStream(infile)

inhandle=BufferedReader(InputStreamReader(instream))

outfile=File(fileName || ".new")

outstream=FileOutputStream(outfile)

outhandle=OutputStreamWriter(outstream)

say 'Processing' infile'...'

catch e=IOException

say '# error opening file' e.getMessage

exit

end

/* The main processing loop */

method FileScanned()

if Debug_Level > 30 then trace results

loop linenum=1 by 1 to 300

if linenum // 100 = 0 then do

say "Processed another 100 records."

say "Elapsed time:" elapsed()

end

theLine=Rexx inhandle.readLine -- get next line [as Rexx string]

if theLine=null then leave linenum -- normal end of file

parse theLine sysId dateIn timeIn theRest -- process the line

fd = SimpleDateFormat("E") /* day of the week */

dt = fd.format(Date(dateIn))

-- if Debug_Level > 70 then say dt

-- //formatting Month in MMM format like Jan, Feb etc.

strDateFormat = "MMM";

sdf = SimpleDateFormat(strDateFormat);

theMonth = sdf.format(Date(dateIn));

if Debug_Level > 140 then say "Current Month in MMM format : " theMonth

strDateFormat = "YY";

sdf = SimpleDateFormat(strDateFormat);

theYear = sdf.format(Date(dateIn));

if Debug_Level > 140 then say "Current Year in YY format : " theYear

strDateFormat = "w";

sdf = SimpleDateFormat(strDateFormat);

theWeek = sdf.format(Date(dateIn));

if Debug_Level > 140 then say "Current Week in 1-53 format : " theWeek

if dt="Sat" then iterate linenum -- skip the wkends

if dt="Sun" then iterate linenum -- skip the wkends

if (theMonth = "May") & (theYear \= 12) then iterate linenum -- skip May in 2011 and 2013

if linenum>1 then outhandle.write(linesep, 0, linesep.length)

outLine = sysId dateIn theWeek timeIn theRest

outhandle.write(outLine, 0, outLine.length)

catch e=IOException

say '# error reading or writing file' e.getMessage

catch RuntimeException

say '# processing ended due to -RuntimeException-.'

finally do -- close files

if inhandle\=null then inhandle.close

if outhandle\=null then outhandle.close

catch IOException

-- ignore errors during close

end

end linenum

say linenum-1 'lines written'

method reset() public static returns long

if Debug_Level > 30 then trace results

TimeNow = System.currentTimeMillis()

say Date()

return TimeNow

method elapsed() public static returns float

if Debug_Level > 30 then trace results

current=System.currentTimeMillis()

numeric digits 16

delta = current - Start_Time

delta=delta/60000

numeric digits 9

delta=delta.format(null,3)

-- delta=(delta+totalMinutes) %1

return delta

From: [hidden email] [mailto:[hidden email]] On Behalf Of Kermit Kiser
Sent: Wednesday, May 15, 2013 7:08 PM
To: IBM Netrexx
Subject: Re: [Ibm-netrexx] jEdit performance problem

Kenneth --

I managed to get your sample program to run although I had to move the close for the output file to after the write call for the final line.

Unfortunately, I still cannot duplicate the problem you are seeing. Whether I run your program from batch or from jEdit inside it's VM or in a separate VM or even interpreted, it successfully completes in an elapsed time too small for me to measure.

Granted my system is fairly fast (win7 AMD hexcore at 3+ GHz), I don't think that is a factor. You may have a memory problem or something. I don't know what to look at now. Perhaps if you could tell what type system you are using (OS, processor, speed, memory) and what version of Java, jEdit, and NetRexx you have, I could look more closely.

-- Kermit

On 5/15/2013 1:20 AM, Kenneth Klein (TEMA TPC) wrote:

Thanks, Bill.

KK, I tested with 0.2.14 and got the same results, just as extreme.

From: [hidden email] [[hidden email]] On Behalf Of Kermit Kiser
Sent: Monday, May 13, 2013 2:25 PM
To: IBM Netrexx
Subject: Re: [Ibm-netrexx] jEdit performance problem

Sorry about the delay - had some other pressing issues to handle.

The NetRexx plugin that I am running shows version 0.2.14 - I doubt that the difference affects this issue but it is worth checking out.

Latest jar is here:

https://kenai.com/projects/netrexx-plus/downloads/download/jEdit%20NetRexxPlugin/NetRexxPlugin.jar

I will see if I can duplicate the problem and isolate a cause as soon as I can get the time.

-- Kermit

On 5/10/2013 2:26 AM, Kenneth Klein (TEMA TPC) wrote:
1)      ?? I dunno. I installed this stuff over a year ago, maybe longer. How can I tell? About jEdit says “5.0.0”. Plugin Manager shows NetRexx plugin to be at 0.2.11. Is there a newer one?

2)      I just click on the little badge icon, or is it an arrow head, and then the triangle and off it goes.

3)      Never looked at it before, it is still unchecked.

4)      Working code below. Running on windoze 7. I should add that even with trace results and trace var for a slew of variables the program runs outside of jEdit in a minute or two.

/* This is a sample file input and output program, showing how to open,

   check, and process text files, and handle exceptions.

   Note the use of the Reader and Writer classes, which convert your

   local computer's 'code page' (character encoding) to Unicode during

   reading and back again during writing. */

options verbose4 trace3 logo

import java.util.Date

import java.text.

import java.text.DateFormat

import java.text.SimpleDateFormat

import java.io

class Percent_CPU_minutes_per_day_per_LPAR

            properties static

                        savedCP1A_Minutes

                        savedCP1C_Minutes

                        savedCP1D_Minutes

                        savedCP1F_Minutes

                        savedCP1H_Minutes

                        savedCP1K_Minutes

                        savedCP1L_Minutes

                        savedCP1S_Minutes

                        savedCP1U_Minutes

                        savedCP1Z_Minutes

                        sysId = ''

                        dateIn = ''

                        theWeek = 01

                        theYear = 01

                        fin = string

                        outline = string

                        inhandle = BufferedReader

                        outhandle = BufferedWriter

                        linesep = string

                        linesWritten = int 0

                        Debug_Level = 55 -- pretty serious debugging

method main(arg=string[]) static

            filename = "rmf.report.rolledup.txt"

            Percent_CPU_minutes_per_day_per_LPAR(filename)

method Percent_CPU_minutes_per_day_per_LPAR(arg=string) signals IOException

if Debug_Level > 50 then trace results

if Debug_Level > 10 then trace var -

      savedWeek theWeek -

      savedYear theYear -

            percentA_Minutes -

      percentC_Minutes -

      percentD_Minutes -

      percentF_Minutes -

      percentH_Minutes -

      percentK_Minutes -

      percentL_Minutes -

      percentS_Minutes -

      percentU_Minutes -

      percentZ_Minutes -

      linesep

parse arg fin .   -- get the arguments: input and output files

if fin='' then do

say '# Please specify input file.'

exit 1

end

/* Open and check the files */

do

            if Debug_Level > 30 then say "fin= " fin

            inhandle=BufferedReader(FileReader(fin))

          outhandle=BufferedWriter(FileWriter(fin || '.new'))

          say 'Processing' fin

catch Z=IOException --, X=FileNotFoundException

            say '# error opening file' Z.getMessage

end

linesep=System.getProperty('line.separator') -- be platform-neutral

/* The main processing loop */

savedWeek = 99

savedYear = 999

      firstWeek = 1

      savedCP1A_Minutes = 0

      savedCP1C_Minutes = 0

      savedCP1D_Minutes = 0

      savedCP1F_Minutes = 0

      savedCP1H_Minutes = 0

      savedCP1K_Minutes = 0

      savedCP1L_Minutes = 0

      savedCP1S_Minutes = 0

      savedCP1U_Minutes = 0

      savedCP1Z_Minutes = 0

loop linenum=1 by 1 -- to 1000

theLine=Rexx inhandle.readLine           -- get next line [as Rexx string]

if theLine=null then leave linenum       -- normal end of file



  parse theLine sysId dateIn timeIn CP1A_Minutes -

                                    CP1C_Minutes -

                                    CP1D_Minutes -

                                    CP1F_Minutes -

                                    CP1H_Minutes -

                                    CP1K_Minutes -

                                    CP1L_Minutes -

                                    CP1S_Minutes -

                                    CP1U_Minutes -

                                   CP1Z_Minutes -

                                    CF1_Minutes CF2_Minutes MVS_percent LPAR_percent

      fd = SimpleDateFormat("E") /* day of the week */

      dt = fd.format(Date(dateIn))

      if Debug_Level > 70 then say dt

-- //formatting Month in MMM format like Jan, Feb etc.

          strDateFormat = "MMM";

     sdf = SimpleDateFormat(strDateFormat);

     theMonth = sdf.format(Date(dateIn));

     if Debug_Level > 40 then say "Current Month in MMM format : " theMonth



     strDateFormat = "YY";

     sdf = SimpleDateFormat(strDateFormat);

     theYear = sdf.format(Date(dateIn));

     if Debug_Level > 40 then say "Current Year in YY format : " theYear



     strDateFormat = "w";

     sdf = SimpleDateFormat(strDateFormat);

     theWeek = sdf.format(Date(dateIn));

     if Debug_Level > 40 then say "Current Week in 1-53 format : " theWeek

     if linenum=1 then do

            savedWeek = theWeek

            savedYear = theYear

     end



  if dt="Sat" then iterate linenum       -- skip the wkends

if dt="Sun" then iterate linenum       -- skip the wkends

  savedCP1A_Minutes = savedCP1A_Minutes + CP1A_Minutes

savedCP1C_Minutes = savedCP1C_Minutes + CP1C_Minutes

savedCP1D_Minutes = savedCP1D_Minutes + CP1D_Minutes

savedCP1F_Minutes = savedCP1F_Minutes + CP1F_Minutes

savedCP1H_Minutes = savedCP1H_Minutes + CP1H_Minutes

savedCP1K_Minutes = savedCP1K_Minutes + CP1K_Minutes

savedCP1L_Minutes = savedCP1L_Minutes + CP1L_Minutes

savedCP1S_Minutes = savedCP1S_Minutes + CP1S_Minutes

savedCP1U_Minutes = savedCP1U_Minutes + CP1U_Minutes

savedCP1Z_Minutes = savedCP1Z_Minutes + CP1Z_Minutes



  if theWeek > savedWeek | theYear > savedYear | firstWeek then do

            WriteTheRecord()

      savedWeek = theWeek

      savedYear = theYear

      savedCP1A_Minutes = 0

      savedCP1C_Minutes = 0

      savedCP1D_Minutes = 0

      savedCP1F_Minutes = 0

      savedCP1H_Minutes = 0

      savedCP1K_Minutes = 0

      savedCP1L_Minutes = 0

      savedCP1S_Minutes = 0

      savedCP1U_Minutes = 0

      savedCP1Z_Minutes = 0

      firstWeek = 0

      end -- the do when the week number changes.

      catch e=IOException

              say '# error reading or writing file' e.getMessage

      catch RuntimeException

              say '# processing ended due to -RuntimeException-.'

      finally do                              -- close files

              if inhandle\=null then inhandle.close

              if outhandle\=null then outhandle.close

          -- ignore errors during close

      end -- the finally do

end linenum

WriteTheRecord() -- write the last record out to the file

say linenum-1 'records read'

method WriteTheRecord() public signals IOException

if Debug_Level > 50 then trace results

do

            percentA_Minutes = 100 * savedCP1A_Minutes / (7 * 5 * 24 * 60)

      percentC_Minutes = 100 * savedCP1C_Minutes / (7 * 5 * 24 * 60)

      percentD_Minutes = 100 * savedCP1D_Minutes / (7 * 5 * 24 * 60)

      percentF_Minutes = 100 * savedCP1F_Minutes / (7 * 5 * 24 * 60)

      percentH_Minutes = 100 * savedCP1H_Minutes / (7 * 5 * 24 * 60)

      percentK_Minutes = 100 * savedCP1K_Minutes / (7 * 5 * 24 * 60)

      percentL_Minutes = 100 * savedCP1L_Minutes / (7 * 5 * 24 * 60)

      percentS_Minutes = 100 * savedCP1S_Minutes / (7 * 5 * 24 * 60)

      percentU_Minutes = 100 * savedCP1U_Minutes / (7 * 5 * 24 * 60)

      percentZ_Minutes = 100 * savedCP1Z_Minutes / (7 * 5 * 24 * 60)

            outLine = sysId dateIn theWeek savedCP1A_Minutes.format(5,2) -

                                                                                                          savedCP1C_Minutes.format(5,2) -

                                    savedCP1D_Minutes.format(5,2) -

                                    savedCP1F_Minutes.format(5,2) -

                                    savedCP1H_Minutes.format(5,2) -

                                    savedCP1K_Minutes.format(5,2) -

                                    savedCP1L_Minutes.format(5,2) -

                                    savedCP1S_Minutes.format(5,2) -

                                    savedCP1U_Minutes.format(5,2) -

                                    savedCP1Z_Minutes.format(5,2) -

                                    percentA_Minutes.format(5,2) -

                                    percentC_Minutes.format(5,2) -

                                    percentD_Minutes.format(5,2) -

                                    percentF_Minutes.format(5,2) -

                                    percentH_Minutes.format(5,2) -

                                    percentK_Minutes.format(5,2) -

                                    percentL_Minutes.format(5,2) -

                                    percentS_Minutes.format(5,2) -

                                    percentU_Minutes.format(5,2) -

                                    percentZ_Minutes.format(5,2) -

                                   (percentA_Minutes.format(5,2) + -

                                    percentC_Minutes.format(5,2) + -

                                    percentD_Minutes.format(5,2) + -

                                    percentF_Minutes.format(5,2) + -

                                    percentH_Minutes.format(5,2) + -

                                    percentK_Minutes.format(5,2) + -

                                    percentL_Minutes.format(5,2) + -

                                    percentS_Minutes.format(5,2) + -

                                    percentU_Minutes.format(5,2) + -

                                    percentZ_Minutes.format(5,2))

                                    -- CF1_Minutes CF2_Minutes MVS_percent LPAR_percent

      outhandle.write(outLine, int 0, outLine.length)

            outhandle.write(linesep, int 0, linesep.length)

            linesWritten = linesWritten + 1

              say linesWritten 'lines written'

            catch e=IOException

                        say '# error reading or writing file' e.getMessage

            catch RuntimeException

                        say '# processing ended due to -RuntimeException-.'

end -- of the write method

return

Data input looks like this.

CP1C 05/22/2011 00.00.00 1.06673333 5.63965 1.12473333 3.36356667 5.92073333 1.05851667 0.743516667 1.04328333 1.0913 0.675883333 0 0 6.31 6.41

CP1C 05/22/2011 00.30.00 1.05656667 12.3385833 1.1176 5.46706667 1.55308333 1.0248 0.68035 1.05033333 1.0962 0.686533333 0 0 13.78 13.98

CP1C 05/22/2011 01.00.00 1.23403333 13.5865833 1.27228333 3.50931667 3.17801667 1.21045 0.745016667 1.23228333 1.30766667 0.839883333 0 0 15.21 15.45

CP1C 05/22/2011 01.30.00 1.08826667 11.60555 1.26056667 10.43555 1.64288333 1.19426667 0.77275 1.21945 1.2818 0.84645 0 0 13.01 13.20

CP1C 05/22/2011 02.00.00 3.73188333 14.7386333 2.37851667 50.2841 1.87278333 4.97086667 0.925883333 2.6139 4.1597 0.950533333 0 0 16.49 16.66

CP1C 05/22/2011 02.30.00 8.9105 14.7110833 3.07421667 42.2248167 2.47958333 3.87048333 1.03523333 14.543 5.68586667 1.01661667 0 0 16.45 16.58

CP1C 05/22/2011 03.00.00 1.71783333 12.898 3.4578 25.9902833 2.6842 9.619 1.28545 16.1819333 15.6703333 0.974783333 0 0 14.44 14.50

From: [hidden email] [[hidden email]] On Behalf Of Kermit Kiser
Sent: Thursday, May 09, 2013 4:48 PM
To: IBM Netrexx
Subject: Re: [Ibm-netrexx] jEdit performance problem

Hi Kenneth --

Can you verify some things for me?

1) Are you using the new NetRexx plugin that merges the compiler and interpreter plugins together?
2) Did you compile the program before running it or are you interpreting it?
3) On the NetRexx plugin options screen for the Compiler, have you checked the box titled "Run compiled classes in jEdit rather than a separate Java environment?"
4) Can you provide a sample program to duplicate the problem?

Unfortunately the help files for the new plugin are out of date, but if you run compiled programs in a separate Java, the technique used to capture program output there is rather inefficient.

-- Kermit

On 5/9/2013 2:24 AM, Kenneth Klein (TEMA TPC) wrote:
When I run a program under Jedit using the netrexx plugin and trace results turned on, my poor quad core processor runs 1 cpu at 25% in javaw.exe and the netrexx output area displays my “say” statements at a rate of about one record per minute. Jedit response time is minute-long. Is this normal?
_______________________________________________
Ibm-netrexx mailing list
[hidden email]
Online Archive : http://ibm-netrexx.215625.n3.nabble.com/
 
_______________________________________________
Ibm-netrexx mailing list
[hidden email]
Online Archive : http://ibm-netrexx.215625.n3.nabble.com/
 
_______________________________________________
Ibm-netrexx mailing list
[hidden email]
Online Archive : http://ibm-netrexx.215625.n3.nabble.com/
 

_______________________________________________
Ibm-netrexx mailing list
[hidden email]
Online Archive : http://ibm-netrexx.215625.n3.nabble.com/