Random problem with the new Toolkit / XMLSERVICE

Random problem with the new Toolkit / XMLSERVICE

Postby timo_karvinen on Thu Oct 25, 2012 10:25 am

We randomly get this error message with the new toolkit:
Toolkit request failed. Possible reason: a CCSID not matching that of system, or updated PTFs may be required. Database code (if any): 58004. Message: SQL-järjestelmävirhe. SQLCODE=-901

By random I mean that the exactly same calls can be made right before and right after the erroneous one and they work.
As in, when I have a page in browser, I hit refresh and get this error, I hit refresh again and I don't get the error.

Here are the debug logs, first is the failed call with the error message, second is successfull call after hitting refresh:
Code: Select all
Creating new conn with database: '*LOCAL', user or i5 naming flag: 'WEBSMERX', ext prefix: '', persistence: '1'
Going to create a new db connection.
Exec start: 2012-10-23 17:47:42
IPC: '/tmp/xtoolkit/WEBSMERX6'. Control key: *cdata *sbmjob(ZENDSVR/ZSVR_JOBD/XTOOLKIT)
Stmt: call XMLSERVICE.iPLUG1M(?,?,?,?)
Input XML: <?xml version="1.0" encoding="ISO-8859-1" ?>
<script>
<pgm name='RMWSLOG' lib='*LIBL'>
<parm io='in' comment='PI_Service'><data var='PI_Service' type='100a'>wsdl: GetOhjaustieto</data></parm>
<parm io='in' comment='PI_IP'><data var='PI_IP' type='15a'>172.17.66.58</data></parm>
<parm io='in' comment='PI_Caller'><data var='PI_Caller' type='10a' /></parm>
<parm io='in' comment='PI_ProReq'><data var='PI_ProReq' type='1a'>P</data></parm>
<parm io='in' comment='PI_Type'><data var='PI_Type' type='1a'>W</data></parm>
<parm io='in' comment='PI_ErrorCode'><data var='PI_ErrorCode' type='1a'>0</data></parm>
<parm io='in' comment='PI_Note'><data var='PI_Note' type='128a' /></parm>
</pgm>
</script>


Creating new conn with database: '*LOCAL', user or i5 naming flag: 'WEBSMERX', ext prefix: '', persistence: '1'
Going to create a new db connection.
Exec start: 2012-10-23 17:42:16
IPC: '/tmp/xtoolkit/WEBSMERX1'. Control key: *cdata *sbmjob(ZENDSVR/ZSVR_JOBD/XTOOLKIT)
Stmt: call XMLSERVICE.iPLUG1M(?,?,?,?)
Input XML: <?xml version="1.0" encoding="ISO-8859-1" ?>
<script>
<pgm name='RMWSLOG' lib='*LIBL'>
<parm io='in' comment='PI_Service'><data var='PI_Service' type='100a'>wsdl: GetOhjaustieto</data></parm>
<parm io='in' comment='PI_IP'><data var='PI_IP' type='15a'>172.17.66.58</data></parm>
<parm io='in' comment='PI_Caller'><data var='PI_Caller' type='10a' /></parm>
<parm io='in' comment='PI_ProReq'><data var='PI_ProReq' type='1a'>P</data></parm>
<parm io='in' comment='PI_Type'><data var='PI_Type' type='1a'>W</data></parm>
<parm io='in' comment='PI_ErrorCode'><data var='PI_ErrorCode' type='1a'>0</data></parm>
<parm io='in' comment='PI_Note'><data var='PI_Note' type='128a' /></parm>
</pgm>
</script>
Output XML: <?xml version="1.0" encoding="ISO-8859-1" ?>
<script>
<pgm name='RMWSLOG' lib='*LIBL'>
</pgm>
</script>
Exec end: 2012-10-23 17:42:16. Seconds to execute: 0,0062019824981689.


Here are the job logs I dug out, they're not from the exact calls above but same error at different time.
Sorry for Finnish in some of these, the machine is running i in Finnish.
But at least you can see the error codes.
Code: Select all
Space offset X'00000000' or X'000000804400802D' is outside current limit
  for object QSQSRVR   QUSER     094158.                               
Application error.  MCH0601 unmonitored by XMLSTOREDP at statement     
  0000006366, instruction X'0000'.                                     
Toimintakatko. Valvomaton sanoma CEE9901 ohjelman QPZA017735 lauseen   
  0000000985 käskystä X'0000'.                                         
Toimintakatko. Valvomaton sanoma CEE9901 ohjelman QSQRUN1 lauseen
  0000000985 käskystä X'0000'.                                   
SQL-järjestelmävirhe.                                                   


