Object Request Broker communications trace: WAS v5.1

Object Request Broker communications trace

The ORB communications trace, typically referred to as CommTrace, contains the sequence of General InterORB Protocol (GIOP) messages sent and received by the ORB during application execution. It might be necessary to understand the low-level sequence of client-to-server or server-to-server interactions during problem determination. This article uses trace entries from log examples to explain the contents of the log and help you understand the interaction sequence. It focuses only in the GIOP messages and does not discuss in detail additional trace information that appears when intervening with the GIOP-message boundaries.

Location

When ORB tracing is enabled, this information is placed in $WAS_HOME/logs/trace.

Usage notes

Is this file read-only?
Yes
Is this file updated by a product component?
This file is updated by the administrative function.
How and when are the contents of this file used?
You use this file to localize and resolve ORB-related problems.

How to interpret the output

The following sections refer to sample log output found later in this topic.

Identifying information The start of a GIOP message is identified by a line which contains either "OUT GOING:" or "IN COMING:" depending on whether the message is sent or received by the process that is being traced.
Following the identifying line entry is a series of items, formatted for convenience, with information extracted from the raw message that identify the endpoints in this particular message interaction. See lines 3-13 in both examples. The formatted items include the following...

GIOP message type (line 3)
Date and time that message was recorded (line 4)
Information useful in uniquely identifying the thread in execution when the message was recorded, with other thread-specific information (line 5, broken for publication in the reply example)
Local and remote TCP/IP ports used for the interaction (lines 6 through 9)
GIOP version, byte order, whether the message is a fragment, and message size (lines 10 through 13)

Request ID, response expected and reply status Following the introductory message information, the request ID is an integer generated by the ORB. It is used to identify and associate each request with its corresponding reply. This is necessary because the ORB can receive requests from multiple clients and must be able to associate each reply with the corresponding originating request.

Lines 15-17 in the request example show the request ID, followed by an indication to the receiving endpoint that a response is expected CORBA(allows sending of one-way requests for which a response is not expected.)
Line 15 in the reply example shows the request ID; line 33 shows the reply status received after completing the previously sent request.

Object Key Lines 18-20 in the request example show the object key, the internal representation used by the ORB during execution to identify and locate the target object intended to receive the request message. Object keys are not standardized.

Operation Line 21 in the request example shows the name of the operation to be executed by the target object in the receiving endpoint. In this example, the specific operation requested is named _get_value.

Service context information The service contexts in the message are also formatted for convenience. Each GIOP message might contain a sequence of service contexts sent/received by each endpoint. Service contexts, identified uniquely with an ID, contain data used in the specific interaction, such as security, character codeset conversion, and ORB version information. The content of some of the service contexts is standardized and specified by OMG, while other service contexts are proprietary and specified by each vendor. IBM-specific service contexts are identified with IDs that begin with 0x4942.
Lines 22-41 in the request example illustrate typical service context entries. There are three service contexts in the request message, as shown in line 22. The ID, length of data, and raw data for each service context is printed next. Lines 23-25 show an IBM-proprietary context, as indicated by the ID 0x49424D12. Lines 26-41 show two standard service contexts, identified by ID 0x6 (line 26) and 0x1 (line 39).
Lines 16-32 in the the reply example illustrate two service contexts, one IBM-proprietary (line 17) and one standardized (line 20).
For the definition of the standardized service contexts, see the CORBA specification. Service context 0x1 (CORBA::IOP::CodeSets) is used to publish the character codesets supported by the ORB in order to negotiate and determine the codeset used to transmit character data. Service context 0x6 (CORBA::IOP::SendingContextRunTime) is used by RMI-IIOP to provide the receiving endpoint with the IOR for the SendingContextRuntime object. IBM service context 0x49424D12 is used to publish ORB PartnerVersion information in order to support release-to-release interoperability between sending and receiving ORBs.

Data offset Line 42 in the request example shows the offset, relative to the beginning of the GIOP message, where the remainder body of the request or reply message is located. This portion of the message is specific to each operation and varies from operation to operation. Therefore, it is not formatted, as the specific contents are not known by the ORB. The offset is printed as an aid to quickly locating the operation-specific data in the raw GIOP message dump, which follows the data offset.

