Huge slowdown in 'ggspectra' with 'ggplot2' 3.5.0

[aphalo]

@teunbrand @thomasp85

I noticed this problem because locally checking 'ggspectra' started triggering multiple NOTEs for too-long a runing time for examples (as much as 20s), as well as the unit tests of 'ggspectra' taking much longer to run than earlier.

I see a x3 or more increase in run time when redering plots created with autoplot() methods when going from 3.4.4 to 3.5.0 or under the current main branch here. I see this problem both under R 4.4.0 and R 4.3.2 patched. I am on Windows 11.

I see the problem also happening with my derived ggplot() methods, which are called by my derived autoplot() methods, so the something in the ggplot() methods triggers this. The main difference introduced by 'ggspectra' is that the p$data is set to a class derived from data.frame (i.e., the class of the argument passed to data is preserved) and also retains some attributes used to store metadata.

This reprex shows how derived ggplot() methods work, the actual problem is shown farther down.

library(ggspectra)
#> Loading required package: photobiology
#> News at https://www.r4photobiology.info/
#> Loading required package: ggplot2

p <- ggplot(polyester.spct) + geom_line()
class(p$data)
#> [1] "filter_spct"  "generic_spct" "tbl_df"       "tbl"          "data.frame"
get_attributes(p$data)
#> $multiple.wl
#> [1] 1
#> 
#> $Tfr.type
#> [1] "total"
#> 
#> $filter.properties
#> Rfr (/1): 0.074, thickness (mm): 0.125, attenuation mode: absorption.
#> $comment
#> [1] "Smoothed using 'supsmu', span = 0.01"
#> 
#> $what.measured
#> [1] "Polyester, clear film, 0.000125 m thick, Autostat CT5 from McDermit Autotype; new"

^{Created on 2024-02-29 with reprex v2.1.0}

I do not know if the problem is in 'ggspectra' or 'ggplot2' but something in the current 'ggplot2' that was not in earlier versions triggers this problem. What I find disconcerting is that I see with profvis() that the slowdown is mainly caused under 3.5.0 by multiple calls to utils:::readCitationFile() when rendering plots with ggplotGrob() or print(). Clearly there is something in my code in 'ggspectra' that triggers this, as the problem does not seem to affect other plots built within 'ggplot2', or at least not all of them.

The number of calls to utils:::readCitationFile() seems to increase with increasing number of layers in the plots. I give to examples below.

Do you have any idea where I can start looking for the source of this calls to utils:::readCitationFile()?

A simple examples using ggplot(), really dispatched to ggplot.filter_spct().

library(profvis)
library(ggspectra)

ggplot(polyester.spct) + geom_line()

profvis(
  p <- ggplot(polyester.spct) + geom_line(),
  interval = 0.005,
  rerun = TRUE
)

ggpg <- ggplotGrob(p)

profvis(
  ggpg <- ggplotGrob(p),
  interval = 0.005,
  rerun = TRUE
)

and a detail

More examples

Additional examples using autoplot() showing the same pattern, but differing in the number of calls to utils:::readCitationFile().

autoplot(sun.spct)

profvis(
  p <- autoplot(sun.spct),
  interval = 0.005,
  rerun = TRUE
)

ggpg <- ggplotGrob(p)

profvis(
  ggpg <- ggplotGrob(p),
  interval = 0.005,
  rerun = TRUE
)

print(p)

profvis(
  print(p),
  interval = 0.005,
  rerun = TRUE
)

Building p

ggplotGrob()

And a detail

print()

A simpler plot with a single layer

p <- autoplot(sun.spct, annotations = "")

ggpg <- ggplotGrob(p)

profvis(
  ggpg <- ggplotGrob(p),
  interval = 0.005,
  rerun = TRUE
)

And the detail

[teunbrand]

Hi Pedro, thanks for the report! Would you mind posting or pointing to one of these examples that run for a long time?
I don't think profvis gives a complete overview of all function calls, just the ones that are currently running when the time interval is probed.

[aphalo]

Hi, thanks!
I may have already found the culprit. Seems like a call to .data in the arguments passed to aes() is triggering the problem. I will clean these up in the code, test and let you know in an hour or so if this is solved. I think, that the call to .data has been unnecessary for quite some time...

[teunbrand]

My debug attempts were leading down the same path. Specifically it seems that unrowname() wants to throw errors for data pronouns that are then fetched and discarded. Not exactly sure what in the new release would cause this though.

[aphalo]

Hi, here is a something closer to a reprex. Using .data triggers the problem. I added .data time back when aes_() was deprecated. In fact, the help page for aes_() still recommends using .data. In 3.5.0 .data no longer works as expected. The correct plots are created but rendering is much slower than when not using .data.

library(ggplot2)
library(profvis)

p <- ggplot(mtcars, aes(x = mpg, y = disp)) +
  geom_point() +
  facet_grid(gear ~ cyl)

profvis(ggpgrob <- ggplotGrob(p),
        interval = 0.005,
        rerun = TRUE
)

p1 <- ggplot(mtcars, aes(x = .data[["mpg"]], y = .data[["disp"]])) +
  geom_point() +
  facet_grid(gear ~ cyl)

profvis(ggpgrob <- ggplotGrob(p1),
        interval = 0.005,
        rerun = TRUE
)

[teunbrand]

Thanks for providing the examples. I've separated the slowdown with the .data pronoun into its own issue, so that this issue can move on from that if anything else is slowing down ggspectra.

[aphalo]

o.k., no I think that was the main problem, but causes a very noticeable slow down because the plots I was testing contain seven or more layers. Many thnaks!