And detailed descriptions:
Code: Select all
Sanoman tunnus . . . . :   MCH0601                                           
Lähetyspäivämäärä  . . :   23.10.12      Lähetysaika  . . . . . :   16:23:48 
                                                                             
Sanoma  . . . . :   Space offset X'00000000' or X'000000804400802D' is outside
  current limit for object QSQSRVR   QUSER     094158.                       
                                                                             
Cause . . . . . :   A program tried to set a space pointer, tried to use     
  storage outside a space, or tried to use an unallocated page in teraspace. 
  The space class is X'07'. The space class designates the type of space:     
    00-primary associated space (includes space objects).                     
    01-secondary associated space 0.                                         
    02-implicit process space for automatic storage.                         
    03-implicit process space for static storage in activation group mark     
  X'0000000000000000'.                                                       
    04-implicit process space for heap identifier X'00000000' in activation   
  group mark X'0000000000000000'.                                             
    05-constant space.                                                     
    06-space for handle-based heap identifier X'00000000'.                 
    07-teraspace offset X'000000804400802D'.                               
    08-teraspace for i5/OS PASE memory address X'000000804400802D'.       
    Offset X'00000000' only applies to storage outside teraspace.         
  X'40000000000000009E9526804400802D' is a pointer to the teraspace page or
  the start of the implicit process space for the allocation.             
 

Sanoman tunnus . . . . :   CEE9901                                           
Lähetyspäivämäärä  . . :   23.10.12      Lähetysaika  . . . . . :   16:23:48 
                                                                             
Sanoma  . . . . :   Application error.  MCH0601 unmonitored by XMLSTOREDP at 
  statement 0000006366, instruction X'0000'.                                 
                                                                             
Cause . . . . . :   The application ended abnormally because an exception     
  occurred and was not handled.  The name of the program to which the         
  unhandled exception is sent is XMLSTOREDP PLUGIPC IPCENDJOBBUSY. The program
  was stopped at the high-level language statement number(s) 0000006366 at the
  time the message was sent.  If more than one statement number is shown, the
  program is an optimized ILE program.  Optimization does not allow a single 
  statement number to be determined.  If *N is shown as a value, it means the
  real value was not available.                                               
Recovery  . . . :   See the low level messages previously listed to locate the
  cause of the exception.  Correct any errors, and then try the request again.
 

Sanoman tunnus . . . . :   CPF9999                                         
Lähetyspäivämäärä  . . :   23.10.12      Lähetysaika  . . . . . :   16:23:49
                                                                           
Sanoma  . . . . :   Toimintakatko. Valvomaton sanoma CEE9901 ohjelman       
  QPZA017735 lauseen 0000000985 käskystä X'0000'.                           
                                                                           
Selitys . . . . :   Katkosanoma lähetettiin ohjelmalle, joka ei valvonut   
  sanomaa. Sen ohjelman koko nimi, jolle valvomaton sanoma lähetettiin, on 
  QPZA017735 QSQPREP SQL_Prepare. Sanoman lähetyksen aikana ohjelma pysähtyi
  lausekielen lausenumerossa 0000000985. Jos näkyvissä on useampi kuin yksi
  lausenumero, ohjelma oli sidottu ohjelma. Optimointi ei salli yksittäisen
  lausenumeron määritystä. Jos arvona on *N, se tarkoittaa, että todellinen
  arvo ei ollut saatavissa.                                                 
Korjaus . . . . :   Saat selville toimintakatkon syyn katsomalla aiempia   
  alatason sanomia.  Korjaa virheet ja yritä uudelleen.                     
 

Sanoman tunnus . . . . :   SQL0901                                           
Lähetyspäivämäärä  . . :   23.10.12      Lähetysaika  . . . . . :   16:23:49
                                                                             
Sanoma  . . . . :   SQL-järjestelmävirhe.                                   
                                                                             
Selitys . . . . :   On ilmennyt SQL-järjestelmävirhe.  SQL-käskyä ei voi     
  päättää virheettömästi.  Virhe ei kuitenkaan estä muiden SQL-käskyjen     
  käsittelyä. Aiemmista sanomista voi käydä ilmi, että SQL-käskyssä on       
  ilmennyt virhe ja että SQL ei ole määrittänyt virhettä oikein. Edellisen   
  sanoman tunnus on CEE9901. On ilmennyt sisäinen ohjelmavirhe 3002. Jos     
  kyseessä on esikäännösvaihe, käsittely ei jatku tämän käskyn jälkeen.     
