Skip to end of metadata
Go to start of metadata

x_cons <database_name> show t_cnt [dw|sv|us|gc|<taskindex>]

Displays highly-detailed measurement values for individual database tasks. In this way, you can monitor the database activity of an application while it remains connected to a database task. Furthermore, with "x_cons <database_name> time enable", you can activate precise time measurement of the different database states. Depending on the operating system, this time measurement costs a 1% to 5% drop in performance.

------- T1    (   7)              TIMEOUT          ( pid = ?          ) -------
 dispatcher_cnt: 56662                                 command_cnt   : 0
 exclusive_cnt : 14403018   self_susp_chk : 12589094   self_susp_cnt : 3071
 self_susp_nice: 0
 resume count 0  total 6          History [ T555 T555 T555 T555 T555 ]
 dev_write_io  : 88         rel_dev_wr_tm : 0.0001     abs_dev_wr_tm : 0.0001
 dev_write_pg  : 5477                                  pages_per_io  : 62.2
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T2    (   2)              LOGWRITER        ( pid = ?          ) -------
 dispatcher_cnt: 4368078                               command_cnt   : 0
 exclusive_cnt : 2154041    self_susp_chk : 2154036    self_susp_cnt : 0
 self_susp_nice: 0
 resume count -1 total 995281     History [ T164 T401 T401 T158 T401 ]
 self_write_io : 1087148    self_write_pg : 1167810    avg_self_wr_tm: 0.0027
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T3    (   1)              TRACEWRITER      ( pid = ?          ) -------
 dispatcher_cnt: 3                                     command_cnt   : 0
 exclusive_cnt : 1          self_susp_chk : 2          self_susp_cnt : 0
 self_susp_nice: 0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T4    (   3)              UTILITY          ( pid = ?          ) -------
 dispatcher_cnt: 2                                     command_cnt   : 0
 exclusive_cnt : 2          self_susp_chk : 3          self_susp_cnt : 0
 self_susp_nice: 0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T5    (   8)              IDLE             ( pid = ?          ) -------
 dispatcher_cnt: 2                                     command_cnt   : 0
 exclusive_cnt : 0          self_susp_chk : 0          self_susp_cnt : 0
 self_susp_nice: 0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

:
------- T13   (   7)              PAGER            ( pid = ?          ) -------
 dispatcher_cnt: 106078                                command_cnt   : 0
 exclusive_cnt : 343009     self_susp_chk : 343006     self_susp_cnt : 0
 self_susp_nice: 0
 resume count -1 total 1232       History [ T554 T554 T554 T554 T554 ]
 dev_read_io   : 1279       rel_dev_rd_tm : 0.0049     abs_dev_rd_tm : 0.0075
 dev_read_pg   : 1279                                  pages_per_io  : 1.0
 dev_write_io  : 89322      rel_dev_wr_tm : 0.0148     abs_dev_wr_tm : 0.0150
 dev_write_pg  : 89331                                 pages_per_io  : 1.0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T14   (   7)              PAGER            ( pid = ?          ) -------
 dispatcher_cnt: 76293                                 command_cnt   : 0
 exclusive_cnt : 269952     self_susp_chk : 269943     self_susp_cnt : 0
 self_susp_nice: 0
 resume count -1 total 1232       History [ T554 T554 T554 T554 T554 ]
 dev_write_io  : 67006      rel_dev_wr_tm : 0.0141     abs_dev_wr_tm : 0.0143
 dev_write_pg  : 67016                                 pages_per_io  : 1.0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------
:
------- T540  (  11)              USER             ( pid = 1855       ) -------
 remote_node   : lddbagg.wdf.sap.corp                  remote_pid    : 1855
 dispatcher_cnt: 120                                   command_cnt   : 116
 exclusive_cnt : 4419       self_susp_chk : 5550       self_susp_cnt : 1
 self_susp_nice: 0
 resume count 0  total 98798      History [ T2 T2 T2 T2 T2 ]
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ...c
-------------------------------------------------------------------------------

