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              0        0 1059553087.        0B        0
#> 2 fun()                      99ns    100ns    5086252.        0B        0
#> 3 .Call(ccli_tick_reset)     99ns    100ns    7910867.        0B        0
#> 4 interactive()                 0        0  998807203.        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…     0      0 37658699.        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]]       99ns    100ns  6657415.        0B        0
#> 2 ta[[1]]        99ns    200ns  6073915.        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())
#> Warning: Some expressions had a GC in every iteration; so filtering is
#> disabled.
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()         15.7ms   18.4ms      52.5    25.2KB     50.6
#> 2 fp()         20.9ms   21.2ms      45.8    83.2KB     45.8
(ben_taf$median[2] - ben_taf$median[1]) / 1e5
#> [1] 28.3ns

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)     181ms    186ms      4.95        0B     47.8
#> 2 fp(1e+06)     198ms    198ms      5.01    1.88KB     46.7
(ben_taf2$median[2] - ben_taf2$median[1]) / 1e6
#> [1] 11.7ns

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.79s    1.79s     0.560        0B     35.8
#> 2 fp(1e+07)     1.94s    1.94s     0.517    1.88KB     27.9
(ben_taf3$median[2] - ben_taf3$median[1]) / 1e7
#> [1] 14.8ns

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)     17.6s    17.6s    0.0568        0B     35.7
#> 2 fp(1e+08)     19.7s    19.7s    0.0507    1.88KB     30.7
(ben_taf4$median[2] - ben_taf4$median[1]) / 1e8
#> [1] 21.1ns

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()         90.1ms   97.7ms      7.93     781KB     13.9
#> 2 f01()         105ms    111ms      8.67     781KB     10.4
#> 3 fp()        113.5ms  128.6ms      7.20     783KB     14.4
(ben_tam$median[3] - ben_tam$median[1]) / 1e5
#> [1] 309ns

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)  879.41ms 879.41ms     1.14     7.63MB     3.41
#> 2 f01(1e+06)    1.15s    1.15s     0.873    7.63MB     5.24
#> 3 fp(1e+06)     1.39s    1.39s     0.718    7.63MB     3.59
(ben_tam2$median[3] - ben_tam2$median[1]) / 1e6
#> [1] 513ns
(ben_tam2$median[3] - ben_tam2$median[2]) / 1e6
#> [1] 247ns

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()         77.3ms   77.9ms      12.8     884KB     9.60
#> 2 f01()        92.6ms   93.2ms      10.7     781KB    10.7 
#> 3 fp()         93.1ms  100.7ms      10.1     783KB     6.73
(ben_pur$median[3] - ben_pur$median[1]) / 1e5
#> [1] 228ns
(ben_pur$median[3] - ben_pur$median[2]) / 1e5
#> [1] 74.2ns

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)  895.89ms 895.89ms     1.12     7.63MB     3.35
#> 2 f01(1e+06)    1.11s    1.11s     0.897    7.63MB     2.69
#> 3 fp(1e+06)     1.48s    1.48s     0.678    7.63MB     2.71
(ben_pur2$median[3] - ben_pur2$median[1]) / 1e6
#> [1] 579ns
(ben_pur2$median[3] - ben_pur2$median[2]) / 1e6
#> [1] 361ns

