(german content)

Ist die CPU durch oninit-Prozesse stark belastet fällt es häufig schwer, die Ursache zu ermitteln. Dieser Artikel zeigt einige gebräuchliche Methoden auf und widmet sich vor allem der Thread-Analyse.

Oninit-Prozesse werden auch "virtuelle Prozessoren" genannt. Sie bekommen vom Betriebssystem Rechenzeit zugeteilt, und können diese wiederum nach eigenem Scheduling-Mechanismus an Threads verteilen. Ist das System durch oninit-Prozesse stark belastet, spiegelt sich das z.B. in der Ausgabe von "top" wider:

System: ISRMSHP2                                      Tue Apr 15 18:25:07 2008
Load averages: 0.37, 0.13, 0.08
140 processes: 121 sleeping, 19 running
Cpu states:
CPU   LOAD   USER   NICE    SYS   IDLE  BLOCK  SWAIT   INTR   SSYS
 0    0.52  71.1%   0.0%   1.4%  27.5%   0.0%   0.0%   0.0%   0.0%
 1    0.22  11.7%   0.0%   8.1%  80.2%   0.0%   0.0%   0.0%   0.0%
---   ----  -----  -----  -----  -----  -----  -----  -----  -----
avg   0.37  41.4%   0.0%   4.8%  53.9%   0.0%   0.0%   0.0%   0.0%

Memory: 1288572K (896788K) real, 1958356K (1380160K) virtual, 21568K free  Page# 1/6

CPU TTY PID USERNAME PRI NI   SIZE    RES STATE    TIME %WCPU  %CPU CMD
 1   ? 3544 informix 178 20 16764K  9884K sleep   16:02 43.07 43.00 oninit
 0   ? 3540 informix 178 20 16764K 10776K run      7:32 24.84 24.79 oninit
 0   ? 3545 informix 178 20 16764K  6984K sleep    0:16  1.50  1.50 oninit
 1   ? 3547 informix 178 20 16764K  6992K run      0:58  1.19  1.19 oninit
 0   ? 3549 informix 178 20 16764K  6988K sleep    0:30  1.09  1.09 oninit

An erster Stelle finden sich hier die oninit-Prozesse, aber was sie machen, weiß man noch nicht. Man benötigt einen Zusammenhang zwischen oninit-Prozess (Unix PID), CPU-VP (Informix PID), Benutzersession (SID) und Thread (TID). Welcher oninit-Prozess welchem virtuellen Prozessor entspricht, schlüsselt
onstat -g glo
auf:

IBM Informix Dynamic Server Version 10.00.HC6     -- On-Line -- Up 04:44:36 -- 458648 Kbytes

MT global info:
sessions threads  vps      lngspins
1        24       9        7

          sched calls     thread switches yield 0   yield n   yield forever
total:    2236466         1112181         1063925   637364    3364
per sec:  2               2               0         1         0

Virtual processor summary:
 class       vps       usercpu   syscpu    total
 cpu         2         1365.35   33.28     1398.63
 aio         2         22.06     66.17     88.23
 shm         1         0.31      0.72      1.03
 lio         1         1.95      14.87     16.82
 pio         1         1.80      8.33      10.13
 adm         1         2.44      4.12      6.56
 msc         1         1.42      1.01      2.43
 total       9         1395.33   128.50    1523.83

Individual virtual processors:
 vp    pid       class       usercpu   syscpu    total
 1     3540      cpu         421.77    25.20     446.97
 2     3543      adm         2.44      4.12      6.56
 3     3544      cpu         943.58    8.08      951.66
 4     3545      lio         1.95      14.87     16.82
 5     3546      pio         1.80      8.33      10.13
 6     3547      aio         15.10     42.91     58.01
 7     3548      msc         1.42      1.01      2.43
 8     3549      aio         6.96      23.26     30.22
 9     3551      shm         0.31      0.72      1.03
                 tot         1395.33   128.50    1523.83