------- T541  (   4)              SERVER           ( pid = ?          ) -------
 dispatcher_cnt: 10454585                              command_cnt   : 0
 exclusive_cnt : 170555570  self_susp_chk : 170202394  self_susp_cnt : 1698
 self_susp_nice: 112
 resume count -1 total 289875     History [ T401 T522 T163 T163 T163 ]
 dev_read_io   : 2745150    rel_dev_rd_tm : 0.0272     abs_dev_rd_tm : 0.0272
 dev_read_pg   : 2745653                               pages_per_io  : 1.0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 nice_total_cnt: 360        foreign_nice  : 202        renice_tot_cnt: 125
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------
:
------- T552  (   4)              SERVER           ( pid = ?          ) -------
 dispatcher_cnt: 402                                   command_cnt   : 0
 exclusive_cnt : 882        self_susp_chk : 857        self_susp_cnt : 0
 self_susp_nice: 0
 resume count -1 total 35         History [ T531 T527 T290 T527 T527 ]
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T553  (   4)            Data IO Completion ( pid = ?          ) -------
 dispatcher_cnt: 11342481                              command_cnt   : 0
 exclusive_cnt : 1700051    self_susp_chk : 1700048    self_susp_cnt : 0
 self_susp_nice: 0
 resume count 0  total 1          History [ T1 ]
 I/O on cport: DataCache::ReadAcknowledgement
 dev_read_io   : 1699975    rel_dev_rd_tm : 0.0119     abs_dev_rd_tm : 0.0121
 dev_read_pg   : 1700046                               pages_per_io  : 1.0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T554  (   4)         Savepoint Coordinator ( pid = ?          ) -------
 dispatcher_cnt: 18818                                 command_cnt   : 0
 exclusive_cnt : 703142     self_susp_chk : 677593     self_susp_cnt : 2
 self_susp_nice: 0
 resume count -1 total 2298       History [ T10 T24 T2 T2 T32 ]
 dev_read_io   : 408        rel_dev_rd_tm : 0.0259     abs_dev_rd_tm : 0.0259
 dev_read_pg   : 408                                   pages_per_io  : 1.0
 dev_write_io  : 14493      rel_dev_wr_tm : 0.0065     abs_dev_wr_tm : 0.0065
 dev_write_pg  : 14493                                 pages_per_io  : 1.0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T555  (   4)           Autosave Log Writer ( pid = ?          ) -------
 dispatcher_cnt: 351182                                command_cnt   : 0
 exclusive_cnt : 298591     self_susp_chk : 298591     self_susp_cnt : 0
 self_susp_nice: 0
 resume count -1 total 149054     History [ T1 T556 T556 T556 T556 ]
 asyn_write_io : 149359     rel_asyn_wr_tm: 0.0042     abs_asyn_wr_tm: 0.0042
 asyn_write_pg : 1194872                               pages_per_io  : 8.0
 dev_read_io   : 35         rel_dev_rd_tm : 0.0067     abs_dev_rd_tm : 0.0068
 dev_read_pg   : 35                                    pages_per_io  : 1.0
 dev_write_io  : 14         rel_dev_wr_tm : 0.0043     abs_dev_wr_tm : 0.0043
 dev_write_pg  : 14                                    pages_per_io  : 1.0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 7                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T556  (   4)           Autosave Log Reader ( pid = ?          ) -------
 dispatcher_cnt: 238355                                command_cnt   : 0
 exclusive_cnt : 149409     self_susp_chk : 149409     self_susp_cnt : 0
 self_susp_nice: 0
 resume count -1 total 33         History [ T555 T555 T555 T555 T555 ]
 dev_read_io   : 149340     rel_dev_rd_tm : 0.0039     abs_dev_rd_tm : 0.0039
 dev_read_pg   : 1194662                               pages_per_io  : 8.0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T557  (   4)              SERVER           ( pid = ?          ) -------
 dispatcher_cnt: 2                                     command_cnt   : 0
 exclusive_cnt : 3          self_susp_chk : 3          self_susp_cnt : 0
 self_susp_nice: 0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------
:
------- T563  (   4)  Backup / Restore Volume Task ( pid = ?          ) -------
 dispatcher_cnt: 114928                                command_cnt   : 0
 exclusive_cnt : 631825     self_susp_chk : 631825     self_susp_cnt : 0
 self_susp_nice: 0
 resume count -1 total 48805      History [ T570 T570 T570 T570 T570 ]
 asyn_read_io  : 69320      rel_asyn_rd_tm: 0.0006     abs_asyn_rd_tm: 0.0007
 asyn_read_pg  : 395000                                pages_per_io  : 5.7
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------
:
------- T570  (   4)  Backup / Restore Medium Task ( pid = ?          ) -------
 dispatcher_cnt: 393213                                command_cnt   : 0
 exclusive_cnt : 345738     self_susp_chk : 345739     self_susp_cnt : 0
 self_susp_nice: 0
 resume count 0  total 408        History [ T568 T565 T567 T564 T564 ]
 I/O on volume: /sapdb/AGG/saplog2/wt_pipe
 asyn_write_io : 345325     rel_asyn_wr_tm: 0.0024     abs_asyn_wr_tm: 0.0024
 asyn_write_pg : 2762600                               pages_per_io  : 8.0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T578  (   5)              EVENT            ( pid = 3813       ) -------
 dispatcher_cnt: 533022516                             command_cnt   : 35841
 exclusive_cnt : 1          self_susp_chk : 1          self_susp_cnt : 0
 self_susp_nice: 0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

