Example: response time monitoring (RTM) output

The following sections show example output from each Response Time Monitoring setting.

RTM:2

248(  6112) 10/21/2013 11:09:59  RTE D Response-Total: 0.016 -- RAD:0.016  JS:0.000 Log:0.000 Database:0.000  LoadBalancer: 0.000 (CPU 0.781) Transaction - format:wizard-wiz.prompt.patchrel.unl application:display,show.rio option:0
248(  6112) 10/21/2013 11:09:59  RTE D -Memory : D(261304) S(4011264) O(1212028) MAX(5387068) - MALLOC's Transaction(17425) Total(397602)

The debugging output includes:

  • Process ID — lists the process identification number for the transaction
  • Thread ID — lists the thread identification number for the transaction
  • Date — lists the date the transaction occurred
  • Time — lists the time the transaction occurred
  • Response -Total — lists the number of seconds taken to complete the entire transaction
  • RAD — lists the number of seconds taken for the RAD to complete the transaction
  • JS — lists the number of seconds taken for the JavaScript to complete the transaction
  • Log — lists the number of seconds taken for the log to complete the transaction
  • Database — lists the number of seconds taken for the database to complete the transaction
  • LoadBalancer — lists the number of seconds taken for the load balancer to complete the transaction
  • (CPU n) — lists the cumulative number of seconds the process used on the CPU
  • Transaction - format — lists the form displayed by the transaction
  • Application — lists the application when the transaction is completed
  • Option ID — lists the GUI option or button ID number used in this transaction
  • D — lists the memory delta from the previous transaction. This value could be positive or negative.
  • S — lists the storage (in bytes) currently allocated to this session by Service Manager. This does not include shared memory or memory that is not directly allocated by Service Manager.
  • O — lists the overhead associated with the internal memory manager.
  • MAX — lists the peak value of the storage (in bytes) allocated to this session by Service Manager.
  • MALLOC's Transaction — lists the delta number of times of Service Manager called MALLOC to allocate memory from the previous transaction
  • Total — lists the total number of times of Service Manager called MALLOC to allocate memory

RTM:3

248(   364) 10/21/2013 11:06:04  RTE D RADTRACE   2781 [ 1] display                             show.rio                  rio          CPU(    0    874 )
248(   364) 10/21/2013 11:06:04  RTE D Response-Total: 3.047 -- RAD:3.031  JS:0.000 Log:0.000 Database:0.016  LoadBalancer: 0.000 (CPU 0.874) Transaction - format:wizard-wiz.prompt.patchrel.unl application:display,show.rio option:0
248(   364) 10/21/2013 11:06:04  RTE D -Memory : D(272304) S(3343528) O(945684) MAX(4440604) - MALLOC's Transaction(18643) Total(409020)

The debugging output includes:

  • Process ID — lists the process identification number for the transaction
  • Thread ID — lists the thread identification number for the transaction
  • Date — lists the date the transaction occurred
  • Time — lists the time the transaction occurred
  • RADTRACE # — lists the cumulative elapsed time for the transaction in milliseconds
  • [ n] — lists the thread number of the process
  • RAD application — lists the RAD application used in the transaction
  • RAD panel — lists the name of the RAD panel
  • CPU ( n m ) — lists the number of milliseconds that the CPU processed the RAD panel (n) and the total number of milliseconds since the RAD trace began (m)
  • Response -Total — lists the number of seconds taken to complete the entire transaction
  • RAD — lists the number of seconds taken for the RAD to complete the transaction
  • JS — lists the number of seconds taken for the JavaScript to complete the transaction
  • Log — lists the number of seconds taken for the log to complete the transaction
  • Database — lists the number of seconds taken for the database to complete the transaction
  • LoadBalancer — lists the number of seconds taken for the load balancer to complete the transaction
  • (CPU n) — lists the cumulative number of seconds the process used on the CPU
  • Transaction - format — lists the form displayed by the transaction
  • Application — lists the application when the transaction is completed
  • Option ID — lists the GUI option or button ID number used in this transaction
  • D — lists the memory delta from the previous transaction. This value could be positive or negative.
  • S — lists the number of bytes of storage allocated by Service Manager. This does not include shared memory or memory that is not directly allocated by Service Manager.
  • O — lists the overhead associated with the internal memory manager.
  • MAX — lists the peak value of the number of bytes of storage allocated by Service Manager.
  • MALLOC's Transaction — lists the delta number of times of Service Manager called MALLOC to allocate memory from the previous transaction
  • Total — lists the total number of times of Service Manager called MALLOC to allocate memory

