From dc482644a09b36bf2193c05dfddecb2a35887cae Mon Sep 17 00:00:00 2001
From: Xavier Delaruelle <xavier.delaruelle@cea.fr>
Date: Mon, 22 Apr 2024 08:09:52 +0200
Subject: [PATCH] Log messages at end of modulecmd processing

Create logfd and logging states to manage respectively logger pipe file
descriptor and log enablement. Logging is disabled is logger command is
an empty string or if there is no message to log.

Logs are sent during the termination phase of the modulecmd process.
Logger pipe is started for the duration of the flush operation only.
---
 .hunspell.en.dic  |  1 +
 tcl/init.tcl.in   | 30 +++++++++++++++++++++++++++++-
 tcl/main.tcl.in   |  2 ++
 tcl/report.tcl.in | 19 +++++++++++++++++++
 4 files changed, 51 insertions(+), 1 deletion(-)

diff --git a/.hunspell.en.dic b/.hunspell.en.dic
index 22a61cbf..8c28d74a 100644
--- a/.hunspell.en.dic
+++ b/.hunspell.en.dic
@@ -1167,3 +1167,4 @@ mogui
 modulepathlist
 codename
 EVENTLIST
+logfd
diff --git a/tcl/init.tcl.in b/tcl/init.tcl.in
index 6108ee91..404a7ce0 100644
--- a/tcl/init.tcl.in
+++ b/tcl/init.tcl.in
@@ -22,7 +22,7 @@
 
 # Runtime state properties (default value, proc to call to initialize state
 # value?)
-##nagelfar ignore +34 Found constant
+##nagelfar ignore +36 Found constant
 array set g_state_defs [list\
    autoinit {0}\
    clock_seconds {<undef> initStateClockSeconds}\
@@ -39,6 +39,8 @@ array set g_state_defs [list\
    is_win {<undef> initStateIsWin}\
    kernelversion {<undef> {runCommand uname -v}}\
    lm_info_cached {0}\
+   logfd {{} initStateLogfd}\
+   logging {<undef> initStateLogging}\
    lsb_codename {<undef> {runCommand lsb_release -s -c}}\
    lsb_id {<undef> {runCommand lsb_release -s -i}}\
    lsb_release {<undef> {runCommand lsb_release -s -r}}\
@@ -469,6 +471,32 @@ proc initStateReportfd {} {
    return $reportfd
 }
 
+# Determine if logging need to be started
+proc initStateLogging {} {
+   set logger_not_empty [string length [lindex [getConf logger] 0]]
+   set something_to_log [info exists ::g_log_msg_list]
+   return [expr {$logger_not_empty && $something_to_log}]
+}
+
+# start logger pipe process with defined configuration
+proc initStateLogfd {} {
+   # sets default fallback value
+   lassign $::g_state_defs(logfd) logfd
+
+   # start logger at first call and only if enabled
+   if {[getState logging]} {
+      if {[catch {
+         # drop output of logger command to avoid it pollutes main channels
+         set logfd [open "|[getConf logger] >/dev/null 2>/dev/null" w]
+         fconfigure $logfd -buffering none -blocking 1
+      } errMsg]} {
+         reportWarning $errMsg
+      }
+   }
+
+   return $logfd
+}
+
 # Provide columns number for output formatting
 proc initStateTermColumns {} {
    set cols [getConf term_width]
diff --git a/tcl/main.tcl.in b/tcl/main.tcl.in
index 900a4828..acdb8dd7 100644
--- a/tcl/main.tcl.in
+++ b/tcl/main.tcl.in
@@ -25,6 +25,8 @@
 proc flushAndExit {code} {
    # output all shell code generated on stdout
    renderFlush
+   # send messages to log if any and enabled
+   logFlush
    # output last messages on the report file descriptor and close it
    reportFlush
 
diff --git a/tcl/report.tcl.in b/tcl/report.tcl.in
index 840a4051..a210c484 100644
--- a/tcl/report.tcl.in
+++ b/tcl/report.tcl.in
@@ -791,6 +791,25 @@ proc reportFlush {} {
    }
 }
 
+# send messages to log
+proc logFlush {} {
+   # logger pipe is started only if enabled and some msgs need to be logged
+   set logfd [getState logfd]
+
+   # logging only occurs from this procedure with is run during termination
+   if {[string length $logfd]} {
+      if {[catch {
+         foreach log_msg $::g_log_msg_list {
+            puts $logfd $log_msg
+         }
+         flush $logfd
+         close $logfd
+      } errMsg]} {
+         reportWarning {Issue occurred when logging information}
+      }
+   }
+}
+
 # check if element passed as argument (corresponding to a kind of information)
 # should be part of output content
 proc isEltInReport {elt {retifnotdef 1}} {