------- T579  (   6)              GARBAGECOLLECTOR ( pid = ?          ) -------
 dispatcher_cnt: 9560                                  command_cnt   : 0
 exclusive_cnt : 511069     self_susp_chk : 509606     self_susp_cnt : 27
 self_susp_nice: 0
 resume count -1 total 4454       History [ T146 T149 T401 T158 T273 ]
 dev_read_io   : 4063       rel_dev_rd_tm : 0.0111     abs_dev_rd_tm : 0.0114
 dev_read_pg   : 4063                                  pages_per_io  : 1.0
 dev_write_io  : 106        rel_dev_wr_tm : 0.0029     abs_dev_wr_tm : 0.0029
 dev_write_pg  : 106                                   pages_per_io  : 1.0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------



------- T588  (   6)              GARBAGECOLLECTOR ( pid = ?          ) -------
 dispatcher_cnt: 6513                                  command_cnt   : 0
 exclusive_cnt : 21354      self_susp_chk : 21354      self_susp_cnt : 0
 self_susp_nice: 0
 resume count -1 total 4458       History [ T146 T149 T401 T158 T273 ]
 dev_read_io   : 2049       rel_dev_rd_tm : 0.0113     abs_dev_rd_tm : 0.0118
 dev_read_pg   : 2049                                  pages_per_io  : 1.0
 state_vwait   : 0          state_vsleep  : 0          state_vsusp   : 0
 same_ukt_coll : 0                                     time_leaps    : 0
 queue_occupied: ....
-------------------------------------------------------------------------------

