Tuesday, May 12, 2015

A typical .gitconfig that make my life easier when working with git

This is what make my life working with git easier. alisa save thousands of keystrokes every weeks !


$cat .gitconfig
[user]
        name = Nasimuddin Ansari
        email = Nasimuddin Ansari@example.com
[push]
        default = matching
[branch]
        autosetupbase = always
        autosetuprebase = always
[color]
        ui = true
        status = auto
        branch = auto
[core]
        editor = vi
        excludesfile = ~/.gitignore

[alias]
        bd = branch -d
        l = log --graph --decorate --oneline --all -n15
        rbm = rebase master
        co = checkout
        cm = checkout master
        ss = status -s
        s = status
        b = branch -v
        a = add .
        c = commit -a
        ca = commit --amend
        d = diff
        p = pull
        dc = diff --cached
        dh = diff HEAD
        dhh = diff HEAD^
        cb = checkout -b
        r = review -v
        rn = review -n

[help]
        autocorrect = 3



Ref: https://gist.github.com/pksunkara/988716

Monday, May 4, 2015

Veritas VVR - removing a volume from VVR and deleting it from disk group

Follow below steps to remove a volume  from VVR replication and remove it from disk group.


1- Unmount filesystem using volume ( say app_vol)

2- Run below command on Primary site to delete volume from VVR

  vradmin -g app_dg -f delvol app_rvg app_vol

3- Confirm volume has been removed from VVR

 vradmin -g app_dg -l repstatus app_rvg
 vradmin printvol

4- Now remove, volume from Primary as well as secondary systems

  vxvol -g app_dg stop app_vol
 vxassist -g app_dg remove volume app_vol

5- Confirm, volume has been removed from Disk Group and space has been freed up

vxprint -v
vxdg -g app_dg -u h free

6-If you want to use freed up space in another replicated volume, follow.




Monday, April 13, 2015

Reset (unbind and bind) a HBA without rebooting Linux system

One of path of SAN LUN is in 'failed faulty running' state. I reset HBA and it has brought path in active state.


>>Below shows that one path of LUN was failed.

# multipath -ll
mpath999 (3600a0b80000b5c9c0000044d3b667c19) dm-0 STORAGE,VV
size=200G features='1 queue_if_no_path' hwhandler='0' wp=rw
`-+- policy='round-robin 0' prio=1 status=active
  |- 4:0:0:0 sdb 8:16 failed faulty running
  `- 1:0:0:0 sdc 8:32 active ready  running



>> 'fdisk -l' did not list anything on faulty path but works fine on working one.

# fdisk -l /dev/sdb <
#
# fdisk -l /dev/sdc

Disk /dev/sdc: 214.7 GB, 214748364800 bytes
255 heads, 63 sectors/track, 26108 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 16384 bytes / 16777216 bytes
Disk identifier: 0x00000000



>> 'dmsetup status' also shows path is in in F state ( 8:16 F )

# dmsetup status mpath999
0 419430400 multipath 2 0 0 0 1 1 A 0 2 0 8:16 F 1 8:32 A 0



>> Rescanning HBA, restarting multipathd and resetting - none of bring faulty path online.

# for scsi_bus in $(ls /sys/class/scsi_host/); do echo '- - -' > /sys/class/scsi_host/$scsi_bus/scan; done
# /etc/init.d/multipathd restart
# echo '1' >/sys/class/fc_host/host4/issue_lip



>> On this system, 2 FC hosts are online, hence each SAN disk should have 2 paths. Also take note of host4 device ID - 0000:21:00.1

# cd /sys/class/fc_host/
# ls -l
total 0
lrwxrwxrwx 1 root root 0 Jun 21  2014 host1 -> ../../devices/pci0000:00/0000:00:03.0/0000:05:00.0/host1/fc_host/host1
lrwxrwxrwx 1 root root 0 Jun 21  2014 host2 -> ../../devices/pci0000:00/0000:00:03.0/0000:05:00.1/host2/fc_host/host2
lrwxrwxrwx 1 root root 0 Jun 21  2014 host3 -> ../../devices/pci0000:20/0000:20:03.0/0000:21:00.0/host3/fc_host/host3
lrwxrwxrwx 1 root root 0 Jun 21  2014 host4 -> ../../devices/pci0000:20/0000:20:03.0/0000:21:00.1/host4/fc_host/host4
# cat host1/port_state
Online
# cat host?/port_state
Online
Linkdown
Linkdown
Online



>> Check what are devices connected with problematic HBA host

# ls -l /dev/disk/by-path|grep 0000:21:00.1
lrwxrwxrwx 1 root root  9 Apr 13 10:11 pci-0000:21:00.1-fc-0x22220002ac004714-lun-0 -> ../../sdb



>>Force all the paths attached to that HBA to fail, and remove all the device entries from the system

# faulty_hba=0000:21:00.1
# for d in $(ls -l /dev/disk/by-path/| grep $faulty_hba |awk -F'/' '{print $NF}') 
    echo "Dealing with $d" 
    echo "fail path $d" | multipathd -k 
    echo "del path $d" | multipathd -k 
    echo 1 > /sys/block/$d/device/delete 
done 



>> failed path should disappear from multipath

# multipath -ll
mpath999 (3600a0b80000b5c9c0000044d3b667c19) dm-0 STORAGE,VV
size=200G features='1 queue_if_no_path' hwhandler='0' wp=rw
`-+- policy='round-robin 0' prio=1 status=active
  `- 1:0:0:0 sdc 8:32 active ready  running



