Random problem with the new Toolkit / XMLSERVICE

Post Reply
timo_karvinen
Posts: 82
Joined: Wed Aug 12, 2009 7:58 am
Location: Tampere, Finland
Contact:

Random problem with the new Toolkit / XMLSERVICE

Post by timo_karvinen » 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.                      

rangercairns
Posts: 222
Joined: Fri Jul 24, 2009 6:28 pm

Re: Random problem with the new Toolkit / XMLSERVICE

Post by rangercairns » 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: 222
Joined: Fri Jul 24, 2009 6:28 pm

Re: Random problem with the new Toolkit / XMLSERVICE

Post by rangercairns » 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

timo_karvinen
Posts: 82
Joined: Wed Aug 12, 2009 7:58 am
Location: Tampere, Finland
Contact:

Re: Random problem with the new Toolkit / XMLSERVICE

Post by timo_karvinen » 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: 82
Joined: Wed Aug 12, 2009 7:58 am
Location: Tampere, Finland
Contact:

Re: Random problem with the new Toolkit / XMLSERVICE

Post by timo_karvinen » 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: 82
Joined: Wed Aug 12, 2009 7:58 am
Location: Tampere, Finland
Contact:

Re: Random problem with the new Toolkit / XMLSERVICE

Post by timo_karvinen » 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

rangercairns
Posts: 222
Joined: Fri Jul 24, 2009 6:28 pm

Re: Random problem with the new Toolkit / XMLSERVICE

Post by rangercairns » 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

graebert
Posts: 16
Joined: Fri Jan 20, 2012 6:30 pm

Re: Random problem with the new Toolkit / XMLSERVICE

Post by graebert » 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.

aseiden
Posts: 874
Joined: Thu Apr 09, 2009 5:45 pm

Re: Random problem with the new Toolkit / XMLSERVICE

Post by aseiden » Tue Nov 24, 2015 4:32 pm

Installing a newer version of XMLSERVICE corrects this problem. Recently I was able to eliminate the error by upgrading XMLSERVICE from 1.7.5 to 1.9.1.

--Alan

Post Reply