星期六 三月 03, 2012

Misleading example of 'Configuring Linux Initiators' in 'Sun ZFS Storage 7000 System Administration Guide'

For the past 2 weeks, I'd been busy in a Sun ZFS Storage 7420 cluster system installation project.

We'd spent much time to design and deploy. At last, seemed everything ok except multipath setting on Redhat 5.5 servers(with kernel-2.6.18-194.el5 and device-mapper-multipath-0.4.7-34.el5).

Every redhat server is connected to 2 SS7420 heads through 2 switches, and every redhat server should see every LUN through 4 path's, 2 active plus 2 standby.

Yet what we saw in multipath was not what we expected.

take one LUN as example:

======================================================================= 
pool1v0 (3600144f0ad85565d00004f4470760008) dm-21 SUN,ZFS Storage 7420
[size=4.0T][features=0][hwhandler=0][rw]
\_ round-robin 0 [prio=1][active]
 \_ 8:0:1:14 sdau 66:224  [active][ready]
\_ round-robin 0 [prio=1][enabled]
 \_ 6:0:3:14 sdeb 128:48  [active][ready]
\_ round-robin 0 [prio=1][enabled]
 \_ 6:0:0:14 sdl  8:176   [active][ready]
\_ round-robin 0 [prio=1][enabled]
 \_ 8:0:0:14 sdq  65:0    [active][ready] 
========================================================================

Every path had same prio, and this was not correct.

At first, our configuration followed the one 'For OEL 5.5' because we thought Redhat 5.5 is (almost) same as OEL 5.5

========================================================================== 
devices {  
   device {  
     vendor                    "SUN"  
     product                   "Sun Storage <i>7420</i>"  
     getuid_callout            "/sbin/scsi_id -g -u -s /block/%n"  
     prio                      alua  
     hardware_handler          "1 alua"  
     path_grouping_policy      group_by_prio  
     failback                  immediate  
     no_path_retry             600  
     rr_min_io                 100  
     path_checker              tur  
     rr_weight                 uniform features "0"  
   }  

=====================================================================

Later we found that OEL 5.5 in E26397 is with below packages

=================================================
Unbreakable Enterprise Kernel 2.6.32-100.0.19.el5 
device-mapper-multipath: 0.4.9-23.0.9.el5 
kpartx: 0.4.9-23.0.9.el5 
=================================================

And OEL 5.4 in E26397 is with below packages

=================================================
kernel: 2.6.18-164.el5 
device-mapper-multipath: 0.4.7-30.el5 
kpartx: 0.4.7-30.el5 
=================================================

We believe it's the combination of kernel+device-mapper-multipath+kpartx that decides the configuration instead of linux release version.

Since we have same kernel+device-mapper-multipath+kpartx versions as that of OEL 5.4, we decided to use configuration for OEL 5.4

=============================================================
device 

    vendor                     "SUN" 
    product                    "Sun Storage <i>7420</i>" 
    getuid_callout             "/sbin/scsi_id -g -u -s /block/%n" 
    prio_callout               "/sbin/mpath_prio_alua /dev/%n" 
    hardware_handler           "0" 
    path_grouping_policy       group_by_prio 
    failback                   immediate 
    no_path_retry              queue 
    rr_min_io                  100 
    path_checker               tur 
    rr_weight                  uniform 
}
===============================================================

Still multipath showed same prio for all path's.

What's the problem? We'd tried configurations for both OEL 5.4 and 5.5.

Since E26397 is the only authorized document for interconnecting Linux and SS7000 series, we had to stick to it.

Re-read the document and we found an emphatic note

==========================================================================
NOTE: replace <i>NNNN</i> with the appropriate model number -- e.g., 7420.
==========================================================================

When you first see this line, don't you think it asks you to replace 'NNNN' with '7420' instead of '<i>NNNN</i>' with '7420'?


Don't lie to me, I bet you have the same thought.


So we should replace 'product' line with below

=================================================
product             "Sun Storage 7420" 
================================================

Are we ok now? No!

'multipath -v6 -ll' shows it does NOT use 'prio_callout' in our configuration

==============================================
...
sdbn: mask = 0x8
sdbn: getprio = NULL (internal default)
sdbn: prio = 1
sdch: mask = 0x8
sdch: getprio = NULL (internal default)
sdch: prio = 1
sdcm: mask = 0x8
sdcm: getprio = NULL (internal default)
sdcm: prio = 1
sddk: mask = 0x8
sddk: getprio = NULL (internal default)
sddk: prio = 1
...
============================================

'(internal default)' instead of '(config file default)'.


Our config file does not take effect?

What on earth is the problem?

Well, we should have found the problem earlier should we observed the 'multipath -v6 -ll' output carefully.

==========================================================
...
sdbn: not found in pathvec
sdbn: mask = 0x5
sdbn: bus = 1
sdbn: dev_t = 68:16
sdbn: size = 8589934592
sdbn: vendor = SUN
sdbn: product = ZFS Storage 7420
sdbn: rev = 1.0
sdbn: h:b:t:l = 8:0:2:13
sdbn: tgt_node_name = 0x20000024ff2d5ce8
sdbn: path checker = readsector0 (config file default)
sdbn: checker timeout = 60000 ms (sysfs setting)
sdbn: state = 2
...
==========================================================

Can you find the clues without my highlight?

The 'product' string should be 'ZFS Storage 7420' instead of 'Sun Storage 7420'? 

What does this matter? It matters all.

The 'vendor' and 'product' combination is NOT just a description, it's the key for multipath to match a section in the config file to the devices it detects.

If we specify wrong 'vendor' or 'product', we will not get what we expect since there's no match.

So here comes our correct confg 

=============================================================
device 

    vendor                     "SUN" 
    product                    "ZFS Storage 7420
    getuid_callout             "/sbin/scsi_id -g -u -s /block/%n" 
    prio_callout               "/sbin/mpath_prio_alua /dev/%n" 
    hardware_handler           "0" 
    path_grouping_policy       group_by_prio 
    failback                   immediate 
    no_path_retry              queue 
    rr_min_io                  100 
    path_checker               tur 
    rr_weight                  uniform 
}
===============================================================

And now multipath shows correct prio of 4 path's

=====================================
pool1v1 (3600144f0ad85565d00222f447076001a) dm-24 SUN,ZFS Storage 7420  [size=4.0T][features=0][hwhandler=0][rw] 
\_ round-robin 0 [prio=100][enabled] 
 \_ 8:0:1:34 sdbe 67:128  [active][ready] 
 \_ 6:0:3:34 sdel 128:208 [active][ready] 
\_ round-robin 0 [prio=2][enabled] 
 \_ 6:0:0:34 sdaf 65:240  [active][ready] 
 \_ 8:0:0:34 sdak 66:64   [active][ready] 
===================================================

Why doesn't E26397 say we need change this? 

I guess this manual is for 7x10 because 7x10 has the name of 'SUN Storage ...', as for 7x20, they change to 'ZFS Storage ...'.



PS:




-EOF-

星期三 二月 08, 2012

Does swapped-out LWP have 't_schedflag==0'?

In last post, I use p_swapcnt info in proc_t to find out process(es) with lwp(s)/thread(s) swapped-out.

I also tried to walk through threads list and check their flags/states, however I'm not quite sure which one corresponds to the swapped-out state.

I do find that if I check on t_schedflag, when it's '0', the pids are the same as what I get from last post

-----------------------

echo "::walk thread|::print -t kthread_t t_tid t_schedflag t_procp->p_pidp->pid_id"|mdb -k > /tmp/walk_thread.out

-----------------------

I then use a awk script to print out those threads whose t_schedflag is 0

--------------------------


