|
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 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.
midrange.com