Korjaus . . . . :   Katso aiemmista sanomista, onko SQL-käskyssä ilmennyt   
  jokin virhe. Voit tuoda sanomat näyttöön komennolla DSPJOBLOG, jos ajat   
  kyselyä vuorovaikutteisesti. Antamalla komennon WRKJOB voit tuoda näyttöön
  esikäännöksen lopputuloksen.  Sovellusohjelma, joka vastaanottaa tämän     
  paluukoodin, saattaa yrittää muiden SQL-käskyjen käsittelyä. Korjaa virheet
  ja yritä pyyntöä uudelleen.
 
 
Sanoman tunnus . . . . :   CPF9999                                           
Lähetyspäivämäärä  . . :   23.10.12      Lähetysaika  . . . . . :   13:39:59
                                                                             
Sanoma  . . . . :   Toimintakatko. Valvomaton sanoma CEE9901 ohjelman QSQRUN1
  lauseen 0000000985 käskystä X'0000'.                                       
                                                                             
Selitys . . . . :   Katkosanoma lähetettiin ohjelmalle, joka ei valvonut     
  sanomaa. Sen ohjelman koko nimi, jolle valvomaton sanoma lähetettiin, on   
  QSQRUN1 QSQPREP SQL_Prepare. Sanoman lähetyksen aikana ohjelma pysähtyi   
  lausekielen lausenumerossa 0000000985. Jos näkyvissä on useampi kuin yksi 
  lausenumero, ohjelma oli sidottu ohjelma. Optimointi ei salli yksittäisen 
  lausenumeron määritystä. Jos arvona on *N, se tarkoittaa, että todellinen 
  arvo ei ollut saatavissa.                                                 
Korjaus . . . . :   Saat selville toimintakatkon syyn katsomalla aiempia     
  alatason sanomia.  Korjaa virheet ja yritä uudelleen.                     
timo_karvinen
 
Posts: 74
Joined: Wed Aug 12, 2009 7:58 am
Location: Tampere, Finland

Re: Random problem with the new Toolkit / XMLSERVICE

Postby rangercairns on Fri Oct 26, 2012 11:44 pm

i may have a fix for this (i think) ... i will post new version XMLSERVICE to YiPs when tests run ok.
rangercairns
 
Posts: 215
Joined: Fri Jul 24, 2009 6:28 pm

Re: Random problem with the new Toolkit / XMLSERVICE

Postby rangercairns on Mon Oct 29, 2012 11:35 pm

Ok, i have a test version of xmlservice 1.7.4-sg1 available ... if you try let us know.

http://www.youngiprofessionals.com/wiki ... ICETesting

Active test versions
2012–10–29 -xmlservice-rpg-1.7.4-sg1.zip
FIX — BUG XMLSERVICE PLUGXML XMLWRKVAL 7161 - Length or start position is out of range for the string operation
FIX — BUG XMLSTOREDP PLUGIPC IPCENDJOBBUSY 6366 - unhandled exception is sent
FIX — BUG XMLSERVICE PLUGPERF log_query - possible XMLSERVLOG SQL error 38501
rangercairns
 
Posts: 215
Joined: Fri Jul 24, 2009 6:28 pm

Re: Random problem with the new Toolkit / XMLSERVICE

Postby timo_karvinen on Tue Oct 30, 2012 10:27 am

I did only a quick test run on this, but initially it seems indeed that the fix is working.
I'll let you know if I hit the problem again later.

Thank you for the update.

-Timo
timo_karvinen
 
Posts: 74
Joined: Wed Aug 12, 2009 7:58 am
Location: Tampere, Finland

Re: Random problem with the new Toolkit / XMLSERVICE

Postby timo_karvinen on Tue Oct 30, 2012 5:14 pm

Other errors seem to be gone, but we are still sometimes getting this one:
Code: Select all
Sanoman tunnus . . . . :   MCH0601       Vakavuus . . . . . . . :   40       
Sanomalaji . . . . . . :   Katkosanoma                                       
Lähetyspäivämäärä  . . :   30.10.12      Lähetysaika  . . . . . :   17:21:08 
                                                                             
Sanoma  . . . . :   Space offset X'00000000' or X'000000800400802E' is outside
  current limit for object QSQSRVR   QUSER     115964.                       
Cause . . . . . :   A program tried to set a space pointer, tried to use     
  storage outside a space, or tried to use an unallocated page in teraspace. 
  The space class is X'07'. The space class designates the type of space:     
    00-primary associated space (includes space objects).                     
    01-secondary associated space 0.                                         
    02-implicit process space for automatic storage.                         
    03-implicit process space for static storage in activation group mark     
  X'0000000000000000'.                                                       
    04-implicit process space for heap identifier X'00000000' in activation   
  group mark X'0000000000000000'.                                             
    05-constant space.                                                     
    06-space for handle-based heap identifier X'00000000'.                 
    07-teraspace offset X'000000800400802E'.                               
    08-teraspace for i5/OS PASE memory address X'000000800400802E'.       
    Offset X'00000000' only applies to storage outside teraspace.         
  X'4000000000000000985EEF800400802E' is a pointer to the teraspace page or
  the start of the implicit process space for the allocation.             



