cli progress bar benchmark

Introduction

We make sure that the timer is not TRUE, by setting it to ten hours.

library(cli)
# 10 hours
cli:::cli_tick_set(10 * 60 * 60 * 1000)
cli_tick_reset()
#> NULL

`__cli_update_due`
#> [1] FALSE

R benchmarks

The timer

fun <- function() NULL
ben_st <- bench::mark(
  `__cli_update_due`,
  fun(),
  .Call(ccli_tick_reset),
  interactive(),
  check = FALSE
)
ben_st
#> # A tibble: 4 × 6
#>   expression                  min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr>             <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 __cli_update_due         8.96ns     20ns 48510971.        0B        0
#> 2 fun()                  140.05ns    161ns  4631155.        0B        0
#> 3 .Call(ccli_tick_reset) 110.01ns    121ns  7540076.        0B        0
#> 4 interactive()           28.99ns     40ns 27501599.        0B        0

ben_st2 <- bench::mark(
  if (`__cli_update_due`) foobar()
)
ben_st2
#> # A tibble: 1 × 6
#>   expression                       min median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr>                     <bch> <bch:>     <dbl> <bch:byt>    <dbl>
#> 1 if (`__cli_update_due`) fooba…  40ns 51.1ns 17549174.        0B        0

`cli_progress_along()`

seq <- 1:100000
ta <- cli_progress_along(seq)
bench::mark(seq[[1]], ta[[1]])
#> # A tibble: 2 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 seq[[1]]      130ns    151ns  5945068.        0B        0
#> 2 ta[[1]]       150ns    180ns  5087156.        0B        0

`for` loop

This is the baseline:

f0 <- function(n = 1e5) {
  x <- 0
  seq <- 1:n
  for (i in seq) {
    x <- x + i %% 2
  }
  x
}

With progress bars:

fp <- function(n = 1e5) {
  x <- 0
  seq <- 1:n
  for (i in cli_progress_along(seq)) {
    x <- x + seq[[i]] %% 2
  }
  x
}

Overhead per iteration:

ben_taf <- bench::mark(f0(), fp())
ben_taf
#> # A tibble: 2 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 f0()         11.7ms   11.8ms      82.4    25.1KB     907.
#> 2 fp()         13.5ms   13.6ms      73.5    83.1KB    1103.

(ben_taf$median[2] - ben_taf$median[1]) / 1e5
#> [1] 17.7ns

ben_taf2 <- bench::mark(f0(1e6), fp(1e6))
#> Warning: Some expressions had a GC in every iteration; so filtering is
#> disabled.

ben_taf2
#> # A tibble: 2 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 f0(1e+06)     129ms    134ms      6.79        0B     62.8
#> 2 fp(1e+06)     143ms    144ms      6.94    1.82KB     62.4

(ben_taf2$median[2] - ben_taf2$median[1]) / 1e6
#> [1] 10.5ns

ben_taf3 <- bench::mark(f0(1e7), fp(1e7))
#> Warning: Some expressions had a GC in every iteration; so filtering is
#> disabled.

ben_taf3
#> # A tibble: 2 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 f0(1e+07)     1.33s    1.33s     0.751        0B     71.3
#> 2 fp(1e+07)      1.5s     1.5s     0.668    1.82KB     62.8

(ben_taf3$median[2] - ben_taf3$median[1]) / 1e7
#> [1] 16.5ns

ben_taf4 <- bench::mark(f0(1e8), fp(1e8))
#> Warning: Some expressions had a GC in every iteration; so filtering is
#> disabled.

ben_taf4
#> # A tibble: 2 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 f0(1e+08)     13.3s    13.3s    0.0753        0B     31.3
#> 2 fp(1e+08)     14.2s    14.2s    0.0702    1.82KB     29.2

(ben_taf4$median[2] - ben_taf4$median[1]) / 1e8
#> [1] 9.5ns

Mapping with `lapply()`

This is the baseline:

f0 <- function(n = 1e5) {
  seq <- 1:n
  ret <- lapply(seq, function(x) {
    x %% 2
  })
  invisible(ret)
}

With an index vector:

