search

r-dbi / RPostgres

A DBI-compliant interface to PostgreSQL
https://rpostgres.r-dbi.org
Other
328 stars 78 forks source link

Curious bug with transaction and `dbSendQuery()` #424

Open mgirlich opened 1 year ago

mgirlich commented 1 year ago

I'm not sure if this is expected behaviour, a bug in RPostgres, or a bug in Postgres itself. But it took quite some time to figure out the issue...

con <- DBI::dbConnect(RPostgres::Postgres())

write_table <- function(n) {
  DBI::dbWriteTable(
    con,
    "df_x",
    tibble::tibble(x = 1:n),
    temporary = TRUE,
    overwrite = TRUE
  )
}

DBI::dbWithTransaction(
  con, {
    write_table(2e3)
    res <- DBI::dbSendQuery(con, "SELECT * FROM df_x")
    DBI::dbFetch(res, n = 0)
    DBI::dbClearResult(res)
    DBI::dbGetQuery(con, "SELECT * FROM df_x LIMIT 1")
  }
)
#> Error: Failed to prepare query: ERROR:  current transaction is aborted, commands ignored until end of transaction block

# Interestingly, this works if the table is small
DBI::dbWithTransaction(
  con, {
    write_table(200)
    res <- DBI::dbSendQuery(con, "SELECT * FROM df_x")
    DBI::dbFetch(res, n = 0)
    DBI::dbClearResult(res)
    DBI::dbGetQuery(con, "SELECT * FROM df_x LIMIT 1")
  }
)
#>   x
#> 1 1

Created on 2023-03-09 with reprex v2.0.2

krlmlr commented 1 year ago

Thanks, interesting. I can repro locally on Linux with Postgres 12 and write_table(1e5) .

krlmlr commented 1 year ago

Confirmed with Postgres 14 and 15 on macOS aarch64, built with client 14.5.

Reprex that uses simpler libpq calls under the hood, with variants:

con <- DBI::dbConnect(RPostgres::Postgres())

write_table <- function(n) {
  DBI::dbWriteTable(
    con,
    "df_x",
    tibble::tibble(x = 1:n),
    temporary = TRUE,
    overwrite = TRUE
  )
}

# Install with `R_PLOGR_ENABLE=1 R CMD INSTALL .` to enable the code below
# init_logging("VERB")

DBI::dbBegin(con)

# Setup
write_table(2e3)

res <- DBI::dbSendQuery(con, "SELECT * FROM df_x", immediate = TRUE)
# Also causes failure with:
# res <- DBI::dbSendQuery(con, "SELECT * FROM df_x")

invisible(DBI::dbFetch(res, n = 500))
# Also causes failure with:
# invisible(DBI::dbFetch(res, n = 0))
# invisible(DBI::dbFetch(res, n = 1))
# Successful with:
# invisible(DBI::dbFetch(res, n = 800))
DBI::dbClearResult(res)

# This is the failing call:
DBI::dbGetQuery(con, "SELECT * FROM df_x LIMIT 1", immediate = TRUE)
#> Error: Failed to fetch row : ERROR:  current transaction is aborted, commands ignored until end of transaction block

# Also failing with:
# DBI::dbGetQuery(con, "SELECT * FROM df_x LIMIT 1")
# DBI::dbGetQuery(con, "SELECT * FROM df_x LIMIT 10", immediate = TRUE)
# DBI::dbGetQuery(con, "SELECT * FROM df_x", immediate = TRUE)

# Not reached in case of failure
DBI::dbCommit(con)

Created on 2023-03-16 with reprex v2.0.2

@Antonov548: can you reproduce this with the most recent development (bleeding edge) version of Postgres and libpq? (Is there a Docker image that we can use? Otherwise, we'll need to build from source I'm afraid.)

mgirlich commented 1 year ago

How curious that it is successful for n = 800. A quick loop shows that:

library(tidyverse)

con <- DBI::dbConnect(RPostgres::Postgres())