RTM:4

3688(  5512) 10/21/2013 17:21:25  RTE D RADTRACE    219 [ 1] display                             show.rio                  rio          CPU(    0   3108 )
3688(  5512) 10/21/2013 17:21:25  RTE D Response-Total: 0.328 -- RAD:0.187  JS:0.000 Log:0.125 Database:0.141  LoadBalancer: 0.000 (CPU 3.155) Transaction - format:wizard-wiz.prompt.patchrel.unl application:display,show.rio option:0
3688(  5512) 10/21/2013 17:21:25  RTE D -Memory : D(272624) S(3341592) O(943524) MAX(4440604) - MALLOC's Transaction(54547) Total(879376)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 88   calls made to ';' (1)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 252  calls made to '=' (2)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 7    calls made to ' or ' (3)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 38   calls made to ' and ' (4)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 16   calls made to 'not ' (5)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 1    calls made to '<=' (7)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 47   calls made to '=' (8)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 17   calls made to '~=' (9)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 10   calls made to '>' (11)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 72   calls made to '+' (12)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 61   calls made to 'if ' (19)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 2    calls made to 'if ' (20)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 8    calls made to 'for ' (22)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 834  calls made to ' in ' (23)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 32   calls made to 'decision' (28)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 29   calls made to 'process' (42)
3688  5512) 10/21/2013 17:21:25  RTE D ... 1    calls made to 'rio' (48)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 5    calls made to 'select' (50)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 23   calls made to 'str' (51)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 6    calls made to 'userdefn' (53)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 9    calls made to 'lng' (54)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 14   calls made to 'filename' (55)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 1    calls made to 'operator' (56)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 11   calls made to 'rinit' (58)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 17   calls made to 'currec' (59)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 11   calls made to '#' (60)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 1    calls made to 'val' (72)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 1    calls made to 'index' (78)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 29   calls made to 'null' (88)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 7    calls made to 'denull' (113)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 1    calls made to 'contents' (117)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 1    calls made to 'loop' (119)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 17   calls made to 'parse' (122)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 39   calls made to 'evaluate' (123)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 12   calls made to 'type' (124)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 67   calls made to 'nullsub' (125)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 2    calls made to 'cleanup' (127)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 8    calls made to '+=' (128)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 8    calls made to 'same' (133)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 6    calls made to 'param2' (134)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 4    calls made to 'gui' (155)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 1    calls made to 'sysinfo.get' (169)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 9    calls made to 'strrep' (188)
3688(  5512) 10/21/2013 17:21:25  RTE D ... 14   calls made to 'scmsg' (238)