f01 <- function(n = 1e5) {
  seq <- 1:n
  ret <- lapply(seq_along(seq), function(i) {
    seq[[i]] %% 2
  })
  invisible(ret)
}

With progress bars:

fp <- function(n = 1e5) {
  seq <- 1:n
  ret <- lapply(cli_progress_along(seq), function(i) {
    seq[[i]] %% 2
  })
  invisible(ret)
}

Overhead per iteration:

ben_tam <- bench::mark(f0(), f01(), fp())
#> Warning: Some expressions had a GC in every iteration; so filtering is
#> disabled.

ben_tam
#> # A tibble: 3 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 f0()         74.6ms   80.5ms     12.0      781KB     20.6
#> 2 f01()        82.3ms   91.6ms      7.56     781KB     17.0
#> 3 fp()        106.8ms  112.2ms      8.57     783KB     17.1

(ben_tam$median[3] - ben_tam$median[1]) / 1e5
#> [1] 317ns

ben_tam2 <- bench::mark(f0(1e6), f01(1e6), fp(1e6))
#> Warning: Some expressions had a GC in every iteration; so filtering is
#> disabled.

ben_tam2
#> # A tibble: 3 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 f0(1e+06)  726.17ms 726.17ms     1.38     7.63MB     4.13
#> 2 f01(1e+06) 957.32ms 957.32ms     1.04     7.63MB     4.18
#> 3 fp(1e+06)     1.81s    1.81s     0.552    7.63MB     2.76

(ben_tam2$median[3] - ben_tam2$median[1]) / 1e6
#> [1] 1.08µs

(ben_tam2$median[3] - ben_tam2$median[2]) / 1e6
#> [1] 854ns

Mapping with purrr

This is the baseline:

f0 <- function(n = 1e5) {
  seq <- 1:n
  ret <- purrr::map(seq, function(x) {
    x %% 2
  })
  invisible(ret)
}

With index vector:

f01 <- function(n = 1e5) {
  seq <- 1:n
  ret <- purrr::map(seq_along(seq), function(i) {
    seq[[i]] %% 2
  })
  invisible(ret)
}

With progress bars:

fp <- function(n = 1e5) {
  seq <- 1:n
  ret <- purrr::map(cli_progress_along(seq), function(i) {
    seq[[i]] %% 2
  })
  invisible(ret)
}

Overhead per iteration:

ben_pur <- bench::mark(f0(), f01(), fp())
ben_pur
#> # A tibble: 3 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 f0()         66.7ms   66.9ms      15.0     884KB     8.97
#> 2 f01()        82.9ms   83.3ms      11.9     781KB     5.94
#> 3 fp()         89.7ms     92ms      10.6     783KB     2.64

(ben_pur$median[3] - ben_pur$median[1]) / 1e5
#> [1] 251ns

(ben_pur$median[3] - ben_pur$median[2]) / 1e5
#> [1] 87.6ns

ben_pur2 <- bench::mark(f0(1e6), f01(1e6), fp(1e6))
#> Warning: Some expressions had a GC in every iteration; so filtering is
#> disabled.

ben_pur2
#> # A tibble: 3 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 f0(1e+06)  813.26ms 813.26ms     1.23     7.63MB     3.69
#> 2 f01(1e+06)    1.03s    1.03s     0.967    7.63MB     2.90
#> 3 fp(1e+06)     1.46s    1.46s     0.683    7.63MB     3.42

(ben_pur2$median[3] - ben_pur2$median[1]) / 1e6
#> [1] 651ns

(ben_pur2$median[3] - ben_pur2$median[2]) / 1e6
#> [1] 429ns

`ticking()`

f0 <- function(n = 1e5) {
  i <- 0
  x <- 0 
  while (i < n) {
    x <- x + i %% 2
    i <- i + 1
  }
  x
}

fp <- function(n = 1e5) {
  i <- 0
  x <- 0 
  while (ticking(i < n)) {
    x <- x + i %% 2
    i <- i + 1
  }
  x
}

ben_tk <- bench::mark(f0(), fp())
#> Warning: Some expressions had a GC in every iteration; so filtering is
#> disabled.

