× The internal search function is temporarily non-functional. The current search engine is no longer viable and we are researching alternatives.
As a stop gap measure, we are using Google's custom search engine service.
If you know of an easy to use, open source, search engine ... please contact support@midrange.com.


  • Subject: RE: Character to Decimal With CVTEFN - Performance Data
  • From: "Richard Jackson" <richardjackson@xxxxxxxxxxxxxxxxxx>
  • Date: Wed, 23 Aug 2000 15:42:39 -0600
  • Importance: Normal

I'm not ignoring you - at least not on purpose :)  As you already know, the
problem is in the error handling.

I just printed this stuff and did a quick analysis.  I think that it does
something like this when it fails.

1. CVTEFN detects the fault
2. CVTEFN sends a failure message to the previous invocation (the RPG
program)
3. The send message notices that the RPG program does not contain a handler
for this error.
4. The process default exception handler is called, he nukes the CVTEFN
invocation
5. The general error handler in the RPG program is invoked
6. he receives the error message and ignores it
7. the next sequential instruction following the call is executed

I don't have a trace of this so I'm using some very tired brain cells but I
think that the receive (QMHRCVPM) calls QWCSCVTR and QMHRTMSS.  This is a
pretty standard way of killing a called routine on the AS/400 but it is a
hugely expensive undertaking for a crashed MI instruction.  If you take a
close look at the "bad data" run, you will notice that the RPG program run
time changed from 35 microseconds per iteration to 730 microseconds per
iteration (a 20x increase) but the total job time changed from about 61
mikes for iteration to about 2,300 mikes per iteration (a 37x increase).  In
other words, the time charged to the job (and not the program) changed by a
larger amount than the time charged to the program.

The cost of CVTEFN goes from 140 mills for 10,000 invocations to 1,098 mills
for 10,000 invocations but the total time changes from 350 mills to more
than 7,000 mills.  All of that extra time is tied up in sending the error
message, killing the MI instruction, and having the RPG program receive and
deal with the error message.  In my opinion, this is either (a) a poor
implementation or (b) there is some kind of magical RPG "error suppress"
flag that would have prevented the error messages from being send and
received and that I don't know about and you didn't turn on or (c) we should
have preceded the call to CVTEFN with some kind of quick scan to insure that
CFTEVN didn't fail.

I suggest that it might be a poor implementation because, in my personal
opinion, the error handling should never cost 20 to 40 times more than the
normal instruction operation and MI instructions are too small to fail in
such a spectacularly expensive way.  There is nothing that the message can
contain that is worth all that effort - "you gave me something to convert
that isn't a number".  Okay, that's all that I need to know.

I think that an MI built-in should work harder to integrate itself into the
exception handling scheme of the RPG program.


Richard Jackson
mailto:richardjackson@richardjackson.net
http://www.richardjacksonltd.com
Voice: 1 (303) 808-8058
Fax:   1 (303) 663-4325

-----Original Message-----
From: owner-rpg400-l@midrange.com [mailto:owner-rpg400-l@midrange.com]On
Behalf Of Mel Rothman
Sent: Monday, August 21, 2000 1:56 PM
To: RPG400-L@midrange.com
Subject: Character to Decimal With CVTEFN - Performance Data


Although I am not a PEX expert, I took a stab at it using type *STATS.

Following are results of two runs using the same procedure (C2N3) with
good data (e.g. 123.33) and bad data (123..33), each 10,000 times.
Subprocedure C2N3 uses CVTEFN.  The driving program is C2N3TEST.

The call to CVTEFN uses the (E) operation extender.  It is followed by a
test for %error.  If true, the subprocedure returns 0; otherwise, it
returns the packed value.

With bad data, CPU time in the RPG program, C2N3TEST, goes up from about
.36 seconds to 7.3 seconds.
Total time goes up from about .6 seconds to 22.6 seconds.  Most of the
additional non-program time seems to be related to handling the
exception.


Definition Information (used for both runs)
-------------------------------------------
                                                    Performance Explorer
Report
                                                      Definition
Information
Library . . :
QPEXDATA
Member. . . :
MEL
Description :
BLANK
Type . . . . . . . . . . . . :
STATISTICS
Definition Name. . . . . . . :
MEL
Defined By . . . . . . . . . :
ROTHMAN
Definition Description . . . :
*BLANK
Data Organization. . . . . . :
FLAT
Overhead Subtraction . . . . :
YES
Merge Jobs . . . . . . . . . :
YES
Include Dependent Jobs . . . :
YES
Selected
Jobs:
    Name       User
Number

*
Selected Task
Names:

*NONE
Selected MI Complex Instructions:
    *ALL


With Good Data
--------------
                                                    Performance Explorer
