allow setting logging level via NANONEXT_LOG

Author: shikokuchuo

NEWS.md

@@ -2,11 +2,11 @@
 
 #### New Features
 
-* Aio fields `$result` for a 'sendAio', `$raw` and `$data` for a 'recvAio' may be queried directly, returning their values or else an NA 'unresolved value' if the Aio operation is yet to complete.
-* `unresolved()` added as an auxiliary function to query whether an Aio is still unresolved in a non-blocking fashion.
+* Aio values `$result`, `$raw` or `$data` now resolve without requiring `call_aio()`. Access the values directly and an NA 'unresolved value' will be returned if the Aio operation is yet to complete.
+* `unresolved()` added as an auxiliary function to query whether an Aio is unresolved, for use in control flow statements.
 * `is_nul_byte()` added as a helper function for request/reply setups.
 * `survey_time()` added as a convenience function for surveyor/respondent patterns.
-* `logging()` function to specify a global package logging level - currently supports 'error' and 'info'.
+* `logging()` function to specify a global package logging level - 'error' or 'info'. Automatically polls the environment variable 'NANONEXT_LOG' on package load and then each time `logging(level = "check")` is called, allowing this to be set externally.
 * `ncurl()` adds a '...' argument. Support for HTTP methods other than GET.
 
 #### Updates

R/aio.R

@@ -26,15 +26,16 @@
 #'     Once the result has been successfully retrieved, the Aio is deallocated
 #'     and only the result is stored in the Aio object.
 #'
-#' @section Non-blocking:
+#' @section Alternatively:
 #'
-#'     To query the value of an Aio without potentially waiting for the Aio
-#'     operation to complete, access the values directly at \code{$result} for a
-#'     'sendAio', and \code{$raw} or \code{$data} for a 'recvAio'.
+#'     Aio values may be accessed directly at \code{$result} for a 'sendAio',
+#'     and \code{$raw} or \code{$data} for a 'recvAio'. If the Aio operation is
+#'     yet to complete, a logical NA 'unresolved value' will be returned. Once
+#'     completed, the resolved value will be returned instead.
 #'
-#'     If the Aio operation is yet to complete, the result will be an
-#'     'unresolved value', which is a logical NA. Once complete, the resolved
-#'     value will be returned instead.
+#'     \code{\link{unresolved}} may also be used, which returns TRUE only if an
+#'     Aio or Aio value has yet to resolve and FALSE otherwise. This is suitable
+#'     for use in control flow statements such as \code{while} or \code{if}.
 #'
 #' @examples
 #' s1 <- socket("pair", listen = "inproc://nanonext")
