VISTA XWB Broker Troubleshooting

Starting the Broker
On GT.M, to start the broker, you need to create an OS service (Xinetd on Linux) that calls.

On Cache, you can start a broker listener using the start-up file ZSTU by calling this:

On Cache, you can also fill out the RPC Broker Site Parameters file like this:

Select OPTION NAME: XWB MENU      RPC Broker Management Menu

RPC Listener Edit Start All RPC Broker Listeners Stop All RPC Broker Listeners Clear XWB Log Files Debug Parameter Edit View XWB Log

Select RPC Broker Management Menu  Option: RPC LISTener Edit

Select RPC BROKER SITE PARAMETERS DOMAIN NAME: ? Answer with RPC BROKER SITE PARAMETERS DOMAIN NAME, or STATUS: VISTA.PLATINUM Select RPC BROKER SITE PARAMETERS DOMAIN NAME:   VISTA.PLATINUM Select BOX-VOLUME PAIR: ICARUS:icarus// BOX-VOLUME PAIR: ICARUS:icarus// Select PORT: 9000 Are you adding '9000' as a new PORT (the 1ST for this LISTENER)? No// Y (Yes) STATUS: STOPPED// TYPE OF LISTENER: ? Choose from: 0       Original 1       New Style TYPE OF LISTENER: 1 New Style CONTROLLED BY LISTENER STARTER: ? Choose from: 0       NO       1        YES CONTROLLED BY LISTENER STARTER: 1 YES

Then ask Taskman to start this upon Taskman start-up, by creating this entry in file 19.2: OUTPUT FROM WHAT FILE: OPTION SCHEDULING// Select OPTION SCHEDULING NAME:   XWB LISTENER STARTER ANOTHER ONE: STANDARD CAPTIONED OUTPUT? Yes//  (Yes) Include COMPUTED fields: (N/Y/R/B): NO//  - No record number (IEN), no Computed Fields

NAME: XWB LISTENER STARTER             SPECIAL QUEUEING: STARTUP

When you start taskman from ZSTU using, the broker will be started by taskman.

Environment Check and Unit Test
The broker can fail at several points. All of them are covered by an environment check that either Wally or Joel wrote:. Here's an example:

GTM>D CHECK^XWBTCPMT

This will check for some of the errors that can prevent the Broker from getting started.

Debugging is set to Very Verbose Broker activity timeout is set to 180 Checking can Write to null device The NULL device is OK. Checking if new JOB's can start. New jobs are allowed. Done with the checks.

From the above, you can glean why a broker might not start or accept connections:
 * 1) The VOLUME multiple in the Kernel System Parameters isn't filled out properly.
 * 2) The VOLUME SET file has the disable flag set to yes.
 * 3) There is more than one NULL device or no NULL device.
 * 4) Your Mumps Implementation license doesn't allow you to start a new job.
 * 5) $$ACTJ^%ZOSV says you ran out of licenses.

In the same routine, there is also a broker tester to test your broker system by connecting to it, only you are doing it directly from Mumps. Here's an example:

GTM>D CALL^XWBTCPMT

Interactive Broker Test IP ADDRESS: 127.0.0.1 PORT: 9200 Success, response: accept

If this call succeeds (and you need to make sure that this is indeed the right port that hooks up to your VISTA system), then you are now certain that the new style broker works to some extent.

Broker Logging
If you have further issues, the easiest way to troubleshoot them is to turn on broker logging.

The following illustrates the use of the RPCBroker logging functionality that was initially added by Wally Fort. This can be controlled from within the menu system or at the programmer level.

'Caution -- If you use 'very Verbose' logging in a production system, it will create a very large amount of logging since it includes all input from the client as well as all output from the server. This may be overwhelming, since there is currently no mechanism provided to isolate logging to one or a few individuals. The use of very Verbose logging is best used in test systems or during off hours on a production system (and then remember to set it back down or off).'

The following illustrates the different levels of logging and its control from within the menu system, starting at EVE or the System Manager Menu.

Select Systems Manager Menu Option: OPerations Management

Select Operations Management Option: RPC Broker Management Menu

RPC Listener Edit Start All RPC Broker Listeners Stop All RPC Broker Listeners Clear XWB Log Files Debug Parameter Edit View XWB Log

Select RPC Broker Management Menu Option: DEBUG Parameter Edit

- Setting RPCBroker debug logging for System: JIVEY3.JIVEYSOFT.COM - Enable Broker Logging: No// ?

Enter a code from the list.

Select one of the following:

0        No          1         Yes 2        Verbose 3        very Verbose

Enable Broker Logging: No// 1 Yes

At this point a broker connection was made with BrokerExample and Execute RPC selected on the Pass By Reference tab. Select RPC Broker Management Menu Option: VIEw XWB Log Log Files