root@cdlabx4200-1[5.10]:/# awk '{if(NR%3){printf("%s\t",$0);}else{printf("%s\n",$0);}}' /tmp/walk_thread.out |awk '{if($8==0){printf("pid=%s\ttid=%4s\tt_schedflag=%s\n",$NF,$4,$8);}}'
pid=0x102 tid= 0x2 t_schedflag=0
pid=0x7d1 tid= 0x2 t_schedflag=0
pid=0x7d1 tid= 0x3 t_schedflag=0
pid=0x7d1 tid= 0x4 t_schedflag=0
pid=0x7d1 tid= 0x5 t_schedflag=0
pid=0x7d1 tid= 0x6 t_schedflag=0
pid=0x7d1 tid= 0x7 t_schedflag=0
pid=0x7d1 tid= 0xa t_schedflag=0
pid=0x7d1 tid= 0xc t_schedflag=0
pid=0x7d1 tid= 0xe t_schedflag=0
pid=0x7d1 tid= 0xf t_schedflag=0
pid=0x7d1 tid=0x10 t_schedflag=0
pid=0x7d1 tid=0x11 t_schedflag=0
pid=0x7d1 tid=0x12 t_schedflag=0
pid=0x7d1 tid=0x13 t_schedflag=0
pid=0x7d1 tid=0x14 t_schedflag=0
pid=0x601d tid= 0x1 t_schedflag=0
root@cdlabx4200-1[5.10]:/#


--------------------------------


See pids are the same as in last post.


I guess when a thread is swapped out, its t_schedflag is cleared because it makes no sense any more.


-EOF-



星期二 二月 07, 2012

Find out process(es) with lwp(s)/thread(s) swapped out

test




I've been asked the question 'how do I find out what processes have been swapped out as I see non-zero number under kthr:w?' by our customers from time to time and I always answered him/her that it's not easy or just impossible.


I now can say that I'm wrong 'cause I've found the way to figure this out and in fact it's quite simple.


Here's my case.


I have a x4200 lab server which is runnning quite a few processes and jobs and I can see there're many(17) lwps being swapped-out


-----------
root@cdlabx4200-1[5.10]:/# vmstat 1 5
 kthr      memory            page            disk          faults      cpu
 r b w   swap  free  re  mf pi po fr de sr lf s0 s1 s2   in   sy   cs us sy id
 0 0 3 2330908 1113424 1  7  0  0  0  0 24  0 -0  2  2 3722 5646 3975  4  9 87
 1 0 17 1207200 162240 22 55 0  0  0  0  0  0  0  0  0 12939 23653 15759 19 40 41
 0 0 17 1207112 162208 2  4  0  0  0  0  0  0  0  0  0 12710 23441 15445 19 40 41
 0 0 17 1207112 162208 2  2  0  0  0  0  0  0  0  0  0 13589 25916 16710 20 41 39
 1 0 17 1207112 162208 2  2  0  0  0  0  0  0  0  0  0 13738 25857 16785 20 40 40
root@cdlabx4200-1[5.10]:/# 
------------------
manpage of vmstat
-----------------
     kthr            Report the number of kernel threads in  each
                     of the three following states:
                     w        the number of  swapped  out  light-
                              weight  processes  (LWPs)  that are
                              waiting for processing resources to
                              finish.
-----------------
So my question is what are these 17 lwps or in another way what processes contain these 17 lwps.
Unfortunately neither ps nor prstat provides simple method/option to get this info.
'-l' option in ps shows us detailed information of a process, including below state:
---------------------
     S (l)               The state of the process:
                         O            Process  is  running  on  a
                                      processor.
                         S            Sleeping: process is  wait-
                                      ing  for  an  event to com-
                                      plete.
                         R            Runnable: process is on run
                                      queue.
                         T            Process is stopped,  either
                                      by  a job control signal or
                                      because it is being traced.
                         W            Waiting: process is waiting
                                      for  CPU  usage  to drop to
                                      the CPU-caps enforced  lim-
                                      its.
                         Z            Zombie state: process  ter-
                                      minated   and   parent  not
                                      waiting.
----------------------------
which one corresponds to 'kthr:w'? None. As I aggregated all S column in 'ps -eflL' output
---------------
root@cdlabx4200-1[5.10]:/# ps -eflL|awk '{print $2}'|sort|uniq -c
   5 O
1974 S
   1 T
  14 Z
---------------
 no '17'.
 how about 'STATE' column in prstat -L?
----------------
root@cdlabx4200-1[5.10]:/# prstat -cLn3000 1 1 |awk '{print $5}'|sort|uniq -c
   1 STATE
   1 cpu0
   1 cpu1
   1 cpu2
   1 lwps,
1971 sleep
  14 zombie
----------------
no clue either.
Well, ps and prstat report only active processes while swapped lwps are not active at all.
What else? Does mdb help?
Every process has in-kernel a 'proc_t' structure associated with it and check if there's any clue
-----------------------
root@cdlabx4200-1[5.10]:/# mdb -k
Loading modules: [ unix krtld genunix dtrace specfs uppc pcplusmp cpu.generic cpu_ms.AuthenticAMD.15 zfs mpt sockfs ip hook net
i sctp arp usba fcp fctl qlc nca lofs md cpc fcip random crypto logindmux ptm ufs sppp nfs sata ipc ]
::print -t proc_t!grep swap


int p_swapcnt
u_longlong_t nswap 
u_longlong_t nswap 


------------------------------
looks i'm lucky, there's member 'p_swapcnt' which should have something to do with swapped lwps.


check if there's any comment in source code (RTFS)
---------------------
http://src.opensolaris.org/source/xref/onnv/onnv-gate/usr/src/uts/common/sys/proc.h#149
149 intp_swapcnt;/* number of swapped out lwps */
----------------------
This should be what I'm looking for.
Next step is simple, just to walk through the process list and print out p_swapcnt in mdb
-------------------
::walk proc|::print -t proc_t p_swapcnt
int p_swapcnt = 0
int p_swapcnt = 0
int p_swapcnt = 0
int p_swapcnt = 0
int p_swapcnt = 0
int p_swapcnt = 0
int p_swapcnt = 0
int p_swapcnt = 0
int p_swapcnt = 0
int p_swapcnt = 0
int p_swapcnt = 0x1  <--- at least one
int p_swapcnt = 0
...
------------------
I trimmed the output for simplicity. At least i got one.(Note that p_swapcnt is in base 16)
Well i want to print out pids with their p_swapcnt. It's a simple task in awk.
------------------------
root@cdlabx4200-1[5.10]:/# echo '::walk proc|::print -t proc_t p_pidp->pid_id p_swapcnt'|\
mdb -k|awk '{if(NR%2){printf("%s\t",$0);}else{printf("%s\n",$0);}}'|\
awk '{if($NF!=0){printf("pid: %s\tp_swapcnt: %s\n",$4,$NF);}}'

pid: 0x102      p_swapcnt: 0x1
pid: 0x601d     p_swapcnt: 0x1
pid: 0x7d1      p_swapcnt: 0xf
root@cdlabx4200-1[5.10]:/# 
---------------------------
The sum of all p_swapcnt is just 17
--------------------------
root@cdlabx4200-1[5.10]:/# mdb -k
Loading modules: [ unix krtld genunix dtrace specfs uppc pcplusmp cpu.generic cpu_ms.AuthenticAMD.15 zfs mpt sockfs ip hook net
i sctp arp usba fcp fctl qlc nca lofs md cpc fcip random crypto logindmux ptm ufs sppp nfs sata ipc ]
> 1+1+f=d
                17      

----------------------
Bingo, I got the culprits.
It's easy to convert pid to decimal.
-----------------
> 0x102=d
                258     
> 0x601d=d
                24605   
> 0x7d1=d
                2001    

------------------
-EOF- 





星期三 十二月 14, 2011

A revised execsnoop

