Merge pull request #38 from reside-ic/mrc-5048

mrc-5048: Add request ID into logs

.github/workflows/R-CMD-check.yaml

@@ -1,14 +1,10 @@
-# For help debugging build failures open an issue on the RStudio community with the 'github-actions' tag.
-# https://community.rstudio.com/new-topic?category=Package%20development&tags=github-actions
+# Workflow derived from https://github.com/r-lib/actions/tree/v2/examples
+# Need help debugging build failures? Start at https://github.com/r-lib/actions#where-to-find-help
 on:
   push:
-    branches:
-      - main
-      - master
+    branches: [main, master]
   pull_request:
-    branches:
-      - main
-      - master
+    branches: [main, master]
 
 name: R-CMD-check
 
@@ -22,63 +18,35 @@ jobs:
       fail-fast: false
       matrix:
         config:
+          - {os: macos-latest,   r: 'release'}
           - {os: windows-latest, r: 'release'}
-          - {os: macOS-latest, r: 'release'}
-          - {os: ubuntu-20.04, r: 'release', rspm: "https://packagemanager.rstudio.com/cran/__linux__/focal/latest"}
-          - {os: ubuntu-20.04, r: 'devel', rspm: "https://packagemanager.rstudio.com/cran/__linux__/focal/latest"}
+          - {os: ubuntu-latest,   r: 'devel', http-user-agent: 'release'}
+          - {os: ubuntu-latest,   r: 'release'}
+          - {os: ubuntu-latest,   r: 'oldrel-1'}
+
+    # Shorter timeout to prevent mac builders hanging for 6 hours!
+    timeout-minutes: 30
 
     env:
-      R_REMOTES_NO_ERRORS_FROM_WARNINGS: true
-      RSPM: ${{ matrix.config.rspm }}
       GITHUB_PAT: ${{ secrets.GITHUB_TOKEN }}
+      R_KEEP_PKG_SOURCE: yes
 
     steps:
-      - uses: actions/checkout@v2
+      - uses: actions/checkout@v3
+
+      - uses: r-lib/actions/setup-pandoc@v2
 
       - uses: r-lib/actions/setup-r@v2
         with:
           r-version: ${{ matrix.config.r }}
+          http-user-agent: ${{ matrix.config.http-user-agent }}
+          use-public-rspm: true
 
-      - uses: r-lib/actions/setup-pandoc@v2
-
-      - name: Query dependencies
-        run: |
-          install.packages('remotes')
-          saveRDS(remotes::dev_package_deps(dependencies = TRUE), ".github/depends.Rds", version = 2)
-          writeLines(sprintf("R-%i.%i", getRversion()$major, getRversion()$minor), ".github/R-version")
-        shell: Rscript {0}
-
-      - name: Cache R packages
-        if: runner.os != 'Windows'
-        uses: actions/cache@v2
+      - uses: r-lib/actions/setup-r-dependencies@v2
         with:
-          path: ${{ env.R_LIBS_USER }}
-          key: ${{ runner.os }}-${{ hashFiles('.github/R-version') }}-1-${{ hashFiles('.github/depends.Rds') }}
-          restore-keys: ${{ runner.os }}-${{ hashFiles('.github/R-version') }}-1-
-
-      - name: Install system dependencies
-        if: runner.os == 'Linux'
-        run: |
-          while read -r cmd
-          do
-            eval sudo $cmd
-          done < <(Rscript -e 'writeLines(remotes::system_requirements("ubuntu", "20.04"))')
-
-      - name: Install dependencies
-        run: |
-          remotes::install_deps(dependencies = TRUE)
-          remotes::install_cran("rcmdcheck")
-        shell: Rscript {0}
-
-      - name: Check
-        env:
-          _R_CHECK_CRAN_INCOMING_REMOTE_: false
-        run: rcmdcheck::rcmdcheck(args = c("--no-manual", "--as-cran"), error_on = "warning", check_dir = "check")
-        shell: Rscript {0}
+          extra-packages: any::rcmdcheck
+          needs: check
 
-      - name: Upload check results
-        if: failure()
-        uses: actions/upload-artifact@main
+      - uses: r-lib/actions/check-r-package@v2
         with:
-          name: ${{ runner.os }}-r${{ matrix.config.r }}-results
-          path: check
+          upload-snapshots: true

.github/workflows/pkgdown.yaml

@@ -1,48 +1,46 @@
+# Workflow derived from https://github.com/r-lib/actions/tree/v2/examples
+# Need help debugging build failures? Start at https://github.com/r-lib/actions#where-to-find-help
 on:
   push:
-    branches:
-      - main
-      - master
+    branches: [main, master]
+  pull_request:
+    branches: [main, master]
+  release:
+    types: [published]
+  workflow_dispatch:
 
 name: pkgdown
 
 jobs:
   pkgdown:
-    runs-on: macOS-latest
+    runs-on: ubuntu-latest
+    # Only restrict concurrency for non-PR jobs
+    concurrency:
+      group: pkgdown-${{ github.event_name != 'pull_request' || github.run_id }}
     env:
       GITHUB_PAT: ${{ secrets.GITHUB_TOKEN }}
     steps:
-      - uses: actions/checkout@v2
-
-      - uses: r-lib/actions/setup-r@v2
+      - uses: actions/checkout@v3
 
       - uses: r-lib/actions/setup-pandoc@v2
 
-      - name: Query dependencies
-        run: |
-          install.packages('remotes')
-          saveRDS(remotes::dev_package_deps(dependencies = TRUE), ".github/depends.Rds", version = 2)
-          writeLines(sprintf("R-%i.%i", getRversion()$major, getRversion()$minor), ".github/R-version")
-        shell: Rscript {0}
+      - uses: r-lib/actions/setup-r@v2
+        with:
+          use-public-rspm: true
 
-      - name: Cache R packages
-        uses: actions/cache@v2
+      - uses: r-lib/actions/setup-r-dependencies@v2
         with:
-          path: ${{ env.R_LIBS_USER }}
-          key: ${{ runner.os }}-${{ hashFiles('.github/R-version') }}-1-${{ hashFiles('.github/depends.Rds') }}
-          restore-keys: ${{ runner.os }}-${{ hashFiles('.github/R-version') }}-1-
+          extra-packages: any::pkgdown, local::.
+          needs: website
 
-      - name: Install dependencies
-        run: |
-          remotes::install_deps(dependencies = TRUE)
-          install.packages("pkgdown", type = "binary")
+      - name: Build site
+        run: pkgdown::build_site_github_pages(new_process = FALSE, install = FALSE)
         shell: Rscript {0}
 
-      - name: Install package
-        run: R CMD INSTALL .
-
-      - name: Deploy package
-        run: |
-          git config --local user.email "[email protected]"
-          git config --local user.name "GitHub Actions"
-          Rscript -e 'pkgdown::deploy_to_branch(new_process = FALSE)'
+      - name: Deploy to GitHub pages 🚀
+        if: github.event_name != 'pull_request'
+        uses: JamesIves/[email protected]
+        with:
+          clean: false
+          branch: gh-pages
+          folder: docs

.github/workflows/test-coverage.yaml

@@ -1,48 +1,50 @@
+# Workflow derived from https://github.com/r-lib/actions/tree/v2/examples
+# Need help debugging build failures? Start at https://github.com/r-lib/actions#where-to-find-help
 on:
   push:
-    branches:
-      - main
-      - master
+    branches: [main, master]
   pull_request:
-    branches:
-      - main
-      - master
+    branches: [main, master]
 
 name: test-coverage
 
 jobs:
   test-coverage:
-    runs-on: macOS-latest
+    runs-on: ubuntu-latest
     env:
       GITHUB_PAT: ${{ secrets.GITHUB_TOKEN }}
+
     steps:
-      - uses: actions/checkout@v2
+      - uses: actions/checkout@v3
 
       - uses: r-lib/actions/setup-r@v2
+        with:
+          use-public-rspm: true
 
-      - uses: r-lib/actions/setup-pandoc@v2
+      - uses: r-lib/actions/setup-r-dependencies@v2
+        with:
+          extra-packages: any::covr
+          needs: coverage
 
-      - name: Query dependencies
+      - name: Test coverage
         run: |
-          install.packages('remotes')
-          saveRDS(remotes::dev_package_deps(dependencies = TRUE), ".github/depends.Rds", version = 2)
-          writeLines(sprintf("R-%i.%i", getRversion()$major, getRversion()$minor), ".github/R-version")
+          covr::codecov(
+            quiet = FALSE,
+            clean = FALSE,
+            install_path = file.path(Sys.getenv("RUNNER_TEMP"), "package")
+          )
         shell: Rscript {0}
 
-      - name: Cache R packages
-        uses: actions/cache@v2
-        with:
-          path: ${{ env.R_LIBS_USER }}
-          key: ${{ runner.os }}-${{ hashFiles('.github/R-version') }}-1-${{ hashFiles('.github/depends.Rds') }}
-          restore-keys: ${{ runner.os }}-${{ hashFiles('.github/R-version') }}-1-
-
-      - name: Install dependencies
+      - name: Show testthat output
+        if: always()
         run: |
-          install.packages(c("remotes"))
-          remotes::install_deps(dependencies = TRUE)
-          remotes::install_cran("covr")
-        shell: Rscript {0}
+          ## --------------------------------------------------------------------
+          find ${{ runner.temp }}/package -name 'testthat.Rout*' -exec cat '{}' \; || true
+        shell: bash
 
