In Solaris, a process can be in any of the following states during the course of its execution.
O Running
S Sleeping
R Runnable (in dispatch queue)
Z Zombie
T Terminated
C* CPU
Using uptime to get quick summary statistics
-bash-3.00$ uptime
2:18pm up 119 day(s), 12:38, 56 users, load average: 1.00, 0.84, 0.81
[root@db:/] uptime
2:19pm up 194 day(s), 1:59, 16 users, load average: 16.64, 11.16, 13.32
When the competition for processor and other resources gets intense, the processes start getting increasingly delayed. We can see that on the db server, at the time of run queue being sampled, there were between 13 to 16 processes waiting to run (ready for CPU).
What processes are running?
One way to see what processes are running is to use the ps -el command. The e option displays information about every process that is currently running, while the l option specifies that the long listing format be used to display the information.
[root@db:/] ps -el | more
F S UID PID PPID C PRI NI ADDR SZ WCHAN TTY TIME CMD
1 T 0 0 0 0 0 SY ? 0 ? 0:43 sched
0 S 0 1 0 0 40 20 ? 298 ? ? 3:09 init
1 S 0 2 0 0 0 SY ? 0 ? ? 1:45 pageout
1 S 0 3 0 1 0 SY ? 0 ? ? 5522:07 fsflush
0 S 0 23152 23147 0 40 20 ? 376 ? pts/8 0:00 bash
0 S 0 8998 8975 0 39 20 ? 178 ? pts/7 0:00 more
0 S 0 23581 23579 0 40 20 ? 164 ? pts/6 0:00 sh
0 O 100 26297 26275 0 40 20 ? 961014 ? 7135:55 mysqld
In the above output:
F: historical flags
S: Process state
UID: ID of the process owner
PID: Process ID
PPID: Parent process ID
C: This is now obsolete. Historically it showed the utilization of the processor for scheduling
PRI: Process priority. In the above output the priority of the mysqld process is 40.
NI: Settings for nice
ADDR: Process address in memory
SZ: Process size. For the mysqld process, the size is 961014. SZ reports the total size of the process in virtual memory (includes all mapped file and devices).
WCHAN: The process is waiting for the resource which has this address.
TTY: What terminal is associated with this process.
TIME: How much time this process has accumulated on the CPU. We can see mysqld process has accumuated almost 7136 minutes.
CMD: The command (name of the process)
In the above output, we can also see that the fsflush process has accumulated a significant amount of time (5522:07 minutes) on the CPU.
The fsflush process flushes write buffers to disk at a predefined interval of time. Some Solaris performance tuning gurus suggest that the fsflush process shouldn't use 5 to 6 percent of the CPU. For dedicated database servers (running mysqld) like this, the fsflush can use more of the CPU, as in this case.
We can see that the fsflush process has used about 78% of the CPU time accumulated by the mysqld process, a figure that is indeed quite high.
Both the scheduler process (sched) and the fsflush process have the priority set to 0, which is the highest possible priority.
By specifying the y option in addition to e and l we can omit the F and ADDR columns and instead include an RSS column. The RSS column stands for "resident set size" of the process. One thing that is important to note is that when the y option is specified, the display units are changed to kilobytes instead of the default unit size of pages.
[root@db:/] ps -ely | more
S UID PID PPID C PRI NI RSS SZ WCHAN TTY TIME CMD
T 0 0 0 0 0 SY 0 0 ? 0:43 sched
S 0 1 0 0 40 20 440 2384 ? ? 3:09 init
S 0 2 0 0 0 SY 0 0 ? ? 1:47 pageout
S 0 3 0 1 0 SY 0 0 ? ? 5522:52 fsflush
S 0 19873 19872 0 40 20 104 2856 ? pts/12 2:41 top
S 0 7 1 0 40 20 520 9024 ? ? 29:20 svc.star
S 0 9 1 0 40 20 368 9664 ? ? 5:49 svc.conf
S 0 142 1 0 40 20 416 2320 ? ? 10:02 in.mpath
S 1 101 1 0 40 20 1688 4704 ? ? 14:15 kcfd
S 0 23202 23197 0 40 20 440 3008 ? pts/9 0:00 bash
S 0 378 1 0 40 20 288 2384 ? ? 0:07 snmpdx
S 0 100 1 0 40 20 208 2832 ? ? 0:00 devfsadm
S 0 8970 8968 0 40 20 800 1312 ? pts/7 0:00 sh
S 0 92 1 0 40 20 128 2544 ? ? 0:00 sysevent
S 0 23572 308 0 40 20 720 8584 ? ? 0:00 sshd
S 0 13895 1 0 40 20 1968 4400 ? ? 18:58 nscd
S 0 23147 23145 0 40 20 232 1312 ? pts/8 0:00 sh
S 0 91 1 0 40 20 528 4256 ? ? 34:32 picld
S 0 23152 23147 0 40 20 440 3008 ? pts/8 0:00 bash
S 0 8739 8737 0 40 20 232 1312 ? pts/4 0:00 sh
S 0 17517 17510 0 40 20 328 8272 ? ? 0:00 sshd
S 0 225 7 0 40 20 240 2016 ? ? 0:07 sac
S 0 23742 23735 0 40 20 328 8272 ? ? 0:00 sshd
S 0 309 1 0 40 20 416 8320 ? ? 5:40 fmd
S 0 236 1 0 40 20 440 1288 ? ? 1:24 utmpd
S 0 27866 7 0 40 20 208 2104 ? console 0:00 ttymon
S 0 23197 23195 0 40 20 232 1312 ? pts/9 0:00 sh
S 0 293 1 0 40 20 792 3896 ? ? 0:45 syslogd
S 0 23888 308 0 40 20 720 8584 ? ? 0:00 sshd
S 0 308 1 0 40 20 800 3936 ? ? 1:32 sshd
S 0 23581 23579 0 40 20 232 1312 ? pts/6 0:00 sh
S 100 26297 26275 3 40 20 7216696 7688112 ? ? 7241:22 mysqld
S 60001 403 1 0 40 20 344 2048 ? ? 4:07 nrpe
By dividing the SZ column for the mysqld process by 1024, we can get virtual memory usage by the mysqld process in megabytes. In the example above, the mysqld process is using 7688112 /1024 = 7151.6 MB or 89.4% of the virtual memory.
How many threads are associated with each process?
To find out how many threads are associated with the mysqld process, we can run the ps command with customized output. The output of ps can be customized by supplying the -o option. For instance, to show the number of LWPs associated, we specify nlwp after -o.
[root@db:/] ps -ef -onlwp -oargs | more
NLWP COMMAND
1 sched
1 /sbin/init -r
1 pageout
1 fsflush
1 top
11 /lib/svc/bin/svc.startd -r
13 /lib/svc/bin/svc.configd
1 /usr/lib/inet/in.mpathd -a
3 /usr/lib/crypto/kcfd
1 /usr/bin/bash
1 /usr/lib/snmp/snmpdx -y -c /etc/snmp/conf
6 devfsadmd
1 -sh
14 /usr/lib/sysevent/syseventd
1 /usr/lib/ssh/sshd
25 /usr/sbin/nscd
1 -sh
6 /usr/lib/picl/picld
1 /usr/bin/bash
1 -sh
1 /usr/lib/ssh/sshd
1 /usr/lib/saf/sac -t 300
1 /usr/lib/ssh/sshd
15 /usr/lib/fm/fmd/fmd
1 /usr/lib/utmpd
1 /usr/lib/saf/ttymon -g -d /dev/console -l console -T sun -m ldterm,ttcompat -h
1 -sh
13 /usr/sbin/syslogd
1 /usr/lib/ssh/sshd
1 /usr/lib/ssh/sshd
1 -sh
1210 /usr/local/mysql/bin/mysqld --defaults-file=/opt/db/mysql/product/production/et
We can see that mysqld process currently has 1210 threads associated to it.
Another tool to monitor performance is by using top. Unfortunately, top is not included by default on Solaris systems. The good news is that you can get it from www.sunfreeware.com.
When using top, beaware of broken top. Consider the following top output:
last pid: 9350; load avg: 20.6, 17.8, 15.4; up 194+03:23:12 15:43:04
90 processes: 89 sleeping, 1 on cpu
CPU states: 13.8% idle, 58.2% user, 28.1% kernel, 0.0% iowait, 0.0% swap
Memory: 8192M phys mem, 119M free mem, 16G swap, 11G free swap
PID USERNAME LWP PRI NICE SIZE RES STATE TIME CPU COMMAND
26297 mysql 999 59 0 7508M 7118M sleep 121.9H 316% mysqld
23646 root 1 59 0 3792K 784K sleep 15:56 0.46% top2
9350 root 1 59 0 2920K 1760K cpu 0:00 0.43% top
23664 root 1 59 0 2432K 816K sleep 7:12 0.16% iostat
23579 root 1 59 0 8272K 808K sleep 1:29 0.03% sshd
13895 root 25 59 0 4400K 1640K sleep 18:57 0.03% nscd
7 root 11 59 0 9024K 520K sleep 29:20 0.02% svc.startd
8968 root 1 59 0 8272K 1264K sleep 0:00 0.01% sshd
91 root 6 59 0 4256K 528K sleep 34:32 0.01% picld
236 root 1 59 0 1288K 440K sleep 1:23 0.01% utmpd
23638 root 1 59 0 8272K 800K sleep 0:19 0.01% sshd
410 root 1 59 0 9416K 2328K sleep 31:28 0.01% snmpd
9 root 13 59 0 9664K 368K sleep 5:48 0.00% svc.configd
309 root 15 59 0 8320K 416K sleep 5:40 0.00% fmd
101 daemon 3 59 0 4704K 1112K sleep 14:15 0.00% kcfd
Notice how top is reporting that mysqld is using 316% of CPU, something that is just not possible. On this machine when I installed a fresh copy of top, I got a totally different (and much more believable picture)
load averages: 14.62, 16.79, 15.29 15:44:27
90 processes: 88 sleeping, 2 on cpu
CPU states: 38.2% idle, 44.8% user, 17.0% kernel, 0.0% iowait, 0.0% swap
Memory: 8192M real, 124M free, 7619M swap in use, 15G swap free
PID USERNAME LWP PRI NICE SIZE RES STATE TIME CPU COMMAND
26297 mysql 999 54 0 0K 0K cpu/3 122.0H 61.40% mysqld
9356 root 1 59 0 3792K 1456K cpu/1 0:00 0.16% top2
23646 root 1 59 0 3792K 784K sleep 15:56 0.09% top2
23664 root 1 59 0 2432K 816K sleep 7:12 0.04% iostat
20766 root 1 59 0 2432K 856K sleep 4:33 0.01% iostat
23579 root 1 59 0 8272K 808K sleep 1:29 0.01% sshd
91 root 6 59 0 4256K 528K sleep 34:32 0.00% picld
7 root 11 59 0 9024K 520K sleep 29:20 0.00% svc.startd
8975 root 1 59 0 3000K 1568K sleep 0:00 0.00% bash
8968 root 1 59 0 8272K 1264K sleep 0:00 0.00% sshd
410 root 1 59 0 0K 0K sleep 31:28 0.00% snmpd
13895 root 25 59 0 4400K 1640K sleep 18:57 0.00% nscd
101 daemon 3 59 0 4704K 1112K sleep 14:15 0.00% kcfd
142 root 1 59 0 2320K 416K sleep 10:01 0.00% in.mpathd
9 root 13 59 0 9664K 368K sleep 5:48 0.00% svc.configd
Now we can see that top is reporting only 61.40% of CPU is being used by the mysqld process. In addition, top is reporting that CPU is 38.2% idle.
Another, very useful tool to monitor process status is by using prstat, which has been a part of Solaris OS since Solaris 8. prstat provides us with a report on active process statistics. Once invoked, like top, prstat continues to run until it is interrupted by the user.
PID USERNAME SIZE RSS STATE PRI NICE TIME CPU PROCESS/NLWP
26297 mysql 7508M 7140M cpu3 59 0 122:17:36 63% mysqld/1210
23646 root 3792K 784K sleep 59 0 0:15:58 0.1% top2/1
9376 root 4896K 4608K cpu0 59 0 0:00:00 0.1% prstat/1
23664 root 2432K 816K sleep 59 0 0:07:13 0.0% iostat/1
23579 root 8272K 808K sleep 59 0 0:01:29 0.0% sshd/1
20766 root 2432K 856K sleep 59 0 0:04:33 0.0% iostat/1
8968 root 8272K 1272K sleep 59 0 0:00:00 0.0% sshd/1
91 root 4256K 528K sleep 59 0 0:34:32 0.0% picld/6
13895 root 4400K 1184K sleep 59 0 0:18:57 0.0% nscd/25
7 root 9024K 520K sleep 59 0 0:29:20 0.0% svc.startd/11
23188 root 8584K 720K sleep 59 0 0:00:00 0.0% sshd/1
1457 root 1312K 232K sleep 59 0 0:00:00 0.0% sh/1
23638 root 8272K 800K sleep 59 0 0:00:19 0.0% sshd/1
23602 root 8272K 328K sleep 59 0 0:00:00 0.0% sshd/1
17524 root 3016K 432K sleep 59 0 0:00:00 0.0% bash/1
14739 root 8584K 728K sleep 59 0 0:00:00 0.0% sshd/1
22814 root 8584K 720K sleep 59 0 0:00:00 0.0% sshd/1
22828 root 3008K 440K sleep 59 0 0:00:00 0.0% bash/1
8730 root 8584K 704K sleep 59 0 0:00:00 0.0% sshd/1
1455 root 8272K 328K sleep 59 0 0:00:00 0.0% sshd/1
23138 root 8584K 720K sleep 59 0 0:00:00 0.0% sshd/1
19867 root 1312K 232K sleep 59 0 0:00:00 0.0% sh/1
17519 root 1312K 232K sleep 59 0 0:00:00 0.0% sh/1
410 root 9416K 1136K sleep 59 0 0:31:28 0.0% snmpd/1
403 nobody 2048K 344K sleep 59 0 0:04:07 0.0% nrpe/1
23581 root 1312K 232K sleep 59 0 0:00:00 0.0% sh/1
308 root 3936K 744K sleep 59 0 0:01:32 0.0% sshd/1
23888 root 8584K 720K sleep 59 0 0:00:00 0.0% sshd/1
293 root 3896K 584K sleep 59 0 0:00:44 0.0% syslogd/13
23197 root 1312K 232K sleep 59 0 0:00:00 0.0% sh/1
27866 root 2104K 208K sleep 59 0 0:00:00 0.0% ttymon/1
236 root 1288K 440K sleep 59 0 0:01:23 0.0% utmpd/1
309 root 8320K 416K sleep 59 0 0:05:40 0.0% fmd/15
23742 root 8272K 328K sleep 59 0 0:00:00 0.0% sshd/1
225 root 2016K 248K sleep 59 0 0:00:07 0.0% sac/1
17517 root 8272K 328K sleep 59 0 0:00:00 0.0% sshd/1
8739 root 1312K 232K sleep 59 0 0:00:00 0.0% sh/1
23152 root 3008K 440K sleep 59 0 0:00:00 0.0% bash/1
23147 root 1312K 232K sleep 59 0 0:00:00 0.0% sh/1
23572 root 8584K 720K sleep 59 0 0:00:00 0.0% sshd/1
92 root 2544K 128K sleep 59 0 0:00:00 0.0% syseventd/14
8970 root 1312K 760K sleep 59 0 0:00:00 0.0% sh/1
100 root 2832K 208K sleep 59 0 0:00:00 0.0% devfsadm/6
Total: 90 processes, 1396 lwps, load averages: 16.72, 17.71, 16.19
We can filter the output of prstat by specifying PIDs, UIDs, zone IDs, CPU IDs, and even processor set IDs. A list of these IDs can be separated by commas (enclosed in quotes).
By invoking prstat with the a option, we can see information about both users and processes.
prstat -a
PID USERNAME SIZE RSS STATE PRI NICE TIME CPU PROCESS/NLWP
26297 mysql 7508M 6985M cpu0 49 0 135:08:13 36% mysqld/1210
10702 root 4832K 4568K cpu2 59 0 0:00:00 0.1% prstat/1
23646 root 3792K 784K sleep 59 0 0:17:21 0.1% top2/1
23664 root 2432K 816K sleep 59 0 0:07:50 0.0% iostat/1
23579 root 8272K 816K sleep 59 0 0:01:37 0.0% sshd/1
20766 root 2432K 856K sleep 59 0 0:04:38 0.0% iostat/1
91 root 4256K 528K sleep 59 0 0:34:35 0.0% picld/6
13895 root 4400K 1408K sleep 59 0 0:19:00 0.0% nscd/25
7 root 9024K 520K sleep 59 0 0:29:23 0.0% svc.startd/11
23147 root 1312K 232K sleep 59 0 0:00:00 0.0% sh/1
23572 root 8584K 720K sleep 59 0 0:00:00 0.0% sshd/1
92 root 2544K 128K sleep 59 0 0:00:00 0.0% syseventd/14
8970 root 1312K 592K sleep 59 0 0:00:00 0.0% sh/1
100 root 2832K 208K sleep 59 0 0:00:00 0.0% devfsadm/6
378 root 2384K 288K sleep 59 0 0:00:07 0.0% snmpdx/1
NPROC USERNAME SIZE RSS MEMORY TIME CPU
1 mysql 7508M 6985M 87% 135:08:13 36%
91 root 441M 52M 0.5% 2:59:09 0.2%
1 nobody 2048K 352K 0.0% 0:04:07 0.0%
1 daemon 4704K 1680K 0.0% 0:14:17 0.0%
Total: 94 processes, 1400 lwps, load averages: 2.21, 2.62, 2.89
If you would like to see new reports below the old report, specify the c option.
To filter the prstat output to display only processes or lwps that are bound to specified processor sets, specify the "-C" option.
Similarly to get CPU specific prstat report, use the -P option.
To sort the output in descending order specify the -s option followed by one of the five following values:
- cpu (default)
- pri (priority)
- rss (resident set size)
- size (size of process image)
- time (process execution time)
Summary of total statistics can be viewed by using the -t option.
NPROC USERNAME SIZE RSS MEMORY TIME CPU
1 mysql 7508M 7036M 88% 135:58:53 38%
91 root 441M 53M 0.5% 2:59:21 0.3%
1 nobody 2048K 352K 0.0% 0:04:07 0.0%
1 daemon 4704K 1552K 0.0% 0:14:17 0.0%
Total: 94 processes, 1400 lwps, load averages: 2.22, 2.47, 2.60
See man prstat for more on the prstat command.
Todo:
Usng psrset how can we make MySQL we bind mysqld process to groups of processors, instead of having it run on a single processor?
No comments:
Post a Comment