従来のプロファイラーがどのように機能するかを考えると、この課題に対する一般的な自由ソフトウェアソリューションを思い付くのは簡単なはずです。
問題を2つの部分に分けてみましょう。
データの収集
Webアプリケーションを個々の構成要素(API、関数)に分割し、これらの各部分が完了するまでにかかる時間を測定できると仮定します。各部分は1日に数千回呼び出されるため、複数のホストで1日程度にわたってこのデータを収集できます。1日が終わると、かなり大きくて関連性の高いデータセットができあがります。
エピファニー#1: 「関数」を「 URL 」に置き換えます。既存のWebログは「それ」です。必要なデータはすでにあります。
- Web APIの各部分は、リクエストURLによって定義されます(場合によってはいくつかのパラメーターを使用)
- ラウンドトリップ時間(多くの場合マイクロ秒単位)が各行に表示されますこのデータを使用して、1日(週、月)に相当する行があります。
したがって、Webアプリケーションの分散されたすべての部分の標準Webログにアクセスできれば、問題の1つ(データの収集)は解決されます。
データの提示
これでビッグデータセットができましたが、それでも本当の洞察はありません。どうすれば洞察を得ることができますか?
Epiphany#2:(複数の)Webサーバーログを直接視覚化します。
写真は1000語の価値があります。どの写真を使用できますか?
数十万または数百万行の複数のWebサーバーログを短い要約に凝縮する必要があります。これにより、パフォーマンスに関するほとんどのストーリーがわかります。言い換えると、目標はプロファイラーのようなレポートを生成することです。さらに良いのは、Webログから直接グラフィカルなプロファイラーレポートを生成することです。
マップできると想像してみてください。
- 1次元への通話遅延
- 別のディメンションへの呼び出しの数、および
- 色に対する関数の恒等式(基本的には3次元)
そのような図の1つ:APIによるレイテンシーのスタック密度チャートを以下に示します(関数名は説明のために作成されました)。
チャート:

この例からのいくつかの観察
- アプリケーションには、3つの根本的に異なる「世界」を表す3つのモーダル分布があります。
- 最速の応答は、約300マイクロ秒の遅延を中心としています。これらの応答は、ニスキャッシュからのものです
- 2番目に速く、平均で0.01秒弱かかりますが、中間層のWebアプリケーション(Apache / Tomcat)によって提供されるさまざまなAPIからのものです。
- 最も遅い応答は、約0.1秒を中心とし、応答に数秒かかる場合があり、SQLデータベースへのラウンドトリップが含まれます。
アプリケーションでキャッシュ効果がどれほど劇的になるかを確認できます(x軸はlog10スケールであることに注意してください)。
どのAPIが高速か低速かを具体的に確認できるため、何に焦点を当てるべきかがわかります。
毎日最も頻繁に呼び出されるAPIを確認できます。また、それらのいくつかはめったに呼び出されないため、チャート上でそれらの色を確認することさえ困難であることがわかります。
どうやってするの?
最初のステップは、必要なサブセットデータを前処理してログから抽出することです。ここでは、複数のログに対するUnixの「cut」のような簡単なユーティリティで十分な場合があります。また、複数の類似したURLを、「登録」や「購入」などの関数/APIを説明する短い文字列に折りたたむ必要がある場合もあります。ロードバランサーによって生成されたマルチホスト統合ログビューがある場合、このタスクの方が簡単な場合があります。API(URL)の名前とそのレイテンシーのみを抽出するため、TABで区切られた1組の列を持つ1つの大きなファイルになります。
*API_Name Latency_in_microSecs*
func_01 32734
func_01 32851
func_06 598452
...
func_11 232734
次に、結果のデータペアに対して以下のRスクリプトを実行して、必要なグラフを作成します(Hadley Wickhamのすばらしいggplot2ライブラリを使用)。
出来上がり!
チャートを生成するためのコード
最後に、API +LatencyTSVデータファイルからグラフを作成するコードは次のとおりです。
#!/usr/bin/Rscript --vanilla
#
# Generate stacked chart of API latencies by API from a TSV data-set
#
# ariel faigon - Dec 2012
#
.libPaths(c('~/local/lib/R',
'/usr/lib/R/library',
'/usr/lib/R/site-library'
))
suppressPackageStartupMessages(library(ggplot2))
# grid lib needed for 'unit()':
suppressPackageStartupMessages(library(grid))
#
# Constants: width, height, resolution, font-colors and styles
# Adapt to taste
#
wh.ratio = 2
WIDTH = 8
HEIGHT = WIDTH / wh.ratio
DPI = 200
FONTSIZE = 11
MyGray = gray(0.5)
title.theme = element_text(family="FreeSans", face="bold.italic",
size=FONTSIZE)
x.label.theme = element_text(family="FreeSans", face="bold.italic",
size=FONTSIZE-1, vjust=-0.1)
y.label.theme = element_text(family="FreeSans", face="bold.italic",
size=FONTSIZE-1, angle=90, vjust=0.2)
x.axis.theme = element_text(family="FreeSans", face="bold",
size=FONTSIZE-1, colour=MyGray)
y.axis.theme = element_text(family="FreeSans", face="bold",
size=FONTSIZE-1, colour=MyGray)
#
# Function generating well-spaced & well-labeled y-axis (count) breaks
#
yscale_breaks <- function(from.to) {
from <- 0
to <- from.to[2]
# round to 10 ceiling
to <- ceiling(to / 10.0) * 10
# Count major breaks on 10^N boundaries, include the 0
n.maj = 1 + ceiling(log(to) / log(10))
# if major breaks are too few, add minor-breaks half-way between them
n.breaks <- ifelse(n.maj < 5, max(5, n.maj*2+1), n.maj)
breaks <- as.integer(seq(from, to, length.out=n.breaks))
breaks
}
#
# -- main
#
# -- process the command line args: [tsv_file [png_file]]
# (use defaults if they aren't provided)
#
argv <- commandArgs(trailingOnly = TRUE)
if (is.null(argv) || (length(argv) < 1)) {
argv <- c(Sys.glob('*api-lat.tsv')[1])
}
tsvfile <- argv[1]
stopifnot(! is.na(tsvfile))
pngfile <- ifelse(is.na(argv[2]), paste(tsvfile, '.png', sep=''), argv[2])
# -- Read the data from the TSV file into an internal data.frame d
d <- read.csv(tsvfile, sep='\t', head=F)
# -- Give each data column a human readable name
names(d) <- c('API', 'Latency')
#
# -- Convert microseconds Latency (our weblog resolution) to seconds
#
d <- transform(d, Latency=Latency/1e6)
#
# -- Trim the latency axis:
# Drop the few 0.001% extreme-slowest outliers on the right
# to prevent them from pushing the bulk of the data to the left
Max.Lat <- quantile(d$Latency, probs=0.99999)
d <- subset(d, Latency < Max.Lat)
#
# -- API factor pruning
# Drop rows where the APIs is less than small % of total calls
#
Rare.APIs.pct <- 0.001
if (Rare.APIs.pct > 0.0) {
d.N <- nrow(d)
API.counts <- table(d$API)
d <- transform(d, CallPct=100.0*API.counts[d$API]/d.N)
d <- d[d$CallPct > Rare.APIs.pct, ]
d.N.new <- nrow(d)
}
#
# -- Adjust legend item-height &font-size
# to the number of distinct APIs we have
#
API.count <- nlevels(as.factor(d$API))
Legend.LineSize <- ifelse(API.count < 20, 1.0, 20.0/API.count)
Legend.FontSize <- max(6, as.integer(Legend.LineSize * (FONTSIZE - 1)))
legend.theme = element_text(family="FreeSans", face="bold.italic",
size=Legend.FontSize,
colour=gray(0.3))
# -- set latency (X-axis) breaks and labels (s.b made more generic)
lat.breaks <- c(0.00001, 0.0001, 0.001, 0.01, 0.1, 1, 10)
lat.labels <- sprintf("%g", lat.breaks)
#
# -- Generate the chart using ggplot
#
p <- ggplot(data=d, aes(x=Latency, y=..count../1000.0, group=API, fill=API)) +
geom_bar(binwidth=0.01) +
scale_x_log10(breaks=lat.breaks, labels=lat.labels) +
scale_y_continuous(breaks=yscale_breaks) +
ggtitle('APIs Calls & Latency Distribution') +
xlab('Latency in seconds - log(10) scale') +
ylab('Call count (in 1000s)') +
theme(
plot.title=title.theme,
axis.title.y=y.label.theme,
axis.title.x=x.label.theme,
axis.text.x=x.axis.theme,
axis.text.y=y.axis.theme,
legend.text=legend.theme,
legend.key.height=unit(Legend.LineSize, "line")
)
#
# -- Save the plot into the png file
#
ggsave(p, file=pngfile, width=WIDTH, height=HEIGHT, dpi=DPI)