Tracing Presentation Client Requests and Messages

When the Trace parameter in the [JadeThinClient] section of the presentation client initialization file is set to all or messages, requests made to and from that presentation client are traced to the presentation client directory specified by the TraceDirectory parameter in the [JadeThinClient] section of the JADE initialization file.

In addition, when you set the TraceAppServer parameter in the [JadeThinClient] section of the JADE initialization file to true, a thin client trace file is generated on the application server for each application initiated by the user. (The TraceDirectory parameter in the [JadeAppServer] section of the JADE initialization file specifies the application server directory for requests made to and from presentation clients.)

For presentation client tracing, the TraceAppServer parameter is independent of the value of the Trace parameter. The presentation client splash screen displays Tracing is On if the TraceAppServer parameter is set to true or the Trace parameter is set to all or messages.

A separate trace file, opened for each application that is initiated, has the following format.

ThinClientTrace-<user-name>-<date>-<time>.log

Although a generated trace file on the application server contains the same information as that of a presentation client trace file, the entries in the trace file on the application server provide actual time gap information between each GUI logic statement that is called. You can therefore use them as an indication as to where performance issues might be. Comparing the file with a presentation client trace file also provides information about network performance issues.

The text Tracing is ON is displayed directly under the start-up status line on the splash screen when tracing is on.

