From Wiki-UX.info

Wiki-UX / How to generate reports using glance binary log files
Jump to: navigation, search

How to generate reports using glance binary log files

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.

Contents


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 used


cat > global_cpumem.plot << EOF
<gnuplot>
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
<plotdata>
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
</plotdata>
</gnuplot>
EOF
 
cat global_cpumem.plot

The script will provided the required code for the GNUplot to chart the resources.

GnuplotBasic Plot

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
<gnuplot>
set size 1, 0.5
set yrange [0:$TOP]
set xlabel "Samples"
plot '-' using 1:2 title 'Pg Out KB' with lines
<plotdata>
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
</plotdata>
</gnuplot>
EOF

The script will provided the required code for the GNUplot to chart the Page Out.

GnuplotBasic Plot

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

Authors

This page was last modified on 17 March 2010, at 14:34. This page has been accessed 10,003 times.