Protocol exploration in RES Automation Manager – Part 1
Dispatchers and consoles talk directly to the database, using standard DB clients. In the case of MS SQL Server, used in the vast majority of implementations, this is the SQL Native Client (SQLNCLI). Protocol details are not of much interest, since we can run a profiler on the SQL server to see exactly what queries are performed. According to the Administration Guide:
The Agent contacts the Dispatcher at regular intervals. If a new Job is available, the Agent will download all necessary data from the Dispatcher and perform the Job.
Great, but how does this communication work? What does a conversation between an agent and a dispatcher look like?
Interactive Agent
The agent executable accepts the /interactive parameter which starts the agent with a GUI. This can be used to switch RES AM envropnment connections but it also shows Current Activity indicating it is sending messages to the dispatcher. When the agent is idle it usually just shows this:
So the agent sends out a CHECKFORCHANGES message every few seconds, which makes perfect sense. During startup, and when a job is executed you see many different types of messages flying past. Unfortunately the GUI updates rather quickly and does not seem to show or keep any history.
Trace-file
Next stop is the logging and tracing built into the product. The logfile and Windows Application Event-log do not show many interesting things but in the registry you can enable a detailed trace of any RES AM component. You simply specify Trace and TraceDetailed as well as a location for the file. It uses rotational logging to a file with a fixed size of 2 MB. Loading the trace-file in excel let’s you analyse the information with relative ease. Split the columns on tabs and split the [Info] column on a semicolon to give you detailed information on the agents activity. This sequence shows up regularly and seems to correspond with the CHECKFORCHANGES message being sent out:
| Source | Data |
|---|---|
| frmMain.tmrScheduler_Timer | Begin |
| frmMain.tmrScheduler | Checking for jobs to process (jobcount = '0') |
| frmMain.tmrScheduler | mysnFreshBoot = 'no' |
| frmMain.tmrScheduler | mysnFirstTimeScheduleRetrieved = 'no' |
| frmMain.tmrScheduler | mysnComputerResumed = 'no' |
| frmMain.tmrScheduler | mysnComputerResumedScheduleRetrieved = 'no' |
| frmMain.tmrScheduler_Timer | End |
This is kind of boring, what else is in there? Scheduling a simple module on the agent and applying some filtering on the columns we can extract a variety of messages being sent:
| Source | Data |
|---|---|
| frmMain.ctlComm.IPPortS_Connected | Begin (192.168.2.110) |
| frmMain.ctlComm.SendMessage | Begin (CHECKCSN) |
| frmMain.ctlComm.SendMessage | Begin (CHECKFORCHANGES) |
| frmMain.ctlComm.SendMessage | Begin (CHECKFORUPDATES) |
| modMain.fysnIsFormLoaded | Begin (Form: frmDiscoverDispatchers) |
| frmMain.ctlComm.SendMessage | Begin (GETDISPATCHERLIST) |
| frmMain.ctlComm.SendMessage | Begin (GETGLOBALPROPERTIES) |
| frmMain.ctlComm.SendMessage | Begin (GETIDMETHOD) |
| frmMain.ctlComm.SendMessage | Begin (GETJOBDETAILS) |
| frmMain.ctlComm.SendMessage | Begin (GETPROPERTIES) |
| frmMain.ctlComm.SendMessage | Begin (GETSCHEDULEOVERVIEW) |
| frmMain.ctlComm.SendMessage | Begin (LOGON) |
| frmMain.ctlComm.SendMessage | Begin (SETJOBCURRENTACTIVITY) |
| frmMain.ctlComm.SendMessage | Begin (SETJOBSTATUS) |
| frmMain.ctlComm.SendMessage | Begin (SETLOG) |
| frmMain.ctlComm.SendMessage | Begin (SETLOGGEDONUSER) |
| frmMain.ctlComm.SendMessage | Begin (SETQUERYIMAGE) |
| frmMain.ctlComm.SendMessage | Begin (SETQUERYRESULTS) |
| frmMain.ctlComm.SendMessage | Begin (SETWTCOFFSET) |
| frmDiscoverDispatchers.ctlComm.SendMessage | Begin (WHOAREYOU1) |
Now that’s more like it! We see some different messages being sent, mainly from the frmMain.ctlComm.SendMessage source which seems to be the shared class/method for network communication. However, even if we look at all the details in the trace-file for any particular message, we only see information like this:
| Source | Data |
|---|---|
| frmMain.ctlComm.SendMessage | Begin (SETJOBSTATUS) |
| modMain.flngSetJobStatus | Start |
| frmMain.ctlComm.SendMessage | Start Sending Message |
| frmMain.ctlComm.SendData | Begin |
| sharedWisdomFunctions.flngDetermineMaxSpeed | Agent Speed: 524288 vs Dispatcher Speed: 524288 |
| sharedWisdomFunctions.flngDetermineMaxSpeed | End (Return: 524288) |
| frmMain.ctlComm.SendData | Segment |
| frmMain.ctlComm.SendData | Block Send OK (994 Bytes send) |
| frmMain.ctlComm.SendData | End (994 / 994) |
| frmMain.ctlComm.IPPortS_DataIn | First package |
| sharedFileOperations.fstrGetTempFile | Return: "C:\WINDOWS\TEMP\wis7E8.tmp" |
| frmMain.ctlComm.IPPortS_DataIn | All packages received (4 bytes) |
We get quite a bit of information but not the contents of the messages. So the trace-file definitely helps in understanding the functioning of the agent but to figure out the protocol we need to dig a little deeper.
Protocol Characteristics
RES Automation Manager uses port 3163 (TCP/UDP) for communication between Agents and Dispatchers. This port is hard-coded and cannot be changed.
Both TCP and UDP port 3163 are registered as RES-SAP protocol with IANA. According to the documentation, UDP is only used for discovery / broadcasting. That may be interesting down the line but let’s start the investigation with TCP.
Network sniffing with Wireshark
Using Wireshark we can quickly confirm that the dispatcher receives regular traffic on TCP port 3163 from the agent(s). Start capturing on the dispatcher with a rule tcp.port == 3163 to filter out all the noise. A common exchange we see with an idle agent is this:
| Len | Info | |
|---|---|---|
| TCP | 66 | 2765 > 3163 [SYN] Seq=0 Win=65535 Len=0 MSS=1460 WS=2 SACK_PERM=1 |
| TCP | 66 | 3163 > 2765 [SYN, ACK] Seq=0 Ack=1 Win=8192 Len=0 MSS=1460 WS=256 SACK_PERM=1 |
| TCP | 60 | 2765 > 3163 [ACK] Seq=1 Ack=1 Win=122880 Len=0 |
| TCP | 74 | 2765 > 3163 [PSH, ACK] Seq=1 Ack=1 Win=122880 Len=20 |
| TCP | 84 | 3163 > 2765 [PSH, ACK] Seq=1 Ack=21 Win=65536 Len=30 |
| TCP | 687 | 2765 > 3163 [PSH, ACK] Seq=21 Ack=31 Win=122850 Len=633 |
| TCP | 66 | 3163 > 2765 [PSH, ACK] Seq=31 Ack=654 Win=65024 Len=12 |
| TCP | 618 | 3163 > 2765 [PSH, ACK] Seq=43 Ack=654 Win=65024 Len=564 |
| TCP | 60 | 2765 > 3163 [ACK] Seq=654 Ack=607 Win=122274 Len=0 |
| TCP | 60 | 2765 > 3163 [RST, ACK] Seq=654 Ack=607 Win=0 Len=0 |
Quintessential TCP handshake, some data flowing back and forth and the connection ends rather impolitely with the agent sending a RST/ACK. I say impolitely because according to the RFC a TCP connection should end with a two way FIN/ACK handshake. This normal termination also requires the connection to remain in a TIME-WAIT state for a significant period and therefore it is quite common to end it a bit more abrupt with a reset. This immediately discards the connection state freeing up resources, simple common sense really.
TCP stream contents
Although many different protocols are automatically recognized by Wireshark and can be explored in the lower pane, there is no built in dissector for the RES-SAP protocol. Wireshark has a function called “follow tcp stream” which allows you to view a sequence of packets like this to be viewed in several different ways and opening this up does show us the contents of the communication:
So there we have it, the actual message being sent and the response from the dispatcher. Not exactly scintillating conversation but it does give us a peek under the hood of RES AM agent-dispatcher communication. Nothing spectacular, and definitely not very practical to explore all these packages manually this way, therefore this post is titled “part 1”.