ben_tk
#> # A tibble: 2 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 f0()        13.38ms  19.43ms    52.4      40.2KB     3.88
#> 2 fp()          4.21s    4.21s     0.238   100.7KB     3.09

(ben_tk$median[2] - ben_tk$median[1]) / 1e5
#> [1] 41.9µs

Traditional API

f0 <- function(n = 1e5) {
  x <- 0
  for (i in 1:n) {
    x <- x + i %% 2
  }
  x
}

fp <- function(n = 1e5) {
  cli_progress_bar(total = n)
  x <- 0
  for (i in 1:n) {
    x <- x + i %% 2
    cli_progress_update()
  }
  x
}

ff <- function(n = 1e5) {
  cli_progress_bar(total = n)
  x <- 0
  for (i in 1:n) {
    x <- x + i %% 2
    if (`__cli_update_due`) cli_progress_update()
  }
  x
}

ben_api <- bench::mark(f0(), ff(), fp())
#> Warning: Some expressions had a GC in every iteration; so filtering is
#> disabled.

ben_api
#> # A tibble: 3 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 f0()         11.6ms  11.75ms    82.2      19.9KB     7.83
#> 2 ff()        21.82ms  22.16ms    44.3      28.5KB     5.78
#> 3 fp()          2.05s    2.05s     0.487    25.9KB     2.43

(ben_api$median[3] - ben_api$median[1]) / 1e5
#> [1] 20.4µs

(ben_api$median[2] - ben_api$median[1]) / 1e5
#> [1] 104ns

ben_api2 <- bench::mark(f0(1e6), ff(1e6), fp(1e6))
#> Warning: Some expressions had a GC in every iteration; so filtering is
#> disabled.

ben_api2
#> # A tibble: 3 × 6
#>   expression      min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr> <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 f0(1e+06)     124ms  124.2ms    7.92          0B     7.92
#> 2 ff(1e+06)   238.9ms    260ms    3.85      1.82KB     3.85
#> 3 fp(1e+06)     22.7s    22.7s    0.0440    1.82KB     2.42

(ben_api2$median[3] - ben_api2$median[1]) / 1e6
#> [1] 22.6µs

(ben_api2$median[2] - ben_api2$median[1]) / 1e6
#> [1] 136ns

C benchmarks

Baseline function:

SEXP test_baseline() {
  int i;
  int res = 0;
  for (i = 0; i < 2000000000; i++) {
    res += i % 2;
  }
  return ScalarInteger(res);
}

Switch + modulo check:

SEXP test_modulo(SEXP progress) {
  int i;
  int res = 0;
  int progress_ = LOGICAL(progress)[0];
  for (i = 0; i < 2000000000; i++) {
    if (i % 10000 == 0 && progress_) cli_progress_set(R_NilValue, i);
    res += i % 2;
  }
  return ScalarInteger(res);
}

cli progress bar API:

SEXP test_cli() {
  int i;
  int res = 0;
  SEXP bar = PROTECT(cli_progress_bar(2000000000, NULL));
  for (i = 0; i < 2000000000; i++) {
    if (CLI_SHOULD_TICK) cli_progress_set(bar, i);
    res += i % 2;
  }
  cli_progress_done(bar);
  UNPROTECT(1);
  return ScalarInteger(res);
}

SEXP test_cli_unroll() {
  int i = 0;
  int res = 0;
  SEXP bar = PROTECT(cli_progress_bar(2000000000, NULL));
  int s, final, step = 2000000000 / 100000;
  for (s = 0; s < 100000; s++) {
    if (CLI_SHOULD_TICK) cli_progress_set(bar, i);
    final = (s + 1) * step;
    for (i = s * step; i < final; i++) {
      res += i % 2;
    }
  }
  cli_progress_done(bar);
  UNPROTECT(1);
  return ScalarInteger(res);
}

library(progresstest)
ben_c <- bench::mark(
  test_baseline(),
  test_modulo(),
  test_cli(),
  test_cli_unroll()
)
ben_c
#> # A tibble: 4 × 6
#>   expression             min   median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr>        <bch:tm> <bch:tm>     <dbl> <bch:byt>    <dbl>
#> 1 test_baseline()   631.86ms 631.86ms     1.58     2.08KB        0
#> 2 test_modulo()        1.25s    1.25s     0.800    2.23KB        0
#> 3 test_cli()           1.24s    1.24s     0.807   23.93KB        0
#> 4 test_cli_unroll() 620.12ms 620.12ms     1.61     3.59KB        0

