Compaq DCE for OpenVMS VAX and OpenVMS Alpha

Document revision date: 5 July 2000

Compaq DCE for OpenVMS VAX and OpenVMS Alpha
Product Guide

Contents

Index

The user then enters the quit command to terminate the rpclm session.

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

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.
<TIME> murp:17868/15 RPC Log Mgr log_events none
rpclm Window --- The user issues a log calls command to enable logging of call events.
rpclm> log calls Event types: calls Events logged to terminal
Server Window --- The newest event log entry indicates that the Event Logger will start logging call events.
<TIME> murp:17868/15 RPC Log Mgr log_events calls
rpclm Window --- Because logging output will increase now that call events are being logged, the user issues an rpclm command to redirect logging output to a file named server_calc.log . When the application terminates and logging is complete, the user can use a text editor to view and search for entries in the log. This log file will contain only those call events from the server process.
rpclm> file server_calc.log Event types: calls Events logged to file 'server_calc.log'
Server Window --- The newest event log entry indicates that the logger will start redirecting logging information to file server_calc.log .
<TIME> murp:17868/15 RPC Log Mgr log_file server_calc.log
Client Window --- The user invokes the client process a third time. The call events that occur during server execution are logged to file server_calc.log . The client process displays the output PASS 3 upon completion.
$ client ncacn_ip_tcp 16.31.48.86 [3123] PASS 3

Server Log --- This is log file server_calc.log :

$ TYPE server_calc.log

<TIME> murp:17868/15 RPC Log Mgr log_start server_calc.log <TIME> murp:17868/15 fpe.setup activate ncacn_ip_tcp:16.31.48[2905] <TIME> murp:17868/15 fpe.setup terminate ncacn_ip_tcp:16.31.48[2905] <TIME> murp:17868/15 fpe.flt_overflw activate ncacn_ip_tcp:16.31.48[2905] <TIME> murp:17868/15 fpe.flt_overflw terminate <TIME> murp:17868/15 fpe.flt_underflw activate ncacn_ip_tcp:16.31.48[2905] <TIME> murp:17868/15 fpe.flt_underflw terminate <TIME> murp:17868/15 fpe.flt_divbyzer activate ncacn_ip_tcp:16.31.48[2905] <TIME> murp:17868/15 fpe.flt_divbyzer terminate <TIME> murp:17868/15 fpe.dble_overflw activate ncacn_ip_tcp:16.31.48[2905] <TIME> murp:17868/15 fpe.dble_overflw terminate <TIME> murp:17868/15 fpe.dble_underflw activate ncacn_ip_tcp:16.31.48[2905] <TIME> murp:17868/15 fpe.dble_underflw terminate <TIME> murp:17868/15 fpe.dble_divbyzer activate ncacn_ip_tcp:16.31.48[2905] <TIME> murp:17868/15 fpe.dble_divbyzer terminate

rpclm Window --- The user issues a file command to redirect event logging output from server_calc.log to the terminal screen. To do this, press the Return key without specifying a filename when the Log Manager prompts for one.
rpclm> file New File Name: <RETURN> Event types: calls Events logged to terminal rpclm>
Server Window --- The final event in the server_calc.log file is a log_file event, which indicates that event logging output is being redirected, in this case to the terminal screen. Therefore, no filename is displayed to the right of the event name.
<TIME> murp:17868/15 RPC Log Mgr log_file

12.5 Using Event Logs to Debug Applications

The RPC Event Logger is designed to help you debug your distributed application and is an enhancement over the basic diagnostics in the RPC product. The diagnostics alone provide minimal information. For example, the sample program called test2, which is provided with the Compaq DCE software kit, generates the rpc_x_no_more_bindings exception when the client fails to contact the server. Without the aid of RPC event logging, this is the only diagnostic information available.

The following example shows the basic RPC diagnostic information that an application displays when an error occurs:

$ run test2 %CMA-F-EXCCOPLOS, exception raised; some information lost -DCERPC-E-NOMOREBINDINGS, no more bindings (dce / rpc) *** Unable to obtain server binding information $

If you enable RPC event logging by defining the symbol RPC_LOG_FILE, then the details of client execution can be captured in a file. From the event log, you can determine which servers the client tried to contact and the reason each attempt failed.

In the following event log example, the Event Data field on the rebind events indicates that the interface is not registered in the end point map and that a communications failure occurred. This information indicates that the server either is not running or it failed to register properly with the end point mapper.

The final event, call_failure , indicates that the call was terminated with the no more bindings status. This event indicates that the client tried all available servers but failed to communicate with any of them. (Note that in the first column the word <TIME> represents the actual value for time.)

