logger issues with pipe

[xec-cm]

Hi, I have some weird logger problems when I run functions with the pipeline.

Minimal example:

library(magrittr)
fun_1 <- function(x) { logger::log_info("hello_", x) }
fun_2 <- function(x) { logger::log_warn("bye_", x) }

fun_1("Federick")
#> INFO [2020-11-24 16:54:46] hello_Federick
fun_2("Federick")
#> WARN [2020-11-24 16:54:46] bye_Federick

"Federick" %>% 
    fun_1() %>% 
    fun_2()
#> INFO [2020-11-24 16:54:46] hello_Federick
#> WARN [2020-11-24 16:54:46]

Real example: log information is printed before function execution and in reverse order. After printing, the functions are executed correctly and in the correct order.

library(metar)
#> Registered S3 method overwritten by 'quantmod':
#>   method            from
#>   as.zoo.data.frame zoo
mre <- metarExperiment('RealData') %>% 
    metaphlan_ancom(tax_level = 'Genus') %>% 
    kraken_ancom(tax_level = 'Genus') %>% 
    metaphlan_barplots(tax_level = 'Genus') %>% 
    kraken_barplots(tax_level = 'Genus')
#> INFO [2020-24-11 17:03:06] [kraken_barplots   ] running
#> INFO [2020-24-11 17:03:06] [metaphlan_barplots] running
#> INFO [2020-24-11 17:03:06] [kraken_ancom      ] running
#> INFO [2020-24-11 17:03:06] [metaphlan_ancom   ] running
#> INFO [2020-24-11 17:03:06] [metarExperiment   ] Collecting data

Thanks in advance

[daroczig]

minimal example

I think that's expected: the log calls do not return anything. Instead of trying to chain the log calls, why not use the namespace or index options in logger?

log information is printed before function execution and in reverse order

I cannot run that code without the metar package, but I guess this is something similar:

library(logger)
log_drop_head <- function(x, n = 1) {
    log_info('Found {length(x)} element(s), dropping the first {n} element(s): {paste(head(x, n), collapse = ",")}')
    tail(x, -1 * n)
}
library(magrittr)
1:5 %>% log_drop_head %>% log_drop_head %>% log_drop_head

Resulting in:

INFO [2020-11-24 23:19:57] Found 5 element(s), dropping the first 1 element(s): 1
INFO [2020-11-24 23:19:57] Found 4 element(s), dropping the first 1 element(s): 2
INFO [2020-11-24 23:19:57] Found 3 element(s), dropping the first 1 element(s): 3
[1] 4 5

That looks good to me. So thus I'm closing the ticket, but feel free to reopen with more info.