Utah Scientific 
HOW-TO
SYSLOG Program

Installing the System Logging Application
1.	Locate the system CD and open the folder called Install2020.
2.	Open the folder called release-syslog.
3.	Double click the batch file called setup.bat to install the system logging application. The folder usilogs will be added to the C: drive with the following sub folders along with this “How To” application guide.

Figure 1

Running the Application
Note: Only one instance of the syslogs application can run at a time. 

Go to c:/usilogs and double click the syslog.exe program file. You will see the following window open and within a few seconds data numbers should begin counting up at the right as noted by the white arrow in figure 2. The more devices that are on the network and setup for logging as well as how much activity is going on with all the devices, the quicker this number will progress.

System Logging Menu
There are three menu items that can be used in the logging application. Press the Enter key to see these items. The following menu will appear. (See figure 2)

Keyboard Control Commands
-> D – Display Clients    I – Displays IP addresses
-> S – Displays Statistics
-> X – Exit application
1.	Press the letter S and you will see these general statistics. (see figure 2)
A.	Main logging server ID – (default is USI_SYSLOG01)
B.	Start of application time and current computer time
C.	Bytes being logged per hour, minute and second
D.	Current log being generated
2.	Press the letter D and you will see the names of the devices that are active on the network. Note: these names will only show up when the Log Server name in the device config file matches the name of the Log Server. See next section for details. (see figure 2) The names in this section are assigned in the following locations.
A.	SC4 name is the name assigned to the chassis. To change this name, refer to the System Installation Guide section D using chassis commands. 
B.	All Master Control device names are the system name found at the top of the device configuration file. NOTE: If you modify the system name in the MC card or CPU then you must put this exact name in the chassis connection table found in the MCP control panel being used for that card or CPU. I.e. if you had an MC400 card that you change the system name in then you must go to the MCP400 file and put the same name in its table.
3.	Press I to see the active device IP addresses. Same note applies as step 2 above. (see figure 2)

ACTIVE LOG SERVER DISPLAY							Figure 2

S - Statistics

MENU

I – 
Device IP addresses

D -Device Display

	
Default Log Server Name and Location

In order for the logging to function properly there is a default name of USI_SYSLOG01 that has been placed in each device config file. They are found in the following sections:

SC4/SC400/SCX400 – The logging name is found in the 6th section from the top of the config file and looks like this:
############################################################################## SYSLOG Server Name
[SYSLOG_NAME]

# NAME
  USI_SYSLOG01

#############################################################################

MC2020/MC400/ MC40 – The logging name is found in the MISC Start section which is the first section from the top of the config file after the system name info and looks like this:

AUDIO_CHANNELS:		@00FF
AUDIO_DIM_ADJUST:	@-15
VIDEO_MIX_POSITION:	@08
KEY_LEVEL_RESET_MASK:	@0f
KEY_LEVEL_XFER_MASK:	@00
TRANS_SPEED_FAST:	@30
TRANS_SPEED_MEDIUM:	@60
TRANS_SPEED_SLOW:	@120
SYSLOG_SERVER_ID:       @USI_SYSLOG01
#AUX_OUT_XPOINT_SEL:	@PVW

MCP2020/MCP400/MCP40 - The logging name is found in the MISC Start section which is the first section from the top of the config file after the system name info and looks like this:

#PASSWORD_MAINT: NOT CONFIGURED
SYSLOG_SERVER_ID:	@USI_SYSLOG01
#AUDIO_POT_LINKED: NOT CONFIGURED

Customizing Log Server Name
Even though the default log server name is USI_SYSLOG01 this can be changed. You will need to locate the device config file in the c:\usi\device folder\encode directory and then go to the section shown above for that device and only change the name. If there is an @ sign it must remain as it is. The next thing is to go to the c:\usilogs folder and open the syslog.cfg file and go to the very bottom line which looks like this.
########################
#LOGPATH, c:\usilogs
#SERVNAME, SYSLOG_RT01

You will need to remove the # sign from the SERVNAME line and then change the SYSLOG_RT01 named to the desired name you are changing it to.
If you wanted to separate the different devices and log only a specific device at one time then edit this syslog.cfg file and put all the device names in the list, but only remove the # sign from the line that you will be logging.
For example; if you had two channels of master control and wanted to separate these and log only the events on channel 2 then this may be what you would want to do.
1.	Change the name in the config files for both channels to something of your choice like, MC_CH1 and MC_CH2. Like the following.

SYSLOG_SERVER_ID:       @MC_CH1  (Put this in ch1 config)
SYSLOG_SERVER_ID:       @MC_CH2  (Put this in ch2 config)   

2.	Next add both names in the syslog.cfg and remove the # sign from the MC_CH2 line like the following.

########################
#LOGPATH, c:\usilogs
#SERVNAME, MC_CH1
SERVNAME, MC_CH2

3.	Launch the syslog.exe program from c:\usisyslogs and watch for the data to start  in the dos window and that the log has been created in the day of the week as described in the sections above.

Logging Results
While the logging application is running it will open a file in the day of the week for the hour (24 hour time base) that the computer is currently on. The folders for each day of the week are located in the c:\usilogs directory. As long as the logging application is running it will close each log and start a new one at the top of each hour. I.e. if the logging application was ran between 11:15am and 2:35pm on a Tuesday then in the c:\usilog\Tuesday folder you would see 4 log files that had been generated. They would be called syslog11.log, syslog12.log, syslog13.log and syslog14.log. The numbers represent the hour the log was running in 24 hour time base. See figure 3.

Figure 3

Parsing the data from the logs
Note: due to the complexity of the logs, parsing through and looking for the problem through the extracted logs is not expected to be used from the customer and can be sent to Utah Scientific Customer Service if desired using the service@utsci.com email address. However, if you wish to attempt parsing through the log then proceed with the next section on how to do this.