Raw GIOP message dump Starting at line 45 in the request example and line 36 in the reply example, a raw dump of the entire GIOP message is printed in hexadecimal format. Request messages contain the parameters required by the given operation and reply messages contain the return values and content of output parameters as required by the given operation. For brevity, not all of the raw data has been included in the figures.

Sample Log Entry - GIOP Request
1. OUT GOING... 3. Request Message 4. Date: April 17, 2002 10:00:43 PM CDT 5. Thread Info: P=842115:O=1:CT 6. Local Port: 1243 (0x4DB) 7. Local IP: jdoe.amsterdam.setgetweb.com/192.168.1.101 8. Remote Port: 1242 (0x4DA) 9. Remote IP: jdoe.amsterdam.setgetweb.com/192.168.1.101 10. GIOP Version: 1.2 11. Byte order: big endian 12. Fragment to follow: No 13. Message size: 268 (0x10C) -- 15. Request ID: 5 16. Response Flag: WITH_TARGET 17. Target Address: 0 18. Object Key: length = 24 (0x18) 4B4D4249 00000010 BA4D6D34 000E0008 00000000 00000000 21. Operation: _get_value 22. Service Context: length = 3 (0x3) 23. Context ID: 1229081874 (0x49424D12) 24. Context data: length = 8 (0x8) 00000000 13100003 26. Context ID: 6 (0x6) 27. Context data: length = 164 (0xA4) 00000000 00000028 49444C3A 6F6D672E 6F72672F 53656E64 696E6743 6F6E7465 78742F43 6F646542 6173653A 312E3000 00000001 00000000 00000068 00010200 0000000E 3139322E 3136382E 312E3130 310004DC 00000018 4B4D4249 00000010 BA4D6D69 000E0008 00000000 00000000 00000002 00000001 00000018 00000000 00010001 00000001 00010020 00010100 00000000 49424D0A 00000008 00000000 13100003 39. Context ID: 1 (0x1) 40. Context data: length = 12 (0xC) 00000000 00010001 00010100 42. Data Offset: 118 45. 0000: 47494F50 01020000 0000010C 00000005 GIOP............ 46. 0010: 03000000 00000000 00000018 4B4D4249 ............KMBI 47. 0020: [remainder of message body deleted for brevity]

Sample Log Entry - GIOP Reply

1.  IN COMING...

3.  Reply Message
4.  Date:          April 17, 2002 10:00:47 PM CDT
5.  Thread Info:   RT=0:P=842115:O=1:com.ibm.rmi.transport.TCPTransportConnection 
5a.   remoteHost=192.168.1.101 remotePort=1242 localPort=1243
6.  Local Port:    1243 (0x4DB)
7.  Local IP:      jdoe.amsterdam.setgetweb.com/192.168.1.101
8.  Remote Port:   1242 (0x4DA)
9.  Remote IP:     jdoe.amsterdam.setgetweb.com/192.168.1.101
10. GIOP Version:  1.2
11. Byte order:    big endian
12. Fragment to follow: No   
13. Message size:  208 (0xD0)
--
15. Request ID:        5
16. Service Context:   length = 2 (0x2)
17. Context ID:  1229081874 (0x49424D12)
18. Context data:  length = 8 (0x8)
                       00000000 13100003                   
20. Context ID:  6 (0x6)
21. Context data:  length = 164 (0xA4)
                       00000000 00000028 49444C3A 6F6D672E 
                       6F72672F 53656E64 696E6743 6F6E7465 
                       78742F43 6F646542 6173653A 312E3000 
                       00000001 00000000 00000068 00010200 
                       0000000E 3139322E 3136382E 312E3130 
                       310004DA 00000018 4B4D4249 00000010 
                       BA4D6D34 000E0008 00000001 00000000 
                       00000002 00000001 00000018 00000000 
                       00010001 00000001 00010020 00010100 
                       00000000 49424D0A 00000008 00000000 
                       13100003                            