Report
                                                   Stats CPU Summary
Information
Library . . . . . :
QPEXDATA
Member. . . . . . :
MEL
Job name. . . . . :  ALL JOBS/TASKS IN
SESSION
Description . . . :
BLANK
Total Raw CPU . . :
896864
Overhead Removed. :
247907
Total CPU . . . . :
648957
Task CPU. . . . . :         37536     5.8
%
Job CPU . . . . . :        611421    94.2
%

-----------------------
   Pgm/Mod CPU. . :        598061    92.2
%
   Unknown CPU. . :         13360     2.1
%

                                                      Statistics
Information
Library . . :
QPEXDATA
Member. . . :
MEL
Job name. . : ALL JOBS/TASKS IN
SESSION
Description :
BLANK
                                  +----------------- Inline Stats
------------+
             Times   Calls MI CPLX              CPU        DB    DB
NDB   NDB
Name        Called    Made  Issued          (us) /   %    SIO   AIO
SIO   AIO
----------------------------------------------------------------------------
---
C2N3TEST         1      12   10019        357,903 55.2      0     0
0     0
*CVTEFN      10001       0       0        140,008 21.6      0     0
0     0
**LIC Task       0       0       0         37,535  5.8      0     0
0     0
QUICMD           2       7      11         17,868  2.8      0     0
0     1
**Unknown        0       0       0         13,359  2.1      0     0
0     0
QUIINMGR        14      28       0          6,163  0.9      0     0
0     0
*DEQWAIT        19       0       0          4,618  0.7      0     0
0     0
QWSGET          15      16      15          4,267  0.7      0     0
0     0
QMHRCVPM        28       6     129          3,443  0.5      0     0
0     0
*MATPRMSG       69       0       0          3,339  0.5      0     0
0     0
*MATBPGM         4       0       0          3,086  0.5      0     0
0     0
*CRTS            3       0       0          3,055  0.5      0     0
4     0
*REQIO          20       0       0          2,667  0.4      0     0
0     0
*RSLVSP         18       0       0          2,647  0.4      0     0
0     0
*DESS            3       0       0          2,571  0.4      0     0
3     0
QWSPUDDS        14       1      14          2,428  0.4      0     0
0     0
QUIEXFMT        14      43       1          2,340  0.4      0     0
0     0
*MATPTR        129       0       0          2,218  0.3      0     0
0     0
QT3REQIO        23       0      58          1,886  0.3      0     0
0     0
*MODPRMSG       25       0       0          1,818  0.3      0     0
0     0
*FNDINXEN       20       0       0          1,644  0.3      0     0
0     0
QWSPUT          10       7      12          1,611  0.2      0     0
0     0
QMHRMVPM        17       0      96          1,478  0.2      0     0
0     0
*SETACST        11       0       0          1,368  0.2      0     0
3     1
QUIOCNV         14       0       0          1,356  0.2      0     0
0     0
*SNDPRMSG       15       0       0          1,314  0.2      0     0
0     0
*DESCR           1       0       0          1,250  0.2      2     1
0     0
QUIACT          15      15       0          1,184  0.2      0     0
0     0
*MATINVIF      127       0       0            959  0.1      0     0
0     0
QUSRJOBI         5       6       2            793  0.1      0     0
0     0
*MATPTRIF       12       0       0            750  0.1      0     0
0     0
QMHSNDPM         4       1      17            691  0.1      0     0
0     0
*CRTDOBJ         1       0       0            642  0.1      0     0
0     0
QWCSCVTR        12       0       0            639  0.1      0     0
0     0
QMHDSEXT         1      23       7            638  0.1      0     0
0     0
*LOCK           11       0       0            632  0.1      0     0
0     0
QLICKOBJ         1       3       1            606  0.1      0     0
0     0
QMHRTMSS         6       0      23            605  0.1      0     0
0     0
QDBOPEN          1       1       6            592  0.1      0     0
0     0
QLIINSRT         1       5      12            576  0.1      0     0
0     0
QMHRTVRQ        12       0      24            549  0.1      0     0
0     0
QCAFLD           3       0       0            513  0.1      0     0
0     0
QSZGTPRD         2       3       9            497  0.1      0     0
0     0
*MODADR          1       0       0            468  0.1      0     0
0     1
*INSDSEN         1       0       0            452  0.1      0     0
2     0
QLIDLOBJ         1       2       7            450  0.1      0     0
0     0
QCANPARS         3       0       0            403  0.1      0     0
0     0
QUIMGFLW         1       5       9            394  0.1      0     0
0     0
QUSCRTUS         1       5      10            385  0.1      0     0
0     0
*MATSOBJ         9       0       0            377  0.1      0     0
0     0
QCAPOS           3       0       0            375  0.1      0     0
0     0
QCMDEXC          1       7       3            374  0.1      0     0
0     0
QUILIST          4       0       4            372  0.1      0     0
0     0
QDMCOPEN         1       1      10            362  0.1      0     0
0     0
QCADRV2          3      14       1            351  0.1      0     0
0     0
QSYGRAUT         1       1       7            351  0.1      0     0
0     0
QWSSFLCT         2       0       0            309  0.0      0     0
0     0
*ACTCR           1       0       0            308  0.0      0     0
0     0
QDMRCLSE         1       5      10            306  0.0      0     0
0     0
*MATPRATR       18       0       0            295  0.0      0     0
0     0
QSFMQDSP         6       6       0            289  0.0      0     0
0     0
QUIOPEN          1       2      10            277  0.0      0     0
0     0
QLEDAGE          1       1       7            272  0.0      0     0
0     0
*GRANT           1       0       0            270  0.0      0     0
1     0
*LOCKSL          9       0       0            265  0.0      0     0
0     0
QUIICHK          4       0       3            258  0.0      0     0
0     0
QLIMROIR         3       0       9            247  0.0      0     0
0     0
QLGCNVCS         1       0       6            245  0.0      0     0
0     0
*MATINVAT        8       0       0            245  0.0      0     0
0     0
*UNLOCK         10       0       0            243  0.0      0     0
0     0
QLILIST          1       1      11            239  0.0      0     0
0     0
*TESTEXCP       16       0       0            231  0.0      0     0
0     0
QWSSPEND         2       4       0            229  0.0      0     0
0     0
*RMVINXEN        2       0       0            218  0.0      0     0
0     0
QWCRSVAL         1       0       2            216  0.0      0     0
0     0
*DIAG            3       0       0            204  0.0      0     0
0     0
QWCCVTDT         4       4       0            193  0.0      0     0
0
*CVTTS           4       0       0            193  0.0      0     0
0
QMHPDEH          2       0       6            181  0.0      0     0
0
*MATS            6       0       0            177  0.0      0     0
0
*MATCTX          2       0       0            173  0.0      0     0
0
QUIDSPP          1       2       0            153  0.0      0     0
0
*TESTAU         15       0       0            152  0.0      0     0
0
QCATRS           2       0       4            150  0.0      0     0
0
*SNSEXCPD        2       0       0            149  0.0      0     0
0
QCARULE          3       0       6            138  0.0      0     0
0
QLIDLOIR         2       0       7            133  0.0      0     0
0
QCAIEXIT         1       0       3            106  0.0      0     0
0
QWSHLM           1       0       0            104  0.0      0     0
0
QCACALL          1       0       4            101  0.0      0     0
0



