Order of messages to console within functions when piped

user_14027466 0
Viewed 150

edit: I don't mean to be rude, SO just did not take my greeting..

Hello,

to keep track about the processing of some functions I would like to print messages in the Console when a function starts and when it is done.

I am a big fan of tidyverse and the pipe operator %>%. But I just found out that the messages at the start of the function are printed in the wrong order while the messages at the end have the correct order.

Does anybody know why or how to solve this?

Here is some code:

library(tidyverse)
testdata <- data.frame(a=c(3,5,7,1,2),b=c(2,5,6,3,9))

foo_1 <- function(DF){
  message("Hello 1")
  Obj <- DF %>% 
    mutate(Test_1=a*b)
  message("Bye 1")
  return(Obj)
} 

foo_2 <- function(DF){
  message("Hello 2")
  
  Obj <- DF %>% 
    mutate(Test_2=Test_1*2)
  message("Bye 2")
  return(Obj)
}

foo_3 <- function(DF){
  message("Hello 3")
  Obj <- DF %>% 
    mutate(Test_3=Test_2/a)
  
  message("Bye 3")
  return(Obj)
}

testdata %>% 
  foo_1() %>% 
  foo_2() %>% 
  foo_3()

The result printed in the console is:

Hello 3
Hello 2
Hello 1
Bye 1
Bye 2
Bye 3
  a b Test_1 Test_2 Test_3
1 3 2      6     12      4
2 5 5     25     50     10
3 7 6     42     84     12
4 1 3      3      6      6
5 2 9     18     36     18

What I would expect is the following order of messages:

Hello 1
Bye 1
Hello 2
Bye 2
Hello 3
Bye 3
  a b Test_1 Test_2 Test_3
1 3 2      6     12      4
2 5 5     25     50     10
3 7 6     42     84     12
4 1 3      3      6      6
5 2 9     18     36     18
tidyverse r pipe
2 Answers

1) flush.console Use flush.console to force the display of the messages queued at that point.

testdata %>% 
  foo_1() %>% 
  { flush.console(); foo_2(.) } %>% 
  { flush.console(); foo_3(.) }

giving this output:

Hello 1
Bye 1
Hello 2
Bye 2
Hello 3
Bye 3
  a b Test_1 Test_2 Test_3
1 3 2      6     12      4
2 5 5     25     50     10
3 7 6     42     84     12
4 1 3      3      6      6
5 2 9     18     36     18

2) Bizarro pipe Another approach is to use the Bizarro pipe, which is just clever base syntax which looks pipe-like, instead.

testdata ->.;
  foo_1(.) ->.;
  foo_2(.) ->.;
  foo_3(.)

giving:

Hello 1
Bye 1
Hello 2
Bye 2
Hello 3
Bye 3
  a b Test_1 Test_2 Test_3
1 3 2      6     12      4
2 5 5     25     50     10
3 7 6     42     84     12
4 1 3      3      6      6
5 2 9     18     36     18

3) force force the evaluation of arguments in the three fuctions.

foo_1 <- function(DF){
  force(DF) #######
  message("Hello 1")
  Obj <- DF %>% 
    mutate(Test_1=a*b)
  message("Bye 1")
  return(Obj)
} 

foo_2 <- function(DF){
  force(DF) #######
  message("Hello 2")
  Obj <- DF %>% 
    mutate(Test_2=Test_1*2)
  message("Bye 2")
  return(Obj)
}

foo_3 <- function(DF){
  force(DF) #######
  message("Hello 3")
  Obj <- DF %>% 
    mutate(Test_3=Test_2/a)
  
  message("Bye 3")
  return(Obj)
}

testdata %>% 
  foo_1 %>%
  foo_2 %>%
  foo_3

giving:

Hello 1
Bye 1
Hello 2
Bye 2
Hello 3
Bye 3
  a b Test_1 Test_2 Test_3
1 3 2      6     12      4
2 5 5     25     50     10
3 7 6     42     84     12
4 1 3      3      6      6
5 2 9     18     36     18

4) pipe_eager_lexical Lionel, the magrittr developer, pointed out to me that magrittr has an eager pipe but does not assign it to a %..% operator; however, we can readily do that.

library(magrittr)

`%>e%` <- pipe_eager_lexical  # eager pipe

testdata %>e% 
  foo_1() %>e% 
  foo_2() %>e% 
  foo_3()

giving:

Hello 1
Bye 1
Hello 2
Bye 2
Hello 3
Bye 3
  a b Test_1 Test_2 Test_3
1 3 2      6     12      4
2 5 5     25     50     10
3 7 6     42     84     12
4 1 3      3      6      6
5 2 9     18     36     18
user_5165480

You move the message out of the individual functions and generate a wrapper around them where you put the messages:

With some sudo-ish code:

my_wrapper <- function(){
message('h1')
foo_1()
message('b1')
message('h2')
...
message('b3')
}
user_111577530
Related