write_table <- function(n) {
  DBI::dbWriteTable(
    con,
    "df_x",
    tibble::tibble(x = 1:n),
    temporary = TRUE,
    overwrite = TRUE
  )
}

f <- function(n) {
  DBI::dbWithTransaction(
    con, {
      write_table(2e3)
      res <- DBI::dbSendQuery(con, "SELECT * FROM df_x", immediate = TRUE)
      invisible(DBI::dbFetch(res, n = n))
      DBI::dbClearResult(res)
      DBI::dbGetQuery(con, "SELECT * FROM df_x LIMIT 1", immediate = TRUE)
    }
  )

  TRUE
}

results <- map(
  1:2e3,
  \(n) safely(f, otherwise = FALSE)(n = n)
)

results_df <- tibble(
  n = seq_along(results),
  success = map_lgl(results, "result")
)

purrr::map(results, "error") |> unique()
#> [[1]]
#> <Rcpp::exception: Failed to fetch row: ERROR:  current transaction is aborted, commands ignored until end of transaction block
#> >
#> 
#> [[2]]
#> NULL

results_df |>
  ggplot(aes(n, success)) +
  geom_line()

Created on 2023-03-16 with reprex v2.0.2

krlmlr commented 3 months ago

This no longer fails for me with libpq 14.11 run against Postgres 15. Are you still seeing this behavior?

mgirlich commented 3 months ago

Running with Postgres 15.2 and the dev version of RPostgres I still get the error.

Not sure which libpq version this is. Does this help?

otool -L /usr/local/opt/postgresql@15/lib/libpq.5.dylib
/usr/local/opt/postgresql@15/lib/libpq.5.dylib:
    /usr/local/opt/postgresql@15/lib/libpq.5.dylib (compatibility version 5.0.0, current version 5.15.0)
    /usr/local/opt/gettext/lib/libintl.8.dylib (compatibility version 13.0.0, current version 13.0.0)
    /usr/local/opt/openssl@3/lib/libssl.3.dylib (compatibility version 3.0.0, current version 3.0.0)
    /usr/local/opt/openssl@3/lib/libcrypto.3.dylib (compatibility version 3.0.0, current version 3.0.0)
    /usr/local/opt/krb5/lib/libgssapi_krb5.2.2.dylib (compatibility version 2.0.0, current version 2.2.0)
    /usr/lib/libSystem.B.dylib (compatibility version 1.0.0, current version 1336.61.1)
    /System/Library/Frameworks/LDAP.framework/Versions/A/LDAP (compatibility version 1.0.0, current version 2.4.0)
DBI::dbGetInfo(RPostgres::Postgres())
#> $driver.version
#> [1] '1.4.6.9006'
#> 
#> $client.version
#> [1] '15.2'

con <- DBI::dbConnect(RPostgres::Postgres())

write_table <- function(n) {
  DBI::dbWriteTable(
    con,
    "df_x",
    tibble::tibble(x = 1:n),
    temporary = TRUE,
    overwrite = TRUE
  )
}

DBI::dbBegin(con)

write_table(2e3)

res <- DBI::dbSendQuery(con, "SELECT * FROM df_x")

invisible(DBI::dbFetch(res, n = 500))
DBI::dbClearResult(res)

# This is the failing call:
DBI::dbGetQuery(con, "SELECT * FROM df_x LIMIT 1", immediate = TRUE)
#> Error: Failed to fetch row : ERROR:  current transaction is aborted, commands ignored until end of transaction block

Created on 2024-04-03 with reprex v2.1.0