The debugging output includes:

  • Process ID — lists the process identification number for the transaction
  • Thread ID — lists the thread identification number for the transaction
  • Date — lists the date the transaction occurred
  • Time — lists the time the transaction occurred
  • RADTRACE # — lists the cumulative elapsed time for the transaction in milliseconds
  • [ n] — lists the thread number of the process
  • RAD application — lists the RAD application used in the transaction
  • RAD panel — lists the name of the RAD panel
  • CPU ( n m ) — lists the number of milliseconds that the CPU processed the RAD panel (n) and the total number of milliseconds since the RAD trace began (m)
  • Response -Total — lists the number of seconds taken to complete the entire transaction
  • RAD — lists the number of seconds taken for the RAD to complete the transaction
  • JS — lists the number of seconds taken for the JavaScript to complete the transaction
  • Log — lists the number of seconds taken for the log to complete the transaction
  • Database — lists the number of seconds taken for the database to complete the transaction
  • LoadBalancer — lists the number of seconds taken for the load balancer to complete the transaction
  • (CPU n) — lists the cumulative number of seconds the process used on the CPU
  • Transaction - format — lists the form displayed by the transaction
  • Application — lists the application when the transaction is completed
  • Option ID — lists the GUI option or button ID number used in this transaction
  • D — lists the memory delta from the previous transaction. This value could be positive or negative.
  • S — lists the number of bytes of storage allocated by Service Manager. This does not include shared memory or memory that is not directly allocated by Service Manager.
  • O — lists the overhead associated with the internal memory manager.
  • MAX — lists the peak value of the S
  • MALLOC's Transaction — lists the delta number of times of Service Manager called MALLOC to allocate memory from the previous transaction
  • Total — lists the total number of times of Service Manager called MALLOC to allocate memory
  • # of calls made to ‘x’ — lists the number of times Service Manager called the function, panel, or operator x from the last format response to this one
  • (#) — lists the function identification number for the function, panel, or operator from the last format response to this one

RTM:5

3688(  3952) 10/21/2013 17:22:45  RTE D RADTRACE    203 [ 1] display                             show.rio                  rio          CPU(    0   2827 )
3688(  3952) 10/21/2013 17:22:45  RTE D Response-Total: 0.281 -- RAD:0.281  JS:0.000 Log:0.265 Database:0.000  LoadBalancer: 0.000 (CPU 2.843) Transaction - format:wizard-wiz.prompt.patchrel.unl application:display,show.rio option:0
3688(  3952) 10/21/2013 17:22:45  RTE D -Memory : D(261512) S(3330480) O(950540) MAX(4440604) - MALLOC's Transaction(54063) Total(878892)
3688(  3952) 10/21/2013 17:22:45  RTE D ... 595  calls made to ' in ' (23)
3688(  3952) 10/21/2013 17:22:45  RTE D ... 1    calls made to 'rio' (48)
3688(  3952) 10/21/2013 17:22:45  RTE D ... 1    calls made to 'evaluate' (123)
3688(  3952) 10/21/2013 17:22:45  RTE D ... 2    calls made to 'nullsub' (125)
3688(  3952) 10/21/2013 17:22:45  RTE D ... 2    calls made to 'gui' (155)

The debugging output includes:

  • Process ID — lists the process identification number for the transaction
  • Thread ID — lists the thread identification number for the transaction
  • Date — lists the date the transaction occurred
  • Time — lists the time the transaction occurred
  • RADTRACE # — lists the cumulative elapsed time for the transaction in milliseconds
  • [ n] — lists the thread number of the process
  • RAD application — lists the RAD application used in the transaction
  • RAD panel — lists the name of the RAD panel
  • CPU ( n m ) — lists the number of milliseconds that the CPU processed the RAD panel (n) and the total number of milliseconds since the RAD trace began (m)
  • Response -Total — lists the number of seconds taken to complete the entire transaction
  • RAD — lists the number of seconds taken for the RAD to complete the transaction
  • JS — lists the number of seconds taken for the JavaScript to complete the transaction
  • Log — lists the number of seconds taken for the log to complete the transaction
  • Database — lists the number of seconds taken for the database to complete the transaction
  • LoadBalancer — lists the number of seconds taken for the load balancer to complete the transaction
  • (CPU n) — lists the cumulative number of seconds the process used on the CPU
  • Transaction - format — lists the form displayed by the transaction
  • Application — lists the application when the transaction is completed
  • Option ID — lists the GUI option or button ID number used in this transaction
  • D — lists the memory delta from the previous transaction. This value could be positive or negative.
  • S — lists the number of bytes of storage allocated by Service Manager. This does not include shared memory or memory that is not directly allocated by Service Manager.
  • O — lists the overhead associated with the internal memory manager.
  • MAX — lists the peak value of the S
  • MALLOC's Transaction — lists the delta number of times of Service Manager called MALLOC to allocate memory from the previous transaction
  • Total — lists the total number of times of Service Manager called MALLOC to allocate memory
  • # of calls made to ‘x’ — lists the number of times Service Manager called the function, panel, or operator x from the last panel response to this one
  • (#) — lists the function identification number for the function, panel, or operator from the last panel response to this one

Related topics

Debugging parameters