Zum Unix-Prozess 3544 gehört ein Informix CPU-VP (vp 3).

Um herauszufinden, woran dieser gerade arbeitet, kann man einen
onstat -g act
bemühen. Er zeigt einem alle Threads mit Status "running" an:

IBM Informix Dynamic Server Version 10.00.HC6     -- On-Line -- Up 04:52:55 -- 458648 Kbytes

Running threads:
 tid     tcb      rstcb    prty status       vp-class  name
 4       e1ad6b98 0        2    running      6aio      aio vp 0
 6       e1b1ab98 0        2    running      8aio      aio vp 1
 8       e1aaa2b0 0        2    running      1cpu      soctcppoll
 9       e1aaad80 0        2    running      9shm      sm_poll
 89      e2157a70 e152deb8 2    running      3cpu      sqlexec

Es handelt sich offenbar um einen sqlexec-Thread, also einen, der eine Benutzersession bedient. Welcher Benutzer dahintersteht, zeigt ein grep im
onstat -u nach der rstcb:

onstat -u |grep e152deb8

address  flags   sid user tty wait     tout locks nreads nwrites
e152deb8 B-BPR-- 63  ifmx td  c7516550 0    43635 1016   104978

Mittels onstat -g ses lässt sich nun genaueres über diese Session herausfinden.

Dieser Ansatz funktioniert nur so lange gut, wie man im onstat -g act nicht allzu viele Threads zurückbekommt. Wird es zu unübersichtlich, kommt man mittels Abfragen gegen sie Sysmaster-DB schneller zum Ziel.

Ein anderer Ansatz ist die Thread-Analyse. Ein
onstat -g tpf
liefert einem die Thread Profile Informationen:

IBM Informix Dynamic Server Version 10.00.HC6     -- On-Line -- Up 05:01:02 -- 458648 Kbytes

Thread profiles
tid lkreqs lkw dl to lgrs isrd iswr isrw isdl isct isrb lx bfr bfw lsus lsmx seq
0   7      0   0  0  62   2    0    0    0    6    0    0  1584 15  13436 16508 0
0   0      0   0  0  0    0    0    0    0    0    0    0  0   0   0    0    0
0   0      0   0  0  0    0    0    0    0    0    0    0  0   0   0    0    0
0   0      0   0  0  0    0    0    0    0    0    0    0  0   0   0    0    0
0   0      0   0  0  0    0    0    0    0    0    0    0  0   0   0    0    0
0   0      0   0  0  0    0    0    0    0    0    0    0  0   0   0    0    0
0   0      0   0  0  0    0    0    0    0    0    0    0  0   0   0    0    0
0   0      0   0  0  0    0    0    0    0    0    0    0  0   0   0    0    0
0   0      0   0  0  0    0    0    0    0    0    0    0  0   0   0    0    0
0   0      0   0  0  0    0    0    0    0    0    0    0  0   0   0    0    0
0   7317688 0   0  0  87   0    0    0    0    29   0    0  589201 12173 0    144  0
89  5092400 0   0  0  3003281 338587 0    338532 0    0    0    1  10875434 3018336 211067100 0    1
25  0      0   0  0  0    0    0    0    0    0    0    0  18  18  0    0    0
41  0      0   0  0  0    0    0    0    0    0    0    0  0   0   0    0    0

Hier lassen sich leicht Ausreißer finden (tid 89), bei denen die Spalten isrd oder iswr extrem hohe Werte aufweisen. Die Ausgabe lässt sich entweder mit "sort" sortieren, oder bequem in eine Tabellenkalkulation wie Excel einfügen.
Hat man den Ausreißerthread identifiziert, lässt man sich einen
onstat -g ses 0
in eine Datei laufen. In dieser kann man bequem nach der tid aus dem onstat -g tpf suchen, und findet so die zugehörige SQL-Session samt dem abgesetzten Statement.