Session info ``` r sessioninfo::session_info() #> ─ Session info ─────────────────────────────────────────────────────────────── #> setting value #> version R version 4.3.0 (2023-04-21) #> os macOS 14.4.1 #> system x86_64, darwin20 #> ui X11 #> language (EN) #> collate en_US.UTF-8 #> ctype en_US.UTF-8 #> tz UTC #> date 2024-04-03 #> pandoc 3.1.1 @ /Applications/RStudio.app/Contents/Resources/app/quarto/bin/tools/ (via rmarkdown) #> #> ─ Packages ─────────────────────────────────────────────────────────────────── #> package * version date (UTC) lib source #> bit 4.0.5 2022-11-15 [1] CRAN (R 4.3.0) #> bit64 4.0.5 2020-08-30 [1] CRAN (R 4.3.0) #> blob 1.2.4 2023-03-17 [1] CRAN (R 4.3.0) #> cli 3.6.2 2023-12-11 [1] CRAN (R 4.3.0) #> DBI 1.2.2 2024-02-16 [1] CRAN (R 4.3.2) #> digest 0.6.35 2024-03-11 [1] CRAN (R 4.3.2) #> evaluate 0.23 2023-11-01 [1] CRAN (R 4.3.0) #> fansi 1.0.6 2023-12-08 [1] CRAN (R 4.3.0) #> fastmap 1.1.1 2023-02-24 [1] CRAN (R 4.3.0) #> fs 1.6.3 2023-07-20 [1] CRAN (R 4.3.0) #> generics 0.1.3 2022-07-05 [1] CRAN (R 4.3.0) #> glue 1.7.0 2024-01-09 [1] CRAN (R 4.3.0) #> hms 1.1.3 2023-03-21 [1] CRAN (R 4.3.0) #> htmltools 0.5.8 2024-03-25 [1] CRAN (R 4.3.2) #> knitr 1.45 2023-10-30 [1] CRAN (R 4.3.0) #> lifecycle 1.0.4 2023-11-07 [1] CRAN (R 4.3.0) #> lubridate 1.9.3 2023-09-27 [1] CRAN (R 4.3.0) #> magrittr 2.0.3 2022-03-30 [1] CRAN (R 4.3.0) #> pillar 1.9.0 2023-03-22 [1] CRAN (R 4.3.0) #> pkgconfig 2.0.3 2019-09-22 [1] CRAN (R 4.3.0) #> purrr 1.0.2 2023-08-10 [1] CRAN (R 4.3.0) #> R.cache 0.16.0 2022-07-21 [1] CRAN (R 4.3.0) #> R.methodsS3 1.8.2 2022-06-13 [1] CRAN (R 4.3.0) #> R.oo 1.26.0 2024-01-24 [1] CRAN (R 4.3.2) #> R.utils 2.12.3 2023-11-18 [1] CRAN (R 4.3.0) #> reprex 2.1.0 2024-01-11 [1] CRAN (R 4.3.0) #> rlang 1.1.3 2024-01-10 [1] CRAN (R 4.3.0) #> rmarkdown 2.26 2024-03-05 [1] CRAN (R 4.3.2) #> RPostgres 1.4.6.9006 2024-04-02 [1] Github (r-dbi/RPostgres@a69fce0) #> rstudioapi 0.16.0 2024-03-24 [1] CRAN (R 4.3.2) #> sessioninfo 1.2.2 2021-12-06 [1] CRAN (R 4.3.0) #> styler 1.10.2 2023-08-29 [1] CRAN (R 4.3.0) #> tibble 3.2.1 2023-03-20 [1] CRAN (R 4.3.0) #> timechange 0.3.0 2024-01-18 [1] CRAN (R 4.3.0) #> utf8 1.2.4 2023-10-22 [1] CRAN (R 4.3.0) #> vctrs 0.6.5 2023-12-01 [1] CRAN (R 4.3.0) #> withr 3.0.0 2024-01-16 [1] CRAN (R 4.3.0) #> xfun 0.43 2024-03-25 [1] CRAN (R 4.3.2) #> yaml 2.3.8 2023-12-11 [1] CRAN (R 4.3.0) #> #> [1] /Library/Frameworks/R.framework/Versions/4.3-x86_64/Resources/library #> #> ────────────────────────────────────────────────────────────────────────────── ```
krlmlr commented 3 months ago

This seems to be libpq 15.2 . I need to work on my setup (https://github.com/r-dbi/docker) to test with different libpq versions.