Google
 

Trailing-Edge - PDP-10 Archives - BB-L288A-RM - swskit-utilities/felog.mem
There is 1 other file named felog.mem in the archive. Click here to see a list.


+-------------+
| | | | | | | |
|d|i|g|i|t|a|l|  I N T E R O F F I C E   M E M O R A N D U M
| | | | | | | |
+-------------+


TO: SWSKIT                         DATE: 19 February 1980
                                   FROM: Steven M. Jenness
                                   DEPT: LCG Comm/Nets
cc: List                           DTN:  231-6926
                                   LOC:  MR1-2/E89
                                   POLE: M17

SUBJ: FELOG/RDLOG IBM comm debugging aid


This pair of modules (FELOG and RDLOG) supply a facility for
DN60  FE  device  transfer  analysis  and  spooler execution
tracing.
SWSKIT                                                Page 2


1.0  DESCRIPTION AND INSIGHT


Every once in a while it  becomes  necessary  to  watch  the
actual  workings  in  a  GALAXY  spooler.  If the spooler is
multi-stream this task becomes non-trivial.  The routines in
FELOG   supply   DN60  FE  device  transaction  logging  and
execution tracing to a data file.  After FELOG has  recorded
this information and the data file has been closed, RDLOG is
used to interpret it.



1.1  FELOG


Overhead in the IBM spoolers has been  trimmed  as  much  as
possible.   Keeping  to  this philosophy of low overhead the
FELOG routines output to mass storage in binary form instead
of  directly  interpreting the data stream.  This stream can
contain  both  DN60  command/data  messages  and   arbitrary
execution  trace information.  The command/data messages are
DN60 spooler dependent (i.e.  exist only in DN60  spoolers).
The execution trace facility can be used in any program that
uses the GLXLIB run time system.



1.2  RDLOG


After the  data  file  has  been  written  it  needs  to  be
interpreted.  This interpretation can be tailored by setting
interpretation parameters indicating which  entries  in  the
data file that are relevant.  Also the data file can contain
enough timing information to allow time  segments  extracted
from it.
SWSKIT                                                Page 3


2.0  FELOG AND RDLOG PREPARATION

Before any logging can occur the modules must  obviously  be
assembled and loaded.  Each of the modules requires that the
GALAXY  library  containing  such   files   as   GLXMAC.UNV,
GLXINI.REL,  GLXLIB.EXE  is  accessable.   These  files  are
normally distributed on the GALAXY distribution tape and are
required for any reassembly of GALAXY components.

After checking for proper assembly context (see above), each
module needs only to be assembled as follows:

        @COMPILE FELOG
        @LOAD RDLOG
        @SAVE RDLOG

This  results  in  the  files   FELOG.REL,   RDLOG.REL   and
RDLOG.EXE.   FELOG.REL is the logging module loaded with the
spooler.  RDLOG.EXE is the interpretation program used after
FELOG does it's logging.  Save these files for later.
SWSKIT                                                Page 4


3.0  SPOOLER PREPARATION

3.1  DN60 Interface Package


The DN60 interface  package  (D60JSY)  already  knows  about
FELOG.   To  enable  the  use  of  the  FELOG  recording,  a
debugging flag must be turned on  at  assembly  time.   This
flag   causes  two  things  to  happen.   First,  calls  are
generated at the appropriate places to the  global  routines
supplied  by FELOG.  Second, D60JSY will make a "REQUIRE" to
LINK for FELOG to be loaded.  This means that the .REL  file
generated  for  D60JSY  will  always need FELOG to be around
when loaded.

A suggested method of  turning  the  debug  flag  on  is  by
putting  it  in  a  disk file, then put the disk file at the
front of the source stream to MACRO.  For TOPS20  this  goes
as follows:

        @COPY TTY: DEBUG.MAC
        FTDEBUG==-1
        ^Z
        @COMPILE DEBUG+D60JSY D60JSY
        @COMPILE DEBUG+NBIO+D60JSY D6JISP

