InfoCenter Home >
8: Problem determination >
8.4: Enabling and reading ORB trace

8.4: Enabling and reading ORB trace

In this section you will find information on how to read and enable ORB trace.

Reading ORB trace

In order to read ORB trace, you need to understand the ORB communications log.

ORB communications log

The ORB communications log, typically referred to as CommTrace, contains the sequence of 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 section uses trace entries from a sample log 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 which appears when intervening with the GIOP-message boundaries.

The Sample Log Entry - GIOP Request and Sample Log Entry - GIOP Reply illustrate typical log entries. The entries have been annotated with line numbers for easy reference.

Enabling CommTrace

The ORB property com.ibm.CORBA.CommTrace is used to enable/disable recording of trace entries during execution. Trace entries are recorded when the property is set true. In addition, the property com.ibm.CORBA.Debug must also be set true.

Identifying start of a GIOP messages

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 a request message or reply message.

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-12 in both figures. The formatted items include:

  • GIOP message type, e.g. "Request Message", "Reply Message", in line 3
  • Date and time message was recorded, in line 4
  • Information useful in uniquely identifying the thread in execution when the message was recorded, along with other thread-specific information, in line 5
  • The local and remote TCP/IP ports used for the interaction, in lines 6-9
  • The GIOP version, byte order and message size, in lines 10-12

Service context information

Following the introductory message 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 the OMG, while other service contexts are proprietary and specified by each vendor. IBM-specific service contexts are identified with ID's which begin with 0x4942.

Lines 14-33 in Sample Log Entry - GIOP Request and Sample Log Entry - GIOP Reply illustrate typical service context entries. There are three service contexts in both the request and reply messages, as shown in line 14. The ID, length of data, and raw data for each service context is printed next. Lines 15-17 show an IBM-proprietary context, as indicated by the ID 0x49424D12. Lines 18-33 show two standard service contexts, identified by ID 0x6 (line 18) and 0x1 (line 31). Refer to the CORBA specification for the definition of the standardized service contexts.

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; and IBM service context 0x49424D12 is used to publish ORB PartnerVersion information in order to support release-to-release inter-operability between sending and receiving ORBs.

Request ID, response expected and reply status

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 34-35 in Sample Log Entry - GIOP Request 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.)

Lines 34-35 in Sample Log Entry - GIOP Reply show the request ID, followed by the reply status received after completing the corresponding previously sent request. Line 35 shows the status of "LOCATION_FORWARD", which indicates to the sending endpoint that the request needs to be re-issued and forwarded to a different object. The message body contains the IOR for the new object. The forwarding action is done automatically by the ORB and is transparent to the client sending the request.

Object Key

Lines 36-42 in Sample Log Entry - GIOP Request 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 43 in Sample Log Entry - GIOP Request shows the name of the operation to be executed by the target object in the receiving endpoint. In this sample the specific operation requested is named "retrieve."

Principal identifier

Lines 44-46 in Sample Log Entry - GIOP Request show the length and contents of the CORBA object known as "CORBA::Principal" used by the CORBA Security Service to identify security credential information of the sender.

Data offset

Line 47 in Sample Log Entry - GIOP Request and line 38 in Sample Log Entry - GIOP Reply show 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 50 in Sample Log Entry - GIOP Request and line 41 in Sample Log Entry - GIOP Reply 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. Not all of the message raw data has been included in the figures for brevity.

Sample ORB communications log entries

Sample Log Entry - GIOP Request

1. OUT GOING:

 

3. Request Message

4. Date: April 18, 2001 10:14:21 AM EDT

5. Thread Info: P=259545:O=0:CT

6. Local Port: 65454 (0xFFAE)

7. Local IP: wl3orb-02.austin.ibm.com/9.53.93.157

8. Remote Port: 9000 (0x2328)

9. Remote IP: wl3orb-02.austin.ibm.com/9.53.93.157

10. GIOP Version: 1.1

11. Byte order: big endian

12. Message size: 380 (0x17C)

--

14. Service Context: length = 3 (0x3)

