@@ -35,60 +35,74 @@ pak::pak("emilhvitfeldt/debrief")
3535
3636First, create a profvis profile of some code:
3737
38- ``` {r example, eval = FALSE }
38+ ``` {r example}
3939library(profvis)
4040library(debrief)
4141
42- # Profile some code
42+ # Define some functions to profile
43+ process_data <- function(n) {
44+ raw <- generate_data(n)
45+ cleaned <- clean_data(raw)
46+ summarize_data(cleaned)
47+ }
48+
49+ generate_data <- function(n) {
50+ x <- rnorm(n)
51+ y <- runif(n)
52+
53+ data.frame(x = x, y = y, z = x * y)
54+ }
55+
56+ clean_data <- function(df) {
57+ df <- df[complete.cases(df), ]
58+ df$x_scaled <- scale(df$x)
59+ df$category <- cut(df$y, breaks = 5)
60+ df
61+ }
62+
63+ summarize_data <- function(df) {
64+ list(
65+ means = colMeans(df[, c("x", "y", "z")]),
66+ sds = apply(df[, c("x", "y", "z")], 2, sd),
67+ counts = table(df$category),
68+ text = paste(round(df$x, 2), collapse = ", ")
69+ )
70+ }
71+
72+ # Profile the data pipeline
4373p <- profvis({
44- x <- rep(1, 1e6)
45- y <- cumsum(x)
46- z <- paste(1:1000, collapse = ", ")
74+ results <- lapply(1:5, function(i) process_data(1e5))
4775})
4876```
4977
5078### Quick Summary
5179
5280Get a comprehensive overview with ` pv_summary() ` :
5381
54- ``` {r summary, eval = FALSE }
82+ ``` {r summary}
5583pv_summary(p)
56- #> ======================================================================
57- #> PROFILING SUMMARY
58- #> ======================================================================
59- #>
60- #> Total time: 120 ms (12 samples @ 10 ms interval)
61- #> Source references: available
62- #>
63- #> --- TOP FUNCTIONS BY SELF-TIME ---
64- #> 40 ms ( 33.3%) paste
65- #> 30 ms ( 25.0%) cumsum
66- #> 20 ms ( 16.7%) rep
67- #> ...
6884```
6985
7086### Time Analysis
7187
7288Analyze where time is spent:
7389
74- ``` {r time, eval = FALSE }
90+ ``` {r time}
7591# Self-time: time spent directly in each function
7692pv_self_time(p)
7793
7894# Total time: time spent in function + all its callees
7995pv_total_time(p)
8096
8197# Filter to significant functions only
82- pv_self_time(p, min_pct = 5) # >= 5% of time
83- pv_self_time(p, n = 10, min_time_ms = 50)
84- # Top 10 functions with >= 50ms
98+ pv_self_time(p, min_pct = 5) # >= 5% of time
8599```
86100
87101### Hot Spots
88102
89103Find the hottest lines and call paths:
90104
91- ``` {r hotspots, eval = FALSE }
105+ ``` {r hotspots}
92106# Hot source lines with context
93107pv_print_hot_lines(p, n = 5, context = 3)
94108
@@ -100,42 +114,30 @@ pv_print_hot_paths(p, n = 10)
100114
101115Deep dive into a specific function:
102116
103- ``` {r focus, eval = FALSE}
104- pv_focus(p, "paste")
105- #> ======================================================================
106- #> FOCUS: paste
107- #> ======================================================================
108- #>
109- #> --- Time Analysis ---
110- #> Total time: 40 ms ( 33.3%) - time on call stack
111- #> Self time: 40 ms ( 33.3%) - time at top of stack
112- #> Child time: 0 ms ( 0.0%) - time in callees
113- #>
114- #> --- Called By ---
115- #> 12 calls (100.0%) (top-level)
116- #> ...
117+ ``` {r focus}
118+ pv_focus(p, "clean_data")
117119```
118120
119121### Call Relationships
120122
121123Understand who calls what:
122124
123- ``` {r calls, eval = FALSE }
125+ ``` {r calls}
124126# Who calls this function?
125- pv_callers(p, "cumsum ")
127+ pv_callers(p, "clean_data ")
126128
127129# What does this function call?
128- pv_callees(p, "my_function ")
130+ pv_callees(p, "process_data ")
129131
130132# Full caller/callee analysis
131- pv_print_callers_callees(p, "target_func ")
133+ pv_print_callers_callees(p, "summarize_data ")
132134```
133135
134136### Memory Analysis
135137
136138Track memory allocations:
137139
138- ``` {r memory, eval = FALSE }
140+ ``` {r memory}
139141# Memory by function
140142pv_print_memory(p, n = 10, by = "function")
141143
@@ -147,102 +149,75 @@ pv_print_memory(p, n = 10, by = "line")
147149
148150Visualize the call tree:
149151
150- ``` {r flame, eval = FALSE }
152+ ``` {r flame}
151153pv_flame(p, width = 70, min_pct = 2)
152- #> ======================================================================
153- #> FLAME GRAPH (text)
154- #> ======================================================================
155- #>
156- #> Total time: 120 ms | Width: 70 chars | Min: 2%
157- #>
158- #> [======================================================================] (root) 100%
159- #> [=======================] paste (33.3%)
160- #> [=================] cumsum (25.0%)
161- #> [===========] rep (16.7%)
162154```
163155
164156### Compare Profiles
165157
166158Measure optimization impact:
167159
168- ``` {r compare, eval = FALSE}
169- # Before optimization
170- p1 <- profvis(slow_function())
160+ ``` {r compare}
161+ # Approach 1: Growing vectors in a loop (slow)
162+ p_slow <- profvis({
163+ result <- c()
164+ for (i in 1:20000) {
165+ result <- c(result, sqrt(i) * log(i))
166+ }
167+ })
171168
172- # After optimization
173- p2 <- profvis(fast_function())
169+ # Approach 2: Vectorized with memory allocation
170+ p_fast <- profvis({
171+ x <- rnorm(5e6)
172+ y <- cumsum(x)
173+ z <- paste(head(round(x, 2), 50000), collapse = ", ")
174+ })
174175
175176# Compare two profiles
176- pv_print_compare(p1, p2)
177- #> ======================================================================
178- #> PROFILE COMPARISON
179- #> ======================================================================
180- #>
181- #> --- Overall ---
182- #> IMPROVED: 500 ms -> 120 ms (4.2x faster, saved 380 ms)
183- #>
184- #> --- Biggest Changes ---
185- #> Function Before After Diff Change
186- #> ------------------------------------------------------------------------
187- #> slow_helper 300 50 -250 -83%
188- #> ...
189-
190- # Compare multiple optimization approaches
177+ pv_print_compare(p_slow, p_fast)
178+
179+ # Approach 3: Data frame operations
180+ p_dataframe <- profvis({
181+ df <- data.frame(
182+ a = rnorm(1e6),
183+ b = runif(1e6),
184+ c = sample(letters, 1e6, replace = TRUE)
185+ )
186+ df$d <- df$a * df$b
187+ result <- aggregate(d ~ c, data = df, FUN = mean)
188+ })
189+
190+ # Compare all three approaches
191191pv_print_compare_many(
192- baseline = p1 ,
193- vectorized = p2 ,
194- parallel = p3
192+ growing_vector = p_slow ,
193+ vectorized = p_fast ,
194+ dataframe_ops = p_dataframe
195195)
196- #> ======================================================================
197- #> MULTI-PROFILE COMPARISON
198- #> ======================================================================
199- #>
200- #> Rank Profile Time (ms) Samples vs Fastest
201- #> --------------------------------------------------------------
202- #> 1* parallel 85 9 fastest
203- #> 2 vectorized 120 12 1.41x
204- #> 3 baseline 500 50 5.88x
205196```
206197
207198### Diagnostics
208199
209200Detect GC pressure and get optimization suggestions:
210201
211- ``` {r diagnostics, eval = FALSE }
202+ ``` {r diagnostics}
212203# Detect GC pressure (indicates memory allocation issues)
213204pv_print_gc_pressure(p)
214- #> [!!!] GC consuming 35.0% of time (350 ms)
215- #> High garbage collection overhead. Look for growing vectors,
216- #> repeated data frame operations, or unnecessary copies.
217205
218206# Get actionable optimization suggestions
219207pv_print_suggestions(p)
220- #> === Priority 1 ===
221- #>
222- #> [hot line] R/analysis.R:42
223- #> Line 'result <- rbind(result, row)' consumes 25% of time.
224- #> Potential impact: 250 ms (25%)
225208```
226209
227210### Export for AI Agents
228211
229212Export structured data for programmatic access:
230213
231- ``` {r export, eval = FALSE}
232- # Export as JSON for AI agents or external tools
233- json <- pv_to_json(p)
234-
235- # Include system info for reproducibility
236- json <- pv_to_json(p, system_info = TRUE)
237-
214+ ``` {r export}
238215# Export as R list for programmatic access
239216results <- pv_to_list(p)
240- results$self_time # Data frame of functions by self-time
241- results$hot_lines # Data frame of hot source lines
242- results$suggestions # Optimization suggestions
217+ names(results)
243218
244- # Export only specific analyses
245- pv_to_json(p, include = c(" self_time", "hot_lines", "gc_pressure"))
219+ # Data frame of functions by self-time
220+ results$ self_time
246221```
247222
248223## Available Functions
0 commit comments