This generates two files:  D60JSY.REL for use with LPTSPL or
CDRIVE  and  D6JISP.REL  for use with IBMSPL.  Remember when
loading  the   spoolers   that   these   .REL   files   will
automatically load the FELOG.REL module.



3.2  Loading GALAXY Components


Load  the  termination  components  LPTSPL  and  CDRIVE   as
follows:

        @LOAD LPTSPL
        @SAVE LPTSPL
        @LOAD CDRIVE
        @SAVE CDRIVE

Each of these components  already  knows  about  D60JSY.REL.
They generate LINK "REQUIRE"s for it.

Load IBMSPL as follows:

        @LOAD IBMSPL,IBMPAT,IBMUSR,D6JISP
        @SAVE IBMSPL
SWSKIT                                                Page 5


3.3  Loading Non-GALAXY Programs


Since the logging facility is  acheived  by  calling  global
routines,  there is no reason why some of the features (such
as execution trace) can't  be  used  by  anyone.   The  only
restriction  is  that the host program must setup the GALAXY
library in the normal fashion and call I%INIT to  initialize
it at run time.

To load a random program that contains global calls to FELOG
do:

        @LOAD random,FELOG
        @SAVE random
SWSKIT                                                Page 6


4.0  RUN TIME USE OF FELOG

4.1  Operation


Since the logging facility is a debugging aid some  niceties
have not been developed.  These specifically are in the area
of enabling and disabling the logging functions.

The  logging  data  file  is  output  to   the   file   spec
LOG:FELOG.DAT.   If  this  file  cannot  be opened, the file
DSK:FELOG.DAT is attempted.  If neither can be  opened,  the
program  stops.   The  logical name LOG:  is used so the log
data file can  be  directed  to  other  than  the  connected
directory.

To enable logging the flag LOGFLG (found in D60JSY)  is  set
to  -1.   When  the next call to a FELOG routine occurs, the
data file is automatically opened for output.

To disable logging the flag LOGFLG is set to zero (0).  When
the next call to a FELOG routine occurs the last data buffer
is output and the data file is closed.  If no more calls  to
FELOG  routines  are anticipated the call can be made to the
global routine FELOG manually.

        @ddt
        LOGFLG/ -1  0 <CR>
        PUSHJ P,FELOG<ESC>X



4.2  Setting Execution Trace Points


Up to  now  only  DN60  FE  device  transactions  have  been
recorded.   To  set  a trace point requires a little work in
DDT (unless it is hardcoded in  the  source).   These  trace
points call the global routine WRTMRK (in FELOG).

Contained in register 1 (R1) is  the  trace  point  name  or
location.   If the upper six bits are non-zero, the value in
R1 is interpreted  as  being  a  SIXBIT  trace  point  name.
Otherwise the value is interpreted as an octal number.
SWSKIT                                                Page 7


5.0  FELOG GLOBAL FUNCTIONAL DESCRIPTION


Since the routines in D60JSY already  know  how  to  log  FE
device   transactions   and  the  code  contains  sufficient
commenting, it will not be described here.  The  only  other
global  routine of importance is WRTMRK, which was described
previously.



6.0  RDLOG FUNCTIONAL DESCRIPTION


This is  the  help  file  used  by  RDLOG,  listed  in  it's
entirety.

      o  DISABLE

         This  command  is  the  complement  of  the  ENABLE
         command.

         This  command  disables  the  output  of   selected
         entries  from  the input data file.  In other words
         they are not interpreted and listed.

         There  are  two  flavors  of  DISABLE.   The  first
         disables specific entry types by the following:

                DISABLE ENTRY type

         where   type   is    one    of:     DEVICE-COMMAND,
         DEVICE-STATUS,      LINE-COMMAND,      LINE-STATUS,
         PORT-STATUS, READ-DATA or  WRITE-DATA.   There  are
         also two optional switches:

                /BODY   Suppress output of entry body only
                /HEADER Suppress output of entry header only

         If neither of the  switches  is  given,  the  total
         entry is suppressed.

         The second flavor disables any entry pertaining  to
         a specific port, line or device.  This is done by:

                DISABLE PORT p LINE l DEVICE d

         If only the port is to be disabled, type a carriage
         return  immediately  after  the  port  number.   Do
         likewise if only a specific line is to be disabled.

      o  ENABLE

         This command  is  the  complement  of  the  DISABLE
         command.