15. Context ID: 1229081874 (0x49424D12)

16. Context data: length = 8 (0x8)

17. 00000000 000C0001

18. Context ID: 6 (0x6)

19. Context data: length = 168 (0xA8)

20. 00000000 00000028 49444C3A 6F6D672E

21. 6F72672F 53656E64 696E6743 6F6E7465

22. 78742F43 6F646542 6173653A 312E3000

23. 00000001 00000000 0000006C 00010100

24. 0000000C 392E3533 2E39332E 31353700

25. 0000FFAF 0000002C 4A4D4249 00000010

26. 42F65A47 33623030 30303030 30303030

27. 30303030 00000024 00000008 00000000

28. 00000000 00000001 00000001 00000018

29. 00000000 00010001 00000001 00010020

30. 00010100 00000000

31. Context ID: 1 (0x1)

32. Context data: length = 12 (0xC)

33. 00000000 00010001 00010100

34. Request ID: 5 (0x5)

35. Response is expected? Yes.

36. Object Key: length = 87 (0x57)

37. 4A4D4249 00000012 33C5F0DD 31303030

38. 30303030 30303030 30303030 00000024

39. 00000033 49454A50 01000D5F 5F61646D

40. 696E5365 72766572 0F747261 6E4C6F67

41. 53696D70 6C654F41 0000000B 7472616E

42. 4C6F6757 697265

43. Operation: retrieve

44. Principal: length = 32 (0x20)

45. 49424D44 3A000000 0000000C 392E3533

46. 2E39332E 31353700 00000000 00000000

47. Data Offset: 17c

 

 

50. 0000: 47494F50 01010000 0000017C 00000003 GIOP.......|....

51. 0010: 49424D12 00000008 00000000 000C0001 IBM.............

52. 0020: [remainder of message body deleted for brevity]

Sample Log Entry - GIOP Reply

IN COMING:

 

3. Reply Message

4. Date: April 18, 2001 10:14:21 AM EDT

5. Thread Info: P=259545:O=0:StandardRT=0:LocalPort=65454:RemoteHost=9.53.93.157:RemotePort=9000:

6. Local Port: 65454 (0xFFAE)

7. Local IP: wl3orb-02.austin.ibm.com/9.53.93.157

8. Remote Port: 9000 (0x2328)

9. Remote IP: wl3orb-02.austin.ibm.com/9.53.93.157

10. GIOP Version: 1.1

11. Byte order: big endian

12. Message size: 396 (0x18C)

--

14. Service Context: length = 3 (0x3)

15. Context ID: 1229081874 (0x49424D12)

16. Context data: length = 8 (0x8)

17. 00000000 000C0001

18. Context ID: 6 (0x6)

19. Context data: length = 168 (0xA8)

20. 00000000 00000028 49444C3A 6F6D672E

21. 6F72672F 53656E64 696E6743 6F6E7465

22. 78742F43 6F646542 6173653A 312E3000

23. 00000001 00000000 0000006C 00010100

24. 0000000C 392E3533 2E39332E 31353700

25. 0000FFAF 0000002C 4A4D4249 00000010

26. 42F65A47 33623030 30303030 30303030

27. 30303030 00000024 00000008 00000000

28. 00000000 00000001 00000001 00000018

29. 00000000 00010001 00000001 00010020

30. 00010100 00000000

31. Context ID: 1 (0x1)

32. Context data: length = 12 (0xC)

33. 00000000 00010001 00010100

34. Request ID: 5 (0x5)

35. Reply Status: LOCATION_FORWARD

36. Object Key: length = 1 (0x1)

37. 00

38. Data Offset: f1

 

 

41. 0000: 47494F50 01010001 0000018C 00000003 GIOP............

42. 0010: 49424D12 00000008 00000000 000C0001 IBM.............

43. 0020: [remainder of message body deleted for brevity]



Enabling ORB trace

Below, you will find instructions for enabling ORB trace in the WebSphere Administrative Server, WebSphere Application Server, administrative client (console) on Windows NT, and the administrative client (console) on UNIX.