$ run test2 <TIME> ko:11436/1 test2.test2_add log_start all <TIME> ko:11436/1 test2.test2_add call_start ncacn_ip_tcp:16.20.16.27[] <TIME> ko:11436/1 test2.test2_add rebind not registered in endpoint map(dce/rpc) <TIME> ko:11436/1 test2.test2_add call_start ncacn_dnet_nsp:4.262[] <TIME> ko:11436/1 test2.test2_add rebind not registered in endpoint map(dce/rpc) <TIME> ko:11436/1 test2.test2_add call_start ncadg_ip_udp:16.20.16.27[] <TIME> ko:11436/1 test2.test2_add rebind communic failure (dce/rpc) <TIME> ko:11436/1 call_failure no more bindings (dce/rpc) %CMA-F-EXCCOPLOS, exception raised; some information lost -DCERPC-E-NOMOREBINDINGS, no more bindings (dce / rpc) *** Unable to obtain server binding information $

12.6 Event Names and Descriptions

Table 12-5 lists and describes RPC events.

Table 12-5 RPC Events
Event Name Description

activate A thread was assigned to process an RPC call on a server, and the server stub has started processing input arguments. The Event Data field of the event log contains the string binding of the client application making the call.

await_reply The transmission of input arguments in a call from a client application to a server is completed. The event is generated by the client stub. The client application is waiting for output arguments from the server.

call_end A call from a client application is complete and the client stub is returning to the caller.

call_failure A client stub terminated abnormally because either an exception occurred or a failing status was returned. The Event Data field of the event log contains the error text associated with the exception or RPC status code.

call_start A client application attempted to make a call to a server. The event is generated by the stub within the client application. The Event Data field of the event log displays the string binding of the server being contacted.

client_ctx_created A client application has allocated a context handle on a particular server. The Event Data field of the event log contains the following information about this event:

The address representing the context handle in the client address space (an opaque pointer)
The UUID that can be used to identify the corresponding context handle on the server
The string binding of the server on which the actual context resided

client_ctx_deleted The client application representation of a context handle is being deleted to reflect the deletion of the context handle on the server. The Event Data field of the event log contains the following information about this event:

The address representing the context handle in the client address space (an opaque pointer)
The UUID that can be used to identify the corresponding context handle on the server
The string binding of the server on which the actual context resided

client_ctx_destroyed A client application has destroyed the client representation of a context handle through the
rpc_ss_destroy_client_context() routine. The Event Data field of the event log contains the following information about this event:

The address representing the context handle in the client address space (an opaque pointer)
The UUID that can be used to identify the corresponding context handle on the server
The string binding of the server on which the actual context resided

context_created A new context handle was created on a server and returned from the application manager routine. The Event Data field of the event log contains both the application value of the context handle and the UUID assigned to represent this context handle.

context_deleted A context handle on a server has been deleted by the application manager routine. The Event Data field of the event log contains both the application value of the context handle and the UUID assigned to represent this context handle.

context_modified A context handle on a server was returned from the application manager routine with a value that is different from its previous value. The Event Data field of the event log contains both the application value of the context handle and the UUID assigned to represent this context handle.

context_rundown A context handle on a server was freed by the context rundown procedure. The Event Data field of the event log contains both the application value of the context handle and the UUID assigned to represent this context handle.

exception An exception was detected in the server stub, and the exception caused the call to terminate. The Event Data field of the event log contains a text description of the exception.

internal_error A failure occurred in the support routines that manage the Event Logger. Check the Event Data field of the event log for a description of the cause of the event. If the error does not seem to indicate a transient network problem or an environmental failure, report the failure in a Software Performance Report (SPR).

listening The RPC Log Manager has started to listen for rpclm commands. The listening event is generated by the portion of the RPC Log Manager built into your application by the RPC runtime when you specify the -trace log_manager option on your IDL compilation. The RPC Log Manager services the requests generated by the rpclm command. You use one of the string bindings from a listening event to invoke the rpclm command interface.

log_events Event logging was modified through the Log Manager command interface rpclm . The Event Data field of the event log contains the new set of events being logged.

log_file Event logging was modified through the Log Manager command interface rpclm . The Event Data field of the event log contains the new filename for the event log. If no filename is displayed, events are being logged to the screen.

log_start A new event log was created or event logging was resumed after being suspended by a user command to the Log Manager command interface rpclm . The Event Data field in the event log contains a list of event types being logged.

log_stop Event logging was stopped through the Log Manager command interface rpclm .

manager_call The server stub is about to call the application manager routine.

manager_return Control has just returned from the application manager routine to the server stub.

rebind A call from a client application to a server failed. The Event Data field in the event log shows the reason for the failure to contact the server. The event is generated by the stub within the client application. The call failed on an auto_handle operation and the client is attempting to rebind to the next server.

receive Following the transmission of input arguments from a client application call to a server, the client received a reply and has started processing output arguments.

receive_fault The client received a fault indicating a failure on the server. The Event Data field of the event log contains the RPC status that identifies the failure. All failures have fault codes that you can find in the file ncastat.idl . If the fault code in the ncastat.idl file is too general (such as unspecified fault ), examine the server event log for precise failure information.

status_fail A failure status was encountered in the server stub. The Event Data field of the event log describes the failure.

terminate The server thread has completed processing the call and has terminated.