Log from Job 13584 7 Lines              <-- output from 1 or Yes logging --> 09:03:28 = Log start: Jul 22, 2013@09:03:28 09:03:28 = XWBTCPM 09:03:28 = MSG format is [XWB] type NEW 09:03:28 = accept 09:06:53 = SETTIME IN POST2^XUSRB 09:07:07 = BYE CMD 09:07:07 = Exit: #BYE# Return to continue, Next log, Exit: Continue// ? <-- note Kill is not listed -->

Enter RETURN to continue, Next for next log, Kill to remove log, Exit to quit log view.

Select one of the following:

1        Continue 2        Next 3        Exit 4        Kill

Return to continue, Next log, Exit: Continue// Kill Log XWBLOG13584 deleted.

Select RPC Broker Management Menu Option: CLear XWB Log Files Remove all XWB log entries? No// YES Done

Select RPC Broker Management Menu Option: DEbug Parameter Edit

- Setting RPCBroker debug logging for System: JIVEY3.JIVEYSOFT.COM - Enable Broker Logging: Yes// ?

Enter a code from the list.

Select one of the following:

0        No          1         Yes 2        Verbose 3        very Verbose

Enable Broker Logging: Yes// 2 Verbose

Again an RPCBroker connection was made and the same RPC used.

Select RPC Broker Management Menu Option: View XWB Log Log Files

Log from Job 11516 18 Lines          <-- output from 2 or Verbose logging --> 09:09:25 = Log start: Jul 22, 2013@09:09:25 09:09:25 = XWBTCPM 09:09:25 = MSG format is [XWB] type NEW 09:09:25 = CMD: TCPConnect 09:09:25 = accept 09:09:25 = RPC: XUS SIGNON SETUP 09:09:25 = RPC: XUS INTRO MSG 09:09:33 = RPC: XUS AV CODE 09:09:34 = SETTIME IN POST2^XUSRB 09:09:34 = RPC: XUS GET USER INFO 09:09:34 = RPC: XWB GET BROKER INFO 09:09:34 = RPC: XUS DIVISION GET 09:09:34 = RPC: XWB CREATE CONTEXT 09:09:34 = RPC: XWB CREATE CONTEXT 09:09:40 = RPC: XWB GET VARIABLE VALUE 09:09:46 = CMD: #BYE# 09:09:46 = BYE CMD 09:09:46 = Exit: #BYE# Return to continue, Next log, Exit: Continue// Kill Log XWBLOG11516 deleted.

Select RPC Broker Management Menu Option: DEBug Parameter Edit

- Setting RPCBroker debug logging for System: JIVEY3.JIVEYSOFT.COM - Enable Broker Logging: Verbose// ?

Enter a code from the list.

Select one of the following:

0        No          1         Yes 2        Verbose 3        very Verbose

Enable Broker Logging: Verbose// 3 very Verbose

Another RPCBroker connection was made and the RPC selected Select RPC Broker Management Menu Option: View XWB Log Log Files