Tracing the WebSphere Administrative Server

  1. Make sure the default server and administrative server are not running.
  2. Make a backup copy of the admin.config file.
  3. Add the following lines to the admin.config file:
    • com.ibm.CORBA.Debug=true
    • com.ibm.CORBA.CommTrace=true
    • com.ibm.ejs.sm.adminServer.traceString="ORBRas=all=enabled"
    • com.ibm.ejs.sm.adminServer.traceOutput=c\:/tracedirectory/adminserver.trace

      NOTE: On Unix the directory path would look more like /opt/tracedirectory or /usr/tracedirectory)
  4. Start the administrative server.
  5. The resulting trace file is c\:/tracedirectory/adminserver.trace.

Tracing the WebSphere Application Server (default server)

There is a check box labeled "Enable ORB Tracing" on the ORB configuration property sheet When that check box is enabled, ORB communication trace is configured for that application server. See the InfoCenter article6.6.30.1: Administering the ORB services of application servers with the Java administrative console for more information.

If there is already a traceOutput file defined for this application server, then the communication trace output is directed to that file. If there is no output file defined, the file product_installation_root/logs/<server name>.trace" is defined to contain the communication trace output.

Tracing the administrative client (console) on Windows NT

  1. Go to the product_installation_root/bin subdirectory and make a backup copy of adminclient.bat file.
  2. Edit the adminclient.bat file for the following:
    Change

    goto NODEBUG
    :DEBUG
    set DEBUGOPTS=-traceString "com.ibm.*=all=enabled"

    to

    goto NODEBUG
    :DEBUG
    set DEBUGOPTS=-traceString "com.ibm.*=all=enabled:ORBRas=all=enabled"
  3. Add the two trace parameters to the following "%JAVA_HOME%\bin\java" statement:
    • -Dcom.ibm.CORBA.Debug=true
    • -Dcom.ibm.CORBA.CommTrace=true
    The statement should be in one continuous line. Add "%DEBUGOPTS%" also to the statement if it does not already exist.

    If "%DEBUGOPTS%"=="" does exist, go to START

    %JAVA_HOME%\bin\java -Dcom.ibm.CORBA.Debug=true -Dcom.ibm.CORBA.CommTrace=true -Xminf0.15 -Xmaxf0.25 -classpath %WAS_CP% %CLIENTSAS% -Dcom.ibm.CORBA.principalName=%COMPUTERNAME%/AdminClient -Dserver.root=%WAS_HOME% com.ibm.ejs.sm.client.ui.EJSConsole %DEST% %DESTPORT% %DEBUGOPTS% %QUALIFYNAMES%

    Go to END
  4. After the administrative server has been started, using the statement "adminclient debug > adminclientttrace" from product_installation_root/bin subdirectory.
  5. The resulting trace file is adminclienttrace.

Tracing administrative client(console) from Unix

  1. Go to product_installation_root/bin subdirectory and make a backup copy of adminclient.sh.
  2. Edit the adminclient.sh for the following:

    Change

    elif [ "$1" = "debug" ]

    then DEBUGOPTS='-traceString "com.ibm.*=all=enabled" '

    to elif [ "$1" = "debug" ]

    then DEBUGOPTS='-traceString "com.ibm.*=all=enabled:ORBRas=all=enabled" '

    Add the three trace parameters to the "$JAVA_HOME/bin/java" statement. If "$DEBUGOPTS" is already in the statment, then there is no need to add it again.
    -Dcom.ibm.CORBA.Debug=true -Dcom.ibm.CORBA.CommTrace=true $DEBUGOPTS

  3. After the administrative server has been started, using the statement "adminclient.sh debug 2>&1 | tee adminclienttrace" from product_installation_root/bin subdirectory.
  4. The resulting trace file is adminclienttrace (in the bin directory).

Go to previous article: Logs and Traces Go to next article: Problem Determination Quick Reference

 

 
Go to previous article: Logs and Traces Go to next article: Problem Determination Quick Reference