>> unbind (off line) problematic HBA- take note that host4 ID is 0000:21:00.1 - it will disappear from driver list.

# cd /sys/bus/pci/drivers/qla2xxx/
# ll
total 0
lrwxrwxrwx 1 root root    0 Apr 13 10:09 0000:05:00.0 -> ../../../../devices/pci0000:00/0000:00:03.0/0000:05:00.0
lrwxrwxrwx 1 root root    0 Apr 13 10:09 0000:05:00.1 -> ../../../../devices/pci0000:00/0000:00:03.0/0000:05:00.1
lrwxrwxrwx 1 root root    0 Apr 13 10:09 0000:21:00.0 -> ../../../../devices/pci0000:20/0000:20:03.0/0000:21:00.0
lrwxrwxrwx 1 root root    0 Apr 13 10:09 0000:21:00.1 -> ../../../../devices/pci0000:20/0000:20:03.0/0000:21:00.1
--w------- 1 root root 4096 Apr 13 10:09 bind
lrwxrwxrwx 1 root root    0 Apr 13 10:09 module -> ../../../../module/qla2xxx
--w------- 1 root root 4096 Apr 13 10:09 new_id
--w------- 1 root root 4096 Apr 13 10:09 remove_id
--w------- 1 root root 4096 Jun 21  2014 uevent
--w------- 1 root root 4096 Apr 13 10:09 unbind
# echo '0000:21:00.1' > unbind
# ll
total 0
lrwxrwxrwx 1 root root    0 Apr 13 10:09 0000:05:00.0 -> ../../../../devices/pci0000:00/0000:00:03.0/0000:05:00.0
lrwxrwxrwx 1 root root    0 Apr 13 10:09 0000:05:00.1 -> ../../../../devices/pci0000:00/0000:00:03.0/0000:05:00.1
lrwxrwxrwx 1 root root    0 Apr 13 10:09 0000:21:00.0 -> ../../../../devices/pci0000:20/0000:20:03.0/0000:21:00.0
--w------- 1 root root 4096 Apr 13 10:09 bind
lrwxrwxrwx 1 root root    0 Apr 13 10:09 module -> ../../../../module/qla2xxx
--w------- 1 root root 4096 Apr 13 10:09 new_id
--w------- 1 root root 4096 Apr 13 10:09 remove_id
--w------- 1 root root 4096 Jun 21  2014 uevent
--w------- 1 root root 4096 Apr 13 10:11 unbind


>> bind (on line) host4 HBA again - corresponding entry should be available

# echo '0000:21:00.1' > bind
# ll
total 0
lrwxrwxrwx 1 root root    0 Apr 13 10:09 0000:05:00.0 -> ../../../../devices/pci0000:00/0000:00:03.0/0000:05:00.0
lrwxrwxrwx 1 root root    0 Apr 13 10:09 0000:05:00.1 -> ../../../../devices/pci0000:00/0000:00:03.0/0000:05:00.1
lrwxrwxrwx 1 root root    0 Apr 13 10:09 0000:21:00.0 -> ../../../../devices/pci0000:20/0000:20:03.0/0000:21:00.0
lrwxrwxrwx 1 root root    0 Apr 13 10:11 0000:21:00.1 -> ../../../../devices/pci0000:20/0000:20:03.0/0000:21:00.1
--w------- 1 root root 4096 Apr 13 10:11 bind
lrwxrwxrwx 1 root root    0 Apr 13 10:09 module -> ../../../../module/qla2xxx
--w------- 1 root root 4096 Apr 13 10:09 new_id
--w------- 1 root root 4096 Apr 13 10:09 remove_id
--w------- 1 root root 4096 Jun 21  2014 uevent
--w------- 1 root root 4096 Apr 13 10:11 unbind



>> HBA port may come up with different name - host7 ( instead of host4)

# ll /sys/class/fc_host/
total 0
lrwxrwxrwx 1 root root 0 Jun 21  2014 host1 -> ../../devices/pci0000:00/0000:00:03.0/0000:05:00.0/host1/fc_host/host1
lrwxrwxrwx 1 root root 0 Jun 21  2014 host2 -> ../../devices/pci0000:00/0000:00:03.0/0000:05:00.1/host2/fc_host/host2
lrwxrwxrwx 1 root root 0 Jun 21  2014 host3 -> ../../devices/pci0000:20/0000:20:03.0/0000:21:00.0/host3/fc_host/host3
lrwxrwxrwx 1 root root 0 Apr 13 10:12 host7 -> ../../devices/pci0000:20/0000:20:03.0/0000:21:00.1/host7/fc_host/host7



>> And, all faulty path of LUN should be active and ready (Assuming there is no other problem of FC cables/SAN network, Storage host port etc)!
# multipath -ll
mpath999 (3600a0b80000b5c9c0000044d3b667c19) dm-0 STORAGE,VV
size=200G features='1 queue_if_no_path' hwhandler='0' wp=rw
`-+- policy='round-robin 0' prio=1 status=active
  |- 1:0:0:0 sdc 8:32 active ready running
  `- 7:0:0:0 sdb 8:16 active ready running



Reference: https://access.redhat.com/solutions/287303

Tuesday, March 31, 2015

Linux kernel - crash utility to analysis vmcore

