== Abstract ==
The following article show a simple method to use Glance binary log for resource bootleneck identification. The '''extract''' command is used to export the glance binary data to ASCII text, that can be use for tabular or plot reports.
__TOC__
== Stop Running OVPA agents ==# /sbin/init.d/ovpa stop
Shutting down Perf Agent collection software
Shutting down scopeux, pid(s) 5418
Waiting on 5418 (10 more tries)
The Perf Agent collector, scopeux has been shut down successfully.
The ARM daemons ttd, midaemon and Glance programs glance and xglance will be terminated (if running).
Shutting down the alarm generator perfalarm, pid(s) 5456
The perfalarm process has terminated
Shutting down coda daemon
Shutting down coda, pid(s) 5450
# /opt/perf/bin/perfstat
**********************************************************
*** perfstat for delta on Tue Nov 24 13:23:26 CST 2009
*** HP-UX delta B.11.31 U 9000/800 510254130 unlimited-user license
**********************************************************
list of performance tool processes:
———————————-
Perf Agent status:
WARNING: scopeux is not active (Perf Agent data collector)
WARNING: midaemon is not active (Measurement Interface daemon)
WARNING: ttd is not active (ARM registration daemon)
Perf Agent Server status:
Running ovcd (OV control component) pid 1849
Running ovbbccb (BBC5 communication broker) pid 1860
WARNING: coda is not active (perf component)
WARNING: perfalarm is not active (alarm generator)
******** (end of perfstat output: note above warning) ********
== Backup System Binary Logs ==# tar -cvf – /var/opt/perf/datafiles/log* | /usr/contrib/bin/gzip > /tmp/glancelogs.tgz
a /var/opt/perf/datafiles/logappl 129 blocks
a /var/opt/perf/datafiles/logdev 884 blocks
a /var/opt/perf/datafiles/logglob 183 blocks
a /var/opt/perf/datafiles/logindx 11 blocks
a /var/opt/perf/datafiles/logpcmd0 1 blocks
a /var/opt/perf/datafiles/logproc 15 blocks
a /var/opt/perf/datafiles/logtran 489 blocks
== Extract Source System Binary Logs ==# /usr/contrib/bin/gzcat /var/tmp/glancelogs.tgz | tar -xvf –
x /var/opt/perf/datafiles/logappl, 17041748 bytes, 33285 tape blocks
x /var/opt/perf/datafiles/logdev, 19638408 bytes, 38357 tape blocks
x /var/opt/perf/datafiles/logglob, 28038808 bytes, 54764 tape blocks
x /var/opt/perf/datafiles/logindx, 46576 bytes, 91 tape blocks
x /var/opt/perf/datafiles/logpcmd0, 15 bytes, 1 tape blocks
x /var/opt/perf/datafiles/logproc, 30438534 bytes, 59451 tape blocks
x /var/opt/perf/datafiles/logtran, 10205840 bytes, 19934 tape blocks
Perform any required reports. See next sections for additional information.
== Clean Binary Logs and Restart OVPA agents ==# rm /var/opt/perf/datafiles/log*
# ls -l /var/opt/perf/datafiles/*
-rw-rw-rw- 1 root sys 31 Nov 23 19:14 /var/opt/perf/datafiles/RUN
-rw-r–r– 1 root root 105 Jul 23 03:18 /var/opt/perf/datafiles/agdb
-rw-r–r– 1 root root 0 Jul 23 03:18 /var/opt/perf/datafiles/agdb.lk
-rw-rw-rw- 1 root root 168 Nov 23 19:15 /var/opt/perf/datafiles/classinfo.db
-rw-r–r– 1 root sys 969354 Nov 23 17:22 /var/opt/perf/datafiles/mikslp.db
# /sbin/init.d/ovpa start
The Perf Agent scope collector is being started.
The ARM registration daemon
/opt/perf/bin/ttd has been started.
The Performance collection daemon
/opt/perf/bin/scopeux has been started.
The coda daemon /opt/OV/lbin/perf/coda has been started.
It will be fully operational in a few minutes.
The Perf Agent alarm generator is being started.
The alarm generator /opt/perf/bin/perfalarm
has been started.
# /opt/perf/bin/perfstat
**********************************************************
*** perfstat for delta on Tue Nov 24 13:28:36 CST 2009
*** HP-UX delta B.11.31 U 9000/800 510254130 unlimited-user license
**********************************************************
list of performance tool processes:
———————————-
Perf Agent status:
Running scopeux (Perf Agent data collector) pid 13766
Running midaemon (Measurement Interface daemon) pid 13778
Running ttd (ARM registration daemon) pid 13760
Perf Agent Server status:
Running ovcd (OV control component) pid 1849
Running ovbbccb (BBC5 communication broker) pid 1860
Running coda (perf component) pid(s) 13798
Running perfalarm (alarm generator) pid(s) 13804
************* (end of perfstat -p output) ****************
# ls -l /var/opt/perf/datafiles/log*
-rw-r–r– 1 root sys 4512 Nov 24 13:28 /var/opt/perf/datafiles/logappl
-rw-r–r– 1 root sys 3836 Nov 24 13:28 /var/opt/perf/datafiles/logdev
-rw-r–r– 1 root sys 3672 Nov 24 13:28 /var/opt/perf/datafiles/logglob
-rw-r–r– 1 root sys 5296 Nov 24 13:28 /var/opt/perf/datafiles/logindx
-rw-r–r– 1 root sys 11 Nov 24 13:28 /var/opt/perf/datafiles/logpcmd0
-rw-r–r– 1 root sys 3672 Nov 24 13:28 /var/opt/perf/datafiles/logproc
-rw-r–r– 1 root sys 4172 Nov 24 13:28 /var/opt/perf/datafiles/logtran
== Global CPU and Memory Utilization ==cat > global_cpumem.rept << EOF
REPORT "OVPA Export !DATE !TIME Logfile: !LOGFILE !COLLECTOR !SYSTEM_ID"
FORMAT ASCII
HEADINGS ON
SEPARATOR="|"
SUMMARY=60
MISSING=0
DATA TYPE GLOBAL
DATE
TIME
GBL_ACTIVE_CPU
GBL_CPU_TOTAL_UTIL
GBL_DISK_PHYS_IO_RATE
GBL_DISK_PHYS_IO
GBL_MEM_FREE
GBL_MEM_UTIL
GBL_MEM_USER_UTIL
GBL_SWAP_SPACE_UTIL
GBL_MEM_PAGEOUT_BYTE
GBL_MEM_PAGEOUT_BYTE_RATE
EOF
/opt/perf/bin/extract -g -xp -r global_cpumem.rept \
-f global_cpumem.out,purge \
-b “11/09/2009 08:00:00” -e “11/09/2009 09:00:00”
# cat global_cpumem.out
OVPA Export 11/17/09 16:37 Logfile: /var/opt/perf/datafiles/logglob SCOPE/UX C.04.70.000(0) delta
| |Active| | Phys | Phys | Free |Memory| User | | Pg Out | Pg Out |
Date | Time | CPUs |CPU % | IO Rt | IOs | Mem | % |Mem % |Swap %| KB | KB Rt |
11/09/2009|08:00:00| 7| 56.44| 2519.8| 754932| 15199| 53.49| 40.20| 53.00| 34843| 116.3|
11/09/2009|08:05:00| 7| 42.31| 1968.5| 590746| 14441| 54.85| 41.55| 55.00| 26138| 87.1|
11/09/2009|08:10:00| 7| 50.72| 1491.7| 447062| 13674| 56.43| 43.11| 57.00| 179| 0.6|
11/09/2009|08:15:00| 7| 44.58| 1188.5| 356431| 13022| 57.76| 44.44| 59.00| 479| 1.6|
11/09/2009|08:20:00| 7| 39.02| 880.1| 263941| 12079| 59.30| 45.96| 61.00| 0| 0.0|
11/09/2009|08:25:00| 7| 52.99| 850.4| 255545| 11146| 60.87| 47.53| 63.00| 8353| 27.8|
11/09/2009|08:30:00| 7| 54.77| 898.3| 269759| 10176| 62.65| 49.28| 65.00| 6366| 21.2|
11/09/2009|08:35:00| 7| 42.04| 860.0| 257742| 9186| 64.49| 51.10| 68.00| 0| 0.0|
11/09/2009|08:40:00| 7| 64.83| 1436.1| 430686| 8392| 65.92| 52.52| 70.00| 299| 1.0|
11/09/2009|08:45:00| 7| 56.19| 557.5| 167361| 7772| 67.56| 54.15| 72.00| 60| 0.2|
11/09/2009|08:50:00| 7| 60.21| 569.8| 170996| 6542| 69.52| 56.09| 74.00| 0| 0.0|
11/09/2009|08:55:00| 7| 54.11| 760.1| 228106| 6131| 70.94| 57.46| 76.00| 0| 0.0|
On larger reports, for example when reviewing whole days or weeks, identification of resource bottleneck is better assisted using graphics charts. Data can be ploted to charts imported it to spreadsheets software ot using the GNUplot plugin to plot the required data. For example, to plot the CPU %, Memory % and User Memory % together, the following script can be usedcat > global_cpumem.plot << EOF
set size 1, 0.5
set yrange [0:120]
set xlabel “Samples”
plot ‘-‘ using 1:2 title ‘CPU %’ with lines, \\
‘-‘ using 1:3 title ‘Memory %’ with lines, \\
‘-‘ using 1:4 title ‘User Memory %’ with lines
EOF
tail -n $(expr $(wc -l global_cpumem.out | cut -d” ” -f 1) – 3 ) global_cpumem.out | \
awk -F’|’ ‘BEGIN {LINE=1; printf “#Sample\tCPU\tMemory\tUser Memory\n”; } {
printf “%-6d\t%4.2f\t%4.2f\t%4.2f\n”, LINE, $4, $8, $9
LINE++
}’ >> global_cpumem.plot
cat >> global_cpumem.plot << EOF
EOF
cat global_cpumem.plot
The script will provided the required code for the GNUplot to chart the resources.
set size 1, 0.5
set yrange [0:100]
set xlabel “Samples”
plot ‘-‘ using 1:2 title ‘CPU %’ with lines, \
‘-‘ using 1:3 title ‘Memory %’ with lines, \
‘-‘ using 1:4 title ‘User Memory %’ with lines
#Sample CPU Memory User Memory
1 50.72 56.43 43.11
2 44.58 57.76 44.44
3 39.02 59.30 45.96
4 52.99 60.87 47.53
5 54.77 62.65 49.28
6 42.04 64.49 51.10
7 64.83 65.92 52.52
8 56.19 67.56 54.15
9 60.21 69.52 56.09
10 54.11 70.94 57.46
== Global Page Out ==export TOP=$(tail -n $(expr $(wc -l global_cpumem.out | cut -d” ” -f 1) – 3 ) global_cpumem.out |
sort -nrk 11,11 | head -n 1 | awk -F”|” ‘{print $11}’)
TOP=$(echo $(( ${TOP} * 110 / 100 )) )
cat > pageout.plot << EOF
set size 1, 0.5
set yrange [0:$TOP]
set xlabel “Samples”
plot ‘-‘ using 1:2 title ‘Pg Out KB’ with lines
EOF
tail -n $(expr $(wc -l global_cpumem.out | cut -d” ” -f 1) – 3 ) global_cpumem.out | \
awk -F’|’ ‘BEGIN {LINE=1; printf “#Sample\tPg Out KB\n”; } {
printf “%-6d\t%10d\n”, LINE, $11
LINE++
}’ >> pageout.plot
cat >> pageout.plot << EOF
EOF
The script will provided the required code for the GNUplot to chart the Page Out.
set size 1, 0.5
set yrange [0:38327]
set xlabel “Samples”
plot ‘-‘ using 1:2 title ‘Pg Out KB’ with lines
#Sample Pg Out KB
1 34843
2 26138
3 179
4 479
5 0
6 8353
7 6366
8 0
9 299
10 60
11 0
12 0
== Per Process CPU and Memory Utilization ==cat > cpumem.rept << EOF
REPORT "OVPA Export !DATE !TIME Logfile: !LOGFILE !COLLECTOR !SYSTEM_ID"
FORMAT ASCII
HEADINGS ON
SEPARATOR="|"
SUMMARY=60
MISSING=0
DATA TYPE PROCESS
DATE
TIME
PROC_PROC_ID
PROC_PROC_NAME
PROC_USER_NAME
PROC_CPU_TOTAL_UTIL
PROC_MEM_RES
PROC_MEM_VIRT
EOF
/opt/perf/bin/extract -p -xp -r /var/tmp/cpumem.rept \
-f cpumem.out,purge \
-b “11/09/2009 08:00:00” -e “11/09/2009 09:00:00”
# head -n 24 cpumem.out
OVPA Export 11/17/09 17:13 Logfile: /var/opt/perf/datafiles/logglob SCOPE/UX C.04.70.000(0) delta
| | | Process | User | | Res |Virtual |
Date | Time | PID | Name | Name | CPU % | Mem | Memory |
11/09/2009|08:00:00| 78|vxfsd |root | 2.05| 38912| 44032|
11/09/2009|08:00:00| 4975|oracleV24P |oracle | 71.14| 41984| 53248|
11/09/2009|08:00:00| 25409|ora_j000_UNIC |oracle | 0.03| 13572| 15880|
11/09/2009|08:00:00| 25153|oraclePAM |oracle | 1.04| 11784| 25576|
11/09/2009|08:00:00| 25393|oraclePAM |oracle | 3.00| 304| 1344|
11/09/2009|08:00:00| 24972|compress |oracle | 15.21| 784| 808|
11/09/2009|08:00:00| 25188|compress |oracle | 54.92| 848| 872|
11/09/2009|08:00:00| 25365|ora_m000_PAM |oracle | 2.08| 14740| 28192|
11/09/2009|08:00:00| 17482|oracleSCHD |oracle | 12.15| 27240| 50176|
11/09/2009|08:00:00| 3138|ora_dbw0_UNIC |oracle | 0.00| 15752| 54272|
11/09/2009|08:00:00| 3266|ora_lgwr_SCHD |oracle | 0.00| 24060| 489472|
11/09/2009|08:00:00| 3621|ora_lgwr_PLIN |oracle | 0.00| 16436| 34816|
11/09/2009|08:00:00| 24581|oracleV24P |oracle | 57.21| 26812| 30536|
11/09/2009|08:00:00| 19689|ftpd |root | 2.12| 1828| 2584|
11/09/2009|08:01:00| 78|vxfsd |root | 3.08| 38912| 44032|
11/09/2009|08:01:00| 4975|oracleV24P |oracle | 56.80| 44032| 52224|
11/09/2009|08:01:00| 25486|oracleSCHD |oracle | 13.37| 25980| 34816|
11/09/2009|08:01:00| 25409|ora_j000_UNIC |oracle | 9.33| 16636| 20824|
11/09/2009|08:01:00| 3140|ora_lgwr_UNIC |oracle | 0.00| 16000| 72704|
11/09/2009|08:01:00| 25447|cimprovagt |root | 0.00| 1248| 2056|
11/09/2009|08:01:00| 3250|ora_dbw2_SCHD |oracle | 0.00| 25476| 55296|
== Per Process CPU and I/O Utilization ==cat > cpuio.rept << EOF
REPORT "OVPA Export !DATE !TIME Logfile: !LOGFILE !COLLECTOR !SYSTEM_ID"
FORMAT ASCII
HEADINGS ON
SEPARATOR="|"
SUMMARY=60
MISSING=0
DATA TYPE PROCESS
DATE
TIME
PROC_PROC_ID
PROC_PROC_NAME
PROC_USER_NAME
PROC_CPU_TOTAL_UTIL
PROC_DISK_PHYS_IO_RATE
PROC_IO_BYTE_RATE
PROC_DISK_FS_IO
PROC_DISK_VM_IO
PROC_DISK_SYSTEM_IO
EOF
/opt/perf/bin/extract -p -xp -r /var/tmp/cpuio.rept \
-f cpuio.out,purge \
-b “11/09/2009 08:00:00” -e “11/09/2009 09:00:00”
# head -n 24 cpuio.out
| | | Process | | Phys | IO Byte |File System| VM | System |
Date | Time | PID | Name | CPU % |IO Rt | Rate | IOs | IOs | IOs |
03/16/2010|11:00:00| 129|vxfsd | 0.04| 20.4| 147.0| 1138| 0| 110|
03/16/2010|11:00:00| 29798|dw.sapCP1_D33 | 10.06| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 8082|dw.sapCP1_D33 | 17.10| 0.1| 0.2| 6| 0| 0|
03/16/2010|11:00:00| 25418|dw.sapCP1_D33 | 25.17| 0.0| 0.1| 0| 0| 0|
03/16/2010|11:00:00| 26554|dw.sapCP1_D33 | 20.09| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 11052|dw.sapCP1_D33 | 18.14| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 29794|dw.sapCP1_D33 | 16.14| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 8902|jlaunch | 0.01| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 28575|dw.sapCP1_D33 | 13.14| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 22427|icman | 38.48| 0.6| 16.0| 0| 0| 36|
03/16/2010|11:00:00| 8903|jlaunch | 0.01| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 29516|dw.sapCP1_D33 | 44.42| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 29801|dw.sapCP1_D33 | 19.09| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 29793|dw.sapCP1_D33 | 14.20| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 29804|dw.sapCP1_D33 | 11.06| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 8189|dw.sapCP1_D33 | 36.30| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 29796|dw.sapCP1_D33 | 20.12| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:00:00| 29792|dw.sapCP1_D33 | 19.10| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:01:00| 129|vxfsd | 0.03| 10.4| 93.0| 583| 0| 35|
03/16/2010|11:01:00| 8082|dw.sapCP1_D33 | 10.04| 0.0| 0.0| 0| 0| 0|
03/16/2010|11:01:00| 25418|dw.sapCP1_D33 | 20.11| 0.0| 0.0| 0| 0| 0|
== Reference ==
* [[How to collect glance binary log files]]
* [[How to create performance statistics charts]]
== Authors ==
* [[Alejandro Marin Badilla]]
[[Category:HP-UX]]
[[Category:Performance]]