With Bad Data
-------------
                                                    Performance Explorer
Report
                                                   Stats CPU Summary
Information
Library . . . . . :  QPEXDATA
Member. . . . . . :  MEL
Job name. . . . . :  ALL JOBS/TASKS IN SESSION
Description . . . :   BLANK
Total Raw CPU . . :      31452600
Overhead Removed. :       8512585
Total CPU . . . . :      22940015
Task CPU. . . . . :        289984     1.3 %
Job CPU . . . . . :      22650031    98.7 %
                     -----------------------
   Pgm/Mod CPU. . :      22635439    98.7 %
   Unknown CPU. . :         14592     0.1 %



                                                    Performance Explorer
Report
                                                      Statistics
Information
Library . . :
QPEXDATA
Member. . . :
MEL
Job name. . : ALL JOBS/TASKS IN
SESSION
Description :
BLANK
                                  +----------------- Inline Stats
------------+
             Times   Calls MI CPLX              CPU        DB    DB
NDB   NDB
Name        Called    Made  Issued          (us) /   %    SIO   AIO
SIO   AIO
----------------------------------------------------------------------------
---
C2N3TEST         1   20012   60019      7,323,251 31.9      0     0
18     0
QMHRCVPM     10031   20009   40132      2,714,113 11.8      0     0
0     0
*FNDINXEN    30023       0       0      2,399,313 10.5      0     0
0     0
*MATPRMSG    30075       0       0      1,762,174  7.7      0     0
0     0
QMHRTMSS     10009       0   40035      1,572,933  6.9      0     0
0     0
*SNDPRMSG    10015       0       0      1,562,951  6.8      0     0
4     0
*CVTEFN      10001       0       0      1,098,417  4.8      0     0
0     0
QMHPDEH      10002       0   20006      1,021,904  4.5      0     0
0     0
*MODPRMSG    10025       0       0        698,147  3.0      0     0
0     0
QWCSCVTR     10012       0       0        661,167  2.9      0     0
0     0
*MODINVAT    10003       0       0        512,938  2.2      0     0
0     0
*MATPTR      30135       0       0        476,341  2.1      0     0
0     0
*MATPTRIF    10012       0       0        455,484  2.0      0     0
0     0
**LIC Task       0       0       0        289,983  1.3      0     0
0     0
*CANINV      10000       0       0        186,840  0.8      0     0
0     0
*TESTAU      10018       0       0        103,886  0.5      0     0
0     0
QUICMD           2       7      11         17,470  0.1      0     0
0     0
**Unknown        0       0       0         14,591  0.1      0     0
0     0
QUIINMGR        14      28       0          6,231  0.0      0     0
0     0
*DEQWAIT        19       0       0          4,758  0.0      0     0
0     0
QWSGET          15      16      15          4,319  0.0      0     0
0     0
*REQIO          20       0       0          2,783  0.0      0     0
0     0
*CRTS            3       0       0          2,753  0.0      0     0
4     0
*RSLVSP         18       0       0          2,681  0.0      0     0
0     0
*DESS            3       0       0          2,623  0.0      0     0
3     0
QUIEXFMT        14      43       1          2,539  0.0      0     0
0     0
QWSPUDDS        14       1      14          2,489  0.0      0     0
0     0
*MATBPGM         4       0       0          2,083  0.0      0     0
0     0
QT3REQIO        23       0      58          2,005  0.0      0     0
0     0
QWSPUT          13       7      15          1,771  0.0      0     0
0     0
*INSDSEN         1       0       0          1,573  0.0      3     1
3     0
QMHRMVPM        17       0      96          1,470  0.0      0     0
0     0
*SETACST        11       0       0          1,414  0.0      0     0
3     1
QUIOCNV         14       0       0          1,347  0.0      0     0
0     0
*DESCR           1       0       0          1,259  0.0      2     1
0     0
QUIACT          15      15       0          1,198  0.0      0     0
0     0
*MATINVIF      127       0       0            986  0.0      0     0
0     0
QMHRTVRQ        12       0      24            983  0.0      0     0
0     0
QUSRJOBI         5       6       2            817  0.0      0     0
0     0
QMHDSEXT         1      32      10            815  0.0      0     0
0     0
QMHSNDPM         4       1      17            695  0.0      0     0
0     0
*LOCK           11       0       0            610  0.0      0     0
0     0
QLICKOBJ         1       3       1            608  0.0      0     0
0     0
*CRTDOBJ         1       0       0            603  0.0      0     0
0     0
QDBOPEN          1       1       6            586  0.0      0     0
0     0