What is crash ?


A tool to interactively analyzing the state of the crash generated by kdump, netdump, diskdump, LKCD, xendump or kvmdump


What are packages required?


yum install crash kernel-debuginfo-$(uname -r) kernel-debuginfo-common-x86_64-$(uname -r) 

How to check created kernel crash file vmcore is valid?

If below command will show date when kernel crash was created and exit - then vmcore is created.

# crash -st /usr/lib/debug/lib/modules/$(uname -r)/vmlinux vmcore
Tue Mar 10 04:02:55 2015

Is vmcore created by crash is valid?

It will take couple of minutes to load kernel and show you crash prompt if crash is valid and you are using correct debug package. It will show number of cpu, system name, memory size, time when crash was created, load of system, date when system was crashed.

# crash /usr/lib/debug/lib/modules/$(uname -r)/vmlinux vmcore
crash 5.1.8-2.el5_9
Copyright (C) 2002-2011  Red Hat, Inc.
Copyright (C) 2004, 2005, 2006  IBM Corporation
Copyright (C) 1999-2006  Hewlett-Packard Co
Copyright (C) 2005, 2006  Fujitsu Limited
Copyright (C) 2006, 2007  VA Linux Systems Japan K.K.
Copyright (C) 2005  NEC Corporation
Copyright (C) 1999, 2002, 2007  Silicon Graphics, Inc.
Copyright (C) 1999, 2000, 2001, 2002  Mission Critical Linux, Inc.
This program is free software, covered by the GNU General Public License,
and you are welcome to change it and/or distribute copies of it under
certain conditions.  Enter "help copying" to see the conditions.
This program has absolutely no warranty.  Enter "help warranty" for details.

GNU gdb (GDB) 7.0
Copyright (C) 2009 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-unknown-linux-gnu"...

      KERNEL: /usr/lib/debug/lib/modules/2.6.18-308.8.2.el5/vmlinux
    DUMPFILE: vmcore
        CPUS: 2
        DATE: Tue Mar 10 04:02:55 2015
      UPTIME: 1 days, 00:09:41
LOAD AVERAGE: 9.29, 4.35, 2.80
       TASKS: 205
    NODENAME: dev001.example.com
     RELEASE: 2.6.18-308.8.2.el5
     VERSION: #1 SMP Tue May 29 11:54:17 EDT 2012
     MACHINE: x86_64  (2699 Mhz)
      MEMORY: 3.9 GB
       PANIC: "Kernel panic - not syncing: out of memory. panic_on_oom is selected"
         PID: 3419
     COMMAND: "sshd"
        TASK: ffff81013b2e5860  [THREAD_INFO: ffff81012f594000]
         CPU: 1
       STATE: TASK_RUNNING (PANIC)

How to use crash commands ?

-log: dump lernel log_buf contents in chronological order.Most interesting information will be at the end of log file. kernel thread dump, memory dump, swap usages etc.

crash>log
.....
lowmem_reserve[]: 0 3000 4010 4010
Node 0 DMA32 free:10008kB min:6052kB low:7564kB high:9076kB active:1483204kB inactive:1420176kB present:3072160kB pages_scanned:10951420 all_unreclaimable? yes
lowmem_reserve[]: 0 0 1010 1010
Node 0 Normal free:1980kB min:2036kB low:2544kB high:3052kB active:442232kB inactive:458364kB present:1034240kB pages_scanned:1716084 all_unreclaimable? yes
lowmem_reserve[]: 0 0 0 0
Node 0 HighMem free:0kB min:128kB low:128kB high:128kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 0 0 0
Node 0 DMA: 4*4kB 3*8kB 4*16kB 1*32kB 3*64kB 4*128kB 0*256kB 0*512kB 1*1024kB 0*2048kB 2*4096kB = 10056kB
Node 0 DMA32: 0*4kB 5*8kB 1*16kB 1*32kB 1*64kB 1*128kB 4*256kB 1*512kB 0*1024kB 0*2048kB 2*4096kB = 10008kB
Node 0 Normal: 5*4kB 5*8kB 0*16kB 0*32kB 2*64kB 4*128kB 1*256kB 0*512kB 1*1024kB 0*2048kB 0*4096kB = 1980kB
Node 0 HighMem: empty
10029 pagecache pages
Swap cache: add 127866954, delete 127858677, find 188220155/188834341, race 0+1692
Free swap  = 0kB
Total swap = 2031608kB
Free swap:            0kB
1310720 pages of RAM
332619 reserved pages
20496 pages shared
8412 pages swap cached
Kernel panic - not syncing: out of memory. panic_on_oom is selected


INFO: task kjournald:602 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kjournald     D ffff810009004420     0   602     49           631   578 (L-TLB)

INFO: task nagios:20831 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
nagios        D ffff810009004420     0 20831   3763               20729 (NOTLB)



-ps : process status at time of crash. Active tasks have a preceding >

crash>ps
   PID    PPID  CPU       TASK        ST  %MEM     VSZ    RSS  COMM
      0      0   0  ffffffff80319b60  RU   0.0       0      0  [swapper]
      0      1   1  ffff8101047460c0  RU   0.0       0      0  [swapper]
      1      0   1  ffff8101047347a0  IN   0.0   10372    484  init
      2      1   0  ffff810104734040  IN   0.0       0      0  [migration/0]
  2979      1   1  ffff81013f5827a0  IN   0.0   28664    356  restorecond