SWSKIT                                                Page 8


         This command enables the output of selected entries
         from  the input data file.  In other words they are
         interpreted and listed.

         There are two flavors of ENABLE.  The first enables
         specific entry types by the following:

                ENABLE ENTRY type

         where   type   is    one    of:     DEVICE-COMMAND,
         DEVICE-STATUS,      LINE-COMMAND,      LINE-STATUS,
         PORT-STATUS, READ-DATA or  WRITE-DATA.   There  are
         also two optional switches:

                /BODY   Output of entry body enabled
                /HEADER Output of entry header enabled

         If neither of the  switches  is  given,  the  total
         entry is output.

         The second flavor enables any entry pertaining to a
         specific port, line or device.  This is done by:

                ENABLE PORT p LINE l DEVICE d

         If only the port is to be enabled, type a  carriage
         return  immediately  after  the  port  number.   Do
         likewise if only a specific line is to be enabled.

      o  EXIT (to EXEC)

         The EXIT command  is  used  to  return  to  monitor
         (EXEC) level.

      o  HELP

         The HELP command is used  to  supply  help  on  any
         other command.

         The format is:

                HELP command

         where command is either a * for all  commands,  one
         of  the following commands:  DISABLE, ENABLE, EXIT,
         HELP, LIST,  OUTPUT,  PUSH,  TAKE,  VERSION,  or  a
         carriage    return    to   get   the   introduction
         information.

      o  LIST (data file) input.fil

         This command interprets  the  input  file  (default
         DSK:FELOG.DAT)  and  prints  it  on the controlling
         terminal.  All interpretation parameters  specified
         in DISABLE and ENABLE commands take effect.
SWSKIT                                                Page 9


      o  OUTPUT (to file) out.fil (from data file) in.fil

         This command interprets  the  input  file  (default
         DSK:FELOG.DAT)  and  outputs  it to the output file
         (default   DSK:RDLOG.LOG).    All    interpretation
         parameters  specified in DISABLE and ENABLE command
         take effect.

      o  PUSH (to EXEC)

         This command saves the current process context  and
         starts  a  inferior  fork  at EXEC level.  The EXEC
         that  is  mapped  in  is  the  one  found  in   the
         top-process of the job.

      o  TAKE (Commands From) cmdfil.cmd

         The TAKE command reads indirect commands files  and
         processes  them as if they were input directly from
         the terminal.

         The format is:

                TAKE (Commands from) file-name

         There are two switches of interest on this command:

                /DISPLAY     Echo commands being processed
                /NODISPLAY   Supresses output of commands

         The default switch is /NODISPLAY  and  the  default
         command file is DSK:RDLOG.CMD.

      o  VERSION (of RDLOG)

         This command outputs the currently running  version
         of RDLOG.
SWSKIT                                               Page 10


7.0  EXAMPLE


This example shows IBMSPL, already loaded with FELOG,  being
patched and run to log both FE device transfers and two mark
locations.

The user input text is in lowercase, the computer output  is
in  uppercase.   Comments have been added to explain what is
being done.

$get ibmspl
$dd
DDT

(* Set the first MARK at IPCF message processing dispatch.
   Give it mark location number 10 *)

MSGPR3 +6/   JUMPT 4,@4   $<
PAT../  0   push p,1
PAT..+1/   0   movei 1,10
PAT..+2/   0   pushj p,wrtmrk
PAT..+3/   0   pop p,1$>
PAT..+4/   0   JUMPT 4,@4
PAT..+5/   0   JUMPA 1,MSGPR3 +7
PAT..+6/   0   JUMPA 2,MSGPR3 +10
MSGPR3 +6/   JUMPT 4,@4   JUMPA INI%L +26    