-------- Original Message --------
Subject: RE: Character to Decimal
Date: Sat, 19 Aug 2000 07:08:34 -0600
From: "Richard Jackson" <richardjackson@richardjackson.net>
Reply-To: RPG400-L@midrange.com
To: <RPG400-L@midrange.com>

Could be ... how are you with PEX?  I'm thinking of a call trace then
perhaps an MI trace.

Richard Jackson
mailto:richardjackson@richardjackson.net
www.richardjacksonltd.com
Voice: 1 (303) 808-8058
Fax:   1 (303) 663-4325

-----Original Message-----
From: owner-rpg400-l@midrange.com [mailto:owner-rpg400-l@midrange.com]On
Behalf Of Mel Rothman
Sent: Friday, August 18, 2000 8:28 PM
To: RPG400-L@midrange.com
Subject: Re: Character to Decimal


...snip

It's possible that a good part of the expense associated with the
exception is
message handling stuff used by RPG to monitor/handle it.



Mel Rothman
+---
| This is the RPG/400 Mailing List!
| To submit a new message, send your mail to RPG400-L@midrange.com.
| To subscribe to this list send email to RPG400-L-SUB@midrange.com.
| To unsubscribe from this list send email to RPG400-L-UNSUB@midrange.com.
| Questions should be directed to the list owner/operator:
david@midrange.com
+---

+---
| This is the RPG/400 Mailing List!
| To submit a new message, send your mail to RPG400-L@midrange.com.
| To subscribe to this list send email to RPG400-L-SUB@midrange.com.
| To unsubscribe from this list send email to RPG400-L-UNSUB@midrange.com.
| Questions should be directed to the list owner/operator: david@midrange.com
+---

As an Amazon Associate we earn from qualifying purchases.

This thread ...

Replies:

Follow On AppleNews
Return to Archive home page | Return to MIDRANGE.COM home page

This mailing list archive is Copyright 1997-2024 by midrange.com and David Gibbs as a compilation work. Use of the archive is restricted to research of a business or technical nature. Any other uses are prohibited. Full details are available on our policy page. If you have questions about this, please contact [javascript protected email address].

Operating expenses for this site are earned using the Amazon Associate program and Google Adsense.