**Before sending logs to Utah Scientific make sure you do the following:
1.	Write a detailed description of the problem that is happening
2.	Note the system name of the device that is having the problem. 
3.	Note the time of the occurrence as close as possible.
4.	Send the proper log file for that hour. (See details in above sections)
Parsing (filtering) the log using key words
1.	Locate the log file that has been created in the day of the week folder. If the log is still running for the hour you wish to look at it and then copy and paste it in the same folder.
2.	Copy the log file from step 1 and paste it into the c:\usilogs\working logs folder.
3.	Right click on the parse.bat file in the c:\usilogs\working logs folder and select edit from the menu. You will see a similar batch file line to something like this example.
la syslog15.log /multi /grep gpi > gpi.txt
4.	You will also see the following items which are simply in the file as descriptions for each item in the batch file. The REM is placed before each description so that it can be in the file without trying to use that line allowing you to still read it.
REM la = log analyze program
REM *.log = file to look in
REM /multi = attribute allowance for file name search
REM /grep = search command
REM PASMLT = this is the item to search for
REM > = pipe to this file name
REM *.txt = new file name to be given for search results
5.	You will need to edit the batch file line with the information from your log. The way it works is it will use your log file, search for an item in it and then create a new file with only the information found from the search. This is what is referred to as parsing.
6.	In the batch file line change the syslog15.log to the name of the file you placed in the working folder from step 2.
7.	Change the item called gpi in the batch file line to whatever item name you would like to search for that is found in the log file. Some keywords are listed in the following sections.
8.	Change the name gpi.txt in the batch file line to whatever name you would like to call the new file that will be created with only the filtered items from step 7.
9.	Save and Close the batch file and then double click it to run the batch file with your changes. You should see the new file name appear in the same working logs folder.
10.	Double click the new file from step 9 to see the results of your search. If nothing was found then you will see something similar to this readout.
Overriding processing mode to [MULTIPLE FILES]
Setting to grep Mode
Overriding grep text to [gpi]
Using cfg file [la.cfg] outputfile is NULL
Process name [DEMOROOM-SD01], dst [dst 0130], level [lev 00]
grep text is [gpi] 
multi is [ON] summary is [OFF]
Analyze Mode is GREP        
Couldn't find matching file for [syslog15.log]

Master Control Keywords
Note: these are only examples of a few words you can search for in the log to see if you can determine what the problem may be.

Name			Description
TAS-PC	This is a good message followed by information about automation.
ROUTER:NUMERIC	this is the command to show automation takes that happen which will show the source index to the pst bus 01.
PANEL:PRC()	take commands from a PANEL in the CHASSIS (this is a good cmd)
(1)grp	button presses on MCP panel

Dst 0	PGM bus being switched
Dst 1	PST bus being switched
grp 01 	indicates the PGM Router button group -------------------[xxxxxxx]
fcn	indicates the button # starting from 0 --------------------[xxxxxxx]
st 01 	indicates the button was pressed
st 00 	indicates the button was released (not important info)
PASMLT	This identifies a command sent by a Master Control to switch a router. 
PASMLS	This identifies a command received by a Master Control showing an output was switched.
GPI:	This is logged when a Master Control detects activity on the GPI interface
MACRO:	This is logged when a Master Control Macro Playback engine performs an action.
EAS_	This is the first part of any command a Master Control logs that pertains to EAS Activity.
TAS	This is logged when a Master Control Automation interface performs various actions.  The level of log messages can be varied using the debug control interfaces.
send Heartbeat	this command is logged when a Master Control processes a command to verify connection to another Ethernet device.
rxed Heartbeat	This command is logged when a Master Control processes a command from another Ethernet device wishing to verify connectivity.
 
HWLOG  		This command is to show sync issues

  11713 08:36:02 [MC-RAIAUXREG        ] - GRP 001000 ID 000002 PRI INFO  08322501 TRANS:  ~TC~08322501 HWLOG:SYNC    sid  8 old 0x00d700d7 new 0x00d900d9
  11723 08:36:03 [MC-RAIAUXREG        ] - GRP 001000 ID 000002 PRI INFO  08322606 TRANS:  ~TC~08322606 HWLOG:SYNC    sid  9 old 0x00d700d7 new 0x00d900d9
  11725 08:36:03 [MC-RAIAUXNAZ        ] - GRP 001000 ID 000002 PRI INFO  19191919 TRANS:  ~VD~13739389 HWLOG:SYNC    sid  8 old 0x00710071 new 0x00730073
  11734 08:36:04 [MC-RAIAUXREG        ] - GRP 001000 ID 000002 PRI INFO  08322712 TRANS:  ~TC~08322712 HWLOG:SYNC    sid  2 old 0x00d700d7 new 0x00d900d9
  11737 08:36:05 [MC-RAIAUXNAZ        ] - GRP 001000 ID 000002 PRI INFO  19191919 TRANS:  ~VD~13739450 HWLOG:SYNC    sid  9 old 0x00710071 new 0x00730073

SC4/SC400/SCX400 Router Controller Keywords
Note: these are only examples of a few words you can search for in the log to see if you can determine what the problem may be.

Name			Description
SCP take:	This is logged when a controller detects a command from a UNET based control panel to switch the router
RCP4 take:	This is logged when a controller processes a command from a ETHERNET based control panel utilizing the RCP3 command protocol.
UTAH router take:	This is logged when a controller sends a command to a physical router device to modify it’s crosspoint map.  This is equivalent to a MX bus command.
Tieline connection:	This is logged when a controller processes a command  which uses a tieline to complete the switch request.
Tieline disconnected: This is logged when a controller processes a command which places a tieline back into the free pool.  This means no other destinations are using the source this tieline was providing.
	
Usage Overview

System Components	SC4, SD MC2020, HD MC2020, MXLATOR, MC400, 	MCP2020, MCP400

TAS PROTOCOL NOTES (Automation)