`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()        18.18ms  22.36ms    44.7      40.3KB     1.94
#> 2 fp()          5.28s    5.28s     0.189   100.8KB     2.46
(ben_tk$median[2] - ben_tk$median[1]) / 1e5
#> [1] 52.6µ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()        17.73ms  26.55ms    34.7      19.9KB     5.79
#> 2 ff()        28.96ms  33.81ms    28.5      28.6KB     1.90
#> 3 fp()          2.91s    2.91s     0.344    26.1KB     2.41
(ben_api$median[3] - ben_api$median[1]) / 1e5
#> [1] 28.8µs
(ben_api$median[2] - ben_api$median[1]) / 1e5
#> [1] 72.6ns

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)   161.5ms  161.8ms    6.17          0B     6.17
#> 2 ff(1e+06)   228.8ms  228.9ms    4.37      1.88KB     4.37
#> 3 fp(1e+06)     26.8s    26.8s    0.0373    1.88KB     2.20
(ben_api2$median[3] - ben_api2$median[1]) / 1e6
#> [1] 26.7µs
(ben_api2$median[2] - ben_api2$median[1]) / 1e6
#> [1] 67.1ns

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()      1.28s    1.28s     0.782    2.08KB        0
#> 2 test_modulo()        2.17s    2.17s     0.462    2.24KB        0
#> 3 test_cli()           1.61s    1.61s     0.622   23.69KB        0
#> 4 test_cli_unroll()    1.28s    1.28s     0.782    3.35KB        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:  6m
#> ■                                  0% | ETA:  2h
#> ■                                  0% | ETA:  2h
#> ■                                  0% | ETA:  1h
#> ■                                  0% | ETA:  1h
#> ■                                  0% | ETA:  1h
#> ■                                  0% | ETA:  1h
#> ■                                  0% | ETA: 46m
#> ■                                  0% | ETA: 42m
#> ■                                  0% | ETA: 39m
#> ■                                  0% | ETA: 37m
#> ■                                  0% | ETA: 35m
#> ■                                  0% | ETA: 33m
#> ■                                  0% | ETA: 32m
#> ■                                  0% | ETA: 30m
#> ■                                  0% | ETA: 29m
#> ■                                  0% | ETA: 28m
#> ■                                  0% | ETA: 27m
#> ■                                  0% | ETA: 27m
#> ■                                  0% | ETA: 26m
#> ■                                  0% | ETA: 25m
#> ■                                  0% | ETA: 25m
#> ■                                  0% | ETA: 24m
#> ■                                  0% | ETA: 24m
#> ■                                  0% | ETA: 23m
#> ■                                  0% | ETA: 23m
#> ■                                  0% | ETA: 22m
#> ■                                  0% | ETA: 22m
#> ■                                  0% | ETA: 22m
#> ■                                  0% | ETA: 21m
#> ■                                  0% | ETA: 21m
#> ■                                  0% | ETA: 21m
#> ■                                  0% | ETA: 21m
#> ■                                  0% | ETA: 20m
#> ■                                  0% | ETA: 20m
#> ■                                  0% | ETA: 20m
#> ■                                  0% | ETA: 20m
#> ■                                  0% | ETA: 19m
#> ■                                  0% | ETA: 19m
#> ■                                  0% | ETA: 19m
#> ■                                  0% | ETA: 19m
#> ■                                  0% | ETA: 19m
#> ■                                  0% | ETA: 19m
#> ■                                  0% | ETA: 19m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 18m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> ■                                  0% | ETA: 17m
#> # 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 = … 7.28ms  7.5ms      131.    1.34MB     2.04
cli_progress_done()

Iterator without a bar

cli_progress_bar(total = NA)
bench::mark(cli_progress_update(force = TRUE), max_iterations = 10000)
#> ⠙ 1 done (335/s) | 4ms
#> ⠹ 2 done (56/s) | 36ms
#> ⠸ 3 done (67/s) | 45ms
#> ⠼ 4 done (74/s) | 54ms
#> ⠴ 5 done (80/s) | 63ms
#> ⠦ 6 done (84/s) | 72ms
#> ⠧ 7 done (87/s) | 81ms
#> ⠇ 8 done (90/s) | 90ms
#> ⠏ 9 done (92/s) | 98ms
#> ⠋ 10 done (94/s) | 107ms
#> ⠙ 11 done (95/s) | 116ms
#> ⠹ 12 done (97/s) | 125ms
#> ⠸ 13 done (98/s) | 133ms
#> ⠼ 14 done (99/s) | 142ms
#> ⠴ 15 done (100/s) | 151ms
#> ⠦ 16 done (101/s) | 160ms
#> ⠧ 17 done (101/s) | 169ms
#> ⠇ 18 done (102/s) | 177ms
#> ⠏ 19 done (102/s) | 186ms
#> ⠋ 20 done (103/s) | 195ms
#> ⠙ 21 done (103/s) | 204ms
#> ⠹ 22 done (104/s) | 212ms
#> ⠸ 23 done (104/s) | 221ms
#> ⠼ 24 done (105/s) | 230ms
#> ⠴ 25 done (105/s) | 238ms
#> ⠦ 26 done (105/s) | 247ms
#> ⠧ 27 done (106/s) | 256ms
#> ⠇ 28 done (106/s) | 265ms
#> ⠏ 29 done (106/s) | 273ms
#> ⠋ 30 done (107/s) | 282ms
#> ⠙ 31 done (107/s) | 291ms
#> ⠹ 32 done (107/s) | 300ms
#> ⠸ 33 done (107/s) | 308ms
#> ⠼ 34 done (107/s) | 317ms
#> ⠴ 35 done (108/s) | 326ms
#> ⠦ 36 done (108/s) | 335ms
#> ⠧ 37 done (108/s) | 343ms
#> ⠇ 38 done (108/s) | 352ms
#> ⠏ 39 done (108/s) | 361ms
#> ⠋ 40 done (108/s) | 370ms
#> ⠙ 41 done (109/s) | 378ms
#> ⠹ 42 done (109/s) | 387ms
#> ⠸ 43 done (109/s) | 396ms
#> ⠼ 44 done (109/s) | 404ms
#> ⠴ 45 done (109/s) | 413ms
#> ⠦ 46 done (109/s) | 422ms
#> ⠧ 47 done (109/s) | 431ms
#> ⠇ 48 done (109/s) | 439ms
#> ⠏ 49 done (109/s) | 448ms
#> ⠋ 50 done (108/s) | 462ms
#> ⠙ 51 done (109/s) | 471ms
#> ⠹ 52 done (109/s) | 479ms
#> ⠸ 53 done (109/s) | 488ms
#> ⠼ 54 done (109/s) | 496ms
#> ⠴ 55 done (109/s) | 505ms
#> ⠦ 56 done (109/s) | 514ms
#> ⠧ 57 done (109/s) | 523ms
#> ⠇ 58 done (109/s) | 532ms
#> # 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 = … 8.54ms 8.74ms      114.     198KB     2.04
cli_progress_done()

Gábor Csárdi

2023-11-03

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

2023-11-03

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()`