>  3419      1   1  ffff81013b2e5860  RU   0.0   60808    456  sshd
   2988  19639   0  ffff810130580820  IN   0.0    5876    388  vmstat
   2990      1   1  ffff81013cb267a0  IN   0.0    5932    472  syslogd
crash>



-bt : display a kernel stack backtrace. bt -a - stack tradce of all active tasks

crash> bt
PID: 3419   TASK: ffff81013b2e5860  CPU: 1   COMMAND: "sshd"
 #0 [ffff81012f595aa0] crash_kexec at ffffffff800b099c
 #1 [ffff81012f595b60] panic at ffffffff80093989
 #2 [ffff81012f595c50] out_of_memory at ffffffff800caa5d
 #3 [ffff81012f595ca0] __alloc_pages at ffffffff8000f612
 #4 [ffff81012f595d10] read_swap_cache_async at ffffffff80032415
 #5 [ffff81012f595d50] swapin_readahead at ffffffff800d0777
 #6 [ffff81012f595da0] __handle_mm_fault at ffffffff800092d9
 #7 [ffff81012f595e60] do_page_fault at ffffffff80067202
 #8 [ffff81012f595f50] error_exit at ffffffff8005dde9
    RIP: 00002b3e2f66a25a  RSP: 00007fff86964840  RFLAGS: 00010206
    RAX: 0000000000000000  RBX: 00002b3e2f9261d8  RCX: 00002b3e2f9261d8
    RDX: 00002b3e4a2363e0  RSI: 000000000000000a  RDI: 0000000000000001
    RBP: 00007fff86964860   R8: 00002b3e4a2363e0   R9: 000000000000000a
    R10: 00007fff86964e10  R11: 0000000000000246  R12: 00002b3e4a236570
    R13: 00007fff86964e50  R14: 0000000000000001  R15: 00002b3e2cd76078
    ORIG_RAX: ffffffffffffffff  CS: 0033  SS: 002b
crash>


-bt : to backtrace a PID

crash > bt
crash > bt -f



-bt -f : display all stack data contained in a frame; this option can be used to determine the arguments passed to each function

crash>bt -f
 #0 [ffff81012f595aa0] crash_kexec at ffffffff800b099c
 #1 [ffff81012f595b60] panic at ffffffff80093989
 #2 [ffff81012f595c50] out_of_memory at ffffffff800caa5d



-kmem : details of kernel memory location e.g. For #2 above

crash> kmem ffffffff800caa5d
ffffffff800caa5d (T) out_of_memory+593 ../debug/kernel-2.6.18/linux-2.6.18-308.8.2.el5.x86_64/mm/oom_kill.c: 506

      PAGE       PHYSICAL      MAPPING       INDEX CNT FLAGS
ffff810100009c30   2ca000                0        0  1 400
crash>




-whatis : search symbol table for data or type information

crash> whatis crash_kexec
void crash_kexec(struct pt_regs *);

crash> whatis panic
void panic(const char *, ...);

crash> whatis out_of_memory
void out_of_memory(struct zonelist *, gfp_t, int, int);



-some_more_commands

crash> sys|egrep -i "cpu|date|uptime|load|tasks|node|release|machine|memory|panic"
    DUMPFILE: /cores/retrace/tasks/152431766/crash/vmcore  [PARTIAL DUMP]
        CPUS: 24
        DATE: Wed Sep  9 07:54:53 2015
      UPTIME: 322 days, 11:00:25
LOAD AVERAGE: 0.13, 0.13, 0.13
       TASKS: 755
    NODENAME: ms00456
     RELEASE: 2.6.32-358.el6.x86_64
     MACHINE: x86_64  (2494 Mhz)
      MEMORY: 192 GB
       PANIC: "Kernel panic - not syncing: An NMI occurred, please see the Integrated Management Log for details."

crash> rd -a 0xffffffff8201c001 100
ffffffff8201c000:  HP
ffffffff8201c004:  P70
ffffffff8201c008:  2.8
ffffffff8201c010:  12/20/2013  <<<
ffffffff8201c01c:  HP
ffffffff8201c020:  ProLiant DL380p Gen8


crash> dis -rl 0xffffffffa00574ca
0xffffffffa00574c8 : callq  0xffffffff8150cf21
/usr/src/debug/kernel-2.6.32-358.el6/linux-2.6.32-358.el6.x86_64/drivers/watchdog/hpwdt.c: 495


crash> mod |grep -E "NAME|"
     MODULE       NAME                   SIZE  OBJECT FILE
ffffffffa00581a0  hpwdt                  7094  /cores/retrace/repos/kernel/x86_64/usr/lib/debug/lib/modules/2.6.32-358.el6.x86_64/kernel/drivers/watchdog/hpwdt.ko.debug 


crash> px ((struct module *)0xffffffffa00581a0)->name
$2 = "hpwdt\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"

crash> px ((struct module *)0xffffffffa00581a0)->version
$3 = 0xffff88301782cb20 "1.3.0"


crash> px ((struct module *)0xffffffffa00581a0)->srcversion
$4 = 0xffff8830194fe4c0 "87D39D97B9E0A6F667C8671"


crash> px ((struct module *)0xffffffffa00581a0)->gpgsig_ok
$5 = 0x1


crash> px notify_die
notify_die = $6 = 
 {int (enum die_val, const char *, struct pt_regs *, long, int, int)} 0xffffffff8109cbd0