Log from Job 13652 53 Lines  <-- output from 3 or very Verbose logging --> 09:10:44 = Log start: Jul 22, 2013@09:10:44 09:10:44 = XWBTCPM 09:10:44 = rd: [XWB]10304\10TCPConnect50013192.168.1.100f00010f0006Jivey3f\04 09:10:44 = MSG format is [XWB] type NEW 09:10:44 = CMD: TCPConnect 09:10:44 = wrt (9): \00\00accept\04 09:10:44 = accept 09:10:44 = rd: [XWB]11302\010\16XUS SIGNON SETUP50048"_"x"g"Ex"DXeT|vD*G|"mevgg |e*Dm"xDxxg*gDv*ynm**x$f\04 09:10:44 = RPC: XUS SIGNON SETUP 09:10:44 = Call: SETUP^XUSRB(.XWBY,XWB(5,"P",0)) 09:10:44 = wrt (83): \00\00Jivey3\13\10VISTA\13\10VISTA\13\10//./nul:13652\13\1          05\13\100\13\10JIVEY3.JIVEYSOFT.COM\13\100\13\10\04 09:10:44 = rd: [XWB]11302\010\13XUS INTRO MSG54f\04 09:10:44 = RPC: XUS INTRO MSG 09:10:44 = Call: INTRO^XUSRB(.XWBY) 09:10:44 = wrt (3): \00\00\04 09:10:51 = rd: [XWB]11302\010\11XUS AV CODE50020&NFb/#NFmmm0Zyyyyyq.f\04 09:10:51 = RPC: XUS AV CODE 09:10:51 = Call: VALIDAV^XUSRB(.XWBY,XWB(5,"P",0)) 09:10:51 = SETTIME IN POST2^XUSRB Return to continue, Next log, Exit: Continue// [H [J [2J [H 09:10:51 = wrt (176): \00\002802\13\100\13\100\13\10\13\100\13\100\13\10\13\10G           ood morning Joel\13\10     You last signed on today at 09:09\13\10Yo           u have 2 new messages. (2 in the 'IN' basket)\13\10\13\10Enter '^NML           ' to read your new messages.\13\10\04 09:10:51 = rd: [XWB]11302\010\17XUS GET USER INFO54f\04 09:10:51 = RPC: XUS GET USER INFO 09:10:51 = Call: USERINFO^XUSRB2(.XWBY) 09:10:51 = wrt (83): \00\002802\13\10IVEY,JOEL L\13\10Joel L Ivey\13\101^SOFTWA RE SERVICE^050\13\10PROGRAMMER\13\10IRM\13\10\13\10600\13\10\04 09:10:51 = rd: [XWB]11302\010\19XWB GET BROKER INFO54f\04 09:10:51 = RPC: XWB GET BROKER INFO 09:10:51 = Call: BRKRINFO^XWBLIB(.XWBY) 09:10:51 = wrt (8): \00\00200\13\10\04 09:10:51 = rd: [XWB]11302\010\16XUS DIVISION GET54f\04 09:10:51 = RPC: XUS DIVISION GET 09:10:51 = Call: DIVGET^XUSRB2(.XWBY) 09:10:51 = wrt (6): \00\000\13\10\04 09:10:51 = rd: [XWB]11302\010\18XWB CREATE CONTEXT50002&,f\04 09:10:51 = RPC: XWB CREATE CONTEXT 09:10:51 = Call: CRCONTXT^XWBSEC(.XWBY,XWB(5,"P",0)) 09:10:51 = wrt (4): \00\001\04 09:10:51 = rd: [XWB]11302\010\18XWB CREATE CONTEXT50020 @|d]deAYVe]V@ENLRV"f\04 09:10:51 = RPC: XWB CREATE CONTEXT 09:10:51 = Call: CRCONTXT^XWBSEC(.XWBY,XWB(5,"P",0)) Return to continue, Next log, Exit: Continue// [H [J [2J [H 09:10:51 = wrt (4): \00\001\04 09:10:56 = rd: [XWB]11302\010\22XWB GET VARIABLE VALUE51008$HOROLOGf\04 09:10:56 = RPC: XWB GET VARIABLE VALUE 09:10:56 = Call: VARVAL^XWBLIB(.XWBY,XWB(5,"P",0)) 09:10:56 = wrt (14): \00\0063025,33056\04 09:11:04 = rd: [XWB]11302\010\22XWB GET VARIABLE VALUE51008$HOROLOGf\04 09:11:04 = RPC: XWB GET VARIABLE VALUE 09:11:04 = Call: VARVAL^XWBLIB(.XWBY,XWB(5,"P",0)) 09:11:04 = wrt (14): \00\0063025,33064\04 09:11:08 = rd: [XWB]10304\05#BYE#\04 09:11:08 = CMD: #BYE# 09:11:08 = wrt (8): \00\00#BYE#\04 09:11:08 = BYE CMD 09:11:08 = Exit: #BYE# Return to continue, Next log, Exit: Continue// Kill Log XWBLOG13652 deleted.

Select RPC Broker Management Menu Option: DEbug Parameter Edit

- Setting RPCBroker debug logging for System: JIVEY3.JIVEYSOFT.COM - Enable Broker Logging: very Verbose// 0 No

These commands can also be run from Programmer Mode

Select RPC Broker Management Menu Option: ^PG

VISTA>D EDITPAR^XPAREDIT("XWBDEBUG")

- Setting RPCBroker debug logging for System: JIVEY3.JIVEYSOFT.COM - Enable Broker Logging: No// ?

Enter a code from the list.

Select one of the following:

0        No          1         Yes 2        Verbose 3        very Verbose

Enable Broker Logging: No// 3 very Verbose

Again a connection was made with RPCBroker and the same RPC used.

VISTA>D VIEW^XWBDLOG

Log Files