-      - name: Test coverage
-        run: covr::codecov()
-        shell: Rscript {0}
+      - name: Upload test results
+        if: failure()
+        uses: actions/upload-artifact@v3
+        with:
+          name: coverage-test-failures
+          path: ${{ runner.temp }}/package

.lintr

@@ -1,6 +1,7 @@
 linters: with_defaults(
     object_length_linter = NULL,
     object_usage_linter = NULL,
-    cyclocomp_linter = NULL
+    cyclocomp_linter = NULL,
+    indentation_linter = NULL
     )
 exclusions: list("tests/testthat.R")

DESCRIPTION

@@ -18,23 +18,24 @@ Depends: R (>= 3.6.0)
 Imports:
     R6,
     V8,
+    ids,
     jsonlite,
     jsonvalidate (>= 1.2.2),
+    lgr,
     plumber
 Suggests:
     callr,
     fs,
     httr,
     knitr,
-    lgr,
     mockery,
     pkgload,
     rmarkdown,
     roxygen2,
     testthat,
     withr
 Roxygen: list(markdown = TRUE)
-RoxygenNote: 7.2.1
+RoxygenNote: 7.3.1
 VignetteBuilder: knitr
 Remotes: ropensci/jsonvalidate
 Config/testthat/edition: 3

R/filter.R

@@ -1,5 +1,6 @@
-porcelain_filters <- function(req, res) {
+porcelain_filters <- function(logger) {
   list(query_string = porcelain_filter_query_string,
+       request_id = porcelain_filter_request_id(logger),
        post_body = porcelain_filter_post_body,
        metadata = porcelain_filter_metadata)
 }
@@ -33,3 +34,17 @@ porcelain_filter_metadata <- function(req, res) {
   req$received_time <- now_utc()
   plumber::forward()
 }
+
+
+porcelain_filter_request_id <- function(logger) {
+  force(logger)
+  function(req, res) {
+    request_id <- req$HTTP_X_REQUEST_ID %||% ids::uuid()
+    req$REQUEST_ID <- request_id
+    res$setHeader("x-request-id", request_id)
+    if (!is.null(logger)) {
+      set_request_id_filter(logger, request_id)
+    }
+    plumber::forward()
+  }
+}

R/logging.R

@@ -1,3 +1,5 @@
+LOG_FILTER_REQUEST_ID_NAME <- "log_filter_request_id" # nolint
+
 ##' Create a json-emitting logger, using the 'lgr' package.
 ##'
 ##' @title Create logger
@@ -33,10 +35,11 @@ porcelain_logger <- function(log_level = "info", name = NULL, path = NULL) {
     appender <- lgr::AppenderJson$new(path)
   }
   logger$add_appender(appender, name = "json")
+  logger$add_filter(cache[[LOG_FILTER_REQUEST_ID_NAME]],
+                    name = LOG_FILTER_REQUEST_ID_NAME)
   logger
 }
 
-
 ## Plumber has stages preroute -> postroute -> preserialize -> postserialize
 ##
 ## We hook up the first bit of logging up against postroute as by that
@@ -89,6 +92,8 @@ porcelain_log_postserialize <- function(logger) {
     logger_detailed(logger, "trace", req, "postserialize", "response",
                     body = describe_body(value$body))
 
+    set_request_id_filter(logger, NA_character_)
+
     value
   }
 }
@@ -117,3 +122,10 @@ describe_body <- function(body) {
   }
   body
 }
+
+
+set_request_id_filter <- function(logger, request_id) {
+  if (LOG_FILTER_REQUEST_ID_NAME %in% names(logger$filters)) {
+    cache[[LOG_FILTER_REQUEST_ID_NAME]]$values$request_id <- request_id
+  }
+}

R/porcelain.R

@@ -33,7 +33,8 @@ porcelain <- R6::R6Class(
     initialize = function(..., validate = FALSE, logger = NULL) {
       ## NOTE: it's not totally clear what the correct environment
       ## here is.
-      super$initialize(NULL, porcelain_filters(), new.env(parent = .GlobalEnv))
+      super$initialize(NULL, porcelain_filters(logger),
+                       new.env(parent = .GlobalEnv))
       private$validate <- porcelain_validate_default(validate)
       self$setErrorHandler(porcelain_error_handler)
       self$set404Handler(porcelain_404_handler)
@@ -122,10 +123,13 @@ porcelain <- R6::R6Class(
     ##' provided alongside \code{body}.  If not provided it is set to
     ##' \code{application/octet-stream} if \code{body} is raw, or
     ##' \code{application/json} otherwise.
+    ##'
+    ##' @param request_id Optional request ID. An ID which is attached to
+    ##' every log raised by this request. Used for tracing purposes.
     request = function(method, path, query = NULL, body = NULL,
-                       content_type = NULL) {
+                       content_type = NULL, request_id = NULL) {
       plumber_request(self, method, path, query, body = body,
-                      content_type = content_type)
+                      content_type = content_type, request_id = request_id)
     }
   ))