Activity

1. pglpm

   added

   bug

   on Apr 14, 2025
2. HenrikBengtsson commented on Apr 14, 2025

   

   HenrikBengtsson

   on Apr 14, 2025

   Collaborator

   More actions

   Hello.

   TL;DR

   The following uses best practices in R to capture output sent to standard output and messages to one file per iteration:

   library(doFuture)
   library(nimble)
   
   plan(multisession, workers = 2)
   
   y <- foreach(i = 1:2) %dofuture% {
       ## Send all standard output to file
       outcon <- file(paste0('testout', i, '.log'), open = 'w') # open file for writing
       sink(outcon, type = "output")
       on.exit({
         sink(NULL, type = "output")
         close(outcon)
       })
       
       withCallingHandlers({
         nimble::messageIfVerbose('nimble message') # message from Nimble
         message('message message')
         cat('cat message\n')
       }, message = function(msg) {
         ## Output messages to stdout, so they end up in the file
         cat(conditionMessage(msg))
         ## Prevent messages from being relayed to the main R session
         invokeRestart("muffleMessage")
       })
       
       i
   }
   
   plan(sequential)
   

   Personally, I would tidy it up by using a helper function that I can reuse, e.g.

   library(doFuture)
   library(nimble)
   
   redirect_stdout_and_messages_to_file <- function(file, expr, envir = parent.frame()) {
     expr <- substitute(expr)
     
     ## Send all standard output to file
     outcon <- file(file, open = "wt")
     sink(outcon, type = "output")
     on.exit({
       sink(NULL, type = "output")
       close(outcon)
     })
     
     withCallingHandlers({
       eval(expr, envir = envir)
     }, message = function(msg) {
       ## Output message to stdout, so they end up in the file
       cat(conditionMessage(msg))
       ## Prevent messages from being relayed to the main R session
       invokeRestart("muffleMessage")
     })
   } ## redirect_stdout_and_messages_to_file()
   
   
       
   ## Configure parallelization
   plan(multisession, workers = 2)
   
   y <- foreach(i = 1:2) %dofuture% {
       redirect_stdout_and_messages_to_file(paste0('testout', i, '.log'), {
         nimble::messageIfVerbose('nimble message') # message from Nimble
         message('message message')
         cat('cat message\n')
       })
       i
   }
   
   ## Disable parallelization
   plan(sequential)
   

   Note that this is the approach you should take regardless of parallelization or not, e.g. with foreach(...) %dopar% { ... }, in a regular for-loop, or in an lapply() call. For example,

   y <- list()
   for(i in 1:2) {
     redirect_stdout_and_messages_to_file(paste0('testout', i, '.log'), {
       nimble::messageIfVerbose('nimble message') # message from Nimble
       message('message message')
       cat('cat message\n')
     })
     y[[i]] <- i
   }

   Details

   There are a few things going on in your original example. I'll try to clarify what's going, that things are working as expected and by design, and how you can get what you want.

   For a started, yes, correct nimble::messageIfVerbose() sends a simple message condition;

   res <- tryCatch(nimble::messageIfVerbose('nimble message'), condition = identity)
   str(res)
   #> List of 2
   #>  $ message: chr "nimble message\n"
   #>  $ call   : language message(...)
   #>  - attr(*, "class")= chr [1:3] "simpleMessage" "message" "condition"

   So, in that sense, and for the discussion here, nimble::messageIfVerbose() is no different from message(). If they had extended class, e.g. nimbleMessage, then we could treat them separately, but given the facts, we don't have to worry about that.

   Second, you can think of message conditions as being SMS/TXT messages. They are delieved to the reciever and there presented in one way or the other, depending on phone, apps, notification settings, smart watches, etc. In R we can "capture" these messages and handle them as we'd like. In Futureverse, the default is that futures captures them on the parallel worker and relays them back to you in the main R session. FWIW, no other parallel framework in R does this - for those frameworks messages (and warnings) often become completely invisible, or sometimes visible depending in what environment the user runs R, e.g. terminal, RStudio Console, ... In Futureverse, the behavior is consistent regardless of environment and parallel backend.

   Third, output from cat(), print(), str() goes to standard output (stdout). That is not a condition - that's just a big internal buffer that gets outputted "somewhere". Similarly to conditions, Futureverse captures the standard output on the parallel workers by defaults and relays it to you in your main R session. The correct way to capture standard output is to use utils::capture.output(...), or low-level sink(..., type = "output") as you did.

   Fourth, the correct way to capture messages is not analogue to howe we capture standard output. That is, we do not want to use utils::capture.output(..., type = "message") or low-level sink(..., type = "message"). The main reason is that it's better to capture messages via withCallingHandlers(..., message = ...) and do what we want there, i.e. forward them to the file. It is true that messages eventually end up on the "message" stream (= standard error) if we don't handle handle them. It is also true that sink(..., type = "message") would grab that output as a last resort, but it's much better to do it via withCallingHandlers(), despite being a bit of coding. That said, an even more important reason is that sink(..., type = "message") is not safe to use. No one should ever use it! That is because how R is designed. Any attempt to use it is unreliable and you can never be in full control of it. See HenrikBengtsson/Wishlist-for-R#55 for an explanation. That it worked with %dopar% and doParallel is basically mostly luck. So, just wipe utils::capture.output(..., type = "message") and sink(..., type = "message") from your memory and never look back. Please trust me on that one.
3. futureverse

   locked and limited conversation to collaborators on Apr 14, 2025
4. HenrikBengtsson

   converted this issue into a discussion #777 on Apr 14, 2025