@@ -133,16 +134,16 @@ stop_aio <- function(aio) {
 
 #' Query if an Aio is Unresolved
 #'
-#' Query whether an Aio or Aio value is unresolved. This function is non-blocking
-#'     unlike \code{\link{call_aio}} which waits for completion.
+#' Query whether an Aio or Aio value remains unresolved. Unlike
+#'     \code{\link{call_aio}}, this function does not wait for completion.
 #'
 #' @param aio An Aio (object of class 'sendAio' or 'recvAio'), or Aio value
 #'     stored in \code{$result}, \code{$raw} or \code{$data} as the case may be.
 #'
 #' @return Logical TRUE or FALSE.
 #'
-#' @details Returns TRUE for unresolved nanonext Aios or Aio values; returns
-#'     FALSE in all other cases and for all other objects.
+#' @details Returns TRUE for unresolved Aios or Aio values, FALSE otherwise.
+#'     Suitable for use in control flow statements such as \code{while} or \code{if}.
 #'
 #'     Note: querying resolution may cause a previously unresolved Aio to resolve.
 #'

R/context.R

@@ -261,7 +261,7 @@ reply <- function(context,
 #'
 #' @inheritParams reply
 #' @inheritParams recv
-#' @param data an R object (if send_mode = 'raw', an R vector).
+#' @param data an object (if send_mode = 'raw', a vector).
 #' @param timeout in ms. If unspecified, a socket-specific default timeout will
 #'     be used. Note that this applies to receiving the result.
 #'

R/methods.R

@@ -107,12 +107,7 @@ close.nanoSocket <- function(con, ...) {
 close.nanoContext <- function(con, ...) {
 
   xc <- .Call(rnng_ctx_close, con)
-  if (xc) {
-    message(Sys.time(), " [ ", xc, " ] ", nng_error(xc))
-  } else if (logging()) {
-    cat(format.POSIXct(Sys.time()), "[ ctxt close ] id:",
-        attr(con, "id"), "| sock:", attr(con, "socket"), "\n", file = stdout())
-  }
+  if (xc) message(Sys.time(), " [ ", xc, " ] ", nng_error(xc))
   invisible(xc)
 
 }

R/sendrecv.R

@@ -5,7 +5,7 @@
 #' Send data over a Socket.
 #'
 #' @param socket a Socket.
-#' @param data an R object (if mode = 'raw', an R vector).
+#' @param data an object (if mode = 'raw', a vector).
 #' @param mode [default 'serial'] whether data will be sent serialized or as a
 #'     raw vector. Use 'serial' for sending and receiving within R to ensure
 #'     perfect reproducibility. Use 'raw' for sending vectors of any type (will be

R/socket.R

@@ -104,13 +104,15 @@ socket <- function(protocol = c("pair", "bus", "push", "pull", "req", "rep",
 #' @examples
 #' pub <- socket("pub", listen = "inproc://nanonext")
 #' sub <- socket("sub", dial = "inproc://nanonext")
+#' logging(level = "info")
 #'
 #' subscribe(sub, "examples")
 #' send(pub, c("examples", "this is an example"), mode = "raw")
 #' recv(sub, "character")
 #' send(pub, c("other", "this other topic will not be received"), mode = "raw")
 #' recv(sub, "character")
 #'
+#' logging(level = "error")
 #' close(pub)
 #' close(sub)
 #'
@@ -156,6 +158,7 @@ subscribe <- function(socket, topic = NULL) {
 #' @examples
 #' pub <- socket("pub", listen = "inproc://nanonext")
 #' sub <- socket("sub", dial = "inproc://nanonext")
+#' logging(level = "info")
 #'
 #' subscribe(sub, NULL)
 #' send(pub, c("examples", "this is an example"), mode = "raw")
@@ -164,6 +167,7 @@ subscribe <- function(socket, topic = NULL) {
 #' send(pub, c("examples", "this example will not be received"), mode = "raw")
 #' recv(sub, "character")
 #'
+#' logging(level = "error")
 #' close(pub)
 #' close(sub)
 #'
@@ -193,10 +197,7 @@ unsubscribe <- function(socket, topic = NULL) {
 #'
 #' @return Zero (invisibly) on success.
 #'
-#' @details This is a convenience function that wraps \code{\link{setopt}} with
-#'     the correct parameters.
-#'
-#'     After using this function, to start a new survey, the surveyor must:
+#' @details After using this function, to start a new survey, the surveyor must:
 #'     \itemize{
 #'     \item{send a message using any of the send functions.}
 #'     \item{switch to receiving responses.}
@@ -212,28 +213,33 @@ unsubscribe <- function(socket, topic = NULL) {
 #' @examples
 #' sur <- socket("surveyor", listen = "inproc://nanonext")
 #' res <- socket("respondent", dial = "inproc://nanonext")
+#' logging(level = "info")
 #'
 #' survey_time(sur, 1000)
 #' send(sur, "reply to this survey")
 #' aio <- recv_aio(sur)
 #'
 #' recv(res)
-#' send_aio(res, "replied")
+#' s <- send_aio(res, "replied")
 #'
 #' call_aio(aio)$data
 #'
+#' logging(level = "error")
 #' close(sur)
 #' close(res)
 #'
 #' @export
 #'
 survey_time <- function(socket, time) {
 
-  res <- setopt(socket, type = "ms", opt = "surveyor:survey-time", value = time)
-  if (logging()) {
+  xc <- .Call(rnng_socket_set_ms, socket, "surveyor:survey-time", time)
+  if (xc) {
+    message(Sys.time(), " [ ", xc, " ] ", nng_error(xc))
+  } else if (logging()) {
     cat(format.POSIXct(Sys.time()), "[ survey ] sock:", attr(socket, "id"),
         "| set time:", time, "\n", file = stdout())
   }
+  invisible(xc)
 
 }
 

R/utils.R

@@ -83,12 +83,23 @@ is_nul_byte <- function(x) {
 #'
 #' Set the logging level of nanonext.
 #'
-#' @param level specify a logging level - either 'error' (default) which sends
-#'     all NNG errors to stderr or 'info' which also sends informational events
-#'     such as socket open, listener/dialer start, socket close etc. to stdout.
+#' @param level specify a logging level
+#'     \itemize{
+#'     \item{'prev'} {which continues with the previous logging level}
+#'     \item{'check'} {which checks the value of environment variable 'NANONEXT_LOG'}
+#'     \item{'error'} {which sends all NNG errors to stderr}
+#'     \item{'info'} {which in addition sends key informational events such as
+#'     socket open etc. to stdout.}
+#'     }
 #'
 #' @return Invisible NULL, or if 'level' is not specified, the integer code of
-#'     the logging level.
+#'     the logging level. A confirmation is printed to the console (stdout) if
+#'     the logging level has changed.
+#'
+#' @details The environment variable 'NANONEXT_LOG' is checked automatically on
+#'     package load and then cached for optimal performance. It is also checked
+#'     each time \code{logging(level = "check")} is called. If the variable is
+#'     set incorrectly, the default level of 'error' is used instead.
 #'
 #' @examples
 #' logging(level = "info")
@@ -100,17 +111,24 @@ is_nul_byte <- function(x) {
 #'
 logging <- function(level) {
 
-  cache <- 0L
+  cache <- switch(tolower(Sys.getenv("NANONEXT_LOG")),
+                  info = 1L,
+                  0L)
 
-  logging <- function(level = c("error", "info")) {
+  logging <- function(level = c("prev", "check", "error", "info")) {
 
     missing(level) && return(cache)
     level <- match.arg(level)
+    original <- cache
     cache <<- switch(level,
+                     check = switch(tolower(Sys.getenv("NANONEXT_LOG")),
+                                    info = 1L,
+                                    0L),
                      error = 0L,
-                     info = 1L)
-    cat(format.POSIXct(Sys.time()), "[ log level ] set to:", level,
-        "\n", file = stdout())
+                     info = 1L,
+                     prev = original)
+    if (cache != original) cat(format.POSIXct(Sys.time()), "[ log level ] set to:",
+                               if (cache) "info\n" else "error\n", file = stdout())
 
   }
 

README.Rmd

@@ -277,9 +277,12 @@ In such a case, using `call_aio()` confirms that the operation has completed (or
 
 {nanonext} fully implements NNG's pub/sub protocol as per the below example. 
 
-This example uses the new R4.1 pipe for clarity of code, although this is of course not required.
+The built-in logging levels are also demonstrated here. NNG errors are always output to stderr and operation is otherwise silent by default. To enable key information events to be sent to stdout, use `logging(level = "info")`. 
+
+The log level can also be set externally in production environments via an environment variable `NANONEXT_LOG`.
 
 ```{r pub}
+logging(level = "info")
 
 pub <- socket("pub", listen = "inproc://nanobroadcast")
 sub <- socket("sub", dial = "inproc://nanobroadcast")

README.md

@@ -328,7 +328,7 @@ aio
 #>  - $raw for raw message
 #>  - $data for message data
 str(aio$data)
-#>  num [1:100000000] -0.771 -0.379 -0.377 -1.401 -1.579 ...
+#>  num [1:100000000] 0.837 1.301 2.225 1.43 -1.543 ...
 ```
 
 In this example the calculation is returned, but other operations may
@@ -345,40 +345,57 @@ the function, which may typically be NULL or an exit code.
 {nanonext} fully implements NNG’s pub/sub protocol as per the below
 example.
 
-This example uses the new R4.1 pipe for clarity of code, although this
-is of course not required.
+The built-in logging levels are also demonstrated here. NNG errors are
+always output to stderr and operation is otherwise silent by default. To
+enable key information events to be sent to stdout, use
+`logging(level = "info")`.
+
+The log level can also be set externally in production environments via
+an environment variable `NANONEXT_LOG`.
 
 ``` r
+logging(level = "info")
+#> 2022-03-03 10:51:39 [ log level ] set to: info
+
 pub <- socket("pub", listen = "inproc://nanobroadcast")
+#> 2022-03-03 10:51:39 [ sock open ] id: 9 | protocol: pub 
+#> 2022-03-03 10:51:39 [ list start ] sock: 9 | url: inproc://nanobroadcast
 sub <- socket("sub", dial = "inproc://nanobroadcast")
+#> 2022-03-03 10:51:39 [ sock open ] id: 10 | protocol: sub 
+#> 2022-03-03 10:51:39 [ dial start ] sock: 10 | url: inproc://nanobroadcast
 
 sub |> subscribe(topic = "examples")
+#> 2022-03-03 10:51:39 [ subscribe ] sock: 10 | topic: examples
 pub |> send(c("examples", "this is an example"), mode = "raw", echo = FALSE)
 sub |> recv(mode = "character", keep.raw = FALSE)
 #> [1] "examples"           "this is an example"
 
 pub |> send(c("other", "this other topic will not be received"), mode = "raw", echo = FALSE)
 sub |> recv(mode = "character", keep.raw = FALSE)
-#> 2022-03-02 17:01:22 [ 8 ] Try again
+#> 2022-03-03 10:51:39 [ 8 ] Try again
 
 # specify NULL to subscribe to ALL topics
 sub |> subscribe(topic = NULL)
+#> 2022-03-03 10:51:39 [ subscribe ] sock: 10 | topic: ALL
 pub |> send(c("newTopic", "this is a new topic"), mode = "raw", echo = FALSE)
 sub |> recv("character", keep.raw = FALSE)
 #> [1] "newTopic"            "this is a new topic"
 
 sub |> unsubscribe(topic = NULL)
+#> 2022-03-03 10:51:39 [ unsubscribe ] sock: 10 | topic: ALL
 pub |> send(c("newTopic", "this topic will now not be received"), mode = "raw", echo = FALSE)
 sub |> recv("character", keep.raw = FALSE)
-#> 2022-03-02 17:01:22 [ 8 ] Try again
+#> 2022-03-03 10:51:39 [ 8 ] Try again
 
 # however the topics explicitly subscribed to are still received
 pub |> send(c("examples", "this example will still be received"), mode = "raw", echo = FALSE)
 sub |> recv(mode = "character", keep.raw = FALSE)
 #> [1] "examples"                            "this example will still be received"
 
 close(pub)
+#> 2022-03-03 10:51:39 [ sock close ] id: 9 | protocol: pub
 close(sub)
+#> 2022-03-03 10:51:39 [ sock close ] id: 10 | protocol: sub
 ```
 
 [« Back to ToC](#table-of-contents)
@@ -394,11 +411,11 @@ ncurl("http://httpbin.org/headers")
 #>   [1] 7b 0a 20 20 22 68 65 61 64 65 72 73 22 3a 20 7b 0a 20 20 20 20 22 48 6f 73
 #>  [26] 74 22 3a 20 22 68 74 74 70 62 69 6e 2e 6f 72 67 22 2c 20 0a 20 20 20 20 22
 #>  [51] 58 2d 41 6d 7a 6e 2d 54 72 61 63 65 2d 49 64 22 3a 20 22 52 6f 6f 74 3d 31
-#>  [76] 2d 36 32 31 66 61 32 65 33 2d 37 66 31 34 35 62 63 64 31 65 34 34 36 34 61
-#> [101] 66 36 62 61 62 63 63 33 64 22 0a 20 20 7d 0a 7d 0a
+#>  [76] 2d 36 32 32 30 39 64 62 62 2d 34 61 61 66 66 65 31 37 32 61 64 64 35 39 35
+#> [101] 35 37 33 31 62 35 34 30 30 22 0a 20 20 7d 0a 7d 0a
 #> 
 #> $data
-#> [1] "{\n  \"headers\": {\n    \"Host\": \"httpbin.org\", \n    \"X-Amzn-Trace-Id\": \"Root=1-621fa2e3-7f145bcd1e4464af6babcc3d\"\n  }\n}\n"
+#> [1] "{\n  \"headers\": {\n    \"Host\": \"httpbin.org\", \n    \"X-Amzn-Trace-Id\": \"Root=1-62209dbb-4aaffe172add5955731b5400\"\n  }\n}\n"
 ```
 
 For advanced use, supports additional HTTP methods such as POST or PUT.