stderr timestamps for easier logging

shikokuchuo · shikokuchuo · commit fcb229a9bb4a · 2022-02-27T23:55:20.000Z
diff --git a/NEWS.md b/NEWS.md
@@ -9,6 +9,7 @@
 
 #### Updates
 
+* Common format for NNG errors now starts with a timestamp for easier logging.
 * `listen()` and `dial()` now return (invisible) zero rather than NULL upon success to better align with similar functions.
 * Allows setting the environment variable 'NANONEXT_ARM' prior to package installation
   + Fixes installation issues on certain ARM architectures
diff --git a/R/aio.R b/R/aio.R
@@ -78,7 +78,7 @@ call_aio <- function(aio, block = TRUE) {
     keep.raw <- .subset2(aio, "callparams")[[2L]]
     if (keep.raw) aio[["raw"]] <- res
     is.integer(res) && {
-      message(res, " : ", nng_error(res))
+      message(Sys.time(), " | ", res, " : ", nng_error(res))
       return(invisible(aio))
     }
     on.exit(expr = {
@@ -107,9 +107,8 @@ call_aio <- function(aio, block = TRUE) {
     }
     aio[["result"]] <- res
     rm("aio", envir = aio)
-    if (res) {
-      message(res, " : ", nng_error(res))
-    }
+    if (res) message(Sys.time(), " | ", res, " : ", nng_error(res))
+
   }
 
   invisible(aio)
diff --git a/R/context.R b/R/context.R
@@ -45,7 +45,7 @@ context <- function(socket) {
 
   if (is.environment(socket)) socket <- .subset2(socket, "socket")
   res <- .Call(rnng_ctx_open, socket)
-  if (is.integer(res)) message(res, " : ", nng_error(res))
+  if (is.integer(res)) message(Sys.time(), " | ", res, " : ", nng_error(res))
   res
 
 }
@@ -90,7 +90,7 @@ send_ctx <- function(context, data, mode = c("serial", "raw"), timeout, echo = T
                  raw = if (is.raw(data)) data else writeBin(object = data, con = raw()))
   res <- .Call(rnng_ctx_send, context, data, timeout)
   is.integer(res) && {
-    message(res, " : ", nng_error(res))
+    message(Sys.time(), " | ", res, " : ", nng_error(res))
     return(invisible(res))
   }
   if (missing(echo) || isTRUE(echo)) res else invisible(0L)
@@ -142,7 +142,7 @@ recv_ctx <- function(context,
   if (missing(timeout)) timeout <- -2L
   res <- .Call(rnng_ctx_recv, context, timeout)
   is.integer(res) && {
-    message(res, " : ", nng_error(res))
+    message(Sys.time(), " | ", res, " : ", nng_error(res))
     return(invisible(res))
   }
   on.exit(expr = return(res))
@@ -228,7 +228,7 @@ reply <- function(context,
   if (missing(timeout)) timeout <- -2L
   res <- .Call(rnng_ctx_recv, context, timeout)
   is.integer(res) && {
-    message(res, " : ", nng_error(res))
+    message(Sys.time(), " | ", res, " : ", nng_error(res))
     return(invisible(res))
   }
   on.exit(expr = send_aio(context, as.raw(0L), mode = send_mode))
@@ -244,7 +244,7 @@ reply <- function(context,
   on.exit()
   res <- .Call(rnng_ctx_send, context, data, timeout)
   is.integer(res) && {
-    message(res, " : ", nng_error(res))
+    message(Sys.time(), " | ", res, " : ", nng_error(res))
     return(invisible(res))
   }
   invisible(0L)
@@ -311,12 +311,12 @@ request <- function(context,
                  raw = if (is.raw(data)) data else writeBin(object = data, con = raw()))
   res <- .Call(rnng_send_aio, context, data, -2L)
   is.integer(res) && {
-    message(res, " : ", nng_error(res))
+    message(Sys.time(), " | ", res, " : ", nng_error(res))
     return(invisible(res))
   }
   res <- .Call(rnng_recv_aio, context, timeout)
   is.integer(res) && {
-    message(res, " : ", nng_error(res))
+    message(Sys.time(), " | ", res, " : ", nng_error(res))
     return(invisible(res))
   }
   env <- `class<-`(new.env(), "recvAio")
diff --git a/R/listdial.R b/R/listdial.R
@@ -78,13 +78,13 @@ dial <- function(socket,
     if (missing(autostart) || isTRUE(autostart)) {
       res <- .Call(rnng_dial, .subset2(socket, "socket"), url)
       if (is.integer(res)) {
-        message(res, " : ", nng_error(res))
+        message(Sys.time(), " | ", res, " : ", nng_error(res))
         return(res)
       }
     } else {
       res <- .Call(rnng_dialer_create, .subset2(socket, "socket"), url)
       if (is.integer(res)) {
-        message(res, " : ", nng_error(res))
+        message(Sys.time(), " | ", res, " : ", nng_error(res))
         return(res)
       }
     }
@@ -103,13 +103,13 @@ dial <- function(socket,
     if (missing(autostart) || isTRUE(autostart)) {
       res <- .Call(rnng_dial, socket, url)
       if (is.integer(res)) {
-        message(res, " : ", nng_error(res))
+        message(Sys.time(), " | ", res, " : ", nng_error(res))
         return(res)
       }
     } else {
       res <- .Call(rnng_dialer_create, socket, url)
       if (is.integer(res)) {
-        message(res, " : ", nng_error(res))
+        message(Sys.time(), " | ", res, " : ", nng_error(res))
         return(res)
       }
     }
@@ -199,13 +199,13 @@ listen <- function(socket,
     if (missing(autostart) || isTRUE(autostart)) {
       res <- .Call(rnng_listen, .subset2(socket, "socket"), url)
       if (is.integer(res)) {
-        message(res, " : ", nng_error(res))
+        message(Sys.time(), " | ", res, " : ", nng_error(res))
         return(res)
       }
     } else {
       res <- .Call(rnng_listener_create, .subset2(socket, "socket"), url)
       if (is.integer(res)) {
-        message(res, " : ", nng_error(res))
+        message(Sys.time(), " | ", res, " : ", nng_error(res))
         return(res)
       }
     }
@@ -224,13 +224,13 @@ listen <- function(socket,
     if (missing(autostart) || isTRUE(autostart)) {
       res <- .Call(rnng_listen, socket, url)
       if (is.integer(res)) {
-        message(res, " : ", nng_error(res))
+        message(Sys.time(), " | ", res, " : ", nng_error(res))
         return(res)
       }
     } else {
       res <- .Call(rnng_listener_create, socket, url)
       if (is.integer(res)) {
-        message(res, " : ", nng_error(res))
+        message(Sys.time(), " | ", res, " : ", nng_error(res))
         return(res)
       }
     }
diff --git a/R/methods.R b/R/methods.R
@@ -27,7 +27,7 @@ NULL
 start.nanoListener <- function(x, ...) {
 
   xc <- .Call(rnng_listener_start, x)
-  if (xc) message(xc, " : ", nng_error(xc))
+  if (xc) message(Sys.time(), " | ", xc, " : ", nng_error(xc))
   invisible(xc)
 
 }
@@ -39,7 +39,7 @@ start.nanoListener <- function(x, ...) {
 start.nanoDialer <- function(x, async = TRUE, ...) {
 
   xc <- .Call(rnng_dialer_start, x, async)
-  if (xc) message(xc, " : ", nng_error(xc))
+  if (xc) message(Sys.time(), " | ", xc, " : ", nng_error(xc))
   invisible(xc)
 
 }
@@ -80,7 +80,7 @@ NULL
 close.nanoSocket <- function(con, ...) {
 
   xc <- .Call(rnng_close, con)
-  if (xc) message(xc, " : ", nng_error(xc))
+  if (xc) message(Sys.time(), " | ", xc, " : ", nng_error(xc))
   invisible(xc)
 
 }
@@ -92,7 +92,7 @@ close.nanoSocket <- function(con, ...) {
 close.nanoContext <- function(con, ...) {
 
   xc <- .Call(rnng_ctx_close, con)
-  if (xc) message(xc, " : ", nng_error(xc))
+  if (xc) message(Sys.time(), " | ", xc, " : ", nng_error(xc))
   invisible(xc)
 
 }
@@ -104,7 +104,7 @@ close.nanoContext <- function(con, ...) {
 close.nanoDialer <- function(con, ...) {
 
   xc <- .Call(rnng_dialer_close, con)
-  if (xc) message(xc, " : ", nng_error(xc))
+  if (xc) message(Sys.time(), " | ", xc, " : ", nng_error(xc))
   invisible(xc)
 
 }
@@ -116,7 +116,7 @@ close.nanoDialer <- function(con, ...) {
 close.nanoListener <- function(con, ...) {
 
   xc <- .Call(rnng_listener_close, con)
-  if (xc) message(xc, " : ", nng_error(xc))
+  if (xc) message(Sys.time(), " | ", xc, " : ", nng_error(xc))
   invisible(xc)
 
 }
diff --git a/R/opts.R b/R/opts.R
@@ -53,7 +53,7 @@ setopt.nanoSocket <- function(object,
                string = .Call(rnng_socket_set_string, object, opt, value),
                uint64 = .Call(rnng_socket_set_uint64, object, opt, value))
 
-  if (xc) message(xc, " : ", nng_error(xc))
+  if (xc) message(Sys.time(), " | ", xc, " : ", nng_error(xc))
   invisible(xc)
 
 }
@@ -83,7 +83,7 @@ setopt.nanoDialer <- function(object,
                string = .Call(rnng_dialer_set_string, object, opt, value),
                uint64 = .Call(rnng_dialer_set_uint64, object, opt, value))
 
-  if (xc) message(xc, " : ", nng_error(xc))
+  if (xc) message(Sys.time(), " | ", xc, " : ", nng_error(xc))
   invisible(xc)
 
 }
@@ -113,7 +113,7 @@ setopt.nanoListener <- function(object,
                string = .Call(rnng_listener_set_string, object, opt, value),
                uint64 = .Call(rnng_listener_set_uint64, object, opt, value))
 
-  if (xc) message(xc, " : ", nng_error(xc))
+  if (xc) message(Sys.time(), " | ", xc, " : ", nng_error(xc))
   invisible(xc)
 
 }
@@ -144,7 +144,7 @@ setopt.nanoContext <- function(object,
                string = .Call(rnng_ctx_set_string, object, opt, value),
                uint64 = .Call(rnng_ctx_set_uint64, object, opt, value))
 
-  if (xc) message(xc, " : ", nng_error(xc))
+  if (xc) message(Sys.time(), " | ", xc, " : ", nng_error(xc))
   invisible(xc)
 
 }
diff --git a/R/sendrecv.R b/R/sendrecv.R
@@ -42,7 +42,7 @@ send <- function(socket,
                  raw = if (is.raw(data)) data else writeBin(object = data, con = raw()))
   res <- .Call(rnng_send, socket, data, block)
   is.integer(res) && {
-    message(res, " : ", nng_error(res))
+    message(Sys.time(), " | ", res, " : ", nng_error(res))
     return(invisible(res))
   }
   if (missing(echo) || isTRUE(echo)) res else invisible(0L)
@@ -91,7 +91,7 @@ send_aio <- function(socket, data, mode = c("serial", "raw"), timeout) {
                  raw = if (is.raw(data)) data else writeBin(object = data, con = raw()))
   res <- .Call(rnng_send_aio, socket, data, timeout)
   is.integer(res) && {
-    message(res, " : ", nng_error(res))
+    message(Sys.time(), " | ", res, " : ", nng_error(res))
     return(invisible(res))
   }
   env <- `class<-`(new.env(), "sendAio")
@@ -153,7 +153,7 @@ recv <- function(socket,
   mode <- match.arg(mode)
   res <- .Call(rnng_recv, socket, block)
   is.integer(res) && {
-    message(res, " : ", nng_error(res))
+    message(Sys.time(), " | ", res, " : ", nng_error(res))
     return(invisible(res))
   }
   on.exit(expr = return(res))
@@ -220,7 +220,7 @@ recv_aio <- function(socket,
   if (missing(timeout)) timeout <- -2L
   res <- .Call(rnng_recv_aio, socket, timeout)
   is.integer(res) && {
-    message(res, " : ", nng_error(res))
+    message(Sys.time(), " | ", res, " : ", nng_error(res))
     return(invisible(res))
   }
   env <- `class<-`(new.env(), "recvAio")
diff --git a/R/socket.R b/R/socket.R
@@ -64,7 +64,7 @@ socket <- function(protocol = c("pair", "bus", "push", "pull", "req", "rep",
 
   protocol <- match.arg(protocol)
   res <- .Call(rnng_protocol_open, protocol)
-  if (is.integer(res)) message(res, " : ", nng_error(res))
+  if (is.integer(res)) message(Sys.time(), " | ", res, " : ", nng_error(res))
   if (!missing(dial)) {
     dial(res, url = dial, autostart = autostart)
   }
@@ -114,8 +114,11 @@ socket <- function(protocol = c("pair", "bus", "push", "pull", "req", "rep",
 subscribe <- function(socket, topic = NULL) {
 
   xc <- .Call(rnng_socket_set_string, socket, "sub:subscribe" , topic)
-  if (xc) message(xc, " : ", nng_error(xc)) else message("subscribed topic: ",
-                                                         if (is.null(topic)) "ALL" else topic)
+  if (xc) {
+    message(Sys.time(), " | ", xc, " : ", nng_error(xc))
+  } else {
+    cat("subscribed topic: ", if (is.null(topic)) "ALL" else topic)
+  }
   invisible(xc)
 
 }
@@ -163,8 +166,11 @@ subscribe <- function(socket, topic = NULL) {
 unsubscribe <- function(socket, topic = NULL) {
 
   xc <- .Call(rnng_socket_set_string, socket, "sub:unsubscribe" , topic)
-  if (xc) message(xc, " : ", nng_error(xc)) else message("unsubscribed topic: ",
-                                                         if (is.null(topic)) "ALL" else topic)
+  if (xc) {
+    message(Sys.time(), " | ", xc, " : ", nng_error(xc))
+  } else {
+    cat("unsubscribed topic: ", if (is.null(topic)) "ALL" else topic)
+  }
   invisible(xc)
 
 }
diff --git a/R/utils.R b/R/utils.R
@@ -133,7 +133,7 @@ ncurl <- function(http, ...) {
   res <- .Call(rnng_ncurl, http, args)
   missing(res) && return(invisible())
   if (is.integer(res)) {
-    message(res, " : ", nng_error(res))
+    message(Sys.time(), " | ", res, " : ", nng_error(res))
     return(invisible(res))
   } else if (is.character(res)) {
     continue <- if (interactive()) readline(paste0("Follow redirect to <", res, ">? [Y/n] ")) else "n"
diff --git a/README.md b/README.md
@@ -333,7 +333,7 @@ aio
 #> < recvAio >
 #>  - $data for message data
 str(aio$data)
-#>  num [1:100000000] -0.123 -0.79 -0.694 -0.84 -1.527 ...
+#>  num [1:100000000] 0.298 0.163 0.278 1.051 0.654 ...
 ```
 
 In this example the calculation is returned, but other operations may
@@ -358,27 +358,27 @@ pub <- socket("pub", listen = "inproc://nanobroadcast")
 sub <- socket("sub", dial = "inproc://nanobroadcast")
 
 sub |> subscribe(topic = "examples")
-#> subscribed topic: examples
+#> subscribed 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)
-#> 8 : Try again
+#> 2022-02-27 23:51:22 | 8 : Try again
 
 # specify NULL to subscribe to ALL topics
 sub |> subscribe(topic = NULL)
-#> subscribed topic: ALL
+#> subscribed 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)
-#> unsubscribed topic: ALL
+#> unsubscribed topic:  ALL
 pub |> send(c("newTopic", "this topic will now not be received"), mode = "raw", echo = FALSE)
 sub |> recv("character", keep.raw = FALSE)
-#> 8 : Try again
+#> 2022-02-27 23:51:22 | 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)
@@ -402,11 +402,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 34 61 61 62 34 2d 37 66 66 39 38 64 34 62 30 36 62 62 39 38 38
-#> [101] 65 31 36 30 33 36 66 39 66 22 0a 20 20 7d 0a 7d 0a
+#>  [76] 2d 36 32 31 63 30 65 37 61 2d 35 36 36 30 35 32 63 63 33 66 61 65 64 30 63
+#> [101] 39 35 31 38 61 62 30 34 30 22 0a 20 20 7d 0a 7d 0a
 #> 
 #> $data
-#> [1] "{\n  \"headers\": {\n    \"Host\": \"httpbin.org\", \n    \"X-Amzn-Trace-Id\": \"Root=1-6214aab4-7ff98d4b06bb988e16036f9f\"\n  }\n}\n"
+#> [1] "{\n  \"headers\": {\n    \"Host\": \"httpbin.org\", \n    \"X-Amzn-Trace-Id\": \"Root=1-621c0e7a-566052cc3faed0c9518ab040\"\n  }\n}\n"
 ```
 
 For advanced use, supports additional HTTP methods such as POST or PUT.

Original file line number	Diff line number	Diff line change
`@@ -78,7 +78,7 @@ call_aio <- function(aio, block = TRUE) {`
`78`	`78`	`keep.raw <- .subset2(aio, "callparams")[[2L]]`
`79`	`79`	`if (keep.raw) aio[["raw"]] <- res`
`80`	`80`	`is.integer(res) && {`
`81`		`- message(res, " : ", nng_error(res))`
	`81`	`+ message(Sys.time(), " \| ", res, " : ", nng_error(res))`
`82`	`82`	`return(invisible(aio))`
`83`	`83`	`}`
`84`	`84`	`on.exit(expr = {`
`@@ -107,9 +107,8 @@ call_aio <- function(aio, block = TRUE) {`
`107`	`107`	`}`
`108`	`108`	`aio[["result"]] <- res`
`109`	`109`	`rm("aio", envir = aio)`
`110`		`- if (res) {`
`111`		`- message(res, " : ", nng_error(res))`
`112`		`- }`
	`110`	`+ if (res) message(Sys.time(), " \| ", res, " : ", nng_error(res))`
	`111`	`+`
`113`	`112`	`}`
`114`	`113`
`115`	`114`	`invisible(aio)`
Original file line number	Diff line number	Diff line change
`@@ -78,13 +78,13 @@ dial <- function(socket,`
`78`	`78`	`if (missing(autostart) \|\| isTRUE(autostart)) {`
`79`	`79`	`res <- .Call(rnng_dial, .subset2(socket, "socket"), url)`
`80`	`80`	`if (is.integer(res)) {`
`81`		`- message(res, " : ", nng_error(res))`
	`81`	`+ message(Sys.time(), " \| ", res, " : ", nng_error(res))`
`82`	`82`	`return(res)`
`83`	`83`	`}`
`84`	`84`	`} else {`
`85`	`85`	`res <- .Call(rnng_dialer_create, .subset2(socket, "socket"), url)`
`86`	`86`	`if (is.integer(res)) {`
`87`		`- message(res, " : ", nng_error(res))`
	`87`	`+ message(Sys.time(), " \| ", res, " : ", nng_error(res))`
`88`	`88`	`return(res)`
`89`	`89`	`}`
`90`	`90`	`}`
`@@ -103,13 +103,13 @@ dial <- function(socket,`
`103`	`103`	`if (missing(autostart) \|\| isTRUE(autostart)) {`
`104`	`104`	`res <- .Call(rnng_dial, socket, url)`
`105`	`105`	`if (is.integer(res)) {`
`106`		`- message(res, " : ", nng_error(res))`
	`106`	`+ message(Sys.time(), " \| ", res, " : ", nng_error(res))`
`107`	`107`	`return(res)`
`108`	`108`	`}`
`109`	`109`	`} else {`
`110`	`110`	`res <- .Call(rnng_dialer_create, socket, url)`
`111`	`111`	`if (is.integer(res)) {`
`112`		`- message(res, " : ", nng_error(res))`
	`112`	`+ message(Sys.time(), " \| ", res, " : ", nng_error(res))`
`113`	`113`	`return(res)`
`114`	`114`	`}`
`115`	`115`	`}`
`@@ -199,13 +199,13 @@ listen <- function(socket,`
`199`	`199`	`if (missing(autostart) \|\| isTRUE(autostart)) {`
`200`	`200`	`res <- .Call(rnng_listen, .subset2(socket, "socket"), url)`
`201`	`201`	`if (is.integer(res)) {`
`202`		`- message(res, " : ", nng_error(res))`
	`202`	`+ message(Sys.time(), " \| ", res, " : ", nng_error(res))`
`203`	`203`	`return(res)`
`204`	`204`	`}`
`205`	`205`	`} else {`
`206`	`206`	`res <- .Call(rnng_listener_create, .subset2(socket, "socket"), url)`
`207`	`207`	`if (is.integer(res)) {`
`208`		`- message(res, " : ", nng_error(res))`
	`208`	`+ message(Sys.time(), " \| ", res, " : ", nng_error(res))`
`209`	`209`	`return(res)`
`210`	`210`	`}`
`211`	`211`	`}`
`@@ -224,13 +224,13 @@ listen <- function(socket,`
`224`	`224`	`if (missing(autostart) \|\| isTRUE(autostart)) {`
`225`	`225`	`res <- .Call(rnng_listen, socket, url)`
`226`	`226`	`if (is.integer(res)) {`
`227`		`- message(res, " : ", nng_error(res))`
	`227`	`+ message(Sys.time(), " \| ", res, " : ", nng_error(res))`
`228`	`228`	`return(res)`
`229`	`229`	`}`
`230`	`230`	`} else {`
`231`	`231`	`res <- .Call(rnng_listener_create, socket, url)`
`232`	`232`	`if (is.integer(res)) {`
`233`		`- message(res, " : ", nng_error(res))`
	`233`	`+ message(Sys.time(), " \| ", res, " : ", nng_error(res))`
`234`	`234`	`return(res)`
`235`	`235`	`}`
`236`	`236`	`}`