crash> eval -b 00000000000000f1


-Other crash command

help : list all supported crash command
help : to know available option and details of a crash command e.g 'help bt'
net : show network interfaces and ip address configured
mount : show mount point and mount option at time of crash
sys : system specific information excatly what you see when crash was started
swap : swap usages
task : task structure of running task. In above example, it is sshd with PID 3419
runq : displays the tasks on the run queues of each cpu
set -v : display the current state of internal crash variables.


How to run crash analysis unattended and save in a text file ?


# cat > inputfile.txt
sys
mount
net
swap
log
ps
runq
bt
bt -a
bt -g
bt -t
bt -al
bt -f
foreach bt
task
kmem
kmem -i
kmem -S
exit

# crash /usr/lib/debug/lib/modules/$(uname -r)/vmlinux vmcore -i inputfile.txt > crash-analysys.txt
# less crash-analysys.txt

- References
http://people.redhat.com/anderson/crash_whitepaper/
http://www.dedoimedo.com/computers/crash-book.html
https://codeascraft.com/2012/03/30/kernel-debugging-101/

Tuesday, March 10, 2015

sar, ksar and watcher-cron - how to use to troubleshoot a Linux system

sar

To know about all options of sar, best place is : $ man sar

ksar


I have created a page on wikipedia : http://en.wikipedia.org/wiki/Ksar_%28Unix_sar_grapher%29

Few points

Always create 1 second interval data for troubleshooting. 

  •  below command will run in background to create binary file having 1 second resolution
  •  binary file will be around 25M
  •  text file size will be 40M


sar -A -o /var/tmp/sar-bin-date-systemname.bin  1 3600 >/dev/null 2>&1 &
ls -l /var/tmp/sar-bin-date-systemname.bin
sar -A -f /var/tmp/sar-bin-date-systemname.bin
LC_ALL=C sar -A -p -f /var/tmp/sar-bin-date-systemname.bin /var/tmp/sar-txt-date-systemname.txt

Load sar-txt-date-systemname.txt in ksar to see granular details.

An example:

Application was loading a 3.5G file on a 4 GB system. It was being closed within 10 second but it was enough to generate huge page-out and ~100% utilization of disk  !

$ sar -rpdB -s 02:27:29 -e 02:27:45 -f /var/tmp/sar-bin-date-systemname.bin
Linux 2.6.18-308.8.2.el5 (testsys001mysystem.com)      10/03/15        _x86_64_        (2 CPU)

02:27:28     pgpgin/s pgpgout/s   fault/s  majflt/s  pgfree/s pgscank/s pgscand/s pgsteal/s    %vmeff
02:27:29        16.16   1826.26 239842.42      1.01 115282.83      0.00      0.00      0.00      0.00
02:27:30        60.00     56.00 331109.00      8.00 204665.00      0.00      0.00      0.00      0.00
02:27:31         0.00     60.00 517659.00      0.00 345388.00      0.00      0.00      0.00      0.00
02:27:32         0.00    327.27 610073.74      0.00 364861.62      0.00      0.00      0.00      0.00
02:27:33         0.00     60.61 330316.16      0.00 181757.58      0.00      0.00      0.00      0.00
02:27:34         0.00    526.53 590945.92      0.00 429371.43      0.00      0.00      0.00      0.00
02:27:35        16.00   1204.00 340554.00      0.00 232284.00   2272.00   4832.00   1080.00     15.20
02:27:36       252.00    704.00  60046.00      4.00  58837.00   3296.00  19806.00  17118.00     74.10
02:27:37      1706.93 334978.22 302981.19     71.29 304998.02 141251.49  44208.91  94489.11     50.95
02:27:38     26574.76 459071.84 349949.51    567.96 359980.58 183487.38  46633.01 115279.61     50.10
02:27:39      7526.53 446142.86 330251.02    262.24 328176.53 198889.80  24097.96 110475.51     49.54
02:27:40      1503.85 413742.31 292217.31     59.62 292017.31 181600.00  24369.23 102852.88     49.94
02:27:41      1619.80  81607.92  56802.97     43.56 979036.63  32285.15   8807.92  20769.31     50.54
02:27:42      3155.56    113.13   8978.79     82.83   1768.69      0.00      0.00      0.00      0.00
02:27:43     13457.43    190.10  23859.41    630.69  13454.46      0.00      0.00      0.00      0.00
02:27:44      1296.97    367.68    128.28     44.44    109.09      0.00      0.00      0.00      0.00
02:27:45      1979.59     36.73   7173.47     36.73    890.82      0.00      0.00      0.00      0.00
Average:      3528.90 103975.52 258296.12    107.83 248765.63  44355.97  10310.59  27579.75     50.45