The following example came from a system using TAS_Rev2. Need to search for TAS_REV2 and then look for the three lines of info received from the serial port. The following is the description of the protocol. Master control uses the pst video and audio when switching and to determine if the protocol is REV2 you will see the second byte on the pst video and audio lines change in hex which is the source index number found in the SC4.

HEADER  (first 6 bytes)	01 01 00 2C 35 02 
NOTHING (next 10 bytes)	00 00 00 00 00 C0 00 00 00 C0 
PGM VID (next 3 bytes)	FF FE FE 
PGM AUD (next 3 bytes)	FF FE FE 
PST VID (next 3 bytes)	00 01 FE 	(second byte used is REV2 – when changing source this number will change in hex)
PST AUD (next 3 bytes)	00 01 FE 	 (second byte used is REV2 – when changing source this number will change in hex)
(these remaining bytes are for aux, keyers, etc.) FF FE FE FF FE FE FF FE FE FF FE FE FE FE FE FE 80 FE 00 FE 02 FE 03 3B 04 

15:17:41 [KSHB-SD01           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~00070887 TAS: Rxed good event msg stack location 00 PGM V fffe A 

15:54:02 [KSHB-SD01           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~00201594 TAS_AUTO_SEND 00 00 00 00 00 00 00 00 00 20 00 00 20 00 FF FF 00 FF FF 00 
15:54:02 [KSHB-SD01           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~00201594 TAS_AUTO_SEND 00 00 00 0C 88 21 11 20 C2 01 FE FE 00 00 00 03 B4 04 
15:54:02 [KSHB-SD01           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~00201605 TAS_REV2_RECV 01 01 00 2C 31 02 00 00 00 00 00 C0 00 00 00 C0 FF FE FE FF 
15:54:02 [KSHB-SD01           ] - GRP 001000 ID 000002 PRI INFO  19191919
(pst video)            PANEL:  ~VD~00201605 TAS_REV2_RECV FE FE 00 9A FE 
(pst video)            00 9A FE FF FE FE FF FE FE FF FE FE FF FE FE 
15:54:02 [KSHB-SD01           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~00201605 TAS_REV2_RECV FE FE FE FE 80 FE 00 FE 02 FE 03 69 04 
15:54:02 [KSHB-SD01           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~00201605 TAS: Rxed good event msg stack 
(TAS rxed good will show this) location 00 PGM V fffe A fffe PST V 9a A 9a
15:54:02 [KSHB-SD01           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~00201605 TAS: ---- TR Type fe Rate 02
15:54:02 [KSHB-SD01           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~00201605 TAS-PC:Event - Processing Event Command 01

TAS uses three commands for control:
				Reset Stack		(01 01 00 02 30 02 20 40 03 98 04)
				Preset Source	(long string of 77 hex values)
				Execute Event	(01 01 00 01 32 02 81 03 BA 04)

At 19:39:19 thru 19:39:22 you see an example of this.

Reset Stack
105   12749 19:39:19 PANEL:  ~VD~07242400 LogSerRaw(T_E) 01 01 00 02 30 02 20 40 03 98 04 

Preset Source
106   12754 19:39:19  PANEL:  ~VD~07242403 LogSerRaw(T_E) 01 01 00 44 31 02 00 00 00 00 00 C0 00 00 00 C0 00 3D 00 00 
107   12755 19:39:19  PANEL:  ~VD~07242403 LogSerRaw(T_E) 3D 00 00 3D 00 00 3D 00 FF FE 00 FF FE 00 FF FE 00 FF FE 00 
    108   12756 19:39:19 PANEL:  ~VD~07242403 LogSerRaw(T_E) FE FE FE 00 00 FE FE 00 01 00 00 00 FE FE FE FE FE FE 00 02 
109   12757 19:39:19  PANEL:  ~VD~07242403 LogSerRaw(T_E) FF FE FF FE FF FE FF FE FE FE FE 80 00 FE 03 3C 04 

Execute Event
110   12792 19:39:22  PANEL:  ~VD~07242554 LogSerRaw(T_E) 01 01 00 01 32 02 81 03 BA 04 

Next we see a sting of commands like this:
Reset Stack
Preset Source
Reset Stack
Preset Source
Reset Stack
Preset Source
Execute Event

111   12827 19:39:22  PANEL:  ~VD~07242594 LogSerRaw(T_E) 01 01 00 02 30 02 20 40 03 98 04 
112   12832 19:39:22  PANEL:  ~VD~07242597 LogSerRaw(T_E) 01 01 00 44 31 02 00 00 00 00 00 C0 00 00 00 C0 00 3D 00 00 
113   12833 19:39:22  PANEL:  ~VD~07242597 LogSerRaw(T_E) 3D 00 00 3D 00 00 3D 00 FF FE 00 FF FE 00 FF FE 00 FF FE 00 
114   12834 19:39:22  PANEL:  ~VD~07242597 LogSerRaw(T_E) FE FE FE 00 00 FE FE 00 01 00 00 00 FE FE FE FE FE FE 00 02 
115   12835 19:39:22  PANEL:  ~VD~07242597 LogSerRaw(T_E) FF FE FF FE FF FE FF FE FE FE FE 80 00 FE 03 3C 04 
116   12879 19:39:25  PANEL:  ~VD~07242774 LogSerRaw(T_E) 01 01 00 02 30 02 20 40 03 98 04 
117   12884 19:39:25  PANEL:  ~VD~07242777 LogSerRaw(T_E) 01 01 00 44 31 02 00 00 00 00 00 C0 00 00 00 C0 00 3D 00 00 
118   12885 19:39:26  PANEL:  ~VD~07242777 LogSerRaw(T_E) 3D 00 00 3D 00 00 3D 00 FF FE 00 FF FE 00 FF FE 00 FF FE 00 
119   12886 19:39:26  PANEL:  ~VD~07242777 LogSerRaw(T_E) FE FE FE 00 00 FE FE 00 01 00 00 00 FE FE FE FE FE FE 00 02 
120   12887 19:39:26  PANEL:  ~VD~07242777 LogSerRaw(T_E) FF FE FF FE FF FE FF FE FE FE FE 80 00 FE 03 3C 04 
121   12918 19:39:30  PANEL:  ~VD~07243032 LogSerRaw(T_E) 01 01 00 02 30 02 20 40 03 98 04 
122   12923 19:39:30  PANEL:  ~VD~07243035 LogSerRaw(T_E) 01 01 00 44 31 02 00 00 00 00 00 C0 00 00 00 C0 00 3D 00 00 
123   12925 19:39:30  PANEL:  ~VD~07243035 LogSerRaw(T_E) 3D 00 00 3D 00 00 3D 00 FF FE 00 FF FE 00 FF FE 00 FF FE 00 
124   12926 19:39:30  PANEL:  ~VD~07243035 LogSerRaw(T_E) FE FE FE 00 00 FE FE 00 01 00 00 00 FE FE FE FE FE FE 00 02 
125   12927 19:39:30  PANEL:  ~VD~07243035 LogSerRaw(T_E) FF FE FF FE FF FE FF FE FE FE FE 80 00 FE 03 3C 04 
126   12964 19:39:32  PANEL:  ~VD~07243186 LogSerRaw(T_E) 01 01 00 01 32 02 81 03 BA 04 

Here is where it breaks.  We see:
Reset Stack
Preset Source
Reset Stack
Preset Source - but the end of this string is bad!!!  We are missing the 04 that should be at the end which tells us the data is complete.

Likewise the following command (Execute Event) is missing the first 01.  Therefore, these strings run together and the MC can't process them.
After it sees the 03 BA 04, it is able to resync, but it has to throw out all the previous data because it is corrupt and can't be processed.
There are only two bytes of data missing, but every byte is critical to understanding the commands.
154   13417 19:40:07  PANEL:  ~VD~07245234 LogSerRaw(T_E) 01 01 00 02 30 02 20 40 03 98 04 
155   13422 19:40:07  PANEL:  ~VD~07245237 LogSerRaw(T_E) 01 01 00 44 31 02 00 00 00 00 00 C0 00 00 00 C0 00 3D 00 00 
156   13423 19:40:07  PANEL:  ~VD~07245237 LogSerRaw(T_E) 3D 00 00 3D 00 00 3D 00 FF FE 00 FF FE 00 FF FE 00 FF FE 00 
157   13424 19:40:07  PANEL:  ~VD~07245237 LogSerRaw(T_E) FE FE FE 00 00 FE FE 00 01 00 00 00 FE FE FE FE FE FE 00 02 
158   13425 19:40:07  PANEL:  ~VD~07245237 LogSerRaw(T_E) FF FE FF FE FF FE FF FE FE FE FE 80 00 FE 03 3C 04 
159   13525 19:40:30  PANEL:  ~VD~07246630 LogSerRaw(T_E) 01 01 00 02 30 02 20 40 03 98 04 
160   13529 19:40:30  PANEL:  ~VD~07246633 LogSerRaw(T_E) 01 01 00 44 31 02 00 00 01 00 01 44 11 02 00 C2 09 1D 09 09 
161   13530 19:40:30  PANEL:  ~VD~07246633 LogSerRaw(T_E) 3D 00 00 3D 00 02 3D 00 FB FE 00 BD FE 00 BD FE 00 AF FE 00 
162   13531 19:40:30  PANEL:  ~VD~07246633 LogSerRaw(T_E) AF FE FF 01 00 FF FF 00 01 00 00 04 EE BD 7A DE FD DE 02 02 
163   13532 19:40:30  PANEL:  ~VD~07246633 LogSerRaw(T_E) FF FE FF FD 7D FD 7D FD 7D FE FE 81 02 FF 03 3D 
164   13539 19:40:32  PANEL:  ~VD~07246784 LogSerRaw(T_E) 01 00 
165   13542 19:40:32  PANEL:  ~VD~07246784 LogSerRaw(T_E) 01 32 
166   13549 19:40:33  PANEL:  ~VD~07246854 LogSerRaw(T_E) 02 81 03 BA 04 01 01 00 02 30 02 20 40 03 98 04 
167   13554 19:40:33  PANEL:  ~VD~07246857 LogSerRaw(T_E) 01 01 00 44 31 02 00 00 00 00 00 C0 00 00 00 C0 00 3D 00 00 
168   13555 19:40:33  PANEL:  ~VD~07246857 LogSerRaw(T_E) 3D 00 00 3D 00 00 3D 00 FF FE 00 FF FE 00 FF FE 00 FF FE 00 
169   13556 19:40:33  PANEL:  ~VD~07246857 LogSerRaw(T_E) FE FE FE 00 00 FE FE 00 01 00 00 00 FE FE FE FE FE FE 00 02 
170   13557 19:40:33  PANEL:  ~VD~07246857 LogSerRaw(T_E) FF FE FF FE FF FE FF FE FE FE FE 80 00 FE 03 3C 04 
171   13587 19:40:37  PANEL:  ~VD~07247034 LogSerRaw(T_E) 01 01 00 02 30 02 20 40 03 98 04 
172   13592 19:40:37  PANEL:  ~VD~07247037 LogSerRaw(T_E) 01 01 00 44 31 02 00 00 00 00 00 C0 00 00 00 C0 00 3D 00 00 
173   13600 19:40:37  PANEL:  ~VD~07247037 LogSerRaw(T_E) 3D 00 00 3D 00 00 3D 00 FF FE 00 FF FE 00 FF FE 00 FF FE 00 
174   13602 19:40:37  PANEL:  ~VD~07247037 LogSerRaw(T_E) FE FE FE 00 00 FE FE 00 01 00 00 00 FE FE FE FE FE FE 00 02 
175   13604 19:40:37  PANEL:  ~VD~07247037 LogSerRaw(T_E) FF FE FF FE FF FE FF FE FE FE FE 80 00 FE 03 3C 04 
208   14758 19:44:04  PANEL:  ~VD~07259458 LogSerRaw(T_E) 01 01 00 02 30 02 20 40 03 98 04 
209   14763 19:44:04  PANEL:  ~VD~07259461 LogSerRaw(T_E) 01 01 00 44 31 02 00 00 00 00 00 C0 00 00 00 C0 00 3D 00 00 
210   14764 19:44:04  PANEL:  ~VD~07259461 LogSerRaw(T_E) 3D 00 00 3D 00 00 3D 00 FF FE 00 FF FE 00 FF FE 00 FF FE 00 
211   14765 19:44:04  PANEL:  ~VD~07259461 LogSerRaw(T_E) FE FE FE 00 00 FE FE 00 01 00 00 00 FE FE FE FE FE FE 00 02 
212   14766 19:44:04  PANEL:  ~VD~07259461 LogSerRaw(T_E) FF FE FF FE FF FE FF FE FE FE FE 80 00 FE 03 3C 04 
213   14797 19:44:06  PANEL:  ~VD~07259612 LogSerRaw(T_E) 01 01 00 01 32 02 81 03 BA 04 

Here is a sample of the full log which shows comments of bad data received.  You can compare the times if you like.

19:40:30 PANEL:  ~VD~07246630 TAS: Rxed good reset stack msg
19:40:30 PANEL:  ~VD~07246630 LogSerRaw(T_E) 01 01 00 02 30 02 20 40 03 98 04 
19:40:30 PANEL:  ~VD~07246630 TAS-PC:Reset - Processing Stack Reset Command cnt 01
19:40:30 PANEL:  ~VD~07246633 TASAUTO: BAD CS 3d should be 1d
19:40:30 PANEL:  ~VD~07246633 TASAUTO: RESYNCING
19:40:30 PANEL:  ~VD~07246633 LogSerRaw(T_E) 01 01 00 44 31 02 00 00 01 00 01 44 11 02 00 C2 09 1D 09 09 
19:40:30 PANEL:  ~VD~07246633 LogSerRaw(T_E) 3D 00 00 3D 00 02 3D 00 FB FE 00 BD FE 00 BD FE 00 AF FE 00 
19:40:30 PANEL:  ~VD~07246633 LogSerRaw(T_E) AF FE FF 01 00 FF FF 00 01 00 00 04 EE BD 7A DE FD DE 02 02 
19:40:30 PANEL:  ~VD~07246633 LogSerRaw(T_E) FF FE FF FD 7D FD 7D FD 7D FE FE 81 02 FF 03 3D 
19:40:30 PANEL:  ~VD~07246633 MAXTIME_GENERAL proc pan 00008175
19:40:30 PANEL:  ~VD~07246633 MAXTIME_GENERAL prpan times [13336962] [13337103] [13337031] [13337050] [1333708
19:40:32 TRANS:  ~VD~07246765 HWLOG:VIC-PVW sid  5 add 101C old 0x00007978 new 0x00007999
19:40:32 PANEL:  ~VD~07246784 Rxed bad seq response 01 should be 34
19:40:32 PANEL:  ~VD~07246784 Rxed bad dest 00 should be 01
19:40:32 PANEL:  ~VD~07246784 TASAUTO: RESYNCING
19:40:32 PANEL:  ~VD~07246784 LogSerRaw(T_E) 01 00 
19:40:32 PANEL:  ~VD~07246784 Rxed bad dest 32 should be 01
19:40:32 PANEL:  ~VD~07246784 TASAUTO: RESYNCING
19:40:32 PANEL:  ~VD~07246784 LogSerRaw(T_E) 01 32 
19:40:33 PANEL:  ~VD~07246784 MAXTIME_GENERAL proc pan 00009951
19:40:33 PANEL:  ~VD~07246784 MAXTIME_GENERAL prpan times [15856585] [15856727] [15856654] [15856673] [1585671
19:40:33 PANEL:  ~VD~07273576 2020ERROR tempErroBit = 0x00000004 state = 1
19:40:33 PANEL:  ~VD~07273576 SystemErrors 00000000, syserr2clr 00000004 syserrlast 00000000 errchng 00000000
19:40:33 PANEL:  ~VD~07246854 TAS: Rxed good reset stack msg
19:40:33 PANEL:  ~VD~07246854 LogSerRaw(T_E) 02 81 03 BA 04 01 01 00 02 30 02 20 40 03 98 04 

EXAMPLE OF PROBLEM WITH TWO BUTTONS PRESSED SIMULTANEOUSLY

Operator presses 2 buttons at the same time.

PROBLEM
 
1.    Customer thinks the MC2020 put the wrong source on air.
2.    Problem occurs around 19:50
3.    Customer was very good at providing all the info required to find the problem (see below).  This REALLY helped!!!!!
 
PROCEDURE
 
1.    Filter the main syslog to seperate the SD and MCP info
log_analyze syslog19.log /grep MC-RAI1SD /on 19_sd.txt /q
log_analyze syslog19.log /grep MCP02-Rai1 /on 19_mcp.txt /q
 
NOTE used the 19_xxxx so that I can work with more than 1 log file and the 19 shows which hour the data is from
 
2.    Filter all take commands from a PANEL in the CHASSIS
log_analyze 19_sd.txt /grep PANEL:PRC() /on 19_sd-panel-takes.txt /q
 
3.    Filter all button presses on MCP panel
log_analyze 19_mcp.txt /grep (1)grp /on 19_mcp-btn.txt /q
 
4.    Open 19_sd-panel-takes.txt, 19_mcp-btn.txt
5.    Open a new file and copy the contents of the 2 files in the line above to the new file
example
   <snip>
828   13407 19:52:35 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 02 fcn 05, st 01 cmdptr 047dd912 *cmdPtr 047db1e8
831   13428 19:52:36 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 02 fcn 05, st 00 cmdptr 047dd912 *cmdPtr 047db1e8
529    7587 19:31:08 [MC-RAI1SD           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~04673204 PANEL:PRC() Send RTR Take Src [PUBB    ] Dst 1 lev 0000
647    8502 19:34:28 [MC-RAI1SD           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~04683179 PANEL:PRC() Send RTR Take Src [SPOT    ] Dst 1 lev 0000
   <snip>
 
6.    Remove 1st column of line #'s on left hand side of file.  This leaves only the real line numbers from the original syslog file.
example
   <snip>
13407 19:52:35 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 02 fcn 05, st 01 cmdptr 047dd912 *cmdPtr 047db1e8
13428 19:52:36 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 02 fcn 05, st 00 cmdptr 047dd912 *cmdPtr 047db1e8
 7587 19:31:08 [MC-RAI1SD           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~04673204 PANEL:PRC() Send RTR Take Src [PUBB    ] Dst 1 lev 0000
 8502 19:34:28 [MC-RAI1SD           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~04683179 PANEL:PRC() Send RTR Take Src [SPOT    ] Dst 1 lev 0000
   <snip>
 
7.    Highlight the line numbers using a column mark in MED
8.    Sort the data [File->Edit->Document->Sort).  Make sure SORT SELECTION is checked
 
Now everything is in order and you can see what's going on.  sometimes the panel commands can be below the chassis commands as is the case with this file.

############################
The important lines are 

1.      lines 12315 and 12319 show the SD chassis processing 2 take commands from the PGM bus.
        The 1st is for SPOT, the 2nd is for PUBB
2.      lines 12348 and 12358 show the MCP Panel processing 2 button press commands for the PGM bus.
        The 1st is fcn 5 (the 6th button), the 2nd is fcn 4 (the 5th button)

So, the system did what it was asked to do.  

NOTE:   The button presses show up later in the log and this is not an error.

#################################

Note: the left hand column of the data below is the line number from the original syslog file

#################################

12020 19:47:46 [MC-RAI1SD           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~04723105 PANEL:PRC() Send RTR Take Src [BLACK   ] Dst 0 lev 0000
12023 19:47:46 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 01 fcn 00, st 01 cmdptr 047dd912 *cmdPtr 047db1e8
12046 19:47:47 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 01 fcn 00, st 00 cmdptr 047dd912 *cmdPtr 047db1e8
12293 19:48:36 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 06 fcn 01, st 01 cmdptr 047dd912 *cmdPtr 047db1e8
12298 19:48:36 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 06 fcn 01, st 00 cmdptr 047dd912 *cmdPtr 047db1e8

### 2 TAKES on PGM 1st is SPOT, 2nd is PUBB
    the Dst 0 indicates PGM is being switched -----------------------------------------------------------------------------------------------[xxxxx]
12315 19:48:37 [MC-RAI1SD           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~04725666 PANEL:PRC() Send RTR Take Src [SPOT    ] Dst 0 lev 0000
12319 19:48:37 [MC-RAI1SD           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~04725667 PANEL:PRC() Send RTR Take Src [PUBB    ] Dst 0 lev 0000

### BUTTON presses from MCP panel that made the 2 takes on PGM above

### 1st press is SPOT on PGM (the 6th button)
    the grp 01 indicates the PGM Router button group ---------------------------[xxxxxxx]
    the fcn 05 indicates the button # starting from 0 -----------------------------------[xxxxxx]
    the st 01 indicates the button was pressed --------------------------------------------------[xxxxx]
12348 19:48:38 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 01 fcn 05, st 01 cmdptr 047dd912 *cmdPtr 047db1e8

### 2nd press is PUBB (the 5th button)
    the grp 01 indicates the PGM Router button group ---------------------------[xxxxxxx]
    the fcn 05 indicates the button # starting from 0 -----------------------------------[xxxxxx]
    the st 01 indicates the button was pressed --------------------------------------------------[xxxxx]
12358 19:48:38 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 01 fcn 04, st 01 cmdptr 047dd912 *cmdPtr 047db1e8

### panel button release events (don't care)
    the grp 01 indicates the PGM Router button group ---------------------------[xxxxxxx]
    the fcn 05 indicates the button # starting from 0 -----------------------------------[xxxxxx]
    the st 00 indicates the button was released -------------------------------------------------[xxxxx]
12361 19:48:38 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 01 fcn 04, st 00 cmdptr 047dd912 *cmdPtr 047db1e8
12369 19:48:38 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 01 fcn 05, st 00 cmdptr 047dd912 *cmdPtr 047db1e8

13093 19:51:40 [MC-RAI1SD           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~04734794 PANEL:PRC() Send RTR Take Src [IMX    2] Dst 1 lev 0000
13106 19:51:41 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 02 fcn 09, st 01 cmdptr 047dd912 *cmdPtr 047db1e8
13113 19:51:41 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 02 fcn 09, st 00 cmdptr 047dd912 *cmdPtr 047db1e8
13242 19:52:08 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 06 fcn 01, st 01 cmdptr 047dd912 *cmdPtr 047db1e8
13245 19:52:08 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 06 fcn 01, st 00 cmdptr 047dd912 *cmdPtr 047db1e8
13407 19:52:35 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 02 fcn 05, st 01 cmdptr 047dd912 *cmdPtr 047db1e8
13408 19:52:35 [MC-RAI1SD           ] - GRP 001000 ID 000002 PRI INFO  19191919 PANEL:  ~VD~04737551 PANEL:PRC() Send RTR Take Src [SPOT    ] Dst 1 lev 0000
13428 19:52:36 [MCP02-Rai1          ] - GRP 006000 ID 001000 PRI INFO  00000000 (1)grp 02 fcn 05, st 00 cmdptr 047dd912 *cmdPtr 047db1e8

EXAMPLE OF AUTO TAKE BEING PRESSED

Date:   03-02-2009
Path:   c:\d\customer\wisc\2009-03-02_mc4000meltdown\findings.txt
Desc:   SUMMARY OF MELTDOWN @ WISC (customer description)
Files:  syslog06.log, wisc-mc4001.conf (supplied by customer)

--------------------------------------------------------------------------------
################################################################################
--------------------------------------------------------------------------------
Issue:  Panel started toggling between 2 different sources @ 2 second intervals

Result: Normal operation (no system bugs)

Info:   Operator turned on the AUTO TAKE @ 6:28:19  (LINE #1892 in syslog06.log)

--------------------------------------------------------------------------------
################################################################################
--------------------------------------------------------------------------------
Break down of log commands from syslog06.log
1.      This excerpt from panel.txtfile 
2.      generated by:

la syslog06.log /grep "USI-MCP40_01 " /on panel.txt /q
   
--------------------------------------------------------------------------------
Here's the operations leading up to AUTO TAKE
### NOTE ###
        This workup is specific to MCP40 control panel!!!!
############
LEGEND
BUTTON PRESS    [EAS LOCAL]     MAIN MENU button 7
BUTTON RELES    [NKK 06]        LOCAL btn released
BUTTON PRESS    [NKK 07]        buttons start @ 0 so this is button 8
BUTTON PRESS    [NKK 07]
BUTTON PRESS    [NKK 07]
BUTTON PRESS    [NKK 01]        button 2 on NKK buttons
--------------------------------------------------------------------------------

   1839 06:28:06 [USI-MCP40_01        ] (1)grp 46 fcn 01, st 01 pbtn 200 cmd 00000000 *cmd 00000000   BUTTON PRESS    [EAS LOCAL]
   1842 06:28:06 [USI-MCP40_01        ] (1)grp 50 fcn 06, st 00 pbtn 06 cmd 04b2bc52 *cmd 04b283d6    BUTTON RELES    [NKK 06]
   1843 06:28:06 [USI-MCP40_01        ] (1)grp 46 fcn 01, st 00 pbtn 200 cmd 00000000 *cmd 00000000   BUTTON RELES    [EAS LOCAL]
   1847 06:28:07 [USI-MCP40_01        ] (1)grp 50 fcn 06, st 01 pbtn 06 cmd 04b2bc52 *cmd 04b283d6    BUTTON PRESS    [NKK 06]
   1848 06:28:07 [USI-MCP40_01        ] (1)grp 46 fcn 01, st 01 pbtn 200 cmd 00000000 *cmd 00000000   BUTTON PRESS    [EAS LOCAL]
   1851 06:28:08 [USI-MCP40_01        ] (1)grp 50 fcn 06, st 00 pbtn 06 cmd 04b2bc52 *cmd 04b283d6    BUTTON RELES    [NKK 06]
   1852 06:28:08 [USI-MCP40_01        ] (1)grp 46 fcn 01, st 00 pbtn 200 cmd 00000000 *cmd 00000000   BUTTON RELES    [EAS LOCAL]
   1857 06:28:09 [USI-MCP40_01        ] (1)grp 50 fcn 06, st 01 pbtn 06 cmd 04b2bc52 *cmd 04b283d6    BUTTON PRESS    [NKK 06]
   1858 06:28:09 [USI-MCP40_01        ] (1)grp 46 fcn 01, st 01 pbtn 200 cmd 00000000 *cmd 00000000   BUTTON PRESS    [EAS LOCAL]
   1861 06:28:10 [USI-MCP40_01        ] (1)grp 50 fcn 06, st 00 pbtn 06 cmd 04b2bc52 *cmd 04b283d6    BUTTON RELES    [NKK 06]
   1862 06:28:10 [USI-MCP40_01        ] (1)grp 46 fcn 01, st 00 pbtn 200 cmd 00000000 *cmd 00000000   BUTTON RELES    [EAS LOCAL]
   ########
   Line 1862 establishes the MCP-40 panel was on the MAIN menu as that is the only place EAS LOCAL is avialable
  ########
   1865 06:28:10 [USI-MCP40_01        ] (1)grp 50 fcn 07, st 01 pbtn 07 cmd 04b2bc52 *cmd 04b283d6    BUTTON PRESS    [NKK 07]        [MAINT SCREEN SELECT]
   1867 06:28:10 [USI-MCP40_01        ] (1)grp 50 fcn 07, st 00 pbtn 07 cmd 04b2bc52 *cmd 04b283d6    BUTTON RELES    [NKK 07]
   1872 06:28:12 [USI-MCP40_01        ] (1)grp 50 fcn 07, st 01 pbtn 07 cmd 04b2bc52 *cmd 04b283d6    BUTTON PRESS    [NKK 07]        [MAINT SCREEN MORE, goto page 2]        
   1874 06:28:12 [USI-MCP40_01        ] rxed Heartbeat cmnd from dev [192.168.17.6]
   1875 06:28:12 [USI-MCP40_01        ] (1)grp 50 fcn 07, st 00 pbtn 07 cmd 04b2bc52 *cmd 04b283d6    BUTTON RELES    [NKK 07]
   1877 06:28:13 [USI-MCP40_01        ] (1)grp 50 fcn 07, st 01 pbtn 07 cmd 04b2bc52 *cmd 04b283d6    BUTTON PRESS    [NKK 07]        [MAINT SCREEN MORE, goto page 3]
   1879 06:28:13 [USI-MCP40_01        ] (1)grp 50 fcn 07, st 00 pbtn 07 cmd 04b2bc52 *cmd 04b283d6    BUTTON RELES    [NKK 07]
   1881 06:28:14 [USI-MCP40_01        ] (1)grp 50 fcn 07, st 01 pbtn 07 cmd 04b2bc52 *cmd 04b283d6    BUTTON PRESS    [NKK 07]        [MAINT SCREEN MORE, goto page 1]
   1883 06:28:14 [USI-MCP40_01        ] (1)grp 50 fcn 07, st 00 pbtn 07 cmd 04b2bc52 *cmd 04b283d6    BUTTON RELES    [NKK 07]
   1888 06:28:17 [USI-MCP40_01        ] STATLOG :MAX Msg Q Count is    8
   1890 06:28:17 [USI-MCP40_01        ] STATLOG :Current Que Stats  hp 465 tp 464 cnt 1
   ################
   1892 06:28:19 [USI-MCP40_01        ] (1)grp 50 fcn 01, st 01 pbtn 01 cmd 04b2bc52 *cmd 04b283d6    BUTTON PRESS    [NKK 01]        [AUTO TAKE ON]
   ################
   1894 06:28:20 [USI-MCP40_01        ] (1)grp 50 fcn 01, st 00 pbtn 01 cmd 04b2bc52 *cmd 04b283d6    BUTTON RELES    [NKK 01]
   1898 06:28:21 [USI-MCP40_01        ] (1)grp 02 fcn 00, st 01 pbtn 255 cmd 04b2bcc2 *cmd 04b283d6   BUTTON PRESS
   1905 06:28:21 [USI-MCP40_01        ] CID() Send Time 0442
   1928 06:28:22 [USI-MCP40_01        ] (1)grp 02 fcn 00, st 00 pbtn 255 cmd 04b2bcc2 *cmd 04b283d6   BUTTON RELES
   1930 06:28:22 [USI-MCP40_01        ] CID() Send Time 0455
   1931 06:28:22 [USI-MCP40_01        ] (1)grp 06 fcn 03, st 01 pbtn 255 cmd 04b2bcc2 *cmd 04b283d6   BUTTON PRESS    [TRANS TAKE]
   1933 06:28:22 [USI-MCP40_01        ] CID() Send Time 0454
   1934 06:28:22 [USI-MCP40_01        ] (1)grp 06 fcn 03, st 00 pbtn 255 cmd 04b2bcc2 *cmd 04b283d6   BUTTON RELES    [TRANS TAKE]

AUTOMATION COMPANY DETAILS for 2020/400 (What we know)

COMPANY		PROTOCOLS USED		BAUD RATES
CRISPIN		AUTO / REV2			
DIGITAL BROADCAST	AUTO				DEFAULT 4800
HARRIS		AUTO / EXTEND
FLORICAL		AUTO/EXTEND
SUNDANCE		AUTO/EXTEND		DEFAULT 38400 RS-422 
Sidon version is 2.01S9-08/29/08
NVERSION		AUTO/EXTEND		Assignable

AUTOMATION COMPANY DETAILS for SC-4/SC-400/SCX-400

SUNDANCE			RCP-1i 38400 8, N, 1 RS-422.  Sundance side 	AVS

DEBUG2020 UTILITY

There is a section at the bottom of the MC2020 and MC400 config files called [degug_control_start] that can be set to run logging for several areas of need. However, we recommend that this not be done as a permanent application due to the fact that it will run many additional entries to the logs of which may be unused information. These can also be set permanently to flash from the diag port 

The best way to run these items is to telnet to the MC2020 or the MC400 and type the following:

debug2020 (displays all of the possible operations used to turn on debug messages.)
debug2020 display (shows all of the group flag names as ON or OFF)
debug2020 set PANEL <enter name here> <enter ON or OFF here> (sets temp flag)
debug2020 set GENERAL <enter name here> <enter ON or OFF here> (sets temp flag)
debug2020 set TRANS <enter name here> <enter ON or OFF here> (sets temp flag)
debug2020 set MACHINE<enter name here> <enter ON or OFF here> (sets temp flag)
debug2020 set ROUTER <enter name here> <enter ON or OFF here> (sets temp flag)
debug2020 set SYSLOG <enter name here> <enter ON or OFF here> (sets temp flag)

LOG ANALYZER APPLICATION

This application will make the sorting of the logs much simpler as it will allow for searching all or part of words and phrases once the logs are retrieved. It will also perform all of the filtering tasks referred to above in the manual operation of sorting through the logs.

Launching the Log Analyzer Application

1. Locate the folder called 2009-06-01-LogAnalyzer-1.4 found in c:\usilogs on open it.
2. Double click on the ‘loganalyzer.exe’ to launch the program. 

Using the Application
The base directory found in the upper right corner will default to c:\usilogs which is the location where each folder for the days of the week reside. As explained in an earlier discussion, the logging application saves each log for each hour and places it in the folder for that day of the week. 

1. Click on the desired day of the week where the desired log to view is found. At this time all of the hours that contain logs will then light up as seen in the figure below where it only has one log file in it for the 1700 hour or 5:00.

2. The next thing to do would be to click on the hour you want to analyze. In this case it would be the number 17. At this time all of the data for that log will appear in text as seen in the next figure below.

3. To filter just the information for any given device, click on the drop down arrow in the section at the middle left titled ‘Devices Filter’ and click on any or all of the devices found. These are the names found in the log file of all actively logged devices. See picture example below. Then click the ‘Filter’ button in the upper right corner and it will only put the text in the table to the right that corresponds to the device you wanted to filter.

4. Next you will need to click on the desired filters from the drop down menu in the ‘Message Filter’ window. There are three areas of messages currently active in this section. They are the ‘System Controller’, ‘Master Control’ and Master Control Panel’. Click on the plus sign next to these items and then select the individual items that you would like to filter. Then click on the ‘Filter button in the upper right corner and it will only show any items found in the message text window.

5. To search the filtered text at any time for specific items type the text in the search windows as either specific words or an entire phrase and then click the search all or find next. You can match the text by case only or whole words by checking the desired box.

To save the text to a location on the computer or another drive click on the ‘Multi Mode’ button and then select the location to save the text file to.