(ben_c$median[3] - ben_c$median[1]) / 2000000000
#> [1] 1ns

Display update

We only update the display a fixed number of times per second. (Currently maximum five times per second.)

Let’s measure how long a single update takes.

Iterator with a bar

cli_progress_bar(total = 100000)
bench::mark(cli_progress_update(force = TRUE), max_iterations = 10000)
#> ■                                  0% | ETA:  5m
#> ■                                  0% | ETA:  2h
#> ■                                  0% | ETA:  1h
#> ■                                  0% | ETA:  1h
#> ■                                  0% | ETA: 49m
#> ■                                  0% | ETA: 42m
#> ■                                  0% | ETA: 38m
#> ■                                  0% | ETA: 34m
#> ■                                  0% | ETA: 31m
#> ■                                  0% | ETA: 29m
#> ■                                  0% | ETA: 27m
#> ■                                  0% | ETA: 26m
#> ■                                  0% | ETA: 25m
#> ■                                  0% | ETA: 23m
#> ■                                  0% | ETA: 23m
#> ■                                  0% | ETA: 22m
#> ■                                  0% | ETA: 21m
#> ■                                  0% | ETA: 20m
#> ■                                  0% | ETA: 20m
#> ■                                  0% | ETA: 19m
#> ■                                  0% | ETA: 19m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 16m
#> ■                                  0% | ETA: 16m
#> ■                                  0% | ETA: 16m
#> ■                                  0% | ETA: 16m
#> ■                                  0% | ETA: 15m
#> ■                                  0% | ETA: 15m
#> ■                                  0% | ETA: 15m
#> ■                                  0% | ETA: 15m
#> ■                                  0% | ETA: 15m
#> ■                                  0% | ETA: 15m
#> ■                                  0% | ETA: 14m
#> ■                                  0% | ETA: 14m
#> ■                                  0% | ETA: 14m
#> ■                                  0% | ETA: 14m
#> ■                                  0% | ETA: 14m
#> ■                                  0% | ETA: 14m
#> ■                                  0% | ETA: 14m
#> ■                                  0% | ETA: 14m
#> ■                                  0% | ETA: 14m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 13m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> ■                                  0% | ETA: 12m
#> # A tibble: 1 × 6
#>   expression                       min median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr>                    <bch:> <bch:>     <dbl> <bch:byt>    <dbl>
#> 1 cli_progress_update(force = … 5.44ms 5.53ms      178.    1.34MB     2.02

cli_progress_done()

Iterator without a bar