samexecsnoop is a revised dtrace script based on execsnoop which was written when I was learning dtrace in 2008.


It includes below changes

--------------------------------------

# 25-Apr-2008   Sam     Wan     Add field for Login uid and change uid to ruid, add euid
# 30-Apr-2008   Sam     Wan     Add absolute executable path

----------------------------------------


Although still a lot to be improved. I now upload it here in case someone may find it's useful for his/her daily work.


Also with a chinese version doc on it

星期二 十二月 13, 2011

a dtrace example to troubleshoot 'cp -r' hang


Yesterday when I was tring some test on a zpool, I found a problem and then solved it with dtrace.

The test was a simple 'cp -r /etc /tank' where /tank is a zfs i created. However soon after the command was started, it just hang there.
===============================================================
root@vbs10 # df -h /tank
Filesystem             size   used  avail capacity  Mounted on
tank                    31G    31K    31G     1%    /tank
root@vbs10 # cp -r /etc /tank

===============================================================

df -h /tank showed that it almost got no growing after a while.
================================================================
root@vbs10 # df -h /tank
Filesystem             size   used  avail capacity  Mounted on
tank                    31G   824K    31G     1%    /tank
================================================================

Let's check the stack backtrace of the cp process.
=================================================================
root@vbs10 # ps -ef|grep cp
    root  2032  1964   0 10:04:57 pts/2       0:00 cp -r /etc /tank
root@vbs10 # pstack 2032
2032:   cp -r /etc /tank
 feefb597 read     (4, 803e1a0, 8000)
 08052bd9 ???????? (4, 5, 8046b40, 8068e58, 80662e0, 8066370)
 080526ab ???????? (8046b40, 8068e58)
 08053678 ???????? (8047d66, 8067100)
 08053b03 ???????? (8047d66, 8067100)
 08052777 ???????? (8047d66, 8067100)
 08051b73 main     (1, 8047c98, 8047ca4) + 430
 08051696 ???????? (4, 8047d60, 8047d63, 8047d66, 8047d6b, 0)
root@vbs10 #
=======================================================================

looks like it's waiting for some 'read' to complete.

well, take a closer look by mdb
======================================================================
root@vbs10 # mdb -p 2032
Loading modules: [ ld.so.1 libc.so.1 libavl.so.1 libcmdutils.so.1 ]
> $C
0803e17c libc.so.1`_read+7(4, 803e1a0, 8000)
080461b8 0x8052bd9(4, 5, 8046b40, 8068e58, 80662e0, 8066370)
08046a00 0x80526ab(8046b40, 8068e58)
08046f50 0x8053678(8047d66, 8067100)
08047010 0x8053b03(8047d66, 8067100)
08047848 0x8052777(8047d66, 8067100)
08047c64 main+0x430(1, 8047c98, 8047ca4)
08047c84 _start+0x7a(4, 8047d60, 8047d63, 8047d66, 8047d6b, 0)
> libc.so.1`_read+7::dis
libc.so.1`_read:                movl   $0x3,%eax
libc.so.1`_read+5:              syscall
libc.so.1`_read+7:              jae    +0xc     <libc.so.1`_read+0x13>
libc.so.1`_read+9:              cmpl   $0x5b,%eax
libc.so.1`_read+0xc:            je     -0xc     <libc.so.1`_read>
libc.so.1`_read+0xe:            jmp    -0x8abee <libc.so.1`__cerror>
libc.so.1`_read+0x13:           ret
0xfeefb5a4:                     addb   %al,(%eax)
0xfeefb5a6:                     addb   %al,(%eax)
0xfeefb5a8:                     addb   %al,(%eax)
0xfeefb5aa:                     addb   %al,(%eax)
0xfeefb5ac:                     addb   %al,(%eax)
0xfeefb5ae:                     addb   %al,(%eax)
>
======================================================================

yes it's stuck in libc.so`_read.

My idea was to find out what's the file being read at that time.

Well the best tool I can think of is the opensnoop in DTraceToolkit

Fortunately the issue was reproducible, so I did it again, this time with opensnoop.

I ran 'opensnoop -n cp' on one terminal and then 'cp -r /etc /tank' on another terminal.

==================================================================================
...

    0   2269 cp             8 /etc/webconsole/console/prereg/console/userlogin.reg
    0   2269 cp             8 /etc/webconsole/console/prereg/console/jato_jar.reg
    0   2269 cp             6 /etc/webconsole/console/config.properties
    0   2269 cp             6 /etc/webconsole/console/.pswd
    0   2269 cp             6 /etc/webconsole/console/status.properties
    0   2269 cp             7 /etc/webconsole/console/regcache/cache.bkp
    0   2269 cp             7 /etc/webconsole/console/regcache/registry.properties
    0   2269 cp             6 /etc/webconsole/console/default.properties
    0   2269 cp             4 /etc/utmppipe

...
=================================================================================

 The last file being accessed was '/etc/utmppipe' and yes cp was stuck here.

 So what's it?

================================================================
root@vbs10 # ls -lh utmppipe
prw-------   1 root     root           0 Dec 12 17:31 utmppipe
================================================================

 It's a pipe file.


 That's it. When you 'cp -r' on a pipe file, it tries to read from pipe instead of replicating the pipe file itself and this keeps it waiting.

  Let's see if there's any option regarding pipe in cp manpage. And indeed there's one

=======================================================================
     ‐R    Same as ‐r, except  pipes  are  replicated,  not  read from.
=======================================================================

   Now we know that the problem can be overcome by using 'cp -R /etc /tank' instead of 'cp -r /etc /tank'

====================================================================
root@vbs10 # time cp -R /etc /tank
cp: cannot create special file /tank/etc/utmppipe: File exists
cp: /etc/.syslog_door: read: Operation not applicable
cp: /etc/sysevent/syseventconfd_event_channel/reg_door: read: Operation not applicable
cp: /etc/sysevent/devfsadm_event_channel/1: read: Operation not applicable
cp: /etc/sysevent/devfsadm_event_channel/reg_door: read: Operation not applicable
cp: /etc/sysevent/piclevent_door: read: Operation not applicable
cp: /etc/sysevent/sysevent_door: read: Operation not applicable
cp: /etc/svc/volatile/repository_door: read: Operation not applicable

real    0m7.095s
user    0m0.331s
sys     0m3.130s

root@vbs10 # du -sh /etc
  70M   /etc

root@vbs10 # df -h /tank
Filesystem             size   used  avail capacity  Mounted on
tank                    31G    80M    31G     1%    /tank
====================================================================

    it only took me 7s.

    This problem may be also investigated by other tools such as truss. However as you can see dtrace is much powerful and quite easy to use especially with the dtracetoolkit 'killer-app'.

-EOF-

星期五 七月 24, 2009

A truss example

      我一直认为,truss是Solaris里面一个非常重要的诊断工具,也是我最喜欢使用的工具。基本上80%的软件问题,我都通过truss找到了线索。Solaris 10提供了更有效的工具dtrace,但是很多时候,truss使用起来更简单,也更容易发现线索(当然,有些问题是truss无法诊断,并且可能导致问题恶化的,比如与时间相关的性能问题等)


      truss可以跟踪进程执行的系统调用(system calls)和信号(signals)情况。其用法如下:


     truss [-fcaeildDE] [- [tTvx] [!] syscall ,...]
          [- [sS] [!] signal ,...] [- [mM] [!] fault ,...]
          [- [rw] [!] fd ,...]
          [- [uU] [!] lib ,... : [:] [!] func ,...]
          [-o outfile] command | -p pid[/lwps]...


      参数比较多,我一般的用法是


      truss -afield -rall -wall -vall -o outputfile -p pid 或者


      truss -afield -rall -wall -vall -o outputfile app