Log from Job 7376 49 Lines     <-- output from 3 or very Vebose logging --> 09:13:21 = Log start: Jul 22, 2013@09:13:21 09:13:21 = XWBTCPM 09:13:21 = rd: [XWB]10304\10TCPConnect50013192.168.1.100f00010f0006Jivey3f\04 09:13:21 = MSG format is [XWB] type NEW 09:13:21 = CMD: TCPConnect 09:13:21 = wrt (9): \00\00accept\04 09:13:21 = accept 09:13:22 = rd: [XWB]11302\010\16XUS SIGNON SETUP50048&H[e[f[xe[xWl_j(xosj[el(ff jloxW[exfefofx(o[eooe)f\04 09:13:22 = RPC: XUS SIGNON SETUP 09:13:22 = Call: SETUP^XUSRB(.XWBY,XWB(5,"P",0)) 09:13:22 = wrt (82): \00\00Jivey3\13\10VISTA\13\10VISTA\13\10//./nul:7376\13\10 5\13\100\13\10JIVEY3.JIVEYSOFT.COM\13\100\13\10\04 09:13:22 = rd: [XWB]11302\010\13XUS INTRO MSG54f\04 09:13:22 = RPC: XUS INTRO MSG 09:13:22 = Call: INTRO^XUSRB(.XWBY) 09:13:22 = wrt (3): \00\00\04 09:13:32 = rd: [XWB]11302\010\11XUS AV CODE50020)'6aHt'6ew6k{wt56U!1f\04 09:13:32 = RPC: XUS AV CODE 09:13:32 = Call: VALIDAV^XUSRB(.XWBY,XWB(5,"P",0)) 09:13:32 = SETTIME IN POST2^XUSRB Return to continue, Next log, Exit: Continue// 09:13:32 = wrt (176): \00\002802\13\100\13\100\13\10\13\100\13\100\13\10\13\10G          ood morning Joel\13\10     You last signed on today at 09:10\13\10Yo           u have 2 new messages. (2 in the 'IN' basket)\13\10\13\10Enter '^NML           ' to read your new messages.\13\10\04 09:13:32 = rd: [XWB]11302\010\17XUS GET USER INFO54f\04 09:13:32 = RPC: XUS GET USER INFO 09:13:32 = Call: USERINFO^XUSRB2(.XWBY) 09:13:32 = wrt (83): \00\002802\13\10IVEY,JOEL L\13\10Joel L Ivey\13\101^SOFTWA           RE SERVICE^050\13\10PROGRAMMER\13\10IRM\13\10\13\10600\13\10\04 09:13:32 = rd: [XWB]11302\010\19XWB GET BROKER INFO54f\04 09:13:32 = RPC: XWB GET BROKER INFO 09:13:32 = Call: BRKRINFO^XWBLIB(.XWBY) 09:13:32 = wrt (8): \00\00200\13\10\04 09:13:32 = rd: [XWB]11302\010\16XUS DIVISION GET54f\04 09:13:32 = RPC: XUS DIVISION GET 09:13:32 = Call: DIVGET^XUSRB2(.XWBY) 09:13:32 = wrt (6): \00\000\13\10\04 09:13:32 = rd: [XWB]11302\010\18XWB CREATE CONTEXT50002'/f\04 09:13:32 = RPC: XWB CREATE CONTEXT 09:13:32 = Call: CRCONTXT^XWBSEC(.XWBY,XWB(5,"P",0)) 09:13:32 = wrt (4): \00\001\04 09:13:32 = rd: [XWB]11302\010\18XWB CREATE CONTEXT50020+G4@]@TBlET]EGS.b0E,f\04 09:13:32 = RPC: XWB CREATE CONTEXT 09:13:32 = Call: CRCONTXT^XWBSEC(.XWBY,XWB(5,"P",0)) Return to continue, Next log, Exit: Continue// 09:13:32 = wrt (4): \00\001\04 09:13:36 = rd: [XWB]11302\010\22XWB GET VARIABLE VALUE51008$HOROLOGf\04 09:13:36 = RPC: XWB GET VARIABLE VALUE 09:13:36 = Call: VARVAL^XWBLIB(.XWBY,XWB(5,"P",0)) 09:13:36 = wrt (14): \00\0063025,33216\04 09:13:39 = rd: [XWB]10304\05#BYE#\04 09:13:39 = CMD: #BYE# 09:13:39 = wrt (8): \00\00#BYE#\04 09:13:39 = BYE CMD 09:13:39 = Exit: #BYE# Return to continue, Next log, Exit: Continue// ?

Enter RETURN to continue, Next for next log, Kill to remove log, Exit to quit log view.

Select one of the following:

1        Continue 2        Next 3        Exit 4        Kill

Return to continue, Next log, Exit: Continue// Kill Log XWBLOG7376 deleted.

VISTA>D KILLALL^XWBDLOG

Remove all XWB log entries? No// YES Done VISTA>

Some essential parts to understand: a byte that is  (\04) always ends a message. A byte "f" means it's the end of the argument. The item just before the argument is the argument length. The client creates this message. Therefore, if this message is not created properly at the client, it won't be read properly by VISTA. VISTA replies usually start with  signifying that there is no error to send to the client.

Foreground Debugging of Broker Calls
Last but not least, for desperate debuggers, you can put breakpoints in your current process and run the listener process in the foreground and then connect your client. You will hit the breakpoint:

GTM>D DEBUG^XWBTCPM

Before running this entry point set your debugger to stop at the place you want to debug. Some spots to use: 'SERV+1^XWBTCPM', 'MAIN+1^XWBTCPM' or 'CAPI+1^XWBPRS.'

or location of your choice.

IP Socket to Listen on: ...