search

zendtech / IbmiToolkit

PHP frontend to XMLSERVICE for IBM i development.
BSD 3-Clause "New" or "Revised" License
46 stars 34 forks source link

ADDLIBLE is slow when library is already in library list #54

Closed alanseiden closed 8 years ago

alanseiden commented 9 years ago

The first time libraries are added to the library list, all is fine and fast:

Input XML: <?xml version="1.0" encoding="ISO-8859-1" ?>
<script>
<cmd exec='system'>ADDLIBLE LIB(SIBMAINTV2)</cmd><cmd exec='system'>ADDLIBLE LIB(SIDDBV2)</cmd>
</script>
Output XML: <?xml version="1.0" encoding="ISO-8859-1" ?>
<script>
<cmd exec='system'><success><![CDATA[+++ success ADDLIBLE LIB(SIBMAINTV2)]]></success>
</cmd>
<cmd exec='system'><success><![CDATA[+++ success ADDLIBLE LIB(SIBDBV2)]]></success>
</cmd>
</script>
Exec end: 2015-11-09 01:06:07. Seconds to execute: 0.66702795028687.

The second time, a "warning"-type error, CPF2103, occurs:

<script>
<cmd exec='system'>ADDLIBLE LIB(SIBMAINTV2)</cmd><cmd exec='system'>ADDLIBLE LIB(SIBDBV2)</cmd>
</script>
Output XML: <?xml version="1.0" encoding="ISO-8859-1" ?>
<script>
<cmd exec='system'><error><![CDATA[*** error ADDLIBLE LIB(SIBMAINTV2)]]></error>
<error>CPF2103</error>
<version>XML Toolkit 1.9.1</version>
<error>
<cpf>CPF2103</cpf>
<errnoxml>1100012</errnoxml>
<xmlerrmsg><![CDATA[XML run cmd failed]]></xmlerrmsg>
<xmlhint><![CDATA[ADDLIBLE LIB(SIDMAINTV2)]]></xmlhint>
</error>
<error>
<cpf>CPF2103</cpf>
<errnoxml>1100012</errnoxml>
<xmlerrmsg><![CDATA[XML run cmd failed]]></xmlerrmsg>
<xmlhint><![CDATA[ADDLIBLE LIB(SIBMAINTV2)]]></xmlhint>
</error>
<jobinfo>
<jobipc></jobipc>
<jobipcskey>FFFFFFFF</jobipcskey>
<jobname>QSQSRVR</jobname>
<jobuser>QUSER</jobuser>
<jobnbr>228234</jobnbr>
<jobsts>*ACTIVE</jobsts>
<curuser>SIDREG2</curuser>
<ccsid>37</ccsid>
<dftccsid>37</dftccsid>
<paseccsid>0</paseccsid>
<langid>ENU</langid>
<cntryid>US</cntryid>
<sbsname>QSYSWRK</sbsname>
<sbslib>QSYS</sbslib>
<curlib></curlib>
<syslibl>IDEVCLDSYS COMCONQSYS QSYS QSYS2 QHLPSYS QUSRSYS</syslibl>
<usrlibl>SIBDBV2 SIBMAINTV2 QGPL QTEMP</usrlibl>
<jobcpffind>see error list, not log scan</jobcpffind>
</jobinfo>
<joblogscan>
<joblogrec>
<jobcpf>CPF1124</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[Job 228234/QUSER/QSQSRVR started on 10/27/15 at 08:54:08]]></jobtext>
</joblogrec>
<joblogrec>
<jobcpf>CPF1301</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[SIDREG2 QWTCCCHJ main 129 ACGDTA for 228234/QUSER/QSQSRVR not journaled; reason 1.]]></jobtext>
</joblogrec>
<joblogrec>
<jobcpf>CPF1336</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[SIDREG2 Errors on CHGJOB command for job 228234/QUSER/QSQSRVR.]]></jobtext>
</joblogrec>
<joblogrec>
<jobcpf>CPF1301</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[SIDREG2 QSQSRVR QSQSRVR 8449 ACGDTA for 228234/QUSER/QSQSRVR not journaled; reason 1.]]></jobtext>
</joblogrec>
<joblogrec>
<jobcpf>*NONE</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[SIDREG2 QSQSRVR QSQSRVR 8537 QSQSRVR QSQSRVR 8537 User Profile = SIDREG2]]></jobtext>
</joblogrec>
<joblogrec>
<jobcpf>CPF9898</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[SIDREG2 QSQSRVR QSQSRVR 8627 QSQSRVR QSQSRVR 8627 SERVER MODE CONNECTING JOB IS 230973/QTMHHTTP/SIDCSS.]]></jobtext>
</joblogrec>
</joblogscan>
<joblog job='QSQSRVR' user='QUSER' nbr='228234'>
<![CDATA[From procedure  . . . . . . :   QSQSRVR
                                     Statement . . . . . . . . . :   8537
                                     To module . . . . . . . . . :   QSQSRVR
                                     To procedure  . . . . . . . :   QSQSRVR
                                     Statement . . . . . . . . . :   8537
                                     Message . . . . :   User Profile = SIDREG2
CPF9898    Completion              40   11/08/15  23:45:29.916766  QSQSRVR      QSYS        *STMT    QSQSRVR     QSYS        *STMT
                                     From user . . . . . . . . . :   SIDREG2
                                     From module . . . . . . . . :   QSQSRVR
                                     From procedure  . . . . . . :   QSQSRVR
                                     Statement . . . . . . . . . :   8627
                                     To module . . . . . . . . . :   QSQSRVR
                                     To procedure  . . . . . . . :   QSQSRVR
                                     Statement . . . . . . . . . :   8627
                                     Message . . . . :   SERVER MODE CONNECTING JOB IS 230973/QTMHHTTP/SIDCSS.
                                     Cause . . . . . :   This message is used by application programs as a general
                                       escape message.
CPC2196    Completion              00   11/09/15  00:06:07.646019  QLICUSRL     QSYS        0114     QC2SYS      QSYS        *STMT
                                     From user . . . . . . . . . :   SIDREG2
                                     To module . . . . . . . . . :   QC2SYS
                                     To procedure  . . . . . . . :   system
                                     Statement . . . . . . . . . :   13
                                     Message . . . . :   Library SIBMAINTV2 added to library list.
                                     Cause . . . . . :   If the ADDLIBLE command was used, SIBMAINTV2 was added to
                                       the user library list.  If the CHGSYSLIBL command was used, SIBMAINTV2 was
                                       added to the system portion of the library list.
CPC2196    Completion              00   11/09/15  00:06:07.652688  QLICUSRL     QSYS        0114     QC2SYS      QSYS        *STMT
                                     From user . . . . . . . . . :   SIDREG2
                                     To module . . . . . . . . . :   QC2SYS
                                     To procedure  . . . . . . . :   system
                                     Statement . . . . . . . . . :   13
                                     Message . . . . :   Library SIBDBV2 added to library list.
                                     Cause . . . . . :   If the ADDLIBLE command was used, SIBDBV2 was added to the
                                       user library list.  If the CHGSYSLIBL command was used, SIBDBV2 was added to
                                       the system portion of the library list.]]>
