Error on SOAP communication "crash" connection client-userver

Author: marco.aquino@dedalus.eu (Marco)

Hi,
I have a problem with calling a web service (via signature) using SOAP 1.0.
Sometimes it happens that it returns error -155 or -150.
If I close and reopen my application, the error disappears.
The structure of my application is:
1) client invoke a uniface service on remote server
2) the uniface service invoke the web service.

The client asn file is:

[PATHS]
$ONSRV TCP:server+13000|user|password|onsrv

[SERVICES_EXEC]
MYSERVICE* $ONSRV:MYSERVICE*

The server asn file is like the client without the section [SERVICE_EXEC]

The entry on the urouter.asn is

onsrv = "c:\uniface\bin\userver.exe" /maxidle=500 /asn="c:\uniface\adm\file.asn" /dir="c:\uniface\project"

the uniface code is

newinstance "MYSERVICE", v_handle
v_handle -> OPERATION1(...)


Debugging the server side of application I have noticed that the call from client to server works properly, the call to web service works too but sometimes the response from web service is not coming back but the client have a -155 or -150 value in $procerror and $status.
Since this moment the client receives the same error on calling of the uniface service.
It seems that the connection client-server is "dedicated" and it is impossible for the urouter instantiate another userver for the client even if the older userver is dead.


I activated the log on urouter and I see this:

0:00.000.00 t=6156: URouter started at 27-jan-2012 14:28:25
0:00.006.78 t=6156: started thread to listen to TCP:+13000
44:50.638.43 t=7948: err=-16: Problems receiving request
75:40.854.83 t=3424: err=-16: Problems receiving request
102:51.045.20 t=604: err=-16: Problems receiving request
215:31.491.67 t=5848: err=-16: Problems receiving request
480:55.284.67 t=5972: err=-16: Problems receiving request
649:06.248.27 t=2860: err=-16: Problems receiving request
391:25.675.24 t=7204: err=-16: Problems receiving request
404:52.222.08 t=8004: server is dead: 2
404:52.222.22 t=8004: err=-16: Problems handling request
405:36.309.58 t=8004: server is dead: 2
405:36.309.63 t=8004: err=-25: Problems handling request
405:53.000.92 t=8004: server is dead: 2
405:53.000.97 t=8004: err=-25: Problems handling request
407:13.082.70 t=8004: server is dead: 0

what is "server is dead" ?
why I have "err=-25: Problems handling request" on my component after a problem with SOAP (I think)?


I think that the

err=-16: Problems receiving request

is the origin of the problem, so the follow problems

server is dead: 2
err=-16: Problems handling request
err=-25: Problems handling request

depend from that.


Anyone can help me?


Other info:
Uniface 8405 D504
Windows server 2003
Oracle


Thanks in advance.

Marco

