Uniface 9.7.05 - umsgutil.exe

Interestingly, when I use the old umsgutil.exe from 9.7.04 in the 9.7.05 environment it works. I know, umsgutil.exe 
has changed with 9.7.05. But I have no idea right now, if I'm running into a bug or if I have to do some further settings. 

Does anyone can help me?

Kind regards,

Michael.

Hi Michael,

As of 9.7.05 the umgutil.exe program also requires access to a number of the uniface runtime DLLs. The reason for this change is to enable the possibility of sending async messages over secure TLS encrypted connections. The Uniface documentation describes the requirements for umsgutil.exe - https://u.uniface.info/docs/1000/uniface/_reference/executables/umsgutil_exe.htm.

I hope this help,

Mike

Interestingly, when I use the old umsgutil.exe from 9.7.04 in the 9.7.05 environment it works. I know, umsgutil.exe 
has changed with 9.7.05. But I have no idea right now, if I'm running into a bug or if I have to do some further settings. 

Does anyone can help me?

Kind regards,

Michael.

Hi Mike,

thank you for your quick response. I checked it. The mentioned dll files at the right place. This seems not to be the solution.

Michael

Hi Michael,

Just did a quick test here with 9.7.05.037 and sending a message via umsgutil.exe is not a problem.

When I, however, try to send a message using the the version 9.7.04 umsgutil.exe to a version 9.7.05 application then I get the error -12017 (Initialize Socket failed). Are you sure that you are addressing the correct URouter service (i.e. that for Uniface 9.7.05)?

I hope this helps.

Daniel
 

Hi Daniel,

very strange... 

First try: Uniface 9.7.05 with the umsgutil from 9.7.04 addressing an urouter with 9.7.05 → this works.

Second try: Uniface 9.7.05 with the umsgutil from 9.7.05 addressing the same urouter with 9.7.05 works as in try 1 → doesn't work