</joblog>
</cmd>
<cmd exec='system'><error><![CDATA[*** error ADDLIBLE LIB(SIBDBV2)]]></error>
<error>CPF2103</error>
<version>XML Toolkit 1.9.1</version>
<error>
<cpf>CPF2103</cpf>
<errnoxml>1100012</errnoxml>
<xmlerrmsg><![CDATA[XML run cmd failed]]></xmlerrmsg>
<xmlhint><![CDATA[ADDLIBLE LIB(SIBDBV2)]]></xmlhint>
</error>
<error>
<cpf>CPF2103</cpf>
<errnoxml>1100012</errnoxml>
<xmlerrmsg><![CDATA[XML run cmd failed]]></xmlerrmsg>
<xmlhint><![CDATA[ADDLIBLE LIB(SIBDBV2)]]></xmlhint>
</error>
<jobinfo>
<jobipc></jobipc>
<jobipcskey>FFFFFFFF</jobipcskey>
<jobname>QSQSRVR</jobname>
<jobuser>QUSER</jobuser>
<jobnbr>228234</jobnbr>
<jobsts>*ACTIVE</jobsts>
<curuser>SIDREG2</curuser>
<ccsid>37</ccsid>
<dftccsid>37</dftccsid>
<paseccsid>0</paseccsid>
<langid>ENU</langid>
<cntryid>US</cntryid>
<sbsname>QSYSWRK</sbsname>
<sbslib>QSYS</sbslib>
<curlib></curlib>
<syslibl>IDEVCLDSYS COMCONQSYS QSYS QSYS2 QHLPSYS QUSRSYS</syslibl>
<usrlibl>SIBDBV2 SIBMAINTV2 QGPL QTEMP</usrlibl>
<jobcpffind>see error list, not log scan</jobcpffind>
</jobinfo>
<joblogscan>
<joblogrec>
<jobcpf>CPF1124</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[Job 228234/QUSER/QSQSRVR started on 10/27/15 at 08:54:08]]></jobtext>
</joblogrec>
<joblogrec>
<jobcpf>CPF1301</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[SIBREG2 QWTCCCHJ main 129 ACGDTA for 228234/QUSER/QSQSRVR not journaled; reason 1.]]></jobtext>
</joblogrec>
<joblogrec>
<jobcpf>CPF1336</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[SIBREG2 Errors on CHGJOB command for job 228234/QUSER/QSQSRVR.]]></jobtext>
</joblogrec>
<joblogrec>
<jobcpf>CPF1301</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[SIBREG2 QSQSRVR QSQSRVR 8449 ACGDTA for 228234/QUSER/QSQSRVR not journaled; reason 1.]]></jobtext>
</joblogrec>
<joblogrec>
<jobcpf>*NONE</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[SIBREG2 QSQSRVR QSQSRVR 8537 QSQSRVR QSQSRVR 8537 User Profile = SIDREG2]]></jobtext>
</joblogrec>
<joblogrec>
<jobcpf>CPF9898</jobcpf>
<jobtime><![CDATA[11/08/15  23:45:29.916766]]></jobtime>
<jobtext><![CDATA[SIBREG2 QSQSRVR QSQSRVR 8627 QSQSRVR QSQSRVR 8627 SERVER MODE CONNECTING JOB IS 230973/QTMHHTTP/SIDCSS.]]></jobtext>
</joblogrec>
</joblogscan>
<joblog job='QSQSRVR' user='QUSER' nbr='228234'>
<![CDATA[Cause . . . . . :   This message is used by application programs as a general
                                       escape message.
CPC2196    Completion              00   11/09/15  00:06:07.646019  QLICUSRL     QSYS        0114     QC2SYS      QSYS        *STMT
                                     From user . . . . . . . . . :   SIBREG2
                                     To module . . . . . . . . . :   QC2SYS
                                     To procedure  . . . . . . . :   system
                                     Statement . . . . . . . . . :   13
                                     Message . . . . :   Library SIBMAINTV2 added to library list.
                                     Cause . . . . . :   If the ADDLIBLE command was used, SIBMAINTV2 was added to
                                       the user library list.  If the CHGSYSLIBL command was used, SIBMAINTV2 was
                                       added to the system portion of the library list.
CPC2196    Completion              00   11/09/15  00:06:07.652688  QLICUSRL     QSYS        0114     QC2SYS      QSYS        *STMT
                                     From user . . . . . . . . . :   SIDREG2
                                     To module . . . . . . . . . :   QC2SYS
                                     To procedure  . . . . . . . :   system
                                     Statement . . . . . . . . . :   13
                                     Message . . . . :   Library SIDDBV2 added to library list.
                                     Cause . . . . . :   If the ADDLIBLE command was used, SIDDBV2 was added to the
                                       user library list.  If the CHGSYSLIBL command was used, SIBDBV2 was added to
                                       the system portion of the library list.
 5770SS1 V7R1M0 100423                        Display Job Log                        IDEVELOP 11/09/15 00:06:48          Page    3
  Job name . . . . . . . . . . :   QSQSRVR         User  . . . . . . :   QUSER        Number . . . . . . . . . . . :   228234
  Job description  . . . . . . :   QDFTSVR         Library . . . . . :   QGPL
MSGID      TYPE                    SEV  DATE      TIME             FROM PGM     LIBRARY     INST     TO PGM      LIBRARY     INST
QSH0005    Completion              00   11/09/15  00:06:47.805658  QZSHRUNC     QSHELL      *STMT    XMLSTOREDP  ZENDSVR6    *STMT
                                     From user . . . . . . . . . :   SIDREG2
                                     From module . . . . . . . . :   QZSHRUNC
                                     From procedure  . . . . . . :   main
                                     Statement . . . . . . . . . :   149
                                     To module . . . . . . . . . :   PLUGILE
                                     To procedure  . . . . . . . :   ILECMDEXC
                                     Statement . . . . . . . . . :   5497
                                     Message . . . . :   Command ended normally with exit status 0.]]>
