1) start import of data.sql into a dummy db when both instances are running
2) pt-stalk –collect –collect-oprofile –no-stalk for the duration of the import

  • oprofile will show where MySQL spends most of its time during the import

3) run pt-diskstats -g all –devices-regex sdb1 for the duration of the import
4) run poor-man-profiler for the duration of the import

I find often time very useful to use this script to evaluate GC behavior/RCA which is published at java.net (http://java.net/projects/printgcstats/sources/svn/show).

# PrintGCStats - summarize statistics about garbage collection, in particular gc
# pause time totals, averages, maximum and standard deviations.
#
# Attribution: written by John Coomes, based on earlier work by Peter Kessler,
# Ross Knippel and Jon Masamitsu.
# This version is based off of a version posted on the OpenJDK
# mailing list on 04/20/2007 and available at:-
# http://article.gmane.org/gmane.comp.java.openjdk.hotspot.gc.devel/51/match=gc+log+reader
# Modifications by Y. Srinivas Ramakrishna
#
# The input to this script should be the output from the HotSpot(TM)
# Virtual Machine when run with one or more of the following flags:
#
# -verbose:gc # produces minimal output so statistics are
# # limited, but available in all VMs
#
# -XX:+PrintGCTimeStamps # enables time-based statistics (e.g.,
# # allocation rates, intervals), but only
# # available in JDK 1.4.0 and later.
#
# -XX:+PrintGCDetails # enables more detailed statistics gathering,
# # but only available in JDK 1.4.1 and later.
#
# -XX:-TraceClassUnloading # [1.5.0 and later] disable messages about class
# # unloading, which are enabled as a side-effect
# # by -XX:+PrintGCDetails. The class unloading
# # messages confuse this script and will cause
# # some GC information in the log to be ignored.
# #
# # Note: This option only has an effect in 1.5.0
# # and later. Prior to 1.5.0, the option is
# # accepted, but is overridden by
# # -XX:+PrintGCDetails. In 1.4.2 and earlier
# # releases, use -XX:-ClassUnloading instead (see
# # below).
#
# -XX:-ClassUnloading # disable class unloading, since PrintGCDetails
# # turns on TraceClassUnloading, which cannot be
# # overridden from the command line until 1.5.0.
#
# Recommended command-line with JDK 1.5.0 and later:
#
# java -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails \
# -XX:-TraceClassUnloading ...
#
# Recommended command-line with JDK 1.4.1 and 1.4.2:
#
# java -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails \
# -XX:-ClassUnloading ...
#
# ------------------------------------------------------------------------------
#
# Usage:
#
# PrintGCStats -v cpus=<n> [-v interval=<seconds>] [-v verbose=1] [file ...]
# PrintGCStats -v plot=name [-v plotcolumns=<n>] [-v verbose=1] [file ...]
#
# cpus - number of cpus on the machine where java was run, used to
# compute cpu time available and gc 'load' factors. No default;
# must be specified on the command line (defaulting to 1 is too
# error prone).
#
# ncpu - synonym for cpus, accepted for backward compatibility
#
# interval - print statistics at the end of each interval; requires
# output from -XX:+PrintGCTimeStamps. Default is 0 (disabled).
#
# plot - generate data points useful for plotting one of the collected
# statistics instead of the normal statistics summary. The name
# argument is the name of one of the output statistics, e.g.,
# "gen0t(s)", "cmsRM(s)", "commit0(MB)", etc.
#
# The default output format for time-based statistics such as
# "gen0t(s)" includes four columns, described below. The
# default output format for size-based statistics such as
# "commit0(MB)" includes just the first two columns. The
# number of columns in the output can be set on the command
# line with -v plotcolumns=<N>.
#
# The output columns are:
#
# 1) the starting timestamp if timestamps are present, or a
# simple counter if not
#
# 2) the value of the desired statistic (e.g., the length of a
# cms remark pause).
#
# 3) the ending timestamp (or counter)
#
# 4) the value of the desired statistic (again)
#
# The last column is to make plotting start & stop events
# easier.
#
# plotcolumns - the number of columns to include in the plot data.
#
# verbose - if non-zero, print each item on a separate line in addition
# to the summary statistics
#
# Typical usage:
#
# PrintGCStats -v cpus=4 gc.log > gc.stats
#
# ------------------------------------------------------------------------------
#
# Basic Output statistics:
#
# gen0(s) - young gen collection time, excluding gc_prologue & gc_epilogue.
# gen0t(s) - young gen collection time, including gc_prologue & gc_epilogue
# gen1i(s) - train generation incremental collection
# gen1t(s) - old generation collection/full GC
# cmsIM(s) - CMS initial mark pause
# cmsRM(s) - CMS remark pause
# cmsRS(s) - CMS resize pause
# GC(s) - all stop-the-world GC pauses
# cmsCM(s) - CMS concurrent mark phase
# cmsCP(s) - CMS concurrent preclean phase
# cmsCS(s) - CMS concurrent sweep phase
# cmsCR(s) - CMS concurrent reset phase
# alloc(MB) - object allocation in MB (approximate***)
# promo(MB) - object promotion in MB (approximate***)
# used0(MB) - young gen used memory size (before gc)
# used1(MB) - old gen used memory size (before gc)
# used(MB) - heap space used memory size (before gc) (excludes perm gen)
# commit0(MB) - young gen committed memory size (after gc)
# commit1(MB) - old gen committed memory size (after gc)
# commit(MB) - heap committed memory size (after gc) (excludes perm gen)
# apptime(s) - amount of time application threads were running
# safept(s) - amount of time the VM spent at safepoints (app threads stopped)
#
# *** - these values are approximate because there is no way to track
# allocations that occur directly into older generations.
#
# Some definitions:
#
# 'mutator' or 'mutator thread': a gc-centric term referring to a non-GC
# thread that modifies or 'mutates' the heap by allocating memory and/or
# updating object fields.
#
# promotion: when an object that was allocated in the young generation has
# survived long enough, it is copied, or promoted, into the old generation.
#
# Time-based Output Statistics (require -XX:+PrintGCTimeStamps):
#
# alloc/elapsed_time - allocation rate, based on elapsed time
# alloc/tot_cpu_time - allocation rate, based on total cpu time
# alloc/mut_cpu_time - allocation rate, based on cpu time available to mutators
# promo/elapsed_time - promotion rate, based on elapsed time
# promo/gc0_time - promotion rate, based on young gen gc time
# gc_seq_load - the percentage of cpu cycles used by gc 'serially'
# (i.e., while java application threads are stopped)
# gc_conc_load - the percentage of cpu cycles used by gc 'concurrently'
# (i.e., while java application threads are also running)
# gc_tot_load - the percentage of cpu cycles spent in gc
java -XX:+PrintFlagsFinal -version| grep -i g1
double G1ConcMarkStepDurationMillis = 10.000000 {product}
intx G1ConcRefinementGreenZone = 0 {product}
intx G1ConcRefinementRedZone = 0 {product}
intx G1ConcRefinementServiceIntervalMillis = 300 {product}
uintx G1ConcRefinementThreads = 0 {product}
intx G1ConcRefinementThresholdStep = 0 {product}
intx G1ConcRefinementYellowZone = 0 {product}
intx G1ConfidencePercent = 50 {product}
uintx G1HeapRegionSize = 0 {product}
intx G1MarkRegionStackSize = 1048576 {product}
intx G1RSetRegionEntries = 0 {product}
uintx G1RSetScanBlockSize = 64 {product}
intx G1RSetSparseRegionEntries = 0 {product}
intx G1RSetUpdatingPauseTimePercent = 10 {product}
intx G1RefProcDrainInterval = 10 {product}
uintx G1ReservePercent = 10 {product}
uintx G1SATBBufferEnqueueingThresholdPercent = 60 {product}
intx G1SATBBufferSize = 1024 {product}
intx G1UpdateBufferSize = 256 {product}
bool G1UseAdaptiveConcRefinement = true {product}
bool UseG1GC = false {product}
java version "1.7.0_03"
Java(TM) SE Runtime Environment (build 1.7.0_03-b04)
Java HotSpot(TM) 64-Bit Server VM (build 22.1-b02, mixed mode)
java -XX:+PrintFlagsFinal -version| grep -i Pre
     intx AllocatePrefetchDistance                  = 192             {product}           
     intx AllocatePrefetchInstr                     = 0               {product}           
     intx AllocatePrefetchLines                     = 4               {product}           
     intx AllocatePrefetchStepSize                  = 64              {product}           
     intx AllocatePrefetchStyle                     = 1               {product}           
     bool AlwaysPreTouch                            = false           {product}           
    uintx CMSAbortablePrecleanMinWorkPerIteration   = 100             {product}           
     intx CMSAbortablePrecleanWaitMillis            = 100             {manageable}        
    uintx CMSMaxAbortablePrecleanLoops              = 0               {product}           
     intx CMSMaxAbortablePrecleanTime               = 5000            {product}           
     bool CMSPermGenPrecleaningEnabled              = true            {product}           
    uintx CMSPrecleanDenominator                    = 3               {product}           
    uintx CMSPrecleanIter                           = 3               {product}           
    uintx CMSPrecleanNumerator                      = 2               {product}           
     bool CMSPrecleanRefLists1                      = true            {product}           
     bool CMSPrecleanRefLists2                      = false           {product}           
     bool CMSPrecleanSurvivors1                     = false           {product}           
     bool CMSPrecleanSurvivors2                     = true            {product}           
    uintx CMSPrecleanThreshold                      = 1000            {product}           
     bool CMSPrecleaningEnabled                     = true            {product}           
     bool CompilerThreadHintNoPreempt               = true            {product}           
    uintx G1HeapRegionSize                          = 0               {product}           
     intx InterpreterProfilePercentage              = 33              {product}           
     intx PreBlockSpin                              = 10              {product}           
     intx PreInflateSpin                            = 10              {pd product}

The query to find the total number of databases can be found by executing the following query:

select count(*) from information_schema.SCHEMATA where schema_name not in
('mysql','information_schema');

Rationale

Sampling tools like oprofile or dtrace’s profile provider don’t really provide methods to see what [multithreaded] programs are blocking on – only where they spend CPU time. Though there exist advanced techniques (such as systemtap and dtrace call level probes), it is overkill to build upon that. Poor man doesn’t have time. Poor man needs food.

Method

For a poor developer to understand what a program is doing, he needs to see stacks. Once upon a time (back in Linux 2.4) there was a ‘pstack’ tool for that, Solaris has it too.

Modern Linux systems though do not have such facilities, and one needs to improvise, like.. use debuggers – they can walk threads and provide stacks.

Technology

Getting stacks:

gdb -ex "set pagination 0" -ex "thread apply all bt" \
  --batch -p $(pidof mysqld)

Or for version-impaired (gdb 6.3 and older):

(echo "set pagination 0";
 echo "thread apply all bt";
 echo "quit"; cat /dev/zero ) | gdb -p $(pidof mysqld)

Collapsing traces (awk!):

BEGIN { s = ""; }
/Thread/ { print s; s = ""; }
/^\#/ { if (s != "" ) { s = s "," $4} else { s = $4 } }
END { print s }

Full technology demonstration:

#!/bin/bash
nsamples=1
sleeptime=0
pid=$(pidof mysqld)

for x in $(seq 1 $nsamples)
  do
    gdb -ex "set pagination 0" -ex "thread apply all bt" -batch -p $pid
    sleep $sleeptime
  done | \
awk '
  BEGIN { s = ""; }
  /Thread/ { print s; s = ""; }
  /^\#/ { if (s != "" ) { s = s "," $4} else { s = $4 } }
  END { print s }' | \
sort | uniq -c | sort -r -n -k 1,1

 

Output

291 pthread_cond_wait@@GLIBC_2.3.2,one_thread_per_connection_end,handle_one_connection
 57 read,my_real_read,my_net_read,do_command,handle_one_connection,start_thread
 26 pthread_cond_wait@@GLIBC_2.3.2,os_event_wait_low,os_aio_simulated_handle,fil_aio_wait,io_handler_thread,start_thread
  3 pthread_cond_wait@@GLIBC_2.3.2,os_event_wait_low,srv_purge_worker_thread
  1 select,os_thread_sleep,srv_purge_thread
  1 select,os_thread_sleep,srv_master_thread
  1 select,os_thread_sleep,srv_lock_timeout_and_monitor_thread
  1 select,os_thread_sleep,srv_error_monitor_thread
  1 select,handle_connections_sockets,main,select
  1 read,vio_read_buff,my_real_read,my_net_read,cli_safe_read,handle_slave_io
  1 pthread_cond_wait@@GLIBC_2.3.2,os_event_wait_low,sync_array_wait_event,rw_lock_s_lock_spin,buf_page_get_gen,btr_cur_search_to_nth_level,row_search_for_mysql,ha_innodb::index_read,handler::index_read_idx_map,join_read_const,join_read_const_table,make_join_statistics,JOIN::optimize,mysql_select,handle_select,execute_sqlcom_select,mysql_execute_command,mysql_parse,dispatch_command,do_command,handle_one_connection
  1 pread64,os_file_pread,os_file_read,fil_io,buf_read_page_low,buf_read_page,buf_page_get_gen,btr_cur_search_to_nth_level,row_search_index_entry,row_upd_step,row_update_for_mysql,ha_innodb::delete_row,handler::ha_delete_row,mysql_delete,mysql_execute_command,mysql_parse,Query_log_event::do_apply_event,apply_event_and_update_pos,handle_slave_sql
  1 pread64,os_file_pread,os_file_read,fil_io,buf_read_page_low,buf_read_page,buf_page_get_gen,btr_cur_search_to_nth_level,row_search_for_mysql,ha_innodb::index_read,handler::index_read_idx_map,join_read_const,join_read_const_table,make_join_statistics,JOIN::optimize,mysql_select,handle_select,execute_sqlcom_select,mysql_execute_command,mysql_parse,dispatch_command,do_command,handle_one_connection
  1 do_sigwait,sigwait,signal_hand

Success stories and references

We hear this technology has been used by performance engineers at Google, Facebook, Wikipedia, Intel, Sun Microsystems and other places.

 

Credits

PoorMansProfiler on Facebook

Originally this technology was released as a collaborative effort by Mark Callaghan and Domas Mituzas at this blog post.

 

Extract RPM file using rpm2cpio and cpio command:

$ rpm2cpio any_rpm_package.x86_64.rpm | cpio -idmv

How do I check RAM speed and type (line DDR or DDR2) without opening my computer? I need to purchase RAM and I need to know the exact speed and type installed. How do I find out ram information from a shell prompt?

$ sudo dmidecode --type 17

dmidecode is a tool for dumping a computer’s DMI (some say SMBIOS) table contents in a human-readable format. This table contains a description of the system’s hardware components, as well as other useful pieces of information such as serial numbers and BIOS revision. Thanks to this table, you can retrieve this information without having to probe for the actual hardware. While this is a good point in terms of report speed and safeness, this also makes the presented information possibly unreliable.

G1 collector is concurrent and parallel with more predictability and better useability. It splits the heap into regions and young and old generational spaces are organized in sets of regions. This eliminates the need to fine tune “NewSize/MaxNewSize”. G1 also provides incremental compaction in those regions by “evacuating” the regions that are full and fragmented. To try this G1 collector, you’ll need the aforementioned Fix Pack/Update and the following JVM options:

-XX:+UnlockExperimentalVMOptions -XX:+UseG1GC

In addition, the following options can be used to adjust G1’s characteristics:

To set the max GC pause time goal in milliseconds that G1 will attempt to meet:

-XX:MaxGCPauseMillis

To set the time interval over which GC pauses totaling up to MaxGCPauseMillis may take place:

-XX:GCPauseIntervalMillis

For more information about G1 (how it operates, more options, etc.) see Java HotSpot Garbage Collection.



Hung, Deadlocked, or Looping Process


  • Print thread stack for all Java threads:
    • Control-\
    • kill -QUIT pid
    • jstack pid (or jstack -F pid if jstack pid does not respond)
  • Detect deadlocks:
    • Request deadlock detection: JConsole tool, Threads tab
    • Print information on deadlocked threads: Control-\
    • Print list of concurrent locks owned by each thread: -XX:+PrintConcurrentLocks set, then Control-\
    • Print lock information for a process: jstack -l pid
  • Get a heap histogram for a process:
    • Start Java process with -XX:+PrintClassHistogram, then Control-\
    • jmap -histo pid (with -F option if pid does not respond)
  • Dump Java heap for a process in binary format to file:
    • jmap -dump:format=b,file=filename pid (with -F option if pid does not respond)
  • Print shared object mappings for a process:
    • jmap pid
  • Print heap summary for a process:
    • Control-\
    • jmap -heap pid
  • Print finalization information for a process:
    • jmap -finalizerinfo pid
  • Attach the command-line debugger to a process:
    • jdb -connect sun.jvm.hotspot.jdi.SAPIDAttachingConnector:pid=pid

Post-mortem Diagnostics, Memory Leaks


  • Examine the fatal error log file. Default file name is hs_err_pidpid.log in the working-directory.
  • Create a heap dump:
    • Start the application with HPROF enabled: java -agentlib:hprof=file=file,format=bapplication; then Control-\
    • Start the application with HPROF enabled: java -agentlib:hprof=heap=dump application
    • JConsole tool, MBeans tab
    • Start VM with -XX:+HeapDumpOnOutOfMemoryError; if OutOfMemoryError is thrown, VM generates a heap dump.
  • Browse Java heap dump:
    • jhat heap-dump-file
  • Dump Java heap from core file in binary format to a file:
    • jmap -dump:format=b,file=filename corefile
  • Get a heap histogram for a process:
    • Start Java process with -XX:+PrintClassHistogram, then Control-\
    • jmap -histo pid (with -F option if pid does not respond)
  • Get a heap histogram from a core file:
    • jmap -histo corefile
  • Print shared object mappings from a core file:
    • jmap corefile
  • Print heap summary from a core file:
    • jmap -heap corefile
  • Print finalization information from a core file:
    • jmap -finalizerinfo corefile
  • Print Java configuration information from a core file:
    • jinfo corefile
  • Print thread trace from a core file:
    • jstack corefile
  • Print lock information from a core file:
    • jstack -l corefile
  • Attach the command-line debugger to a core file on the same machine:
    • jdb -connect sun.jvm.hotspot.jdi.SACoreAttachingConnector:javaExecutable=path,core=corefile
  • Attach the command-line debugger to a core file on a different machine:
    • On the machine with the core file: jsadebugd path corefile
      and on the machine with the debugger: jdb -connect sun.jvm.hotspot.jdi.SADebugServerAttachingConnector:debugServerName=machine
  • libumem can be used to debug memory leaks.