Rprof と profvis でコードをプロファイリングする

プロファイリングとは

Rprof()の開始と停止

# Pattern — do not run Rprof inside knitr/Quarto
# Rprof('my_profile.prof', interval = 0.01)
#
# slow_function <- function(n) {
#   x <- numeric(n)
#   for (i in seq_len(n)) x[i] <- sqrt(i)
#   sum(x)
# }
# slow_function(500000)
#
# Rprof(NULL)  # stop profiling

summaryRprof()で結果を読み取る

# After Rprof() run:
# prof <- summaryRprof('my_profile.prof')
# head(prof$by.self)
#
# Example output columns:
#            self.time self.pct total.time total.pct
# slow_fn        1.22     61.0       1.98      99.0
# sqrt           0.76     38.0       0.76      38.0
# sum            0.02      1.0       0.02       1.0

Self時間とTotal時間の違い

# Conceptual example:
# wrapper() -> process_data() -> slow_sort()
#
# total.pct: wrapper=100, process_data=90, slow_sort=85
# self.pct:  wrapper=5,   process_data=5,  slow_sort=85
#
# => slow_sort is the real bottleneck to fix.
cat('High total + low self => the culprit is a callee function
')

profvisの紹介

# library(profvis)
#
# profvis({
#   n <- 200000
#   x <- numeric(n)
#   for (i in seq_len(n)) x[i] <- log(i)
#   total <- sum(x)
#   sorted <- sort(x)
# })

profvisのフレームグラフを読み取る

# Reading the flame graph:
# - Each horizontal bar = one function on the call stack
# - Width proportional to time spent
# - Bottom = outermost caller, top = deepest callee
# - Click a bar to zoom in
# - 'Memory' tab shows allocation by line
cat('profvis shows self time per source line — invaluable for tight loops
')

ホットスポットを特定する

# Before fix — growing vector in loop (common hot spot)
# profvis reveals repeated reallocations:
# result <- c()
# for (i in 1:50000) result <- c(result, i^2)
#
# After fix — pre-allocated:
# result <- numeric(50000)
# for (i in 1:50000) result[i] <- i^2
cat('Pre-allocation eliminates the most common loop hot spot
')

メモリ割り当てをプロファイリングする

# Memory profiling with Rprof:
# Rprof('mem.prof', interval = 0.01, memory.profiling = TRUE)
# ... slow code ...
# Rprof(NULL)
# prof <- summaryRprof('mem.prof', memory = 'both')
# head(prof$by.self)
#
# profvis also shows mem delta per line automatically
cat('Memory profiling pinpoints allocation hot spots causing GC pauses
')

実際のパイプラインをプロファイリングする

# Workflow:
# 1. profvis({ full_pipeline() })   => identify Stage 3 is 80% of time
# 2. Rewrite Stage 3 (vectorize / use data.table)
# 3. profvis({ full_pipeline() })   => confirm Stage 3 now < 10%
# 4. system.time({ full_pipeline() }) => confirm overall speedup
cat('Profile -> identify -> fix -> re-profile is the correct cycle
')

Rprofのサンプリングにおける制限

# Rprof interval = 0.01s => functions faster than 10ms may not appear
# For sub-millisecond work use microbenchmark:
#   microbenchmark(expr1, expr2, times = 1000L)
#
# For C-level profiling use external tools:
#   - Instruments (macOS)
#   - perf (Linux)
cat('Rprof is for R-level profiling; use microbenchmark for micro-timing
')

Rのプロファイリングにおけるベストプラクティス

# Clean session profiling checklist:
# 1. Restart R (Ctrl+Shift+F10 in RStudio)
# 2. Load only required packages
# 3. Run once to warm up
# 4. profvis({ ... })  on second run
# 5. Compare before/after with system.time()
cat('Always profile with realistic data in a clean R session
')

クイックチェック：RprofのSelf時間とTotal時間

プロファイリングツールのまとめ