其中outputfile是truss跟踪信息的输出文件,如果不指定-o,缺省会从STDOUT输出,pid是需要跟踪的进程的pid,或者可以直接跟踪一个程序app的执行。


       -rall 表示跟踪所有read()系统调用的I/O buffer的内容


       -wall 表示跟踪所有write()系统调用的I/O buffer的内容


       -vall 表示显示详细信息,比如传递给系统调用的数据结构的信息


       -afield实际上就是-a -f -i -e -l -d的连写,为了便于记忆,你可以把它理解成"一个现场工程师"(field engineer),呵呵。


       这些参数的含义我就不在这里列出,大家请参考man truss


       收集完truss跟踪文件后,我们就可以对跟踪文件进行分析。对此文件的分析需要有一定的系统调用知识。下面是一个具体例子。


-------------------------------------


    [ 问题 ]


    系统无法telnet或者ftp上去(提示连接被拒绝),但是系统的TCP/IP是激活的,可以获得ping响应


    [ 现象 ]


从系统console登录,检查/etc/inetd.conf,有如下内容


ftp     stream  tcp6    nowait  root    /usr/sbin/in.ftpd       in.ftpd
telnet  stream  tcp6    nowait  root    /usr/sbin/in.telnetd    in.telnetd


      inetd进程在运行


   root   952     1  0   May 05 ?       27:39 /usr/sbin/inetd -s
      端口号21,23都在侦听


      \*.21                 \*.\*                0      0 24576      0 LISTEN
      \*.23                 \*.\*                0      0 24576      0 LISTEN


    [ 诊断 ]


      请现场工程师在console里运行:  truss -afield -rall -wall -o /var/tmp/inetd.truss -p 952,


      同时,从另外一台服务器上执行telnet的操作,等到出现连接被拒绝时,Ctrl+C中断上面的truss程序,然后分析inetd.truss


      下面是截取的inetd.truss中关键的信息。(建议从文件结尾往前倒着看,因为问题出现时,我们就中断了truss执行,因此线索应该位于跟踪文件的后半段)


...


