|
Digital DCE for OpenVMS VAX and OpenVMS
Alpha Product Guide
17.2.2 Using the -trace Option
Once you have used the Event Logger, you will find that it generates a
large volume of information to be analyzed. Discard any unneeded log
files, since the Event Logger will continue to record information in
the files, enlarging them until the disk is full.
To help reduce the generation of unwanted information, you can use the
-trace options to enable event logging on only a subset of
events. That is, rather than specifying the all option,
specify only calls or only context_handles. The
subset you specify will depend on the part of your application you are
debugging. Because the -trace option provides logging control
on a per-compilation basis, the interface must be rebuilt to enable or
disable logging of different event types. The -trace options
offer the ability to select different event types for the various IDL
interfaces that may make up a single application.
You can use the -trace option to request logging of a single
type of event, such as errors, with a command similar to the
following:
$ idl binopwk.idl -trace errors
|
You can also use the -trace option to request logging of
multiple event types, such as errors and calls as
shown below:
$ idl binopwk.idl -trace errors -trace calls
|
This command enables the Event Logger, specifying error and call event
logging.
To enable event logging to trace the execution of RPC calls within a
process, perform the following steps:
- Enable event logging by specifying the -trace option in
the idl command you use to compile each interface definition.
This example specifies the -trace all option:
$ idl binopwk.idl -trace all
|
- Build and link the client and server portions of the application.
- Use the symbol RPC_LOG_FILE to direct the log output for both the
server and client processes. To store Event Logger output in a file,
assign the symbol to a filename. To direct Event Logger output to the
standard terminal output for the process (stdout), assign the symbol to
double quotation marks (" "). This guide refers to standard terminal
output as the screen.
In the window from which the server portion
of the application will be executed, direct logging for the server to a
file with the following syntax:
$ RPC_LOG_FILE == "server.log"
|
Or, to direct logging for the server to the screen, use the
following syntax:
- In the window from which the client portion of the application
will be executed, direct logging for the client to a file with the
following syntax:
$ RPC_LOG_FILE == "client.log"
|
Or, to direct logging for the client to the screen, use the
following syntax:
Now you can invoke the client and server processes. The event log will
be recorded in the specified file or displayed on your screen when you
execute the application.
17.2.3 Combining Event Logs
Although event logs are generated locally for each process, you can
combine event log files to provide a broader view of application
execution.
Note that this section does not give examples of each step in the
application development process.
The syntax of a merge command is as follows:
$ merge server-filename.log, client-filename.
log client_and_server-filename.log
|
If two events have the same timestamp, you receive a warning message
after the merge is completed.
The following example illustrates how to merge logs from two different
systems:
- The server process command sequence is as follows:
$ idl fpe_server.idl -trace calls -trace errors
$ RPC_LOG_FILE == "server.log"
$ server
|
- The client process command sequence is as follows:
$ idl fpe_client.idl -trace calls -trace errors
$ RPC_LOG_FILE == "client.log"
$ client
|
These command sequences result in two log files:
server.log and client.log, shown below. (Note that,
in the following example log files, the Event Data field is replaced by
the word <DATA> to improve readability of the log.) This is
file server.log:
1993-03-03:20:37.170-5:00I0.121 murp:17924/15 fpe.setup log_start <DATA>
1993-03-03:20:37.170-5:00I0.121 murp:17924/15 RPC LogMgrlistening <DATA>
1993-03-03:20:37.180-5:00I0.121 murp:17924/15 fpe.setup activate <DATA>
1993-03-03:20:37.180-5:00I0.121 murp:17924/15 fpe.setup terminate <DATA>
1993-03-03:20:37.200-5:00I0.121 murp:17924/15 fpe.float <DATA>
1993-03-03:20:37.200-5:00I0.121 murp:17924/15 transmit_fault <DATA>
1993-03-03:20:37.200-5:00I0.121 murp:17924/15 fpe.float terminate <DATA>
|
This is file client.log:
1993-03-03:20:37.850-5:00I0.121 ifdef:28168/1 fpe.stup log_start <DATA>
1993-03-03:20:37.880-5:00I0.121 ifdef:28168/1 fpe.stup call_start <DATA>
1993-03-03:20:37.190-5:00I0.121 ifdef:28168/1 fpe.stup call_end <DATA>
1993-03-03:20:37.190-5:00I0.121 ifdef:28168/1 fpe.flt call_start <DATA>
1993-03-03:20:37.210-5:00I0.121 ifdef:28168/1 receive_fault <DATA>
1993-03-03:20:37.210-5:00I0.121 ifdef:28168/1 call_failure <DATA>
|
- Next, the two log files are merged with the merge command:
$ merge server.log,client.log client_and_server.log
|
The resulting file client_and_server.log is as follows:
1993-03-03:20:37.850-5:00I0.121 ifdef:28168/1 fpe.setup log_start <DATA>
1993-03-03:20:37.880-5:00I0.121 ifdef:28168/1 fpe.setup call_start<DATA>
1993-03-03:20:37.170-5:00I0.121 murp:17924/15 fpe.setup log_start <DATA>
1993-03-03:20:37.170-5:00I0.121 murp:17924/15 RPC LogMgrlistening <DATA>
1993-03-03:20:37.180-5:00I0.121 murp:17924/15 fpe.setup terminate <DATA>
1993-03-03:20:37.190-5:00I0.121 ifdef:28168/1 fpe.setup call_end <DATA>
1993-03-03:20:37.190-5:00I0.121 ifdef:28168/1 fpe.float call_start<DATA>
1993-03-03:20:37.200-5:00I0.121 murp:17924/15 fpe.float activate <DATA>
1993-03-03:20:37.200-5:00I0.121 murp:17924/15 fpe.float exception <DATA>
1993-03-03:20:37.200-5:00I0.121 murp:17924/15 transmit_fault <DATA>
1993-03-03:20:37.200-5:00I0.121 murp:17924/15 fpe.float terminate <DATA>
1993-03-03:20:37.210-5:00I0.121 ifdef:28168/1 receive_fault <DATA>
1993-03-03:20:37.210-5:00I0.121 ifdef:28168/1 call_failure <DATA>
|
For the merged output to be accurate, the system clocks on all hosts on
which event logs are generated must be closely synchronized. The
Distributed Time Service (DTS) component of Digital's DCE provides such
a service. Once the clocks are synchronized, the ordering of events in
a merged log file is valid only if the difference between timestamps
made on different machines is greater than the inaccuracy field in
those timestamps. (See the DTS documentation for more information about
timestamps.)
In the preceding client_and_server.log file example, consider
the event with the timestamp 1993-03-03:20:37:03.180-5:00I0.121 and the
event that follows it (these two event lines are separated from the
rest of the log by a blank line before and after). Note that the
timestamps indicate that the terminate event precedes the
call_end event.
However, you cannot determine this sequence of events by comparing
timestamps because the inaccuracy value at the end of the timestamp is
greater than the difference between the timestamps. That is, the
difference in time between these events is only 10 milliseconds (the
difference between 180 and 190 milliseconds). However, the inaccuracy
in the timestamps is 121 milliseconds (I0.121). Therefore, the log is
not a definitive indicator of which event occurred first. Because of
the simplicity of the example and the single thread of control, you can
assume that the terminate event preceded the call_end
event.
17.2.4 Disabling Event Logging
To disable event logging, compile your interface without specifying the
-trace option. For example:
17.3 Using Symbols and the Log Manager to Control Logging Information
In addition to the -trace options, the Event Logger offers two
other methods for controlling information in the event log. Each
facility is advantageous in different circumstances, depending on the
type of processes with which you are working and the type of events you
need to log. The two methods are as follows:
- Controlling Logged Events with a Symbol: Select a subset of event
types specified previously with the -trace option by creating
the symbol RPC_EVENTS. You assign the symbol to the required event
types before executing the process. This method allows you to use event
logging without rebuilding the interface; however, you must first stop
the process or assign the symbol before starting it. This method is
also useful in cases where you specified all-inclusive event logging
(such as with the -trace all option) but you determine that
you need only a subset of events while the application is executing.
- Controlling Logged Events with the RPC Log Manager: Select a subset
of event types specified previously with the -trace option by
using the RPC Log Manager command interface. This method allows you to
modify event logging parameters for an executing image; there is no
need to rebuild the interface or to stop and restart the process. In
addition, you can use the Log Manager to modify event types specified
with the symbol RPC_EVENTS.
The following sections provide detailed descriptions of how to use each
of these methods to control the type of events logged.
17.3.1 Controlling Logged Events with a Symbol
One way to control the type of events logged is by assigning the symbol
RPC_EVENTS. This method is ideal for an application that contains a
single RPC interface because a symbol provides control at the process
level, rather than at the interface-by-interface level. However, to
enable the symbol you must first stop the client or server process.
To use symbols to control event logging, first use the IDL
-trace option in your idl compile command and then
assign the log file with RPC_LOG_FILE. You can then use the symbol
RPC_EVENTS to reduce the number of events currently being logged. That
is, if you used the -trace errors option to request error
event logging, you can subsequently use only the symbol to request
logging of errors or none. You cannot use the symbol
to increase the number of event types to be logged. To do this, you
must recompile the interface with the required -trace options.
The value of RPC_EVENTS is a list of event types separated by commas.
The list identifies the event types to be monitored. Valid values are
the same as those for -trace (except log_manager).
These values are all, none, calls,
context, errors, and misc.
An example command line follows:
$ RPC_EVENTS == "calls,errors"
|
If the symbol RPC_EVENTS was not assigned, then by default all of the
events specified with the -trace option are written into the
event log.
17.3.2 Controlling Logged Events with the RPC Log Manager
During application development, certain problems occur only after a
server has executed some number of calls. Other problems may require
more information than anticipated to debug. These problems can be
addressed by enabling the RPC Log Manager in your application image.
The Log Manager offers a command line interface (rpclm) for
manipulating logging operations during application execution. When you
use the rpclm command line interface, you need not rebuild
your interface or stop and restart your server or client process to
manipulate logging operations.
The rpclm command interface commands are shown in
Table 17-4.
Table 17-4 Command Interface to rpclm
| Command |
Description |
|
inquire
|
Inquire about the currently logged events and determine the name of the
active log file.
|
|
log
|
Specify additional events to log. Valid values are
all,
none,
calls,
context,
errors, and
misc.
|
|
unlog
|
Disable logging of the specified event types. Valid values are
all,
none,
calls,
context,
errors, and
misc.
|
|
file
|
Change the output device or file to which events are logged.
|
|
quit
|
Terminate the
rpclm session.
|
|
help
|
Display a description of
rpclm commands.
|
Follow these steps to enable the RPC Log Manager to control event
logging:
- Use the -trace log_manager option in your idl
compile command.
- Create the RPC_LOG_FILE symbol and assign it to a filename or to
screen output.
- Execute the client or server process, or both.
- When the first call is made to an interface compiled with the
-trace option, a listening event will be generated into the
event log. Invoke the rpclm command interface (as described in
step 4 which follows) by specifying the string binding from the
listening event.
Note
Only string bindings from a listening event can be used to
invoke rpclm.
|
The rpclm command interface allows you to control event
logging parameters from your keyboard. You can use the command
interface to reduce the events currently being logged as well as to
manipulate logging operations. You can enable or disable logging of
different event types (within the set selected with the -trace
option), store event logging in a file or display it on the screen,
inquire about the current event types being logged, and display the
name of the current log file.
The following procedure illustrates how to use the Log Manager:
- When you compile your interface with the idl compile
option, include the -trace log_manager option. For example:
$ idl binopwk.idl -trace all -trace log_manager
|
- Assign the RPC_LOG_FILE symbol to a filename. For example:
$ RPC_LOG_FILE == "client.log"
|
- Execute the client or server process, or both.
- Upon the first remote procedure call to an interface compiled with
the -trace log_manager option, a listening event will
be generated into the log. Examine the Event Data field of the
listening event in the log to determine the Log Manager string
binding. (The RPC Event Logger is itself a client/server application:
the Log Manager is a server process, and rpclm is its client.
The rpclm client uses the string binding of the
listening event to communicate with the Log Manager server.)
Invoke rpclm and specify the Log Manager string binding. For
example, consider the following event:
<TIME> murp:17868/15 RPC LogMgr listening ncacn_ip_tcp:16.31.48[3820]
|
The listening event indicates that the RPC Log Manager is
waiting for commands from rpclm. (Note that, in the example,
the Time field is replaced by the word <TIME> to improve
readability of the log.) To invoke rpclm, enter the
listening event string binding for this server process from
the Event Data field as follows:
$ rpclm "ncacn_ip_tcp:16.31.48.144[3820]"
|
Note that you must enclose the string binding in double quotation
marks (" ").
- As you execute rpclm commands, the Log Manager displays
current logging parameters that indicate the changes made to event
logging for this process. For example:
rpclm> unlog all
Event types:
Events logged to terminal
rpclm> log calls
Event types: call
Events logged to terminal
|
The log for this server process will have corresponding events
logged as follows:
<TIME> murp:17868/15 RPC Log Mgr log_events none
<TIME> murp:17868/15 RPC Log Mgr log_events calls
|
The following example illustrates a command dialog between the user and
rpclm. The dialog begins when the user specifies a string
binding from a listening event to rpclm.
$ rpclm "ncacn_ip_tcp:cltdce[1821]"
rpclm> help
rpclm Commands:
inquire - Display logged events and log filename
log - Specify additional events to log
unlog - Specify events that should no longer be logged
file - Change file into which events are logged
quit - Exit log manager
rpclm> inquire
Event Types: calls
Events logged to terminal
rpclm> log errors
Event Types: calls errors
Events logged to terminal
rpclm> file server.log
Event Types: calls errors
Events logged to file 'server.log'
rpclm> quit
|
In this dialog, the user enters the help command to display
the rpclm commands and command descriptions.
The user then enters the inquire command to display the types
of events being logged and the log filename. In this example, errors
are being logged to the screen.
The user enters the log calls command to specify that the Log
Manager should start logging all events relating to calls, in addition
to error events.
The user then enters the file command and specifies a
filename. This command requests that rpclm change its output
device from the terminal screen to a file named server.log.
The user then enters the quit command to terminate the
rpclm session.
17.4 Using the -trace Option, Symbols, and the Log Manager Together
This section describes a few different ways to use the -trace
options, symbols, and the Log Manager together. When you are learning
to use the Event Logger, one possible approach is to specify
all-inclusive event logging with the -trace all IDL
compilation option, and then examine the event log to get an
understanding of typical output. You can then use the symbol RPC_EVENTS
to log only those events needed, such as calls or
errors.
In the case of a running process that you do not want to terminate, use
a different method. First enable the Event Logger specifying logging of
all events, and enable the Log Manager also, as follows:
$ idl filename -trace all -trace log_manager
|
Set the event log to display on the screen, as follows:
Then, assign the RPC_EVENTS symbol so it will not log any event types,
as follows:
With these parameters set, the only event that will be displayed is the
listening event once the first call is made to a server interface
compiled with the -trace log_manager option. You can then
obtain the string binding for the process and use it later, if needed.
Once you start the process, if an error occurs, use the string binding
to invoke the rpclm command interface and log the needed
events. Any rpclm commands issued at this point will modify
the RPC_EVENTS symbol assignment. For example, if you assign the symbol
RPC_EVENTS to calls and then issue a command to rpclm
to log errors, errors as well as calls will be logged.
Once you are familiar with Event Logger output, consider regularly
using the command interface to enable or disable subsets of event types
as needed.
This section provides an example of common tasks you may need to
perform during event logging. In this particular example, a distributed
server process provides a mathematical calculation service. The client
process passes data to be calculated to the server process. This type
of processing often generates exception events such as those in the
example event log. That is, some operations are interrupted by floating
point overflow and integer division by zero exceptions, as well as
others. This example uses rpclm to control logging of a server
process; however, rpclm can also be used to control event
logging for a client process.
The following processes are shown in three windows: a server process
window, a client process window, and an rpclm window.
- Server Window --- The user first enables the RPC Event Logger by
specifying the -trace all and -trace log_manager
options in the idl command line:
$ idl server.calc -trace all -trace log_manager
|
- Server Window --- The user starts the server process. The server
receives a client call and initializes the RPC Log Manager. The symbols
were assigned to enable event logging with no event types selected, so
only Log Manager events are output, as shown. (Note that the end point
displayed for the listening event is the end point of the Log
Manager.)
$ RPC_LOG_FILE == ""
$ RPC_EVENTS == "none"
$ server ncacn_ip_tcp
|
<TIME> murp:17868/15 fpe.setup log_start none
<TIME> murp:17868/15 RPC LogMgr listening ncacn_ip_tcp:16.31.48[3820]
|
- Client Window --- The user invokes the client process by using a
foreign command that was previously defined. The specified string
binding is used to find the server. The client process displays the
output PASS 1 upon completion.
$ client ncacn_ip_tcp 16.31.48.86 [3123]
PASS 1
|
- rpclm Window --- The user invokes rpclm and
specifies the string binding displayed in the listening event output by
the server process, shown in step 2. The string binding must be
enclosed in double quotation marks (" "). The user issues the
inquire command, and the event logging parameters for the
server process are displayed. The Log Manager reply indicates that no
event types are enabled and that the event log is being displayed on
the screen from which the server process was started. The user issues
the log errors command to enable logging of error events for
the server process.
$ rpclm "ncacn_ip_tcp:16.31.48.144[3820]"
rpclm> inquire
Event types:
Events logged to terminal
rpclm> log errors
Event types: errors
Events logged to terminal
|
- Client Window --- The user invokes the client process a second
time. The error events that occur during server execution are logged to
the server window. The client process displays the output PASS 2 upon
completion.
$ client ncacn_ip_tcp 16.31.48.86 [3123]
PASS 2
|
- Server Window --- The server process receives the command from
rpclm to start logging errors. Any errors that occur in the
server process are logged.
<TIME> murp:17868/15 RPC Log Mgr log_events errors
<TIME> murp:17868/15 fpe.flt_overflw exception Floating point
overflow (dce/thd)
<TIME> murp:17868/15 transmit_fault rpc_s_fault_fp_overflow
<TIME> murp:17868/15 fpe.flt_underflw exception Floating point
underflow (dce/thd)
<TIME> murp:17868/15 transmit_fault rpc_s_fault_fp_underflow
<TIME> murp:17868/15 fpe.flt_divbyzer exception Floating point/decimal
divide by zero (dce/thd)
<TIME> murp:17868/15 transmit_fault rpc_s_fault_fp_div_by_zero
<TIME> murp:17868/15 fpe.dble_overflw exception Floating point
overflow (dce/thd)
<TIME> murp:17868/15 transmit_fault rpc_s_fault_fp_overflow
<TIME> murp:17868/15 fpe.dble_underflw exception Floating point
underflow (dce/thd)
<TIME> murp:17868/15 transmit_fault rpc_s_fault_fp_underflow
<TIME> murp:17868/15 fpe.dble_divbyzer exception Floating point/decimal
divide by zero (dce/thd)
<TIME> murp:17868/15 transmit_fault rpc_s_fault_fp_div_by_zero
|
- rpclm Window --- The user issues the unlog all
command to disable logging of all previously specified event types.
rpclm> unlog all
Event types:
Events logged to terminal
|
- Server Window --- The event log now contains an entry that
indicates the Event Logger will stop logging previously specified
events.
|