transmit_fault The server runtime is sending fault information to the client application. The Event Data field of the event log indicates the name of the fault being sent. The fault information in this field is listed in the ncastat.idl file. The fault information in this field may be less descriptive than the information logged about the actual error. (See the exception or status_fail events in the event log to obtain precise failure information.)

**Table 12-5 RPC Events**
Event Name	Description
activate	A thread was assigned to process an RPC call on a server, and the server stub has started processing input arguments. The Event Data field of the event log contains the string binding of the client application making the call.
await_reply	The transmission of input arguments in a call from a client application to a server is completed. The event is generated by the client stub. The client application is waiting for output arguments from the server.
call_end	A call from a client application is complete and the client stub is returning to the caller.
call_failure	A client stub terminated abnormally because either an exception occurred or a failing status was returned. The Event Data field of the event log contains the error text associated with the exception or RPC status code.
call_start	A client application attempted to make a call to a server. The event is generated by the stub within the client application. The Event Data field of the event log displays the string binding of the server being contacted.
client_ctx_created	A client application has allocated a context handle on a particular server. The Event Data field of the event log contains the following information about this event: The address representing the context handle in the client address space (an opaque pointer) The UUID that can be used to identify the corresponding context handle on the server The string binding of the server on which the actual context resided
client_ctx_deleted	The client application representation of a context handle is being deleted to reflect the deletion of the context handle on the server. The Event Data field of the event log contains the following information about this event: The address representing the context handle in the client address space (an opaque pointer) The UUID that can be used to identify the corresponding context handle on the server The string binding of the server on which the actual context resided
client_ctx_destroyed	A client application has destroyed the client representation of a context handle through the `rpc_ss_destroy_client_context()` routine. The Event Data field of the event log contains the following information about this event: The address representing the context handle in the client address space (an opaque pointer) The UUID that can be used to identify the corresponding context handle on the server The string binding of the server on which the actual context resided
context_created	A new context handle was created on a server and returned from the application manager routine. The Event Data field of the event log contains both the application value of the context handle and the UUID assigned to represent this context handle.
context_deleted	A context handle on a server has been deleted by the application manager routine. The Event Data field of the event log contains both the application value of the context handle and the UUID assigned to represent this context handle.
context_modified	A context handle on a server was returned from the application manager routine with a value that is different from its previous value. The Event Data field of the event log contains both the application value of the context handle and the UUID assigned to represent this context handle.
context_rundown	A context handle on a server was freed by the context rundown procedure. The Event Data field of the event log contains both the application value of the context handle and the UUID assigned to represent this context handle.
exception	An exception was detected in the server stub, and the exception caused the call to terminate. The Event Data field of the event log contains a text description of the exception.
internal_error	A failure occurred in the support routines that manage the Event Logger. Check the Event Data field of the event log for a description of the cause of the event. If the error does not seem to indicate a transient network problem or an environmental failure, report the failure in a Software Performance Report (SPR).
listening	The RPC Log Manager has started to listen for `rpclm` commands. The `listening` event is generated by the portion of the RPC Log Manager built into your application by the RPC runtime when you specify the `-trace log_manager` option on your IDL compilation. The RPC Log Manager services the requests generated by the `rpclm` command. You use one of the string bindings from a `listening` event to invoke the `rpclm` command interface.
log_events	Event logging was modified through the Log Manager command interface `rpclm` . The Event Data field of the event log contains the new set of events being logged.
log_file	Event logging was modified through the Log Manager command interface `rpclm` . The Event Data field of the event log contains the new filename for the event log. If no filename is displayed, events are being logged to the screen.
log_start	A new event log was created or event logging was resumed after being suspended by a user command to the Log Manager command interface `rpclm` . The Event Data field in the event log contains a list of event types being logged.
log_stop	Event logging was stopped through the Log Manager command interface `rpclm` .
manager_call	The server stub is about to call the application manager routine.
manager_return	Control has just returned from the application manager routine to the server stub.
rebind	A call from a client application to a server failed. The Event Data field in the event log shows the reason for the failure to contact the server. The event is generated by the stub within the client application. The call failed on an auto_handle operation and the client is attempting to rebind to the next server.
receive	Following the transmission of input arguments from a client application call to a server, the client received a reply and has started processing output arguments.
receive_fault	The client received a fault indicating a failure on the server. The Event Data field of the event log contains the RPC status that identifies the failure. All failures have fault codes that you can find in the file `ncastat.idl` . If the fault code in the `ncastat.idl` file is too general (such as `unspecified fault` ), examine the server event log for precise failure information.
status_fail	A failure status was encountered in the server stub. The Event Data field of the event log describes the failure.
terminate	The server thread has completed processing the call and has terminated.
transmit_fault	The server runtime is sending fault information to the client application. The Event Data field of the event log indicates the name of the fault being sent. The fault information in this field is listed in the `ncastat.idl` file. The fault information in this field may be less descriptive than the information logged about the actual error. (See the `exception` or `status_fail` events in the event log to obtain precise failure information.)