02:27:28    kbmemfree kbmemused  %memused kbbuffers  kbcached  kbcommit   %commit
02:27:29      3626448    286212      7.32     14448    109424    587200      9.88
02:27:30      3203408    709252     18.13     14460    109464    980300     16.49
02:27:31      2509876   1402784     35.85     14468    109472   1670800     28.11
02:27:32      1558540   2354120     60.17     14480    109516   2681920     45.12
02:27:33      1002236   2910424     74.38     14492    109480   3295636     55.44
02:27:34       402404   3510256     89.72     14508    109512   3777916     63.56
02:27:35        22300   3890360     99.43     14496    105340   4261476     71.69
02:27:36        22272   3890388     99.43      2832     52344   4266140     71.77
02:27:37        22888   3889772     99.42       520     12892   4640740     78.07
02:27:38        32216   3880444     99.18       872     25420   5006940     84.23
02:27:39        30604   3882056     99.22      1300     27428   5464516     91.93
02:27:40        35468   3877192     99.09      1316     28580   5850808     98.43
02:27:41      3759396    153264      3.92      1336     29276    478424      8.05
02:27:42      3744892    167768      4.29      1548     30996    551996      9.29
02:27:43      3743188    169472      4.33      1812     41488    446000      7.50
02:27:44      3742168    170492      4.36      1840     42508    446000      7.50
02:27:45      3733504    179156      4.58      1936     44268    511600      8.61
Average:      1834812   2077848     53.11      6863     64553   2642260     44.45

02:27:28          DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
02:27:29          sda     56.57     32.32   3652.53     65.14      0.19      3.39      0.61      3.43
02:27:30          sda     11.00    120.00    112.00     21.09      0.04      4.00      4.00      4.40
02:27:31          sda      3.00      0.00    120.00     40.00      0.00      0.33      0.33      0.10
02:27:32          sda      3.03      0.00     80.81     26.67      0.01      2.00      2.00      0.61
02:27:33          sda      6.06      0.00    694.95    114.67      0.00      0.33      0.33      0.20
02:27:34          sda     22.45      0.00   1053.06     46.91      0.02      0.95      0.23      0.51
02:27:35          sda    207.00     32.00   2408.00     11.79      0.24      1.15      0.17      3.60
02:27:36          sda     45.00    504.00   1248.00     38.93      0.38      8.49      3.62     16.30
02:27:37          sda   2812.87   3413.86 666899.01    238.30      7.28      2.58      0.29     81.98
02:27:38          sda   3228.16  53141.75 919541.75    301.31     20.51      6.35      0.30     97.96
02:27:39          sda   4312.24  14995.92 888693.88    209.56     11.21      2.59      0.23    100.10
02:27:40          sda   8043.27   3069.23 832607.69    103.90     13.67      1.70      0.12     97.60
02:27:41          sda    899.01   3239.60 163215.84    185.15      1.58      1.75      0.32     28.51
02:27:42          sda    225.25   6044.44    226.26     27.84      0.41      1.80      1.11     24.95
02:27:43          sda    699.01  27176.24    380.20     39.42      1.44      2.08      1.20     83.76
02:27:44          sda     72.73   2585.86    735.35     45.67      0.12      1.69      1.54     11.21
02:27:45          sda     89.80   3967.35     73.47     45.00      0.15      1.66      1.26     11.33
Average:          sda   1242.32   7057.80 207951.03    173.07      3.43      2.76      0.27     33.71


watcher-cron

A simple script provided by redhat to collect system performance data using below commands. Use this along with sar data. See redhat article https://access.redhat.com/articles/279063 for more detail.

iostat
vmstat
top
mpstat

Also add iotop and ps aux --forest commands in script:

sequences=`seq -s ' ' $2`
eval "for i in $sequences; do date;ps aux --forest; sleep $1;done ${_compress_all} >  $3/${_time}-info-ps-forest.log${_ext_all} &" ; pspid=$!
eval "iotop -n $1 -d $2 -b               ${_compress_all} >  $3/${_time}-info-iotop.log${_ext_all} &" ; iotoppid=$!

References:
https://access.redhat.com/articles/1145953 - PCP
Performance monitoring tools

Wednesday, February 25, 2015

Steps to use OProfile - opcontrol, opreport, oparchive and a script to collect samples

What is OProfile ?

From OProfile documentation ''OProfile is capable of monitoring native hardware events occurring in all parts of a running system, from the kernel (including modules and interrupt handlers) to shared libraries to binaries. OProfile can collect event information for the whole system in the background with very little overhead. These features make it ideal for monitoring entire systems to determine bottle necks in real-world systems."


Installation

OProfile require kernel-debuginfo rpm of running kernel version to install uncompressed and unstripped vmlinux binary. It is in /usr/lib/debug/lib/modules/$(uname -r)/vmlinux.

  # yum install kernel-debuginfo-$(uname -r) kernel-debuginfo-common-$(uname -r) kernel-headers-$(uname -r) kernel-devel-$(uname -r)
  # yum install oprofile oprofile-jit
  # ls -l /usr/lib/debug/lib/modules/$(uname -r)/vmlinux
  # mount -t debugfs nodev /sys/kernel/debug


How to use OProfile?

- Stop OProfile completely, incase anything running
    # opcontrol --deinit

- Enable stats and start the oprofile daemon. It will load oprofile kernel module
    # opcontrol --vmlinux=/usr/lib/debug/lib/modules/`uname -r`/vmlinux
    #lsmod |grep oprofile

- Initialize and start daemon with default sample collection directory ''samples" in default session-dir /var/lib/oprofile. It will also create empty directory /var/lib/oprofile/samples/current.
   # opcontrol --init
   # opcontrol --start-daemon
          Using default event: CPU_CLK_UNHALTED:100000:0:1:1
          Error: counter 0 not available nmi_watchdog using this resource ? Try:

   # opcontrol --deinit
   # echo 0 > /proc/sys/kernel/nmi_watchdog
   # opcontrol --status
         Daemon running: pid 31084
         Separate options: none
         vmlinux file: /usr/lib/debug/lib/modules/2.6.18-348.3.1.el5/vmlinux
         Image filter: none
         Call-graph depth: 0