Here ist some urouter log and trace from both cases (maybe it's helpful):

works (case 1):

7:42.538.86 t=2: accepted new connection on TCP:+13011
7:42.539.34 t=21: From Client:chn=8;len=169: CLTCON;
7:42.539.40 t=21: clt=(hst=192.168.101.123,<client-host>;pid=18064;tid=11808;sid=0;usr=<myuser>;ust=ica-cgp#26)
7:42.539.45 t=21: log=(hst=TCP:<urouter-host>+13011;usr=<myuser>;ust=ica-cgp#26)
7:42.539.60 t=21: reguser: nid=192.168.101.123, node=<client-host>, pid=18064, ust=ica-cgp#26
7:42.539.80 t=21: To Client:chn=8;len=2: CONANS; continue:
7:42.540.23 t=21: From Client:chn=8;len=46: HANDSHAKE; pv=9:max=4096:ver=9.7.05~007F
7:42.540.48 t=21: To Client:chn=8;len=49: HANDSHAKE; pv=9:max=4096:ver=9.7.05~007F
7:44.507.31 t=2: accepted new connection on TCP:+13011
7:44.507.79 t=22: From Client:chn=9;len=286: V7ASYNC: typ=10;don=write;ver=2.0;max=4096;met=UTF-8:
7:44.508.11 t=22: To Client:chn=9;len=12: V7ASYNC: typ=10;don=discon;ver=2.0;max=4096;met=UTF-8:
7:44.508.36 t=22: V7ASYNCH to <urouter-host>|<myuser>||ICA-CGP#26> from <fake-host|fake-user||API>
7:44.508.48 t=22: sending PM directly to <urouter-host>|<myuser>||ICA-CGP#26
7:44.508.71 t=22: To Server:chn=8;len=70: POSTMSG; id=ELA_BERI1;to=
7:44.508.76 t=22: frm=TCP:fake-host|fake-user||API:UMDPOSTMSG

doesn't work (case 2):

53:37.132.14 t=2: accepted new connection on TCP:+13011
53:37.132.61 t=24: From Client:chn=8;len=169: CLTCON;
53:37.132.67 t=24: clt=(hst=192.168.101.123,<client-host>;pid=11960;tid=24628;sid=0;usr=<myuser>;ust=ica-cgp#26)
53:37.132.72 t=24: log=(hst=TCP:<urouter-host>+13011;usr=<myuser>;ust=ica-cgp#26)
53:37.132.87 t=24: reguser: nid=192.168.101.123, node=<client-host>, pid=11960, ust=ica-cgp#26
53:37.133.06 t=24: To Client:chn=8;len=2: CONANS; continue:
53:37.133.57 t=24: From Client:chn=8;len=46: HANDSHAKE; pv=9:max=4096:ver=9.7.05~007F
53:37.133.81 t=24: To Client:chn=8;len=49: HANDSHAKE; pv=9:max=4096:ver=9.7.05~007F
53:48.770.13 t=24: From Client:chn=8;len=36: CLSNETREQ; typ=X;av=I;op=Z;mod=0;iop=0;ign=0;
53:48.770.20 t=24: hop=0;dbg=0;pid=11960;tid=24628;qid=0;ins=0;
53:48.770.46 t=24: To Client:chn=8;len=32: ANSWER; typ=Z;av=X;op=Z;ret=0,0;
53:48.770.50 t=24: hop=0;dbg=0;pid=0;tid=0;qid=0;ins=0;

From urouter trace log (both cases):

5R;506:51.901.37; 24;unctrel: unlock send mutex(1153456) chn=8, sc=0
6P;506:51.901.39; 24;umwgo: enter call=UMWRCVMSG, TCP(00000001001715D0), chn=8, ign=0
6P;506:51.901.42; 24;UMWPSV10: enter call=UMWRCVMSG, TCP(00000001001715D0), chn=8, lst=7, cons=0, refs=1
6P;506:51.901.45; 24;recmsg: enter TCP(00000001001715D0) mode=READNET connr=0; chn=8; lst=7; cons=0; refs=1
6s;506:51.901.48; 24;UNWTCP: enter TCP(4296480208) call=NETGET, chn=8, lst=7
8s;506:51.901.50; 24;UNWTCP: do_recv: Calling recv() for 2 bytes . . .
8s;507:03.537.34; 24;UNWTCP: TCPreceive: expected message length=36
8s;507:03.537.42; 24;UNWTCP: do_recv: Calling recv() for 36 bytes . . .
5s;507:03.537.45; 24;UNWTCP: exit TCP(4296480208) call=NETGET, chn=8, lst=7, result=NET_SUCCESS, err=0
9F;507:03.537.49; 24;From Client:chn=8;len=36: CLSNETREQ; typ=X;av=I;op=Z;mod=0;iop=0;ign=0;
9F;507:03.537.56; 24; hop=0;dbg=0;pid=11960;tid=24628;qid=0;ins=0;
5P;507:03.537.62; 24;recmsg: exit TCP(00000001001715D0) mode=READNET connr=0; chn=8; lst=7; cons=0; refs=1; ret=36
5P;507:03.537.64; 24;UMWPSV10: exit call=UMWRCVMSG, TCP(00000001001715D0), chn=8, lst=7, cons=0, refs=1, ret=NET_SUCCESS [36]
6P;507:03.537.67; 24;umwgo: exit call=UMWRCVMSG, TCP(00000001001715D0), chn=8, ign=0, ret=NET_SUCCESS [36]
9R;507:03.537.71; 24;unctown: enter main=1512912 chn=8 sact=0 sc=0
5R;507:03.537.73; 24;unctown: lock send mutex(1153456) chn=8, sc=1
6P;507:03.537.76; 24;umwgo: enter call=UMWSNDMSG, TCP(00000001001715D0), chn=8, ign=0
6P;507:03.537.79; 24;UMWPSV10: enter call=UMWSNDMSG, TCP(00000001001715D0), chn=8, lst=7, cons=0, refs=1
9F;507:03.537.82; 24;To Client:chn=8;len=32: ANSWER; typ=Z;av=X;op=Z;ret=0,0;
9F;507:03.537.87; 24; hop=0;dbg=0;pid=0;tid=0;qid=0;ins=0;
6s;507:03.537.91; 24;UNWTCP: enter TCP(4296480208) call=NETPUT, chn=8, lst=7
5s;507:03.537.95; 24;UNWTCP: exit TCP(4296480208) call=NETPUT, chn=8, lst=7, result=NET_SUCCESS, err=0
5P;507:03.537.98; 24;UMWPSV10: exit call=UMWSNDMSG, TCP(00000001001715D0), chn=8, lst=7, cons=0, refs=1, ret=NET_SUCCESS [0]
6P;507:03.538.01; 24;umwgo: exit call=UMWSNDMSG, TCP(00000001001715D0), chn=8, ign=0, ret=NET_SUCCESS [0]
9R;507:03.538.04; 24;unctrel: enter main=1512912 chn=8 sact=2 sc=1
5R;507:03.538.06; 24;unctrel: unlock send mutex(1153456) chn=8, sc=0
6P;507:03.538.09; 24;umwgo: enter call=UMWRCVMSG, TCP(00000001001715D0), chn=8, ign=1
6P;507:03.538.12; 24;UMWPSV10: enter call=UMWRCVMSG, TCP(00000001001715D0), chn=8, lst=7, cons=0, refs=1
6P;507:03.538.14; 24;recmsg: enter TCP(00000001001715D0) mode=READNET connr=0; chn=8; lst=7; cons=0; refs=1
6s;507:03.538.17; 24;UNWTCP: enter TCP(4296480208) call=NETGET, chn=8, lst=7
8s;507:03.538.20; 24;UNWTCP: do_recv: Calling recv() for 2 bytes . . .
8s;507:03.538.24; 24;UNWTCP: do_recv: explicitly ignoring error for zero length retries
5s;507:03.538.27; 24;UNWTCP: exit TCP(4296480208) call=NETGET, chn=8, lst=7, result=Ignoring error, err=-4
8P;507:03.538.30; 24;recmsg: exit TCP(00000001001715D0) mode=READNET connr=0; chn=8; lst=7; cons=0; refs=1; ret=-16
5P;507:03.538.33; 24;UMWPSV10: exit call=UMWRCVMSG, TCP(00000001001715D0), chn=8, lst=7, cons=0, refs=1, ret=NETERR_UNKNOWN [-16]
7P;507:03.538.36; 24;umwgo: UMWDISCON call, error on UMWRCVMSG, TCP, chn=8, nerr=-4 ,ret=NETERR_UNKNOWN [-16]
6P;507:03.538.38; 24;UMWPSV10: enter call=UMWDISCON, TCP(00000001001715D0), chn=8, lst=7, cons=0, refs=1
6s;507:03.538.41; 24;UNWTCP: enter TCP(4296480208) call=NETDISCONNECT, chn=8, lst=7
8s;507:03.538.44; 24;UNWTCP: TCPshutdown: chn=8 attempt
8s;507:03.538.47; 24;UNWTCP: TCPshutdown: chn=8 success
8s;507:03.538.50; 24;UNWTCP: TCPclose: chn=8 attempt
8s;507:03.538.53; 24;UNWTCP: TCPclose: chn=8 success
5s;507:03.538.56; 24;UNWTCP: exit TCP(4296480208) call=NETDISCONNECT, chn=0, lst=7, result=NET_SUCCESS, err=0
5P;507:03.538.59; 24;UMWPSV10: exit call=UMWDISCON, TCP(00000001001715D0), chn=0, lst=7, cons=0, refs=1, ret=NET_SUCCESS [0]
6P;507:03.538.61; 24;umwgo: exit call=UMWRCVMSG, TCP(00000001001715D0), chn=0, ign=1, ret=NETERR_UNKNOWN [-16]
6s;507:03.538.64; 24;UNWTCP: enter TCP(4296480208) call=NETDISCONNECT, chn=0, lst=7
5s;507:03.538.67; 24;UNWTCP: exit TCP(4296480208) call=NETDISCONNECT, chn=0, lst=7, result=NET_SUCCESS, err=0
5R;507:03.538.70; 24;udeallocnet: deleting net=TCP(00000001001715D0); prt=13001; cons=0; refs=0; mut=00000001001199B0; cln=F, prv=F, cha=F
1Z;507:03.538.73; 24;thpsv: thread exit, cnt=2, lst=1, pmq=0, cc=0

Hope this helps a bit.

Thanks in advance,

Michael.

I've found now the reason for the -12017 error: the umsgutil.exe from version <9.7.05 does not like it if TCP is specified in the /dnp command line switch (e.g. /dnp=TCP:localhost+13001|uniuser). In Uniface 9.7.05 the network driver is now optional (if omitted then TCP is assumed).

As for your issue, it seems that umsgutil.exe has a problem during start-up. Since version 9.7.05 umsgutil.exe works like a "normal" Uniface application. So, it will read the default INI- and ASN-files. By default umsgutil.exe will try to read an ASN-file called UNI3GL.ASN, but you also can specify a different ASN-file with the /asn command line switch. Maybe creating a putmess logfile with $ioprint=64 (or higher) will give you a clue about what's going wrong here.

I hope this helps.

Daniel

Hi Daniel,

hm... UNI3GL.ASN doesn't exists in our uniface installation. I made my own asn-files and did the tests. ioprint reported the following lines:

Object size=0000109 prc/$$register@system_library.prc
Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\usys.uar
Object size=0000032 msg/u_busy@usys@usa.msg
Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\usys.uar
Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\uidf.uar
Object size=0000524 sig/uurepos.sig
Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\usys.uar
Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\uidf.uar
Object size=0000321 svc/uurepos.svc
Object NOTFOUND [0] rsp/uurepos@usa
Object NOTFOUND [0] rsp/uurepos@system_library@usa.rsp

Then it stops. 

the only place where I could find "svc/uurepos.svc" is in the uidf.uar

What is the "rsp" folder?

This is from the latest help file:

Normally, this program takes the command line arguments /dnp=Destination, /mid=MessageId and /msg=MessageData.

Is there any additional documentation?

I've get the same output here, except that it continuous with the following lines:

Loaded 'umwpsv10' from C:\\Program Files (x86)\\Uniface\\Uniface 9.7.01\\common\\bin\\umwpsv10.dll, version: 9.7.05 037
Loaded 'utcp10' from C:\\Program Files (x86)\\Uniface\\Uniface 9.7.01\\common\\bin\\utcp10.dll, version: 9.7.05 037

You could try to create a trace file with the following settings:

$trc_levels=9DPRs
$trc_start=c:\\temp\\uni3gl.trc

The above settings should be added to the [SETTINGS] section of your UNI3GL.ASN.

And yes, the mentioned settings are not documented. This functionality is only intended for support for troubleshooting.

Hi Daniel,

here is the trace output:

1; 101;Filename=E:\\ProgramData\\ARZ\\usys9_errorlogs\\entwicklung97\\umsgutil11540.trc Tracing=on Info=num,cat,lvl Type=cached Frame=0 Levels=9DPRs At=
3; 1D;Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\usys.uar
3; 2D;Object size=0000220 edc/uobj@text.edc
3; 3D;Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\usys.uar
3; 4D;Object Lookup: uar\\apoprod48.zip
3; 5D;Object size=0000109 prc/$$register@system_library.prc
3; 6D;Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\usys.uar
3; 7D;Object size=0000032 msg/u_busy@usys@usa.msg
3; 8D;Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\usys.uar
3; 9D;Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\uidf.uar
3; 10D;Object size=0000524 sig/uurepos.sig
3; 11D;Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\usys.uar
3; 12D;Object Lookup: C:\\Program Files (x86)\\Uniface\\Uniface 9.7.03\\common\\usys\\uidf.uar
3; 13D;Object size=0000321 svc/uurepos.svc
3; 14D;Object NOTFOUND [0] rsp/uurepos@usa
3; 15D;Object NOTFOUND [0] rsp/uurepos@system_library@usa.rsp
6; 1P;ushutnet: enter
5; 2P;ushutnet: exit

Michael

Thanks for the additional info.

It seems that usmgutil.exe now always needs an instance name in the Destination parameter (/dst). Otherwise it will not work. I can see the problem here now as well, when I use the following destination:

/dst=MyClient1:

This, on the other hand, will work:

/dst=MyClient1:INST1

This will send a postmessage to the instance INST1 of the target application that is registered as MyClient1 with the URouter.

If you, however, specify a non-existing instance name then the message will be sent to the start-up shell (which basically is the same as omitting the instance name in /dst). E.g.

/dst=MyClient1:0

The only difference between this and omitting the instance name is that $msgdst is empty in the latter case and contains "0" in the former.

I hope this helps.

Daniel

Hi Daniel,

the instance name was the solution. Now it works.

Thank you very much for your help. 

Michael