It is through improving our ability to deliver software that organizations can deliver features faster, pivot when needed, respond to compliance and security changes, and take advantage of fast feedback to attract new customers and delight existing ones.
Forsgren PhD, Nicole. Accelerate (p. 31).
Often time I come across situations where server comes under high CPU load. There is a simple way to find out which application thread(s) are responsible for the load. To get the thread which has the highest CPU load, issue:
ps -mo pid,lwp,stime,time,cpu -p
LWP stands for Light-Weight Process and typically refers to kernel threads. To identify the thread, get the LWP with highest CPU load, and convert its unique number (xxxx) into a hexadecimal number (0xxxx).
Get the java stack dump using jstack -l
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)
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.
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.
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
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
We hear this technology has been used by performance engineers at Google, Facebook, Wikipedia, Intel, Sun Microsystems and other places.
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
PermGen holds the metadata about classes that have been loaded/created. This information is garbage collected like the other parts of the heap, however there are rough edges that can prevent this from happening, class loaders in particular. Generally, the amount of PermGen space needed is small in relation to the rest of the heap.
How do I know what classes are being loaded or unloaded? Use the command line options
-XX:+TraceClassLoading and -XX:+TraceClassUnloading .
If you suspect that that classloader isn’t the issue, use -verbose:class to investigate classes which have been loaded. This, as it suggests, will be very verbose.
How do you increase PermGen space?
Increase using the -XX:MaxPermSize option.
Conversion Table
| HEX | DECIMAL | BINARY |
| 0 | 0 = 0+0+0+0 | 0000 |
| 1 | 1 = 0+0+0+1 | 0001 |
| 2 | 2 = 0+0+2+0 | 0010 |
| 3 | 3 = 0+0+2+1 | 0011 |
| 4 | 4 = 0+2+0+0 | 0100 |
| 5 | 5 = 0+4+0+1 | 0101 |
| 6 | 6 = 0+4+2+0 | 0110 |
| 7 | 7 = 0+4+2+1 | 0111 |
| 8 | 8 = 8+0+0+0 | 1000 |
| 9 | 9 = 8+0+0+1 | 1001 |
| A | 10 = 8+0+2+0 | 1010 |
| B | 11 = 8+0+0+1 | 1011 |
| C | 12 = 8+4+0+0 | 1100 |
| D | 13 = 8+4+0+1 | 1101 |
| E | 14 = 8+4+2+0 | 1110 |
| F | 15 = 8+4+2+1 | 1111 |
Data Types and Data Structures
| Primitive Type | Size | Minimum Value | Maximum Value |
| char | 16-bit | Unicode 0 | Unicode 216-1 |
| byte | 8-bit | -128 | +127 |
| short | 16-bit | -215 (-32,768) |
+215-1 (32,767) |
| int | 32-bit | -231 (-2,147,483,648) |
+231-1 (2,147,483,647) |
| long | 64-bit | -263 (-9,223,372,036,854,775,808) |
+263-1 (9,223,372,036,854,775,807) |
| float | 32-bit | 32-bit IEEE 754 floating-point numbers | |
| double | 64-bit | 64-bit IEEE 754 floating-point numbers | |
| boolean | 1-bit | true or false | |
| void | —– | —– | Void |
The new 5.5 is now available with “Semisynchronous Replication”. This comes as an addition to the built-in asynchronous replication. MySQL replication is asynchronous by default. Events written to the binary logs on the Master server being retrieved by the slave server(s). Unfortunately, the Master server has no knowledge of when the slave has retrieved or processed these events. As a result, when Master crashes, transactions committed on Master, might have not have been committed on the slave server(s). In other words, there is no guarantee that any event will ever reach any slave.
In case of “Semisynchronous Replication”, the Master server blockes the transaction commit until at least one of the slave servers acknowledges the it has received all the events for that transaction. Obviously, this is great for consistency, however it brings up questions about replication over the WWW which isn’t an uncommon practice. In case of hitting the timeout limit (in case of no response from any of the slave servers), the Master server reverts back to asynchronous replication.
From MySQL support:
To understand what the “semi” in “semisynchronous replication” means, compare it with asynchronous and fully synchronous replication:
* With asynchronous replication, the master writes events to its binary log and slaves request them when they are ready. There is no guarantee that any event will ever reach any slave.
* With fully synchronous replication, when a master commits a transaction, all slaves also will have committed the transaction before the master returns to the session that performed the transaction. The drawback of this is that there might be a lot of delay to complete a transaction.
* Semisynchronous replication falls between asynchronous and fully synchronous replication. The master waits after commit only until at least one slave has received and logged the events. It does not wait for all slaves to acknowledge receipt, and it requires only receipt, not that the events have been fully executed and committed on the slave side.