- Start to capture a profile with default events (cpu cycles):
    # opcontrol --start

- Periodically dump and save stats
   # cd /var/lib/oprofile/samples
   # time_now=$(date +%F_%Hh%Mm%Ss)
   # /usr/bin/opcontrol --dump
   # /usr/bin/opcontrol --save=$time_now

- Check if saved session is valid
  #opreport -fg -l /usr/lib/debug/lib/modules/`uname -r`/vmlinux session:$time_now

- Create oparchive (using one or more sessions) for analysis on remote system. It will create oparchive-$time_now directory.
   # oparchive -o  oparchive-$time_now  session:$time_now
  # oparchive -o  oparchive-$time_now  session:$time_now,,

- Check if created archive is also healthy and create report.
    # opreport -fg -l archive:oparchive-$time_now session:$time_now >opreport-from-oparchive-${time_now}.txt 2>&1

- Saving session will stop profiling. Hence, start profiling again
  # /usr/bin/opcontrol --start


Profiling using cron

Periodically, run following thru cron once oprofile daemon has been started  (--start-daemon). Or  use below script.
   opcontrol --dump; opcontrol --save=`date +%F_%Hh%Mm%Ss`; opcontrol --start


OProfile on VM

OProfile currently does not support event-based profiling (i.e, using hardware events like cache misses, branch mispredicts) on virtual machine guests running under systems such as VMware. (Note: KVM guests are supported.). See http://blogs.epfl.ch/category/3239 to run OProfile on VMware VM and OProfile officila document.


Script to collect OProfile samples

Assuming you are copying script as /var/tmp/oprofile-cron-script.sh and sample oprofile base data collection directory is /var/lib/oprofile/new. Script will create log /var/lib/oprofile/new/samples/oprofiled.log and /var/lib/oprofile/new/samples/oprofile-script-$(date +%d%b%Y).log

OProfile cron job

Sample data in every 30 minutes and remove

# cat /etc/cron.d/oprofile
*/30 * * * * root  /var/tmp/oprofile-cron-script.sh
0 * * * * root find /var/lib/oprofile/new/samples -maxdepth 1 -mtime +3 -exec rm -rf {} \;

OProfile sample collection script

# cat /var/tmp/oprofile-cron-script.sh
#!/bin/bash
# nasimuddin ansari : nasim.ansari (at) gmail.com
# 16 Feb 2015, version 2, Tested in Production environment
working_dir=/var/lib/oprofile/new
sample_dir=$working_dir/samples
script_log=$sample_dir/oprofile-script-$(date +%d%b%Y).log
time_now=$(date +%F_%Hh%Mm%Ss)
PATH=$PATH:/usr/bin
exit_status=0
#set -x

[ ! -d "$working_dir" ] && echo Failed: $working_dir does not exist && exit 1
[ ! -d "$working_dir/samples" ] && mkdir $working_dir/samples
[ ! -f "$script_log" ] || touch $script_log

function reinitialize_oprofile {
    echo -e "\nReinitializing oprofile ...."
    opcontrol --deinit
    pgrep -f /usr/bin/oprofiled && pkill -f /usr/bin/oprofiled
    opcontrol --vmlinux=/usr/lib/debug/lib/modules/`uname -r`/vmlinux --session-dir=$working_dir
    opcontrol --start-daemon --session-dir=$working_dir
    # start capture a profile - with default events (cpu cycles)
    opcontrol --start
    opcontrol --status
    # for each of detection, when oprofile was reinitiatlize, touch a file
    touch $sample_dir/reinitialize_oprofile-$time_now
    sleep 60
}

