Log module command

[rdauria]

Describe the bug

I have installed modules version 4.7.1 on a CentOS 7 box and I have added the siteconfig.tcl file the example shown in https://modules.readthedocs.io/en/latest/cookbook/log-module-commands.html however upon starting a new shell I now get:

Last login: Wed May  5 22:12:30 PDT 2021 on pts/5
ERROR: invalid command name "getEvalModuleStackDepth"
      while executing
  "getEvalModuleStackDepth"
      (procedure "module" line 2)
      invoked from within
  "module autoinit"
      ("eval" body line 1)
      invoked from within
  "eval $execcmdlist"
  Please report this issue at https://github.com/cea-hpc/modules/issues

To Reproduce

Steps to reproduce the behavior:

$ module config siteconfig
Modules Release 4.7.1 (2021-04-06)

- Config. name ---------.- Value (set by if default overridden) ---------------
siteconfig                /MODULES/4.7.1/etc/siteconfig.tcl

$ vi /MODULES/4.7.1/etc/siteconfig.tcl

content of /MODULES/4.7.1/etc/siteconfig.tcl:

# SITECONFIG.TCL, site-specific configuration script for Modules
#
# This Tcl script enables to supersede any global variable or procedure
# definition of modulecmd.tcl. See 'Modulecmd startup' section in module(1)
# manpage for detailed information.

##########################################################################

# uncomment the following line to forbid the definition of an extra
# site-specific configuration script
#lappendConf locked_configs extra_siteconfig

# uncomment the following line to forbid `implicit_default` config option
# superseding
#lappendConf locked_configs implicit_default

# override 'module' procedure to log each call made by user
rename ::module ::__module
proc module {command args} {
   if {[getEvalModuleStackDepth] == 0} {
      exec logger -t module "[get-env USER]: $command [join $args]"
   }
   return [eval __module "{$command}" $args]
}

If I remove the lines:

# override 'module' procedure to log each call made by user
rename ::module ::__module
proc module {command args} {
   if {[getEvalModuleStackDepth] == 0} {
      exec logger -t module "[get-env USER]: $command [join $args]"
   }
   return [eval __module "{$command}" $args]
}

the error disappears.

Any idea on what is going on?

Also, are the example in the cookbook available on github? I don't seem to have the example directory.

Thanks,

RD

Modules version and configuration

$ module --version
Modules Release 4.7.1 (2021-04-06)
$ module config --dump-state
Modules Release 4.7.1 (2021-04-06)

- Config. name ---------.- Value (set by if default overridden) ---------------
advanced_version_spec     0
auto_handling             0
avail_indepth             1
avail_output              modulepath:alias:dirwsym:sym:tag:key
avail_terse_output        modulepath:alias:dirwsym:sym:tag
collection_pin_version    0
collection_target         <undef>
color                     never
colors                    hi=1:db=2:tr=2:se=2:er=91:wa=93:me=95:in=94:mp=1;94:di=94:al=96:sy=95:de=4:cm=92:aL=100:L=90;47:H=2:F=41:nF=43:S=46:sS=44
contact                   root@localhost
csh_limit                 4000
extended_default          0
extra_siteconfig          <undef>
home                      /MODULES/4.7.1 (env-var)
icase                     never
ignored_dirs              CVS RCS SCCS .svn .git .SYNC .sos
implicit_default          1
implicit_requirement      1
list_output               header:idx:sym:tag:key
list_terse_output         header
locked_configs            
mcookie_version_check     1
ml                        1
nearly_forbidden_days     14
pager                     /usr/bin/less -eFKRX
rcfile                    <undef>
run_quarantine            <undef>
search_match              starts_with
set_shell_startup         1
shells_with_ksh_fpath     
silent_shell_debug        <undef>
siteconfig                /MODULES/4.7.1/etc/siteconfig.tcl
tag_abbrev                auto-loaded=aL:loaded=L:hidden=H:hidden-loaded=H:forbidden=F:nearly-forbidden=nF:sticky=S:super-sticky=sS
tag_color_name            
tcl_ext_lib               /MODULES/4.7.1/lib/libtclenvmodules.so
term_background           dark
term_width                0
unload_match_order        returnlast
verbosity                 normal
wa_277                    0

- State name -----------.- Value ----------------------------------------------
always_read_full_file     1
autoinit                  0
clock_seconds             1620279261
cmdline                   /MODULES/4.7.1/libexec/modulecmd.tcl bash config --dump-state
commandname               config
domainname                (none)
error_count               0
extra_siteconfig_loaded   0
false_rendered            0
force                     0
hiding_threshold          0
inhibit_errreport         0
inhibit_interp            0
init_error_report         1
is_stderr_tty             1
is_win                    0
kernelversion             #1 SMP Wed Feb 3 15:06:38 UTC 2021
lm_info_cached            0
machine                   x86_64
modulefile                {}
nodename                  rh7test
os                        Linux
osversion                 3.10.0-1160.15.2.el7.x86_64
paginate                  1
path_separator            :
report_format             regular
reportfd                  file6
return_false              0
shell                     bash
shelltype                 sh
siteconfig_loaded         1
sub1_separator            &
sub2_separator            |
subcmd                    config
subcmd_args               --dump-state
tcl_ext_lib_loaded        1
tcl_version               8.5.13
tcl_version_lt85          0
term_columns              136
usergroups                dauria
username                  dauria