(* Set the second MARK at the SETUP routine.  Give it the
   mark location name "SETUP" *)

setup/   MOVE 11,7(7)   $<
PAT../   0   push p,1
PAT..+1/   0   move 1,.+5
PAT..+2/   0   pushj p,wrtmrk
PAT..+3/   0   pop p,1$>
PAT..+4/   0   MOVE 11,7(7)
PAT..+5/   0   JUMPA 1,SETUP +1
PAT..+6/   0   JUMPA 2,SETUP +2
SETUP /   MOVE 11,7(7)   JUMPA INI%L +35    
ini%l +43/   JUMPA 2,SETUP +2   $"/SETUP/

(* Turn on the logging flag and let it run. *)

logflg/   0   -1
$G

(* Stop the run, clear logging flag, and close the
   log file. *)

^C
ddt
logflg/   -1   0
pushj p,felog$x
<>
SWSKIT                                               Page 11


Next the data file generated is interpreted by RDLOG.

$rdlog
 RDLOG V.1A(105)
RDLOG>;interpret the complete data file
RDLOG>output (to file) RDLOG.LOG.4 !New generation! (from
data file) FELOG.DAT.1
[Recorded with FELOG version: 1(100)]
[508 entries processed]
RDLOG>
RDLOG>;now modify so only port status messages output
RDLOG>take port.cmd /display 
RDLOG>DISABLE ENTRY WRITE-DATA
RDLOG>DISABLE ENTRY READ-DATA
RDLOG>DISABLE ENTRY DEVICE-COMMAND
RDLOG>DISABLE ENTRY DEVICE-STATUS
RDLOG>DISABLE ENTRY LINE-COMMAND
RDLOG>DISABLE ENTRY LINE-STATUS
RDLOG>ENABLE ENTRY PORT-STATUS
RDLOG>;Output the file again
RDLOG>output (to file) port.log.1 !New file! (from data
file) FELOG.DAT.1 
[Recorded with FELOG version: 1(100)]
[508 entries processed]
RDLOG>exit
$


This is  the  file  RDLOG.LOG.   Comments  have  been  added
instream  to  aid in reading.  Also some of the entries have
been removed so that the log was a manageable length.

[Interpreted by RDLOG version: 1A(105)]
[Recorded with FELOG version: 1(100)]

***************************************************************
- MARK at time 19-Feb-80 14:19:57 number 1 location 10
***************************************************************

***************************************************************
- MARK at time 19-Feb-80 14:19:57 number 2 name SETUP
***************************************************************

Read Line Status        P:12 L:1 "Succeeded"     19-Feb-80 14:19:58
        Line is disabled

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:19:58

Write Line Command      P:12 L:1 "Succeeded"     19-Feb-80 14:19:59
        Enable line, HASP, Emulation, Secondary

(* some line commands removed, this is conditioning the line *)

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:20:01
SWSKIT                                               Page 12


Read Line Status        P:12 L:1 "Succeeded"     19-Feb-80 14:20:01
        HASP, Emulation, Secondary, Line enable complete, Line enabled,
        DTR set, Clear to send delay 3, Silo warning area size 64, Bytes
        per message 400, Record per message 0, Line signature 31522,
        KMC/DUP11

Write Device Command    P:12 L:1 D:3 "Succeeded"     19-Feb-80 14:20:01
        Clear output EOF complete (ACK)

(* some device command removed, this is conditioning the device *)

Read Port Status        P:12     "Succeeded"    19-Feb-80 14:20:02

(* repeat of previous commands done again for device:4 *)
(* repeat of previous commands done again for device:5 *)
(* repeat of previous commands done again for device:1 *)
(* repeat of previous commands done again for device:2 *)


Read Port Status        P:12     "Succeeded"     19-Feb-80 14:20:06

Read Line Status        P:12 L:1 "Succeeded"     19-Feb-80 14:20:06
        HASP, Emulation, Secondary, Line enable complete, Line enabled,
        DTR set, Clear to send delay 3, Silo warning area size 64,
        Bytes per message 400, Record per message 0, Line signature 31522,
        KMC/DUP11