13 Comments

  1. Hi,

    just a guess, but you can check in your service or other called components if they use an exit instead of a return.

    Maybe an profiling (proc-tracing) in your server can temporarly give more information, but be carefull, because this logfile can become very big.

    Best regards

    Thomas


    Author: Thomas.Young (thomas.young@young-consulting.de)
  2. Hi

    To catch thing like unwanted "EXIT"s I did include in every component the two standard operations INIT and CLEANUP.
    -> #INCLUDE STD_OPER
    In this predefined operations there a few PUTMESS (depending on a global, boolean variable) which give me such information if a new instance will be create or destroyed.
    If a programm needs INIT or CLEANUP for its own, I do have precompiler DEFINEs to call local procedures LP_INIT resp. LP_CLEANUP
    -> #DEFINE LP_INIT
    -> #DEFINE LP_CLEABUP

    With this enhancements I can can trace the life-cycle of every instance :-)

    Ingo


    Author: istiller (i2stiller@gmx.de)
  3. My program has exit to the end of the code, but this does not run, because when I debugged, the last statement was the call of the webservice.

    My uniface service code is like this:

    Operation MYOP

       Params
           string P_WS         : IN
        xmlstream P_XML        : IN
        xmlstream P_OUT        : OUT
       EndParams
       Variables
        xmlstream V_XML
           handle V_HANDLE
       EndVariables

       activate "%%P_WS%%%".CALL(V_XML,P_XML)
       if ($status < 0)
          exit -1
       endif
       P_OUT = V_XML

       exit 0
    End

    where activate "%%P_WS%%%"...... is the web service call, the last instruction that I debugged, after this on the client I get a -155 and after this I get an error when I call my uniface service (-155) without enter into my service.

    myservice is called with

    activate "MYSERVICE".MYOP("test",v_xml,v_xml)

     With a deleteinstance after activate or changing activate with newinstance, I will resolve the problem?

    Other think, it is possibile that the problem due a null value at webservice response? I read this in uniface help

    • Error: -150, UACTERR_UNKNOWN
      Description: The Web services call-out uses the MS Soap Toolkit to create the SOAP envelope, to send the request to the Web service, and to receive and parse the returned reply. If an error occurs in this sequence, Uniface returns this error along with the error message received from the Toolkit.
      Reason: The error text that is returned gives a clue to the error. For example, a common error is caused by null values in parameters other than strings. For details, see the next section.

    In this case how I trace it?

     

    Marco


    Author: Marco (marco.aquino@dedalus.eu)
  4. just a maybe stupid question:

    are all your parameters INOUT (rather than out) and are they initialised?

    Think I've heard that this have caused some trouble in a context I can not remember exactly.


    Author: ulrich-merkel (ulrichmerkel@web.de)
  5. The parameter of my uniface service are first two in and last out, the parameters of webservice defined on signature are first out last in.

    The strange thing is that it only sometimes happens.

    Marco


    Author: Marco (marco.aquino@dedalus.eu)
  6. Perhaps a "slow" server exceeding the "maximum wait for reply" from time to time so the client assumes the server is dead?


    Author: ulrich-merkel (ulrichmerkel@web.de)
  7. I don't think this, after close and reopen the application it works.

    The message "the server is dead" I think is from urouter and not from client.

    Now I tried changing activate with newinstance and after that I add a deleteinstance.

     

    Marco


    Author: Marco (marco.aquino@dedalus.eu)
  8. I changed with newinstance but the error remained, so I used urouter monitor to see the situation on the server, and I see that the server is always one or two, the clients are less than 10.

    Other info:

    my urouter.asn has 5 UST defined:

    1) for test (not used)

    2) for webservice call-in (for our integration in web application)

    3) for webservice call-in (to publish web service for other application)

    4) for debug (not used)

    5) for remote execute of uniface services (this case).

    With urouter monitor what I see is that the web call-in instantiates a userver, and received the answer, it closed, while calls for remote execution, remain active in the window even after a userver is closed by maxidle parameter.

    This is normal? Only after the client application is closed, the process disappears from client window? This could be the problem?

    Any suggestions to try?

     

    Thanks to all

     

    Marco


    Author: Marco (marco.aquino@dedalus.eu)
  9. Well as I suggest before, I would have a deeper look at the uniface services on the userver.

    Maybe there are some confusing, when you combine exit statements and call-out parameter.

    Also we had some problem in three-tier-environments when the last service which was called on userver side used exit instead of return.

    Maybe you can use your debug ust to add $proctracing and $procprofiling to this specific userver to get information what is really executed.

    Best regards

    Thomas


    Author: Thomas.Young (thomas.young@young-consulting.de)
  10. Thanks Thomas,

    I actived the proc_tracing, ioprint=2047 and proc_tracing_addition and I see this:

    ...
    Non-DBMS file open: xsserver.svc
    Non-DBMS file close:

    ; BLOCK 1

    To Router:chn=253;len=65: ANSWER; typ=Z;av=S;op=Z;ret=0,0;
        hop=0;dbg=0;pid=736;tid=18980;qid=0;ins=0;
    From Router:chn=253;len=1881: ACTREQ; typ=A;av=I;op=a;mod=1;iop=0;ign=0;
        hop=0;dbg=0;pid=736;tid=18980;qid=0;ins=0;
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:1  if (PAR_XML = "")
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:4  endif
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:5  activate "%%PAR_WS"."CALL"( LV_XML , PAR_XML )
    Descriptor for WSESTAV11 found in usys:udesc.urr
    Loaded 'uwso10' from C:\Programmi\Compuware\Uniface\bin\uwso10.dll, version: (none)
    Descriptor for WSESTAV11 found in usys:udesc.urr
    Loaded 'uutf' from C:\Programmi\Compuware\Uniface\bin\uutf.dll, version: 8.4.5.504 (8.4.05  D504)
    Descriptor for TESTWSSERVICE not found
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:6  if ($status < 0)
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:9  endif
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:10  PAR_INFO = LV_XML
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:11  exit 0
    REC=PROFILING,SEQ=2,NEST=1,ELAPSTIME=273644,TYPE=OPR,MODID=oOP_WSCALL,MODNAM=OP_WSCALL,OBJVERS=80,TRIG=OPER,APSNAM=ANY,CPTNAM=XSSERVER,INSNAM=_I00000001

    ; BLOCK 2

    To Router:chn=253;len=283: ANSWER; typ=Z;av=I;op=Z;ret=0,1;
        hop=0;dbg=0;pid=736;tid=18980;qid=0;ins=0;
    From Router:chn=253;len=124: ACTREQ; typ=A;av=I;op=i;mod=0;iop=0;ign=0;
        hop=0;dbg=0;pid=736;tid=18980;qid=0;ins=0;
    Non-DBMS file open: xsserver.svc
    Non-DBMS file close:

    ; BLOCK 3

    To Router:chn=253;len=65: ANSWER; typ=Z;av=S;op=Z;ret=0,0;
        hop=0;dbg=0;pid=736;tid=18980;qid=0;ins=0;
    From Router:chn=253;len=1267: ACTREQ; typ=A;av=I;op=a;mod=1;iop=0;ign=0;
        hop=0;dbg=0;pid=736;tid=18980;qid=0;ins=0;
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:1  if (PAR_XML = "")
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:4  endif
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:5  activate "%%PAR_WS"."CALL"( LV_XML , PAR_XML )
    Descriptor for TESTWSSERVICE not found
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:6  if ($status < 0)
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:9  endif
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:10  PAR_INFO = LV_XML
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:11  exit 0
    REC=PROFILING,SEQ=3,NEST=1,ELAPSTIME=238948,TYPE=OPR,MODID=oOP_WSCALL,MODNAM=OP_WSCALL,OBJVERS=80,TRIG=OPER,APSNAM=ANY,CPTNAM=XSSERVER,INSNAM=_I00000002

    ...
    more blocks like the above 2) and 3) in sequence, then last blocks
    ...

    To Router:chn=253;len=283: ANSWER; typ=Z;av=I;op=Z;ret=0,1;
        hop=0;dbg=0;pid=19852;tid=18368;qid=0;ins=0;
    From Router:chn=253;len=124: ACTREQ; typ=A;av=I;op=i;mod=0;iop=0;ign=0;
        hop=0;dbg=0;pid=13120;tid=13128;qid=0;ins=0;
    Non-DBMS file open: xsserver.svc
    Non-DBMS file close:

    To Router:chn=253;len=65: ANSWER; typ=Z;av=S;op=Z;ret=0,0;
        hop=0;dbg=0;pid=13120;tid=13128;qid=0;ins=0;
    From Router:chn=253;len=4094: ACTREQ; typ=A;av=I;op=a;mod=1;iop=0;ign=0;
        hop=0;dbg=0;pid=13120;tid=13128;qid=0;ins=0;
    From Router:chn=253;len=4094: ACTREQ;
    From Router:chn=253;len=4094: ACTREQ;
    From Router:chn=253;len=4094: ACTREQ;
    From Router:chn=253;len=4094: ACTREQ;
    From Router:chn=253;len=145: ACTREQ;
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:1  if (PAR_XML = "")
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:4  endif
    "Status:0 - PAR_WS:WSESTAV11 (OPER) OP_WSCALL:5  activate "%%PAR_WS"."CALL"( LV_XML , PAR_XML )

    The operation of the uniface service (xsserver.svc) is very simple, test if the param is not empty, then call the web service with activate, then test the return status and pass the response from webservice in output parameter then exit.

    The uniface component is drop from memory, self contained and attached.

    I saw that after the error, the userver process goes down and the client get status = -1 and procerror = -150 and procerrorcontext and message frame are empty.

    Why the log show the Descriptor for TESTWSSERVICE not found if it isn't the service that I call, the service is WSESTAV11? any suggestion?

    The last instruction is the activate on web service signature then the userver crash.

    On uniface help the -150 meaning

     

    A hardware or software error occurred. Contact your Uniface representative.

     

    Someone can explain me the meaning of BLOCK 2 and the row of log "From Router:chn=253;len=4094: ACTREQ; "

     

    Thanks in advance

     

    Marco


    Author: Marco (marco.aquino@dedalus.eu)
  11. perhaps TESTWSSERVICE is specified as "the real name" in your signature WSESTAV11 ?

    Just a guess, but we found this from time to time causing problems


    Author: ulrich-merkel (ulrichmerkel@web.de)
  12. I found it, TESTWSSERVICE is the real name on wsdl file of the service.

       <wsdl:service name="testWsService">
          <wsdl:port binding="intf:testWsSoapBinding" name="testWs">
             <wsdlsoap:address location="http://localhost/service11"/>
          </wsdl:port>
       </wsdl:service>
     

    I changed it to WSESTAV11 and the message there isn't more.

     

    Marco


    Author: Marco (marco.aquino@dedalus.eu)
  13. At the end the customer has the problem again, now I tried to add /maxreq=1 parameter on urouter.asn file to force the processing of only 1 request, so the userver closes after processing the request and create a new one for a new request. I hope that this trick works well Marco


    Author: Marco (marco.aquino@dedalus.eu)