When all requests made to and from the presentation client are traced (that is, the Trace parameter is set to all), the following trace information for each request to or from the presentation client is output to the trace file (with the default JADE directory of logs for both presentation clients and the application server).

  1. Time of the message or request.

  2. Message or request number.

    Lines of output that do not have a message number indicate that the request is buffered with the previous message. Buffered requests are traced only when the Trace parameter is set to all; that is, these requests are not output when the parameter is set to messages (which outputs only the commands that caused a message to be sent).

  3. Time (in milliseconds) since the last message or request.

  4. The name of the schema and application being initiated.

  5. Direction in which the message or request was sent, represented by paired >> and << symbols. The >> symbols indicate a message or request from the presentation client to the application server and the << symbols indicate a message or request from the application server to the presentation client.

  6. The processing depth (or stack) of the message or request (for example, #=1 or #=2).

  7. Direction of the message or request, represented by paired Send and End statements or Received and End statements.

    Send indicates a message or request from the presentation client to the application server and End indicates the completion of that request. Received indicates a message sent from the application server to the presentation client and End indicates the completion of that request. (These equate to the >> and << symbols and the << and >> symbols, respectively.)

  8. Length (measured in bytes) of the message or request; for example, (len=3521).

  9. Description (or reason) of the message or request (for example, the name of the control and the form on which it is defined followed by the . dot notation and the GUI attribute that was accessed).

When the Trace parameter is set to messages, buffered requests are not output; that is, only commands that caused a message to be sent between the presentation client and the application server are traced.

You can view the trace output file by using Notepad or a Windows editor. (The output file is cumulative; that is, records are appended to any existing records in the file.)

The following is an example of traced output to the log file when the Trace parameter was set to all.

******* Thin Client trace file (version 1) opened: 23 November 2005, 13:28:45
  legend: msg=  is message transmission number
          time= is milli-seconds since last msg
          #=    is processing depth
13:28:45 msg=1 time=310  >> #=1 Send (len=15) Check Software Version
13:28:45 msg=2 time=10   << #=1 End send (len=8)
13:28:45 msg=3 time=0    >> #=1 Send (len=3521) Sign on db
13:28:46 msg=4 time=992  <<     #=1 Received (len=10) printer.create
13:28:46 msg=5 time=0    >>     #=1 End receive (len=12)
13:28:46 msg=6 time=120  <<     #=1 Received (len=843) app.initializePart 1
13:28:46       time=0    << #=1 End send (len=8)
13:28:46 msg=7 time=0     >> #=1 Send (len=11) Run the app
13:28:47 msg=8 time=621   <<     #=1 Received (len=28149) form.create
13:28:47 msg=9 time=60    >>     #=1 End receive (len=480)
13:28:47 msg=10 time=100  <<     #=1 Received (len=10) Start-upFm.load called
13:28:47        time=0    <<     #=1 Received (len=53) external function call
13:28:47 msg=11 time=0    >>     #=1 End receive (len=44)
13:28:47 msg=12 time=100  <<     #=1 Received (len=35) write
13:28:47        time=0   <<     #=1 Received (len=11)
                           Start-upFm.mousePointer
13:28:47        time=0    <<     #=1 Received (len=899) resizetest.bubbleHelp
13:28:47        time=0    <<     #=1 Received (len=10) Start-upFm.clear
13:28:47        time=0    <<     #=1 Received (len=52)
                           progressBar1.drawSolidRectangle
13:28:47        time=0    <<     #=1 Received (len=45)
                           progressBar1.drawSolidRectangle
13:28:47        time=0    <<     #=1 Received (len=53)
                           progressBar1.drawTextIn
13:28:47        time=0    <<     #=1 Received (len=11) Start-upFm.show
13:28:47        time=0    >>     #=2 Send (len=12) Notify property change
13:28:47        time=0    >>     #=2 Send (len=15) Notify property change
13:28:47 msg=13 time=0    >>     #=1 End receive (len=8)
13:28:47 msg=14 time=0    << #=1 End send (len=8)
13:28:47        time=10   >> #=1 Send (len=21) Event:paint
13:28:47 msg=15 time=70   >> #=1 Send (len=11) Send queued requests
13:28:47 msg=16 time=0    <<     #=1 Received (len=52)
                           progressBar1.drawSolidRectangle
13:28:47        time=0    <<     #=1 Received (len=45)
                           progressBar1.drawSolidRectangle
13:28:47        time=0    <<     #=1 Received (len=53)
                           progressBar1.drawTextIn
13:28:47        time=0    << #=1 End send (len=8)
13:28:48        time=111  >> #=1 Send (len=12) Notify property change
13:28:48 msg=17 time=20   >> #=1 Send (len=11) Send queued requests
13:28:48 msg=18 time=0    << #=1 End send (len=8)
13:29:44        time=56050 >> #=1 Send (len=12) Notify property change
13:29:44        time=0    >> #=1 Send (len=15) Notify property change
13:29:44 msg=19 time=0    >> #=1 Send (len=49) Event:mouseDown
13:29:44 msg=20 time=30   << #=1 End send (len=8)
13:29:44 msg=21 time=0    >> #=1 Send (len=24) Event:gotFocus
13:29:44 msg=22 time=10   <<     #=1 Received (len=32) write
13:29:44        time=0    << #=1 End send (len=8)
13:29:44 msg=23 time=40   >> #=1 Send (len=21) Event:click
13:29:44 msg=24 time=0    << #=1 End send (len=8)
13:29:45 msg=25 time=1072 >> #=1 Send (len=28) Event:queryUnload
13:29:45 msg=26 time=0    << #=1 End send (len=12)
13:29:45 msg=27 time=0    >> #=1 Send (len=18) Event:unload
13:29:45 msg=28 time=10   << #=1 End send (len=8)
13:29:45        time=10   >> #=1 Send (len=11) Destroy window
13:29:45 msg=29 time=0    >> #=1 Send (len=11) Shutdown request
13:29:45 msg=30 time=10   << #=1 End send (len=8)
13:29:45 msg=31 time=0    >> #=1 Send (len=11) Call finalize
13:29:45 msg=32 time=0    <<     #=1 Received (len=18) printer.close
13:29:45 msg=33 time=0    >>     #=1 End receive (len=12)
13:29:45 msg=34 time=10   << #=1 End send (len=8)
13:29:45 msg=35 time=0    >> #=1 Send (len=11) Sign off db
13:29:45 msg=36 time=80   <<     #=1 Received (len=10) closeOutputWindow
13:29:45        time=10   << #=1 End send (len=8)