- Env. variable --------.- Value ----------------------------------------------
BASH_FUNC__module_raw()   () {  unset _mlshdbg;
 if [ "${MODULES_SILENT_SHELL_DEBUG:-0}" = '1' ]; then
 case "$-" in 
 *v*x*)
 set +vx;
 _mlshdbg='vx'
 ;;
 *v*)
 set +v;
 _mlshdbg='v'
 ;;
 *x*)
 set +x;
 _mlshdbg='x'
 ;;
 *)
 _mlshdbg=''
 ;;
 esac;
 fi;
 unset _mlre _mlIFS;
 if [ -n "${IFS+x}" ]; then
 _mlIFS=$IFS;
 fi;
 IFS=' ';
 for _mlv in ${MODULES_RUN_QUARANTINE:-};
 do
 if [ "${_mlv}" = "${_mlv##*[!A-Za-z0-9_]}" -a "${_mlv}" = "${_mlv#[0-9]}" ]; then
 if [ -n "`eval 'echo ${'$_mlv'+x}'`" ]; then
 _mlre="${_mlre:-}${_mlv}_modquar='`eval 'echo ${'$_mlv'}'`' ";
 fi;
 _mlrv="MODULES_RUNENV_${_mlv}";
 _mlre="${_mlre:-}${_mlv}='`eval 'echo ${'$_mlrv':-}'`' ";
 fi;
 done;
 if [ -n "${_mlre:-}" ]; then
 eval `eval ${_mlre} /usr/bin/tclsh /MODULES/4.7.1/libexec/modulecmd.tcl bash '"$@"'`;
 else
 eval `/usr/bin/tclsh /MODULES/4.7.1/libexec/modulecmd.tcl bash "$@"`;
 fi;
 _mlstatus=$?;
 if [ -n "${_mlIFS+x}" ]; then
 IFS=$_mlIFS;
 else
 unset IFS;
 fi;
 unset _mlre _mlv _mlrv _mlIFS;
 if [ -n "${_mlshdbg:-}" ]; then
 set -$_mlshdbg;
 fi;
 unset _mlshdbg;
 return $_mlstatus
}
BASH_FUNC_module()        () {  _module_raw "$@" 2>&1
}
LOADEDMODULES             R/4.0.3
LOADEDMODULES_modshare    R/4.0.3:1
MANPATH_modshare          /MODULES/4.7.1/share/man:1::1:/APPS//share/man:1
MODULEPATH                /MODULES/modulefiles:/MODULES/4.7.1/modulefiles
MODULEPATH_modshare       /MODULES/modulefiles:1:/MODULES/4.7.1/modulefiles:1
MODULESHOME               /MODULES/4.7.1
MODULES_CMD               /MODULES/4.7.1/libexec/modulecmd.tcl
PATH_modshare             /usr/sbin:1:/bin:1:/APPS//R/4.0.3/bin:1:/usr/bin:1:/home/dauria/.local/bin:1:/home/dauria/bin:1:/usr/local/sbin:1:/MODULES/4.7.1/bin:1:/usr/local/bin:1:/sbin:1
_LMFILES_                 /MODULES/modulefiles/R/4.0.3
_LMFILES__modshare        /MODULES/modulefiles/R/4.0.3:1

Additional context

[xdelaruelle]

Many thanks for your bug report.

The handling of internal states of modulecmd have been reworked on recent versions and the getEvalModuleStackDepth procedure has been removed. I forgot to update impacted recipes like the log module command one.

Instead of [getEvalModuleStackDepth], it should now be written [depthState modulename].

[rdauria]

Hello Xavier,

Thanks for the fix, it works. Do you have a quick way to perhaps only log module commands only when the first argument is "load"? I suppose I could nest an if statement, but perhaps you have already thought of it?

Also, is the example directory available anywhere for download?

Thanks,

RD

[xdelaruelle]

Thanks for the fix, it works. Do you have a quick way to perhaps only log module commands only when the first argument is "load"? I suppose I could nest an if statement, but perhaps you have already thought of it?

As you say, a nested if on the $command variable can do the job:

if {[depthState modulename] == 0 && [string match lo* $command]} {
   exec logger -t module "[get-env USER]: $command [join $args]"
}

Match is made with lo* pattern as load sub-command can be abbreviated lo or loa.

Also, is the example directory available anywhere for download?

Example from all cookbook recipes can be found in the repository at https://github.com/cea-hpc/modules/tree/master/doc/example