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
Local Administrator
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)
Local Administrator
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)
Local Administrator
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
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)
Local Administrator
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)
Local Administrator
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)
Local Administrator
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)
Local Administrator
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)
Local Administrator
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)
Local Administrator
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)
Local Administrator
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)
Local Administrator
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)
Local Administrator
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)
Local Administrator
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)