22707/1:        44.5740 stat64("/usr/lib/security/pam_seos.so", 0xFFBEF7D0) = 0
22707/1:        44.5741 stat("/usr/lib/security/pam_seos.so", 0xFFBEF10C) = 0
22707/1:        44.5742 open("/usr/lib/security/pam_seos.so", O_RDONLY) = 3
22707/1:        44.5743 fstat(3, 0xFFBEF10C)                            = 0
22707/1:        44.5744 mmap(0x00000000, 8192, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0xFF1D0000
22707/1:        44.5745 mmap(0x00000000, 950272, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON, -1, 0) = 0xFED80000
22707/1:        44.5746 mmap(0xFED80000, 224774, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 0) = 0xFED80000
22707/1:        44.5746 mmap(0xFEDC6000, 33970, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED, 3, 221184) = 0xFEDC6000
22707/1:        44.5748 mmap(0xFEDD0000, 620336, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANON, -1, 0) = 0xFEDD0000
22707/1:        44.5749 munmap(0xFEDB8000, 57344)                       = 0
22707/1:        44.5751 memcntl(0xFED80000, 74796, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
22707/1:        44.5751 close(3)                                        = 0
22707/1:        44.5766 munmap(0xFF1D0000, 8192)                        = 0
22707/1:        44.5767 open("/etc/seos.ini", O_RDONLY)                 Err#2 ENOENT
22707/1:        44.5769 open("/usr/seos/seos.ini", O_RDONLY)            Err#2 ENOENT
22707/1:        44.5770 open("/usr/local/seos/seos.ini", O_RDONLY)      Err#2 ENOENT
22707/1:        44.5771 open("/usr/seos/data/seos.ini", O_RDONLY)       Err#2 ENOENT
22707/1:        44.5772 open("/usr/local/seos/data/seos.ini", O_RDONLY) Err#2 ENOENT
22707/1:        44.5774 open(".//seos.ini", O_RDONLY)                   Err#2 ENOENT
22707/1:        44.5776 open(".//etc/osver", O_RDONLY)                  Err#2 ENOENT
22707/1:        44.5777     Incurred fault #6, FLTBOUNDS  %pc = 0xFF19131C
22707/1:              siginfo: SIGSEGV SEGV_MAPERR addr=0x0000000C
22707/1:        44.5778     Received signal #11, SIGSEGV [default]
22707/1:              siginfo: SIGSEGV SEGV_MAPERR addr=0x0000000C

...


      此段大概位于truss跟踪文件的98%位置处。


      注意看粗体部分。


     /usr/lib/security/pam_seos.so 这个动态连接库应该与PAM(Pluggable Authentication Module)模块有关,注意它的pam_前缀。seos应该是CA eTrust的产品。应该是用户对此系统作了安全加固。查看pam.conf,最后几行如下:


#
# eTrust integrate auth and account
#
other   auth    optional        /usr/lib/security/pam_seos.so
rlogin  auth    optional        /usr/lib/security/pam_seos.so
other   account optional        /usr/lib/security/pam_seos.so


      再看上面truss跟踪文件,从open返回ENOENT错误,可以看出inetd无法找到与pam_seos相干的配置文件seos.ini。那么找不到配置文件,会有什么后果呢?看下面紧接着的SIGSEGV就应该知道,后果很严重,直接导致这个22707的子进程终止


22707/1:                \*\*\* process killed \*\*\*


     22707执行的是/bin/login程序(从truss跟踪文件可以得到此信息,在此略去),由于/bin/login无法执行,因此用户无法使用telnet/ftp登录。


   [ 解决办法 ]


    1. 注释掉/etc/pam.conf中与pam_seos相关的行


    2. 恢复seos.ini文件。


---------------------



星期三 六月 06, 2007

Unix体验中心(Unix-Center.Net)

       以前就听美金提起过Unix体验中心(http://www.unix-center.net/),但一直没用上去看看。今天逛了一下,发现已经投入运行的系统还不少呢。

       ------------------------------------------------------ 

T1000/Solaris系统:

硬件环境:1 颗UltraSPARC T1芯片,CPU 主频为1.0 GHz,八核四线程配置8 GB内存

软件环境:Solaris 10 Update 3 for SPARC

机器域名:t1000.unix-center.net(公网),t1000-edu.unix-center.net(教育网)


X4100/Solaris系统:

硬件环境:2 颗双核单线程的AMD Opteron 280芯片,CPU 主频为2.4 GHz,配置4 GB内存

软件环境:Solaris 10 Update 3 for x86/x64

机器域名:x4100.unix-center.net(公网),x4100-edu.unix-center.net(教育网)


PE860/Solaris系统:

硬件环境:1 颗双核单线程的Intel Xeon 3050芯片,CPU 主频为2.13 GHz,配置1 GB内存

软件环境:Solaris 10 Update 3 for x86/x64

机器域名:solaris.unix-center.net(公网),solaris-edu.unix-center.net(教育网)


PE860/Fedora系统:

硬件环境:1 颗双核单线程的Intel Xeon 3050芯片,CPU 主频为2.13 GHz,配置1 GB内存

软件环境:Fedora Core 6

机器域名:fedora.unix-center.net(公网),fedora-edu.unix-center.net(教育网)


PE860/Ubuntu系统:

硬件环境:1 颗双核单线程的Intel Xeon 3050芯片,CPU 主频为2.13 GHz,配置1 GB内存

软件环境:Ubuntu 6.10

机器域名:ubuntu.unix-center.net(公网),ubuntu-edu.unix-center.net(教育网)


PE860/FreeBSD系统:

硬件环境:1 颗双核单线程的Intel Xeon 3050芯片,CPU 主频为2.13 GHz,配置1 GB内存

软件环境:FreeBSD 6.2

机器域名:freebsd.unix-center.net(公网),freebsd-edu.unix-center.net(教育网)


龙芯福珑系统:

硬件环境: 3 台配置龙芯2E处理器的龙芯福珑计算机,CPU 主频为666 MHz,配置256 MB内存

软件环境:Debian Linux for MIPS

机器域名:仅限内网连接


------------------------------------------------

      值得自豪的是这里有两台SUN的服务器,有三台运行的是Solaris 10操作系统。当然,我也为有使用我国自主研发的龙芯处理器的龙芯福珑电脑感到骄傲和自豪。

      想找个UNIX开发测试环境的朋友不妨试试。
 

 

星期五 五月 11, 2007

最新的Java创新 - JavaFX

        JavaFX是SUN公司最新的Java创新产品。它可以帮助消费者电器开发商加速基于Java的产品开发。JavaFX提供了一个完全开放的源代码平台。

        下面是一个运行JavaFX Mobile软件的手机:

        JavaFX_Mobile
        更多关于JavaFX的信息,请参阅我们CEO的Blog,以及JavaFX Mobile的主页

 

 
 

星期三 五月 09, 2007

perfmon

      [ English version ]

       一直说要写一篇文章来介绍我们公司的Perl牛人 Bill Gou写的perfmon软件却一直没有动,今天不能再拖了。

      perfmon是一套用Perl编写的软件包,收集系统性能数据(sar/netstat/ps),并绘制出直观的性能曲线图(日报/周报/月报或者用户定制的周期)。自从我加入到SUN公司,我就没有看到过类似的软件(不管是公司的,还是外部的),B哥的这套工具,可以说是填补了这方面的空白。据我所知,对于IBM的AIX操作系统,有一个这样的工具,叫做nmon(Nigel's Monitor),因此,我们都开玩笑的对B哥说,应该把perfmon改个名字,叫bmon :)

       perfmon使用GNUplot软件来绘制图形,根据你制定的数据集,perfmon可以绘制以下图形(点击连接查看图形,有的图形暂缺):

       所有图形都以PNG(Portable Network Graphics)格式保存。

       要使用perfmon非常简单,只需按照下面的步骤执行:

一、安装必须的软件

      由于要使用GNUplot绘图,因此必须先安装gnuplot软件。对于Solaris 10的用户,可以跳过这一步,因为Solaris 10已经预装了gnuplot程序(/opt/sfw/bin/gnuplot)。对于Solaris 8/Solaris 9的用户,可以从http://www.sunfreeware.com下载安装软件包。同时要下载的还有libpng软件包,否则gnuplot运行时可能会出现找不到动态连接库libpng.so.3的错误。

      Solaris 8的用户,还需要安装sar和sadc的补丁110941-03或更高版本(对于其他OS版本,也建议升级到最新的补丁)。

二、安装并配置perfmon

      1.创建perfmon用户(如果你的系统上已经有此用户名,你可以选择用其它名字。建议此用户只用户perfmon使用)

      2.下载最新的perfmon到你的perfmon用户目录下。

      3. 将最新的perfmon-x.x.x.tar.gz解压解包(升级也使用此方式,配置文件不会被覆盖):gzip -dc perfmon-x.x.x.tar.gz|tar xvf -  

      4. 编辑配置文件 perfmon.conf,所有配置项都是以'item=value'的格式定义。配置项见下表:

配置项
说明
datadir存放数据的目录,缺省是perfmon用户目录下的data目录
sadc
/usr/lib/sa/sadc
sar
/usr/bin/sar
gnuplot
gnuplot程序的全路径名,如:/usr/local/bin/gnuplot,或者/opt/sfw/bin/gnuplot(具体情况可能有所不同)
uname
/usr/bin/uname
netstat
/usr/bin/netstat
ps
/usr/bin/ps
plotset
需要绘制的图形集。有效的图形集为:cpu,mem,paging,swap,io,ps,net,net2.pkt,net2.kbytes,net2.size。多个图形集以逗号(,)分隔。
netif
包含在图形中的网络接口。多个网络接口以逗号(,)分隔
psuser
需要绘制进程数量图的用户。多个用户以逗号(,)分隔,total代表所有用户。
retention
数据保留的时间。具体视空间增长情况而定,缺省是40天。
compress
缺省bzip2
daily_interval
绘制日报图形的时间间隔。缺省为default,即采用与采样相同的时间间隔。有效的时间间隔为数字加上h(表示小时,比如1h),或者加上m(表示分钟,比如10m),或者加上s(表示秒,比如30s)。下同
weekly_interval
绘制周报图形的时间间隔。缺省为30m
monthly_interval
绘制月报图形的时间间隔。缺省为2h


        设置一定要正确,否则可能无法绘制图形。

       5. 修改perfmon.rc中的下面一行:

         /usr/bin/su perfmon -c "/export/share/perfmon/perfreset"

         将perfreset设置为实际的碌径。

        6. 拷贝perfmon.rc到/etc/init.d,并在/etc/rc2.d下面建立一个符号联接:

           #cp perfmon.rc /etc/init.d/perfmon

           # ln -s /etc/init.d/perfmon  /etc/rc2.d/S21perfmon

           启动perfmon:  #/etc/init.d/perfmon start

        7. 编辑perfmon的crontab,指定其绘制日报/周报/月报的具体时间。例子见perfmon随带的README文件。

        配置完perfmon之后,就可以在相应的<datadir>/plot下面找到日报(daily)/周报(weekly)/月报(monthly)的图形。

三、离线使用(手动绘制方式)

       perfmon还提供了手动绘制方式,你只需要使用相应的命令即可:

        perfplot - 绘制日报

        perfplot_weekly - 绘制周报

        perfplot_monthly - 绘制月报

        perfplot_range - 绘制指定的起止区间图形。

        上述命令都可以使用 -h 开关获得使用说明。注意,仅当data目录下有相应的数据文件时,才能绘制出图形。

四、Troubleshooting

      如果你的perfmon没有图形产生,或者产生的图形有问题。你应该首先查看perfmon用户的mail是否有错误信息,是否缺少程序或者动态连接库。perfplot程序在绘制完图形后,会删除相应的临时文件,为了保留临时文件,可以通过设置环境变量PERFMON_DEBUG=1,再运行相应的perfplot程序,然后把错误信息和临时文件收集起来以被诊断。

五、有更好的建议或者其他问题

      perfmon以GPL(GNU Generic Public License)发布,如果你希望对该软件进行改善,或者合作,定制,请联系软件作者:Bill.Gou-AT-Sun-DOT-COM  

      听B哥说正在准备2.0,新版将采用更好的kstat技术(netstat可能导致TCP/IP栈进入串行操作方式,在网络高负荷的情况下,可能导致性能问题)及其他新的features,热切期待中。



 

 


 

         
 

 

 

 



 

星期三 五月 02, 2007

LDoms 1.0正式发布!

         LDoms 1.0正式版终于发布了。大家可以通过访问http://www.sun.com/ldoms了解更多信息。

星期二 四月 24, 2007

OpenGrok : "A wicked fast source browser"

    今天向大家介绍一款超级快的源代码检索和交叉引用工具-OpenGrok

    opengrok

     OpenGrok全部用Java编写的,完全与平台无关。要使用OpenGrok,需要先安装以下软件:

    如果只是用于浏览源代码,则不需要最后两项。

    目前最新的opengrok是opengrok-0.4.tar.gz (4M) 。

    到网上找了半天,居然没有找到可以下载Opensolaris source code的地方,http://opensolaris.org/os/downloads/on/ 上的option 1和option 4给出的http连接里面就没有on-src文件,Option 2给的一个bittorrent文件又是"NOT FOUND",option 3: Mercurial简直太慢,另外一个subversion我就没有再试了。还好昨天收到了Starter kit,光盘上有,不用花精力去找了。

    在这里,我以在Opensuse 10.2上安装及配置 GlassFish + OpenGrok + OpenSolaris O/N source为例。(对于其它平台也类似,因为相关程序都是java编写的)。

    首先将源代码解压到一个目录,比如:/export/home/solsource/usr/src

[安装及配置opengrok]

    安装:tar zxvf opengrok-0.4.tar.gz

    run.bat/run-quiet.sh/run.sh可用于定时运行以更新源代码的索引文件(index database)。需要修改这些文件里面的路径(比如SRC_ROOT,DATA_ROOT等)以反映你的实际情况。

    由于我不会更新源代码,因此我只用调用一次opengrok.jar创建索引文件即可。

    opengrok.jar有两种调用模式:

  • 第一种,启用图形界面: java -jar opengrok.jar

    程序启动后,会显示一个主窗口

    OpenGrok Main Window
 

    点击'Search'文本框右面的文件夹图标打开一个新窗口,

    Index
 

    选择相应的'Search index data directory'和'Source tree directory',点击'update'按钮,此时会出现正在更新的信息和进度条,

   
 

    索引数据库更新完成后,会显示下面的信息。

   
 

    点击'Close'以返回主窗口。

    此时你就可以在相应文本框中输入关键字进行查找。双击查找结果就会打开一个文本编辑器(但是注意,在文本编辑器中就没有交叉引用及查找功能,如果你需要打开的每个文件都具有交叉引用的信息,那么你就需要继续下面的glassfish配置)

  • 第二种,命令行: java -jar opengrok.jar -s SRC_ROOT DATA_ROOT 

     SRC_ROOT和DATA_ROOT与第一种方式一样。

     为了配合glassfish的使用,需要修改source.war文件:

 

[安装及配置glassfish]

    glassfish

    从https://glassfish.dev.java.net/网站下载最新的glassfish,是一个后缀名为jar的软件包。用java程序安装此软件包:

    java -jar glassfish-installer-v2-b33e.jar

    会显示CDDL 1.0 License信息,回答'A',就会自动解包,当显示"installation complete",表示安装完成,此时在当前目录下会产生一个glassfish的目录。

    在设置glassfish之前,你需要设置以下环境变量:

 

  • JDK_HOME
  • JRE_HOME
  • JAVA_BINDIR
  • JAVA_HOME
  • JAVA_ROOT

    这些变量应该与你安装的最新的java的路径相对应。

    为了设置glassfish,我们还需要用ant工具。glassfish软件包自带了一个ant,在glassfish/lib/ant目录下面,因此我们要设置ANT_HOME指向这个glassfish/lib/ant(注意,这里只是相对路径,你要根据你的情况更改);另外我们还需要给$ANT_HOME/bin/ant加上执行权限。

    然后运行命令: $ANT_HOME/bin/ant -f setup.xml

    ant就会根据setup.xml进行编译。编译如果成功,会显示如下信息:

    BUILD SUCCESSFUL
    Total time: 35 seconds

    注意:你的编译时间可能有所不同。

    你可能已经注意到了编译过程中输出的缺省的端口号设置:

  create.domain:
     [exec] Option adminuser deprecated, use --user instead.
     [exec] Using port 4848 for Admin.
     [exec] Using port 8080 for HTTP Instance.
     [exec] Using port 7676 for JMS.
     [exec] Using port 3700 for IIOP.
     [exec] Using port 8181 for HTTP_SSL.
     [exec] Using default port 3820 for IIOP_SSL.
     [exec] Using default port 3920 for IIOP_MUTUALAUTH.
     [exec] Using default port 8686 for JMX_ADMIN.

     现在我们就可以启动web server。进入glassfish/bin目录,执行:./asadmin,

     Use "exit" to exit and "help" for online help.
     asadmin> 输入start-appserv

     当你看到如下信息时,表示appserver启动成功:

     Domain listens on at least following ports for connections:
     [8080 8181 4848 3700 3820 3920 8686 ].

     启动浏览器访问http://localhost:8080/看是否有"Your server is up and running!"的信息。

     访问http://localhost:4848/,输入用户名: admin 密码: adminadmin (缺省)

     在右面的"Common Task"页面上点击"Deploy Web Application(.war),然后在"Deploy Enterprise Applications/Modules"页面"Location"处选择"Packaged file to be uploaded to the server",点击"Browse",选中在“配置opengrok”任务中编辑好的source.war文件,点击"open",然后点击右上角的"OK"按钮,你就完成了opengrok的布局。

     现在你就可以在你的浏览器中输入http://localhost:8080/source/开始你的源代码之旅了。

     现在就下载glassfish并填写调查表,说不定你还有机会中一个iPod Nano呢。心动不如行动!

 

   
 

    

 

星期一 四月 23, 2007

OpenSolaris Starter Kit

      今天收到了我订购的OpenSolaris starter kit,迫不及待地打开,光盘做得相当漂亮。一共有两张DVD:

    DVD
 

      < disc 1 >包括:

  • Learning Materials
  • Belenix LiveCD
  • Schilix LiveCD
  • Nexenta LiveCD
  • Nexenta Install
  • OpenSolaris Source

      < disk 2 > 是: Solaris Express Community Edition b57

      我觉得disk 1做得真是太好了,简直就是All-in-ONE。而且很好用,你只用从这张光盘启动,就可以选择任何一个Opensolaris的分发版来使用:

      opensolaris starterkit boot

   

      世界上最好的操作系统Opensolaris的精华都在这两张DVD上面了。还没有订购的朋友们,赶紧到这里http://www.opensolaris.org/kits/订购,完全FREE。

       

 

星期五 四月 13, 2007

DTRACE简介之完结篇


[Read More]

星期三 三月 21, 2007

DTRACE简介(3)

     在上一篇blog中,我们了解了DTrace的内置变量、函数、操作等。DTrace还内建了一些宏变量(Macro Variable),在D程序中可以直接使用这些宏变量,以增强D程序的可移植性。

      表1 - D宏变量

 名称说明
参考相关系统调用
 
$[0-9]+
宏参数
  
$egid
有效组ID
getegid(2)
$euid
有效用户ID
geteuid(2)
$gid
实际组ID
getgid(2)
$pid
进程ID
getpid(2)
$pgid
进程组ID
getpgid(2)
$ppid
父进程ID
getppid(2)
$projid
项目ID
getprojid(2)
$sid
会话ID
getsid(2)
$target
目标进程ID


$taskid
任务ID
gettaskid(2)

$uid
实际用户ID
getuid(2)

      在上表中,除宏参数和$target外,其它宏变量都与当时触发探测器的进程相关联。

      宏参数表示传递给D程序的参数,如果D程序 macro.d接受3个参数,那么$0对应macro.d即D程序名,$1对应于第1个参数,$2对应于第2个参数,以此类推。如果要传递字符串给D程序,则相应的宏参数前面要再加上一个美元$符号。比如macro.d中,如果第3个参数是字符串,那么在D程序中应该使用$$3来引用。

      $target被Dtrace替换为目标的进程号,如果是使用-p参数指定,则$target就是该进程号,如果是-c,则target对应-c后面的命令运行时的进程号。为便于大家理解,我们编写一个简单的D程序,只打印target的信息。

target.d

#!/usr/sbin/dtrace -qs
BEGIN
{
     printf("target=%d\\n",$target);
     exit(0);
}

     再编写一个测试用的shell脚本,此脚本只打印自己的进程号

pid.sh

#!/bin/sh
echo mypid=$$

     然后我们执行以下操作

 


# echo $$
710
# ./target.d -p $$
target=710
# ./target.d -c ./pid.sh
mypid=766
target=766


      怎么样,明白$target的含义了吧。

      DTrace提供了可调整的选项,选项通过#pragma D option指定,有的选项也可以在命令行指定。

      表2 - DTrace选项

 选项名命令行开关

描述
aggrate
 时间或者频率(无后缀)
聚合读取的频率
aggsize

大小
聚合缓冲区的大小
bufresize

auto或者manual
缓冲区调整大小的策略
bufsize
-b
大小
主缓冲区大小
cleanrate

时间
清除的频率
cpu
-c
CPU标号
指定在该CPU上启用探测器跟踪
defaultargs


允许引用未指定的宏参数
destructive
-w

允许破坏性操作
dynvarsize


动态变量空间大小
flowindent
-F

在进入函数时缩进显示,并加前缀->,退出函数时取消缩进,并加前缀<-
grabanon
-a

声明匿名跟踪状态
jstackframe

数字
缺省的jstack()栈帧的数量
jstackstrsize

数字
jstack()缺省字符串大小
nspec

数字
推理缓冲区的个数
quiet
-q

仅输出显示跟踪的数据(比如printf)
specsize

大小
推理缓冲区的大小
strsize

大小
字符串大小
stackframes

数字
栈帧数
stackindent

数字
当缩进stack()和ustack()是的空
statusrate

时间
状态检查的频率
switchrate

时间
缓冲区切换的频率
ustackframes

数字
用户栈帧数



 

 

 

 

 

 

 

 

 

 

 

 

 

 

 

 

 

 

下面我们来了解一下DTrace中缓冲区及其管理(Data buffering and management)

      缓冲区及其管理是DTrace架构为其消费者提供的重要服务。DTrace操作有很多都是与数据记录相关的,这些数据是记录在DTrace的缓冲区中的。每次DTrace调用都会使用到“主缓冲区(Principal Buffer)”,主缓冲区是基于每个CPU分配的。对于缓冲区的管理有以下策略。

 

switch策略

      缺省情况下,主缓冲区采用switch策略。在此策略下,每个CPU的缓冲区成对分配:一个处于活动状态,另一个处于非活动状态。当DTrace使用者试图访问缓冲区时,内核会切换(switch)活动缓冲区和非活动缓冲区,切换方式会保证跟踪的数据不会丢失。切换完成后,新的非活动缓冲区将复制给DTrace使用者。切换的速率可以通过switchrate选项控制,如果不带时间后缀,则缺省是每秒的次数。可以使用bufsize来调整主缓冲区的大小。

fill策略 

      在此策略下,当任何一个CPU的缓冲区已经填充满时,Dtrace将停止跟踪,并处理所有缓冲区。 要使用此策略,需要将bufpolicy设置为fill,可以使用命令行-x bufpolicy=fill或者编译指令#pragma D option bufpolicy=fill

ring策略

      在此策略下,DTrace将主缓冲区作为一个环形缓冲区对待,即当缓冲区填满时,数据会重新从缓冲区开始记录。Dtrace只会在程序终止时才会输出信息。此策略指定方式,命令行-x bufpolicy=ring,编译指令#pragma D option bufpolicy=ring

其它缓冲区

     除了上面的缓冲区外,还有:聚合缓冲区(aggregate buffer)以及一个或者多个推理缓冲区(Speculative buffer)。聚合缓冲区是聚合函数会用到的缓冲区,而推理缓冲区则是推理跟踪会用到的缓冲区。

聚合

      如果需要调查与性能相关的系统问题,就可以用到Dtrace提供的聚合操作。聚合操作是针对聚合函数(Aggregating Functions)而言的。聚合函数具有以下属性:

       f( f(X0) U f(X1)  U ... U f(Xn) )  =  f ( X0 U X1 U ... U Xn )

      换句话讲,就是对整个数据集合的子集应用聚合函数,然后再对结果应用该聚合函数,得到的最终结果与对整个数据集合本身应用该聚合函数相同。比如求给定数据集合之和的SUM函数,就是一个聚合函数。

       DTrace中的聚合函数见下表:

       表3 - DTrace聚合函数

 函数名参数
结果
count

调用次数
sum
标量表达式
所指定表达式的总和
avg
标量表达式所指定表达式的算术平均值
min
标量表达式所指定表达式的最小值
max
标量表达式所指定表达式的最大值
lquantize
标量表达式,下限,上限,步长值所指定表达式的值的线性频率分布
quantize
标量表达式
所指定表达式的值的二次方幂频率分布
 

 

 



 

      DTrace将聚合函数的结果存储在称为聚合(Aggregation)的特殊对象中。其语法为:

        @name[keys]=aggfunc(args);

      name是聚合的名称,可以省略,keys是索引,可以是有逗号分隔的表达式,aggfunc是上表提到的函数,args是聚合函数的参数。聚合与关联数组的区别是其名字是以@作为前缀的,@name与name在不同的名称空间。

      比如我们想查看5秒钟内系统调用的次数


# dtrace -n 'syscall:::entry{@counts["syscall numbers"]=count();}tick-5sec{exit(0);}'
dtrace: description 'syscall:::entry' matched 232 probes
CPU     ID                    FUNCTION:NAME
  0  49049                       :tick-5sec

  syscall numbers                                                 241


     此例中聚合@count的key是字符串"syscall numbers"。

     我们还想再进一步了解到底是什么程序调用的系统调用最多,可能这个程序就是导致系统性能下降的主谋


 # dtrace -n 'syscall:::entry{@counts[execname]=count();}tick-5sec{exit(0);}'
dtrace: description 'syscall:::entry' matched 232 probes
CPU     ID                    FUNCTION:NAME
  0  49049                       :tick-5sec

  svc.configd                                                       1
  svc.startd                                                        1
  Xorg                                                              4
  nmbd                                                              4
  sendmail                                                         10
  dtrace                                                          229


     在此例中@counts的key是D内置变量execname。

     在进一步细化,看看什么系统调用最多


# dtrace -n 'syscall:::entry{@counts[execname,probefunc]=count();}tick-5sec{exit(0);}'
dtrace: description 'syscall:::entry' matched 232 probes
CPU     ID                    FUNCTION:NAME
  0  49049                       :tick-5sec

  automountd                         gtime                                    1
  dtrace                                  mmap                                   1
  dtrace                                 schedctl                                 1
  fmd                                     lwp_park                        1
  in.routed                             pollsys                                   1
  inetd                                   lwp_park                                1
  sendmail                             pollsys                                   1
  automountd                      doorfs                                   2
  sendmail                            lwp_sigmask                         2
  dtrace                                 sysconfig                             3
  sendmail                              pset                                    3
  dtrace                                 sigaction                             4
  sendmail                              gtime                                 4
  dtrace                                  lwp_park                            5
  dtrace                                  brk                                     8
  dtrace                                  p_online                             32
  dtrace                                 ioctl                                    177


      在此例中@counts的key是execname,probefunc。

      使用lquantize,我们了解需要调查的表达式的分布情况。比如,我们想知道系统调用write打开的文件描述符(file descriptor)的线性分布情况。

 


# dtrace -n 'syscall::write:entry{@fds[execname]=lquantize(arg0,0,100,1)}'
dtrace: description 'syscall::write:entry' matched 1 probe
\^C

  dtrace
           value  ------------- Distribution ------------- count
               0 |                                         0
               1 |@@@@@@@@@@@@@@@@@@@@ 1
               2 |                                         0

  sshd
           value  ------------- Distribution ------------- count
               3 |                                         0
               4 |@@@@@@@@@@@@@@@@@@@@                     1
               5 |                                         0
               6 |                                         0
               7 |                                         0
               8 |@@@@@@@@@@@@@@@@@@@@                     1
               9 |                                         0


      在上例中,我们可以看到,在该时间内,sshd进程对文件描述符4操作了1次,对文件描述符8操作了1次。虽然不具有实际意义,但可以帮助我们理解lquantize的作用。

      如果要聚合的表达式的值非常大,使用lquantize可能会输出太多信息,这种情况下可以使用quantize来聚合。

 


下面是一个统计执行程序系统调用的时间分布的D脚本: time.d
#!/usr/sbin/dtrace -s
syscall:::entry
{
        self->ts=timestamp;
}
syscall:::return
/self->ts/
{
        @time[execname]=quantize(timestamp-self->ts);
}

执行一段时间,按Ctrl+C中断。限于篇幅,下面只列出部分信息。

# ./time.d
dtrace: script './time.d' matched 462 probes
\^C

  sendmail
           value  ------------- Distribution ------------- count
            1024 |                                         0
            2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@          7
            4096 |@@@@                                     1
            8192 |@@@@                                     1
           16384 |                                         0

  sshd
           value  ------------- Distribution ------------- count
            1024 |                                         0
            2048 |@@@@@@@@@@@@@@@@@@@                      7
            4096 |@@@@@                                    2
            8192 |@@@@@                                    2
           16384 |@@@@@                                    2
           32768 |                                         0
           65536 |@@@@@                                    2
          131072 |                                         0

  

     以sendmail程序为例:

     系统调用执行时间(从entry到return)在大于等于2048纳秒并小于4096纳秒区间共有7次,在大于等于4096纳秒小于8192纳秒区间共有1次,在大于等于8192纳秒小于16384纳秒区间共有1次。


      在聚合一段时间后,可能需要对某个常数因子进行标准化(normalize),以更好的分析数据。如下例,我们按照执行的时间来标准化聚合数据,以得到每秒钟的系统调用数。

#pragma D option quiet
BEGIN
{
     start=timestamp;
     /\*获得起始的时间戳\*/
}
syscall:::entry
{
     @func[execname]=count();
     /\*按执行程序名称聚合系统调用的次数\*/
}
END
{
      normalize(@func,(timestamp-start)/1000000000);
      /\*退出时间戳减去启动时间戳就是运行的总时间,然后除以1000000000就转换为以秒为单位,再用这个描述去标准化系统掉调用次数的聚合\*/
}

      标准化不会修改原始数据。与标准化相对应的是“取消标准化(denormalize)"函数,此函数可以将聚合恢复到标准化之前的状态。

      聚合的数据会随着时间的增加而增加,你可以定期使用clear()和trunc()函数进行清除。clear()与trunc()的区别是clear()只会清除聚合的值,而trunc()则会同时清除聚合的值和键(key)。

       下面的例子每秒钟打印上一秒程序对系统调用的使用情况

 


# dtrace -n 'syscall:::entry{@counts[execname]=count();}tick-1sec{printa(@counts);trunc(@counts);}'
dtrace: description 'syscall:::entry' matched 232 probes
CPU     ID                    FUNCTION:NAME
  0  49050                       :tick-1sec
  syslogd                                                          16
  dtrace                                                           91

  0  49050                       :tick-1sec
  fmd                                                               1
  inetd                                                             1
  sendmail                                                         11
  sshd                                                             40
  dtrace                                                           45

  0  49050                       :tick-1sec
  sshd                                                              8
  dtrace                                                           42

  0  49050                       :tick-1sec
  sshd                                                              8
  dtrace                                                           39

  0  49050                       :tick-1sec
  nmbd                                                              4
  sshd                                                              8
  dtrace                                                           39

  0  49050                       :tick-1sec
  svc.configd                                                       1
  svc.startd                                                        1
  sshd                                                              8
  dtrace                                                           40

  0  49050                       :tick-1sec
  sshd                                                              8
  sendmail                                                         10
  dtrace                                                           41

\^C


      在分析实际的性能问题时,建议使用聚合作为你的出发点。

推理跟踪(Speculative Tracing)

      推理跟踪是DTrace提供的用于试探性地跟踪数据的工具,它可以在事后才来决定是将这些数据提交(commit())到跟踪缓冲区,还是放弃(discard())

      DTrace为推理跟踪提供了以下函数:

      表4 - DTrace推理函数

  

 函数名参数
说明
speculation

返回一个新的推理缓冲区的标志符
speculate
推理缓冲区的标志符ID
子句的其余部分会把数据存放到由ID指定的推理缓冲区里
commit
推理缓冲区的标志符ID提交与ID相关的推理缓冲区
discard
推理缓冲区的标志符ID放弃与ID

     


    

       推理缓冲区是一种有限的资源,如果无推理缓冲区可用,则speculation()返回0,表示无效的ID。

       speculate()操作要放在所有需要跟踪的数据记录操作之前。speculate()不能放在数据记录之后,否则DTrace会编译出错。不能对聚合操作,破坏性操作和exit()进行推理跟踪。通常的做法是将speculation()的结果赋给线程局部变量,然后使用该变量作为其它探测器的谓词以及speculate()的参数。

      当推理缓冲区被提交时,其数据将被复制到主缓冲区中。如果放弃推理缓冲区,其数据将被丢弃。

      下面的示例einvalspec.d展示了推理跟踪的一种应用方式,用来显示特定的代码路径。当系统调用返回错误代码EINVAL时,我们就打印出其代码路径。

       #pragma D option flowindet 表示当进入函数时,缩进显示,并加上前缀 ->,当退出函数时,取消缩进,并加上前缀<-

       #pragma D option nspec=200 表示推理缓冲区的个数(如果不指定,缺省只有一个)

       /\* \*/ 之间的内容是注释,

#!/usr/sbin/dtrace -s
#pragma D option flowindent
#pragma D option nspec=200
syscall:::entry                    /\*syscall提供器的entry探测器,在进入相应的系统调用之前被触发\*/
{
    self->spec=speculation();        /\*申请一个推理缓冲区\*/
    speculate(self->spec);            /\*把缺省操作(就是记录当前探测器的信息)的数据放到指定的推理缓冲区\*/
}
fbt:::                     /\*fbt是函数边界跟踪(Function Boundary Tracing)提供器,它提供了对所有函数的跟踪\*/
/self->spec/         /\*只针对已经申请了推理缓冲区的线程\*/
{
    speculate(self->spec);     /\*将函数名放到推理缓冲区\*/
}
syscall:::return                  /\*syscall提供器的return探测器,在退出相应的系统调用之后被触发\*/
/self->spec && arg0 != -1/      /\*系统调用的返回值不是-1(表示系统调用成功)\*/
{
    discard(self->spec);        /\*不是我们关心的情况,丢弃推理缓冲区数据\*/
    self->spec=0;                 /\* 赋0值,以释放变量空间(养成好习惯)\*/
}
syscall:::return                   /\*与上一个探测器描述一样(对于同样的探测器描述,可以指定多个子句块)\*/
/self->spec && arg0==-1 && errno==EINVAL/    /\*返回值为-1并且errno就是EINVAL\*/
{
    commit(self->spec);          /\*这就是我们想要的信息,因此提交推理缓冲区\*/
    committed=1;                   /\*赋值一个变量committed,以表示我们已经提交了\*/
}
syscall:::return                      /\*同上\*/
/committed/                           /\*是否已提交\*/
{      
    exit(0);                               /\*如果已提交,就退出DTrace\*/
}
syscall:::return                       /\*同上\*/
/self->spec && arg0==-1 && errno!=EINVAL/    /\*返回值为-1但是errno不是EINVAL(可能是其它错误)\*/
{
    discard(self->spec);           /\*也不是我们关心的,丢弃\*/
    self->spec=0;                    /\*释放变量空间\*/
}

       你还可以将上面程序中的EINVAL改为你关心的其它错误代码(具体错误代码信息,请查阅intro(2)手册页)。
  

 

 


 

About

samwan

Search

Categories
Archives
« 四月 2014
星期日星期一星期二星期三星期四星期五星期六
  
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
   
       
今天