Digital DCE for OpenVMS VAX and OpenVMS Alpha
Product Guide


Previous Contents Index

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:

  1. 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
    

  2. Build and link the client and server portions of the application.
  3. 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:


    $ RPC_LOG_FILE == ""
    

  4. 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:


    $ RPC_LOG_FILE == ""
    

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:

  1. The server process command sequence is as follows:


    $ idl fpe_server.idl -trace calls -trace errors
    $ RPC_LOG_FILE == "server.log"
    $ server
    

  2. 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> 
    

  3. 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:


$ idl binopwk.idl

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:

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:

  1. Use the -trace log_manager option in your idl compile command.
  2. Create the RPC_LOG_FILE symbol and assign it to a filename or to screen output.
  3. Execute the client or server process, or both.
  4. 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:

  1. 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
    

  2. Assign the RPC_LOG_FILE symbol to a filename. For example:


    $ RPC_LOG_FILE == "client.log"
    

  3. Execute the client or server process, or both.
  4. 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 (" ").

  5. 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:


$ RPC_LOG_FILE == ""

Then, assign the RPC_EVENTS symbol so it will not log any event types, as follows:


$ RPC_EVENTS == "none"

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.

  1. 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
    

  2. 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] 
    

  3. 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 
    

  4. 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 
    

  5. 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 
    

  6. 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 
    

  7. 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 
    

  8. Server Window --- The event log now contains an entry that indicates the Event Logger will stop logging previously specified events.


    Previous Next Contents Index