cli_progress_bar(total = NA)
bench::mark(cli_progress_update(force = TRUE), max_iterations = 10000)
#> ⠙ 1 done (457/s) | 3ms
#> ⠹ 2 done (75/s) | 27ms
#> ⠸ 3 done (90/s) | 34ms
#> ⠼ 4 done (101/s) | 40ms
#> ⠴ 5 done (108/s) | 47ms
#> ⠦ 6 done (114/s) | 53ms
#> ⠧ 7 done (119/s) | 60ms
#> ⠇ 8 done (122/s) | 66ms
#> ⠏ 9 done (125/s) | 72ms
#> ⠋ 10 done (128/s) | 79ms
#> ⠙ 11 done (130/s) | 85ms
#> ⠹ 12 done (132/s) | 92ms
#> ⠸ 13 done (133/s) | 98ms
#> ⠼ 14 done (134/s) | 105ms
#> ⠴ 15 done (136/s) | 111ms
#> ⠦ 16 done (137/s) | 118ms
#> ⠧ 17 done (137/s) | 124ms
#> ⠇ 18 done (138/s) | 131ms
#> ⠏ 19 done (139/s) | 137ms
#> ⠋ 20 done (140/s) | 144ms
#> ⠙ 21 done (140/s) | 150ms
#> ⠹ 22 done (141/s) | 157ms
#> ⠸ 23 done (141/s) | 164ms
#> ⠼ 24 done (142/s) | 170ms
#> ⠴ 25 done (142/s) | 176ms
#> ⠦ 26 done (143/s) | 183ms
#> ⠧ 27 done (143/s) | 189ms
#> ⠇ 28 done (143/s) | 196ms
#> ⠏ 29 done (144/s) | 202ms
#> ⠋ 30 done (144/s) | 209ms
#> ⠙ 31 done (144/s) | 215ms
#> ⠹ 32 done (145/s) | 222ms
#> ⠸ 33 done (145/s) | 228ms
#> ⠼ 34 done (145/s) | 235ms
#> ⠴ 35 done (146/s) | 241ms
#> ⠦ 36 done (146/s) | 248ms
#> ⠧ 37 done (146/s) | 254ms
#> ⠇ 38 done (146/s) | 261ms
#> ⠏ 39 done (146/s) | 267ms
#> ⠋ 40 done (146/s) | 274ms
#> ⠙ 41 done (145/s) | 284ms
#> ⠹ 42 done (145/s) | 290ms
#> ⠸ 43 done (145/s) | 297ms
#> ⠼ 44 done (145/s) | 303ms
#> ⠴ 45 done (146/s) | 309ms
#> ⠦ 46 done (146/s) | 316ms
#> ⠧ 47 done (146/s) | 322ms
#> ⠇ 48 done (146/s) | 329ms
#> ⠏ 49 done (147/s) | 335ms
#> ⠋ 50 done (147/s) | 341ms
#> ⠙ 51 done (147/s) | 348ms
#> ⠹ 52 done (147/s) | 354ms
#> ⠸ 53 done (147/s) | 361ms
#> ⠼ 54 done (147/s) | 367ms
#> ⠴ 55 done (147/s) | 374ms
#> ⠦ 56 done (147/s) | 380ms
#> ⠧ 57 done (148/s) | 387ms
#> ⠇ 58 done (148/s) | 393ms
#> ⠏ 59 done (148/s) | 400ms
#> ⠋ 60 done (148/s) | 406ms
#> ⠙ 61 done (148/s) | 412ms
#> ⠹ 62 done (148/s) | 419ms
#> ⠸ 63 done (148/s) | 425ms
#> ⠼ 64 done (148/s) | 432ms
#> ⠴ 65 done (149/s) | 438ms
#> ⠦ 66 done (149/s) | 444ms
#> ⠧ 67 done (149/s) | 451ms
#> ⠇ 68 done (149/s) | 457ms
#> ⠏ 69 done (149/s) | 464ms
#> ⠋ 70 done (149/s) | 470ms
#> ⠙ 71 done (149/s) | 477ms
#> ⠹ 72 done (149/s) | 483ms
#> ⠸ 73 done (149/s) | 490ms
#> ⠼ 74 done (149/s) | 496ms
#> ⠴ 75 done (149/s) | 503ms
#> ⠦ 76 done (149/s) | 509ms
#> ⠧ 77 done (150/s) | 516ms
#> ⠇ 78 done (150/s) | 522ms
#> # A tibble: 1 × 6
#>   expression                       min median `itr/sec` mem_alloc `gc/sec`
#>   <bch:expr>                    <bch:> <bch:>     <dbl> <bch:byt>    <dbl>
#> 1 cli_progress_update(force = … 6.33ms 6.44ms      155.     198KB     2.04

cli_progress_done()

Gábor Csárdi

2024-06-23

Introduction

R benchmarks

The timer

`cli_progress_along()`

`for` loop

Mapping with `lapply()`

Mapping with purrr

`ticking()`

Traditional API

C benchmarks

Display update

Iterator with a bar

Iterator without a bar

cli progress bar benchmark

Gábor Csárdi

2024-06-23

Introduction

R benchmarks

The timer

cli_progress_along()

for loop

Mapping with lapply()

Mapping with purrr

ticking()

Traditional API

C benchmarks

Display update

Iterator with a bar

Iterator without a bar

`cli_progress_along()`

`for` loop

Mapping with `lapply()`

`ticking()`