Sanoman tunnus . . . . :   MCH0601       Vakavuus . . . . . . . :   40     
Lähetyspäivämäärä  . . :   30.10.12      Lähetysaika  . . . . . :   17:21:08
Sanomalaji . . . . . . :   Katkosanoma                                     
Lähettäjä  . . . . . . :   WEBSMERX      CCSID-tunnus . . . . . :   65535   
                                                                           
Lähtöohjelma . . . . . . . . . :   XMLSTOREDP                               
  Lähtökirjasto  . . . . . . . :     XMLSERVICE                             
  Lähtömoduuli . . . . . . . . :     PLUGIPC                               
  Lähtötoimintosarja . . . . . :     IPCSAFE                               
  Lähtökäsky . . . . . . . . . :     5334                                   
                                                                           
Vastaanottava ohjelma  . . . . :   XMLSTOREDP                               
  Vastaanottava kirjasto . . . :     XMLSERVICE                             
  Vastaanottava moduuli  . . . :     PLUGIPC                               
  Vastaanottava toimintosarja  :     IPCSAFE                               
  Vastaanottava käsky  . . . . :     5334                                   


-Timo
timo_karvinen
 
Posts: 74
Joined: Wed Aug 12, 2009 7:58 am
Location: Tampere, Finland

Re: Random problem with the new Toolkit / XMLSERVICE

Postby timo_karvinen on Tue Oct 30, 2012 5:35 pm

Never mind, I think this one is on us.
Most likely the above error refers to the call that has broken description on our script.

-Timo
timo_karvinen
 
Posts: 74
Joined: Wed Aug 12, 2009 7:58 am
Location: Tampere, Finland

Re: Random problem with the new Toolkit / XMLSERVICE

Postby rangercairns on Tue Oct 30, 2012 8:55 pm

Yes, you may have an original/originating error, which you may fix in your own script/called program, but i was hoping to fix xmlservice tolerance and apparently missed the mark with first coding arrow.
Code: Select all
Lähtöohjelma . . . . . . . . . :   XMLSTOREDP                               
  Lähtökirjasto  . . . . . . . :     XMLSERVICE                             
  Lähtömoduuli . . . . . . . . :     PLUGIPC                               
  Lähtötoimintosarja . . . . . :     IPCSAFE                               
  Lähtökäsky . . . . . . . . . :     5334 


I will have to think about what to do with IPCSAFE/IPCBUSY to see if i can make them safer under unpredictable memory conditions ... mmm ... ipcHereCtl is a static variable (global variable) ... i wonder how did ipcSafe go bad ???

Code: Select all
     D ipcHereCtl      DS                  likeds(ipcRec_t)
     D ipcCtlP         S               *   inz(*NULL)
     D ipcCtl          DS                  likeds(ipcRec_t) based(ipcCtlP)
     D ipcDoFlagP      s               *   inz(*NULL)
     D ipcDoFlags      ds                  likeds(doRec_t) based(ipcDoFlagP)

:
      *****************************************************
      * set ipc safe (1.7.4)
      * return (NA)
      *****************************************************
     P ipcSafe         B
     D ipcSafe         PI
      * vars
     d rc              s              1N   inz(*OFF)
      /free
       Monitor;
         // check IPC ok
         rc = ipcCtl.ipcReadyGo;
       On-error;
         // local IPC until attached (here)
         ipcCtlP    = %ADDR(ipcHereCtl);
         ipcDoFlagP = %ADDR(ipcCtl.ipcFlags);
       Endmon;
      /end-free
     P                 E
rangercairns
 
Posts: 215
Joined: Fri Jul 24, 2009 6:28 pm

Re: Random problem with the new Toolkit / XMLSERVICE

Postby graebert on Fri Nov 09, 2012 12:14 pm

We had a similar problem. Every now and then we got the message
Toolkit request failed. Possible reason: a CCSID not matching that of system, or updated PTFs may be required. Database code (if any): Fehler bei SQL Call Level Interface.
We installed xmlservice-rpg-1.7.4-sg2 and so far we have not seen this message again.
graebert
 
Posts: 14
Joined: Fri Jan 20, 2012 6:30 pm


Return to New Toolkit

Who is online

Users browsing this forum: No registered users and 2 guests