33. Reply Status:      NO_EXCEPTION


36. 0000: 47494F50 01020001 000000D0 00000005   GIOP............
37. 0010: 00000000 00000002 49424D12 00000008   ........IBM.....
38. 0020: [remainder of message body deleted for brevity]

Identifying information	The start of a GIOP message is identified by a line which contains either "OUT GOING:" or "IN COMING:" depending on whether the message is sent or received by the process that is being traced. Following the identifying line entry is a series of items, formatted for convenience, with information extracted from the raw message that identify the endpoints in this particular message interaction. See lines 3-13 in both examples. The formatted items include the following... GIOP message type (line 3) Date and time that message was recorded (line 4) Information useful in uniquely identifying the thread in execution when the message was recorded, with other thread-specific information (line 5, broken for publication in the reply example) Local and remote TCP/IP ports used for the interaction (lines 6 through 9) GIOP version, byte order, whether the message is a fragment, and message size (lines 10 through 13)
Request ID, response expected and reply status	Following the introductory message information, the request ID is an integer generated by the ORB. It is used to identify and associate each request with its corresponding reply. This is necessary because the ORB can receive requests from multiple clients and must be able to associate each reply with the corresponding originating request. Lines 15-17 in the request example show the request ID, followed by an indication to the receiving endpoint that a response is expected CORBA(allows sending of one-way requests for which a response is not expected.) Line 15 in the reply example shows the request ID; line 33 shows the reply status received after completing the previously sent request.
Object Key	Lines 18-20 in the request example show the object key, the internal representation used by the ORB during execution to identify and locate the target object intended to receive the request message. Object keys are not standardized.
Operation	Line 21 in the request example shows the name of the operation to be executed by the target object in the receiving endpoint. In this example, the specific operation requested is named _get_value.
Service context information	The service contexts in the message are also formatted for convenience. Each GIOP message might contain a sequence of service contexts sent/received by each endpoint. Service contexts, identified uniquely with an ID, contain data used in the specific interaction, such as security, character codeset conversion, and ORB version information. The content of some of the service contexts is standardized and specified by OMG, while other service contexts are proprietary and specified by each vendor. IBM-specific service contexts are identified with IDs that begin with 0x4942. Lines 22-41 in the request example illustrate typical service context entries. There are three service contexts in the request message, as shown in line 22. The ID, length of data, and raw data for each service context is printed next. Lines 23-25 show an IBM-proprietary context, as indicated by the ID 0x49424D12. Lines 26-41 show two standard service contexts, identified by ID 0x6 (line 26) and 0x1 (line 39). Lines 16-32 in the the reply example illustrate two service contexts, one IBM-proprietary (line 17) and one standardized (line 20). For the definition of the standardized service contexts, see the CORBA specification. Service context 0x1 (CORBA::IOP::CodeSets) is used to publish the character codesets supported by the ORB in order to negotiate and determine the codeset used to transmit character data. Service context 0x6 (CORBA::IOP::SendingContextRunTime) is used by RMI-IIOP to provide the receiving endpoint with the IOR for the SendingContextRuntime object. IBM service context 0x49424D12 is used to publish ORB PartnerVersion information in order to support release-to-release interoperability between sending and receiving ORBs.
Data offset	Line 42 in the request example shows the offset, relative to the beginning of the GIOP message, where the remainder body of the request or reply message is located. This portion of the message is specific to each operation and varies from operation to operation. Therefore, it is not formatted, as the specific contents are not known by the ORB. The offset is printed as an aid to quickly locating the operation-specific data in the raw GIOP message dump, which follows the data offset.
Raw GIOP message dump	Starting at line 45 in the request example and line 36 in the reply example, a raw dump of the entire GIOP message is printed in hexadecimal format. Request messages contain the parameters required by the given operation and reply messages contain the return values and content of output parameters as required by the given operation. For brevity, not all of the raw data has been included in the figures.

Object Request Broker communications trace

Location

Usage notes

How to interpret the output

Sample Log Entry - GIOP Request

Sample Log Entry - GIOP Reply

See Also