(
echo -e "\nScript $0 started on $(date)"
cd $sample_dir

# if oprofiled is not running, restart it
if ! pgrep -f /usr/bin/oprofiled  >/dev/null
then
    echo oprofiled is not running ...
    reinitialize_oprofile
    if ! pgrep -f /usr/bin/oprofiled  >/dev/null
    then
        echo Failed: Tried to start oprofile, but could not. Please fix it !
    echo Exiting ....
        exit 1
    fi
fi

# if oprofile is running, dump and save stats
opcontrol --dump
opcontrol --save=$time_now

# above save session will create a directory as $time_now
if [ -d "$time_now" ]; then

    # run opreport on saved session to confirm it is good
    if opreport -fg -l session:$time_now --session-dir=$working_dir >/dev/null 2>&1
    then
        echo OK: saved session $time_now is good, start capturing new profile
    if opcontrol --start
    then
        echo OK: 'opcontrol --start' sucess. Creating oparchive now ...
            oparchive -o oparchive-$time_now session:$time_now --session-dir=$working_dir >/dev/null 2>&1

            # if oparchive has been created in above step, create opreport
            if [ -d "oparchive-$time_now" ]; then
                echo OK: oparchive-$time_now has been created, creating opreport now ....
                opreport -fg -l archive:oparchive-$time_now --session-dir=$working_dir session:$time_now >opreport-from-oparchive-${time_now
}.txt 2>&1

                # if opreport has been created, make tarball and do housekeeping
                if [ $? = 0 ];then
            echo OK: opreport-from-oparchive-${time_now}.txt has been created, creating tarball now ...
                    # create a tar file of session, archive and report
                    tar -jcf oprofile-oparchive-opreport-${time_now}.tar.bz2 \
                        oparchive-$time_now $time_now opreport-from-oparchive-${time_now}.txt
                    rm -rf oparchive-$time_now $time_now opreport-from-oparchive-${time_now}.txt
                    if [ -f oprofile-oparchive-opreport-${time_now}.tar.bz2 ];then
                      echo OK: Created oprofile-oparchive-opreport-${time_now}.tar.bz2 file having session, archive and report
                    else
                      echo Failed: to create oprofile-oparchive-opreport-${time_now}.tar.bz2 file session, archive and report
                      exit_status=1
                    fi
                else
                    echo Failed: to create opreport using archived and session
                    exit_status=1
                fi
            else
                echo Failed: oparchive did not create "$sample_dir/$oparchive-$time_now" directory. Hence opreport has failed.
                exit_status=1
            fi
    else
        echo Failed: 'opcontrol --start'. Please fix it !
        exit_status=1
    fi
    else
        echo Failed: "opreport -fg -l session:$time_now" did not work. Hence oparchive too has failed.
        exit_status=1
    fi
else
    echo Failed: "opcontrol --save=$time_now" did not create a valid session. skipping oparchive and opreport. Fix it please !
    exit_status=1
fi


if [ $exit_status = 1 ]; then
    reinitialize_oprofile
    echo -e "Script $0 completed at $(date) Done....\n"
    exit 1
else
    echo -e "Script $0 completed at $(date) Done....\n"
    exit 0
fi

) >>$script_log 2>&1
#set +x
#end of script


Sample output of above script

 # ls -lrt /var/lib/oprofile/new/samples
-rw-r--r-- 1 root root        0 Feb 25 06:31 reinitialize_oprofile-2015-02-25_06h30m01s
-rw-r--r-- 1 root root        0 Feb 25 06:45 reinitialize_oprofile-2015-02-25_06h45m43s
-rw-r--r-- 1 root root 75284555 Feb 26 02:00 oprofile-oparchive-opreport-2015-02-26_02h00m01s.tar.bz2
-rw-r--r-- 1 root root 78830219 Feb 26 02:30 oprofile-oparchive-opreport-2015-02-26_02h30m01s.tar.bz2
drwxr-xr-x 4 root root     4096 Feb 26 03:00 current
-rw-r--r-- 1 root root 74807618 Feb 26 03:00 oprofile-oparchive-opreport-2015-02-26_03h00m01s.tar.bz2
-rw-r--r-- 1 root root     4613 Feb 26 03:00 oprofile-script-26Feb2015.log
-rw-r--r-- 1 root root  8355537 Feb 26 03:15 oprofiled.log

References

  1. Documentation of oprofile tools : http://oprofile.sourceforge.net/doc/index.html
  2. Redhat :OProfile quick start cheat sheet for RHEL5 : https://access.redhat.com/articles/21842
  3. IBM : Getting started with OProfile : http://www-01.ibm.com/support/knowledgecenter/linuxonibm/liacf/oprofgetstart.htm
  4. Blog : Profiling Tools - ftrace, perf, and oprofile : http://kwangwoo.blogspot.sg/2011/07/profiling-tools-ftrace-perf-and.html
  5. How to use OProfile : https://www.nsnam.org/wiki/HOWTO_use_oprofile
  6. OProfile on VMware VM : http://blogs.epfl.ch/category/3239
  7. Redhat : Tuning with OProfile : http://people.redhat.com/wcohen/OProfileTutorial.txt






Wednesday, February 18, 2015

Redirecting linux / unix time command output to a file

There may be requirement when you need to redirect unix / linux time command output to a file.

for me, -o option of time command did not work. Hence I used this - run command in a sub-shell and then redirect stdout and stderr into a file


>> All below did not work.

$ time -o /tmp/x date
bash: -o: command not found

real    0m0.001s
user    0m0.001s
sys     0m0.000s

$ time date
Wed Feb 18 08:18:41 UTC 2015

real    0m0.002s
user    0m0.000s
sys     0m0.001s
$ time date |grep real

real    0m0.002s
user    0m0.000s
sys     0m0.001s
$ time date 2>&1 |grep real

real    0m0.003s
user    0m0.000s
sys     0m0.002s
$ (time date )2>&1 |grep real
real    0m0.001s



>> Simple script.

$ cat /var/tmp/dns-check-script.sh
(
echo '----------------------------------------------------'
echo $((date;time -p host mysystem.com 10.10.10.11) &>/dev/stdout )
) >>/var/tmp/dns-check-script.log 2>&1



>> Run script via cron

$ cat /etc/cron.d/dns-check-script.cron
# Run script in every 2 minutes
*/2 * * * * root /var/tmp/dns-check-script.sh



>> This is how log will look like

#  tailf /var/tmp/dns-check-script.log
----------------------------------------------------
Tue Feb 17 12:28:01 GMT 2015 Using domain server: Name: 10.10.10.11 Address: 10.10.10.11#53 Aliases: mysystem.com has address 10.254.10.60 real 0.02 user 0.00 sys 0.00
Tue Feb 17 12:30:01 GMT 2015 Using domain server: Name: 10.10.10.11 Address: 10.10.10.11#53 Aliases: mysystem.com has address 10.254.10.60 real 0.02 user 0.00 sys 0.00