</joblog>
</cmd>
</script>
Exec end: 2015-11-09 01:06:48. Seconds to execute: 3.1658799648285.

Note that when ADDLIBLE generates the warnings, execution is slowed to more than 3 seconds. The slowness occurs because by default, XMLSERVICE reacts to errors by retrieving joblog data, which is slow to obtain.

Solution: consider XMLSERVICE's error="fast" mode (http://yips.idevcloud.com/wiki/index.php/XMLService/XMLSERVICEQuick) for commands such as ADDLIBLE where warnings may often be ignored. "Fast" mode returns a brief error rather than a complete joblog.

One way to achieve this easily (for the CW as well as regular toolkit) would be to add something like fastErrorCommands="ADDLIBLE" to toolkit.ini; in PHP, then, when a command is run, use this list (comma-delimited) to determine if "fast" mode should be used.

clarkphp commented 9 years ago

I like this. It provides access to a feature baked into the XMLSERVICE, a feature for exactly this purpose. Is it also a bit of a slippery slope feature, which could be abused if one gets too comfy adding commands to the list? I'm not at all saying "don't implement this;" merely thinking we might caution users to use it judiciously.

Am I being overly-cautious? I still like it! On Nov 9, 2015 12:12 AM, "Alan Seiden" notifications@github.com wrote:

The first time libraries are added to the library list, all is fine and fast:

Input XML: <?xml version="1.0" encoding="ISO-8859-1" ?>

Output XML: <?xml version="1.0" encoding="ISO-8859-1" ?>

Exec end: 2015-11-09 01:06:07. Seconds to execute: 0.66702795028687.

The second time, a "warning"-type error, CPF2103, occurs:

Output XML: <?xml version="1.0" encoding="ISO-8859-1" ?>

Exec end: 2015-11-09 01:06:48. Seconds to execute: 3.1658799648285.

Note that when ADDLIBLE generates the warnings, execution is slowed to more than 3 seconds. The slowness occurs because by default, XMLSERVICE reacts to errors by retrieving joblog data, which is slow to obtain.

Solution: consider XMLSERVICE's error="fast" mode ( http://yips.idevcloud.com/wiki/index.php/XMLService/XMLSERVICEQuick) for commands such as ADDLIBLE where warnings may often be ignored. "Fast" mode returns a brief error rather than a complete joblog.

One way to achieve this easily (for the CW as well as regular toolkit) would be to add something like fastErrorCommands="ADDLIBLE" to toolkit.ini; in PHP, then, when a command is run, use this list (comma-delimited) to determine if "fast" mode should be used.

— Reply to this email directly or view it on GitHub https://github.com/zendtech/IbmiToolkit/issues/54.

alanseiden commented 9 years ago

And we could treat CPF2103 as a non-error if so configured.

Dear Overly Cautious, yes, and ADDLIBLE is the only command I can think of now that needs this assistance. It's been discussed for years; now the issue is official thanks to Github.

alanseiden commented 9 years ago

Incidentally, the compatibility wrapper (CW) uses ADDLIBLE implicitly during i5_connect when a library list has been specified. CW loops through the library list and runs ADDLIBLE for each library. Hence, users may be running ADDLIBLE without knowing it. For that reason, I suggest configuring ADDLIBLE/CPF2103 to be seen as "benign" by default. Other errors such as "library not found" should still be considered serious.

alanseiden commented 8 years ago

Another option: ask XMLSERVICE to add "ADDLIBLE with MONMSG" as a basic capability or plugin

alanseiden commented 8 years ago

Closing issue because covered in #74.