back to top

  • <abs/rel>asyn<rd/wr>_tm:Absolute/Relative duration of an I/O via backup threads
  • <abs/rel>dev<rd/wr>_tm: Absolute/Relative duration of an I/O via DEV threads from the task point of view. Absolute time is the time from the request to the time in which the task will be activated again, so absolute time includes the waiting time spent inside the TaskScheduler until the task gets running Relative time is the time from request to I/O completion queue.
  • <abs/rel>_rpl_rcv_t: Rel_rpl_rcv_t is the time that was consumed between a command-reply and the next received command detected by the TaskScheduler (dispatcher). Abs_rpl_rcv_t includes the waiting time spent inside the TaskScheduler until the task gets running. It's the time after the TaskScheduler-call of the receive statement.
  • <abs/rel>_susp_time: Time spent in the suspend call
  • <abs/rel>_sleep_time: Time spent in the sleep call
  • Abs_latency_t: The time between a client-command-send(kernel semaphore post) and the moment where the kernel starts processing a new command plus the time between the kernel-command-reply (client semaphore post) and the moment where the client gets the result(semaphore wakeup). The latency values are very rough and depend on the workload because other running tasks may delay the detection and processing of new command. (new in MaxDB 7.8)
  • Avg_rcv_rpl_t: Average processing time of an SQL statement in the database kernel, time between command-receive in kernel and command-reply-call(send result)
  • Avg_vwait_time: Average wait time for an SQL lock
  • Asyn_write_io: Number of I/Os via asynchronous I/O threads ( check )
  • Asyn_write_pg: Number of pages written via asynchronous I/O
  • Avg_self_<rd/wr>_tm: Average duration of self read/write time.
  • Callback_cnt: OMS callback count (liveCache only)
  • Cl_req_recv_t: The time needed for SQL processing from the client point of view. Time between send-command and receive-result. (new in MaxDB 7.8)
  • Cl_sem_wait_t: The semaphore-wait time inside the client application. The client is waiting for the reply from the kernel. (new in MaxDB 7.8)
  • Cl_sem_post_t: The semaphore-post time from the client application. When a client sends a request, e.g. SQL statement, to the kernel, it posts a command in shared memory and tries to wake up the kernel by semaphore operation which is an OS call. This situation is the opposite of the wait situation from the kernel. For example, if the UKT sleeps, to wake up the UKT, the semaphore operation is needed. (new in MaxDB 7.8)
  • Command_cnt: Communication count between the application and the kernel
  • <dev/self>_<read/write>_io: Number of I/Os via UKT (self) or DEV threads (dev)
  • <dev/self>_<read/write>_pg: Number of pages written via UKT(self) or DEV threads(dev)
  • <dev/self>_<read/write>_tm: Duration of an I/O via UKT (self) or DEV threads (dev)
  • Dispatcher_cnt: Count of how often the task passed control to the UKT dispatcher because it could not run, its time slot had expired, or another task was prioritized.
  • Exclusive_cnt: Total number of region accesses
  • Foreign_nice: Total number of task nice calls requested by a task outside of the current task scheduler ( foreign task scheduler) (new in MaxDB 7.8)
  • From_oth_ukt: Total number of priority reset by other UKT
  • Knl_sem_post_t: The semaphore-post time from the kernel. The kernel tries to wake up a client. (new in MaxDB 7.8)
  • Latency_cnt: The count of client-command-send and client-command-reply, the total count of counted measurement. Ideally, the total number of cl_sem_wait_t, cl_sem_post_t and knl_sem_post_t should be the same. (new in MaxDB 7.8)
  • Nice_total_cnt: Total number of task nice calls to adjust priority of a task. (new in MaxDB 7.8)
  • OMS callback: OMS callback method (liveCache only)
  • Pages_per_io: Total number of pages per I/O
  • Prio_total_count: Total number of task priority changes
  • Queue_occupied: Queue location where the task schedule request is currently in. (new in MaxDB 7.8)
    • R - the task request is in the run queue
    • E - the task request is in the external request queue
    • C - the task request is in the communication queue
    • I - the task request is in the internal queue
  • Rcv_rpl_count: SQL processing count, the total count of command-receive in kernel and command-reply to the client
  • Rcv_rpl_long: Total number of SQL statements with a processing time of more than one second
  • Rel_latency_t: The time between a client-command-send(kernel semaphore post) and the moment where the kernel has noticed that there is a new command plus the time between the kernel-command-reply (client semaphore post) and the moment where the client gets the result(semaphore wakeup). (new in MaxDB 7.8)
  • Remote_node: Remote node name
  • Remote_pid: Remote node pid
  • Renice_tot_cnt: Total number of re-nice calls. If a task tries to adjust the priority of another task which is already in running or ready to run state, then the renice count is increased. (new in MaxDB 7.8)
  • Req_rcv_count: Total count of received SQL requests
  • Resume count: Total task resume count, History[ resumerTask1, resumerTask2 ] . The number followed by "resume count " has the following meaning.
    • -1: Describes a situation where a task is suspended, but has not received a resume request from another task yet.
    • 0: A task is running and has neither called suspend nor received a resume request A task is currently in suspend state, and has received a resume (wake up) request, hence it is runnable, but has not been scheduled yet.
    • 1: A task has been resumed but has not called suspend yet.
  • Rpl_rcv_count: Count of after the kernel replied to SQL command and until it enters the command-receive function. The kernel might spend a long time inside command receive function in waiting. However, rpl_rcv does not include this waiting time, it only measures the time from the reply until the kernel enters the receive function.
  • Same_ukt_coll: Total number of collisions in the same UKT
  • Self_susp_chk: When a task leaves a critical section lock like a region or a shared lock, it checks if another task inside the same task scheduler is prioritized or the reschedule threshold value, kernel parameter ExclusiveLockRescheduleThreshold, that was previously decreased comes to zero. If one of these checks becomes true, the task gives up the control to another task (yield). Self_susp_chk describes the total number of these checks. (new in MaxDB 7.8)
  • Self_susp_cnt: Total number of self suspends
  • Self_susp_nice: The value of self_susp_nice is increased when a task gives up the control (yield) because there is a prioritized task in the same scheduler. (new in MaxDB 7.8)
  • State_vsleep:Total number of sleeps
  • State_vwait: Total number of waits on SQL locks
  • State_vsusp: Total number of task suspends
  • Time_leaps: Unexpected time leap count, on some platforms, we use CPU internal registor for microsecond measurement. When a thread is moving from one CPU to another CPU, then there might be a time leap. If there exists any leap or zitter (difference in CPU time), the time value is adjusted inside the internal function used by time measurement, and it is usually a few microseconds. (new in MaxDB 7.8)

back to top

  • No labels