(* repeat line and port status, waiting for line to dial up *)

Read Line Status        P:12 L:1 "Succeeded"     19-Feb-80 14:21:28
        HASP, Emulation, Secondary, Line enable complete, Line enabled,
        DTR set, DSR set, Clear to send delay 3, Silo warning area size 64,
        Bytes per message 400, Record per message 0, Line signature 31522,
        KMC/DUP11

Write Device Command    P:12 L:1 D:3 "Succeeded"     19-Feb-80 14:21:28
        Clear input permission "was" requested

Write Data Request      P:12 L:1 D:3 "Succeeded"     19-Feb-80 14:21:29
[80 bytes]
        /*SIGNON       REMOTE12
        DEC<15><12><0><0><0>

Read Line Status        P:12 L:1 "Succeeded"     19-Feb-80 14:21:29
        HASP, Emulation, Secondary, Line enable complete, Line enabled,
        DTR set, DSR set, Clear to send delay 3, Silo warning area size 64,
        Bytes per message 400, Record per message 0, Line signature 31522,
        KMC/DUP11

Write Device Command    P:12 L:1 D:3 "Succeeded"     19-Feb-80 14:21:29
        Signal output EOF

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:29

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:31
SWSKIT                                               Page 13


        Activity on: Line 1 Card reader 0;

Read Line Status        P:12 L:1 "Succeeded"     19-Feb-80 14:21:32
        HASP, Emulation, Secondary, Line enable complete, Line enabled,
        DTR set, DSR set, Clear to send delay 3, Silo warning area size 64,
        Bytes per message 400, Record per message 0, Line signature 31522,
        KMC/DUP11

Read Line Status        P:12 L:1 "Succeeded"     19-Feb-80 14:21:32
        HASP, Emulation, Secondary, Line enable complete, Line enabled,
        DTR set, DSR set, Clear to send delay 3, Silo warning area size 64,
        Bytes per message 400, Record per message 0, Line signature 31522,
        KMC/DUP11

Read Device Status      P:12 L:1 D:3 "Succeeded"     19-Feb-80 14:21:32
        Device type: (0) Unknown, Component code: (223) Card reader,
        Interpret input carriage control, Do component selection,
        Do space compression, New BSC protocol, Output mode,
        Output permission granted, Output running, Output EOF signaled,
        Record size 82, Line signature 31522

Write Device Command    P:12 L:1 D:3 "Succeeded"     19-Feb-80 14:21:32
        Signal output EOF

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:34
        Activity on: Line 1 Card reader 0, Line printer 0;

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:34
        Activity on: Line 1 Card reader 0, Line printer 0;

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:34
        Activity on: Line 1 Card reader 0, Line printer 0;

Read Line Status        P:12 L:1 "Succeeded"     19-Feb-80 14:21:34
        HASP, Emulation, Secondary, Line enable complete, Line enabled,
        DTR set, DSR set, Clear to send delay 3, Silo warning area size 64,
        Bytes per message 400, Record per message 0, Line signature 31522,
        KMC/DUP11

Read Device Status      P:12 L:1 D:3 "Succeeded"     19-Feb-80 14:21:34
        Device type: (0) Unknown, Component code: (223) Card reader,
        Interpret input carriage control, Do component selection,
        Do space compression, New BSC protocol, Output mode,
        Output EOF signaled, Output EOF complete, Record size 82,
        Line signature 31522

Write Device Command    P:12 L:1 D:3 "Succeeded"     19-Feb-80 14:21:34
        Clear output EOF complete (ACK)

(* more device commands to setup device:3 after signon *)

Read Device Status      P:12 L:1 D:4 "Succeeded"     19-Feb-80 14:21:35
        Device type: (0) Unknown, Component code: (224) Line printer,
        Interpret input carriage control, Do component selection,
        Do space compression, New BSC protocol, Input permission sent to HASP,
SWSKIT                                               Page 14


        Input mode, Input permission requested, Input permission was requested,
        Record size 82, Line signature 31522

Write Device Command    P:12 L:1 D:4 "Succeeded"     19-Feb-80 14:21:36
        Grant input permission

Write Device Command    P:12 L:1 D:4 "Succeeded"     19-Feb-80 14:21:36
        Clear input permission "was" requested

Read Device Status      P:12 L:1 D:4 "Succeeded"     19-Feb-80 14:21:36
        Device type: (0) Unknown, Component code: (224) Line printer,
        Interpret input carriage control, Do component selection,
        Do space compression, New BSC protocol, Input mode, Input running,
        Record size 82, Line signature 31522

Read Data Request       P:12 L:1 D:4 "Delayed"     19-Feb-80 14:21:36

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:36

Read Data Request       P:12 L:1 D:4 "Succeeded"     19-Feb-80 14:21:37
[82 bytes]
         0.41.32        $HASP000 C  0,'AVCO COMPUTER SERVICES IS NOW OPERATING
         IN'<15><12> 0.4

Read Data Request       P:12 L:1 D:4 "Succeeded"     19-Feb-80 14:21:37
[82 bytes]
        1.32          $HASP000 C  0,'AN UNATTENDED MODE.  PLEASE SEE UPDATE 98'
        <15><12> 0.41.32 

Read Data Request       P:12 L:1 D:4 "Succeeded"     19-Feb-80 14:21:37
[24 bytes]
                 $HASP000 C  0,'

Read Data Request       P:12 L:1 D:4 "Succeeded"     19-Feb-80 14:21:38
[82 bytes]
        FOR FURTHER DETAILS'<15><12> 9.08.35        $HASP000 C 30,'PLS SIGNOFF
         MUST IPL SYSTEM

Read Data Request       P:12 L:1 D:4 "Succeeded"     19-Feb-80 14:21:38
[23 bytes]
        '<15><12> <15><12><12><12> <15><12><12><12> <15><12><12><12> <15><12>
        <12><12>

Read Data Request       P:12 L:1 D:4 "Delayed"     19-Feb-80 14:21:38

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:38

Read Data Request       P:12 L:1 D:4 "Rejected"     19-Feb-80 14:21:39

Read Device Status      P:12 L:1 D:4 "Succeeded"     19-Feb-80 14:21:39
        Device type: (0) Unknown, Component code: (224) Line printer,
        Interpret input carriage control, Do component selection, Do space
        compression, New BSC protocol, Input mode, Output EOF signaled,
        Input permission requested, Input running, Input EOF complete,
        Input permissmion was requested, Record size 82, Line signature 31522
SWSKIT                                               Page 15



Write Device Command    P:12 L:1 D:4 "Succeeded"     19-Feb-80 14:21:39
        Clear input EOF complete (ACK)

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:41

(* continue polling port for some device activity *)

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:22:59
[508 entries processed]

[End of log]



This  is  the  file  PORT.LOG.   Comments  have  been  added
instream to reduce the monotony (and length) of the log.

[Interpreted by RDLOG version: 1A(105)]
[Recorded with FELOG version: 1(100)]

***************************************************************
- MARK at time 19-Feb-80 14:19:57 number 1 location 10
***************************************************************

***************************************************************
- MARK at time 19-Feb-80 14:19:57 number 2 name SETUP
***************************************************************

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:19:58

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:20:01

(* 37 similar entries removed *)

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:29

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:31
        Activity on: Line 1 Card reader 0;

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:34
        Activity on: Line 1 Card reader 0, Line printer 0;

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:34
        Activity on: Line 1 Card reader 0, Line printer 0;

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:34
        Activity on: Line 1 Card reader 0, Line printer 0;

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:36

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:21:38

(* 34 similar entires removed *)
SWSKIT                                               Page 16


Read Port Status        P:12     "Succeeded"     19-Feb-80 14:22:57

Read Port Status        P:12     "Succeeded"     19-Feb-80 14:22:59
[508 entries processed]

[End of log]



[End of FELOG.MEM]