Bug#748962: marked as done (texlive-bastexlive-base: fmtutil-sys --all may not return error exit code under low free space condition.)

Package: texlive-base
Version: 2013.20140408-1
Severity: important
Tags: d-i upstream patch

Dear Maintainer,

   * What led up to the situation?
     There was a strange failure of tex installation that was likely to be
caused by low free space condition.
It was not clear what failure could lead to such strange condition.

   * What exactly did you do (or not do) that was effective (or
     ineffective)?
     I tried to figure out which command failed and at the same time failed to
    return proper exit value to the invoking programs.

   * What was the outcome of this action?
      I am attaching a patch to fix a slightly buggy function and
      tighten up checks in fmtutil.sh

   * What outcome did you expect instead?

     I think the installer will catch more errors due to low
free-space conditions during the installation with the patch, and this
should save support man-hours later.

Description

"fmtutil-sys --all" may not return error exit code under low free space condition.

This submission is an extension to 748271, but now with a much more
sharper focus.
Bug#748271: Info received (Bug#748271: [latex-cjk-common] latex command did not
work until I ran it once under superuser!?)

Thank you for the help so far regarding 748271.

Now, I *may* have identified WHY the error condition (under low space
condition) was not propagated to debian aptitude/apt-get installation
command under a very rage circumstance, and that could be the reason
why the incorrect TeX* installation was not caught earlier in my previous case.

(It may not be the root cause, but still the problem noticed in this bug report is
valid and can be fixed by the attached patch.)

I found that fmtutil.sh has a slightly buggy function.
(fmtutil.sh is part of texlive-base and is called eventually when
fmtutil-sys --all is called during installation to create .fmt files.)

I am attaching a patch to re-define the problematic function and to
replace log_warning with log_failure to signal the calling program
that a failure occurred.

Short Summary:

There is one shell-function "verbose()" which is used to invoke a
passed command and redirect stderr based on the exit value of
$mktexfmtMode (which is either "true" or "false").

Here is the definition of buggy verbose()
from fmtutil.sh ( linked from /usr/bin/fmtutil to
/usr/share/texlive/texmf-dist/scripts/texlive/fmtutil.sh)

###############################################################################
# verbose (cmd)
#   execute cmd. Redirect output depending on $mktexfmtMode.
###############################################################################
verbose()
{
$mktexfmtMode && ${1+"$@"} >&2 || ${1+"$@"}
}

This function as it is written today is buggy in the sense that
if the command fails when $mktexfmtMode is "true", the failing command
is executed TWICE (!). The first execution is with the rediretion of
STDERR. The second execution is without such redirection.
I think this is quite unintentional.

Also, the exit code from this execution of
"verbose other command options ..." becomes,
when the command fails on the LEFT Hand Side (LHS) of "||",
it is the exit code of the executed command (without re-direction) on
the right-hand side (RHS)

Under very space-tight conditions of a local file system, the failure
may happen while the stderr is re-directed (LHS), but a failure may not
happen when the command is executed as is without re-direction (RHS).

If this rare but possible scenario happens, "set -e" near the top of
fmtutil.sh is useless to catch the error since "verbose ...." 'as a whole'
returns the successful exit code of non-redirected command on the RHS
of "||".

MORE DETAILS:

This slightly buggy function is called within run_initex
(yes, that is where the fmt files are created eventually!)

This "verbose" function should be rewritten to avoid the re-execution
of the command "${1+"$@"}" when it fails when $mktexfmtMode is true.

Correction-1:

verbose()
{
    if $mktexfmtMode
    then
         ${1+"$@"} >&2
    else
        ${1+"$@"}
    fi
}

Background/Detective Work

After bug 748271 was closed, I tried to test what could go wrong a little
further.
I downloaded TeXLive 2013 source file from TUG web site.
I untarred it and began checking fmtutil-sys and found that these end up
as links to fmtutil and that is /usr/bin/fmtutil and again is a symlink
to /usr/share/texlive/texmf-dist/scripts/texlive/fmtutil.sh in Debian.
I tried to check what could go wrong and yet remain undetected, thus
failing to stop apt-get/aptitude as unsuccessful.

First thing, first.
As Norbert noted that there is "set -e" near the installed
fmtutil.sh. Great!
Surprisingly, this "set -e" is missing from the stock TeXLive 2013
source from TUG?! So maybe this is Debian only now? I hope the upstream
TeXLive 2014 is fixed to have this "set -e" in fmtutil.sh

But then what can possibly go wrong? My bet was that some commands
that are called are not returning the exit error code correctly. I
traced what would happen when "--all" is passed to fmtutil, and found
that the user-defined functions are called in this manner.

main
->
recreate_all
->
   recreate_loop
   ->
    run_initex
    ->
     verbose

In run_initex, the following piece of code is where the meat of
processing takes place.

--- quote
verboseMsg "$progname: running \`$engine -ini $tcxflag $jobswitch $prgswitch
$texargs' ..."

# run in a subshell to get a local effect of TEXPOOL manipulation:
(
    # If necessary, set TEXPOOL. Use absolute path, because of KPSE_DOT.
    $localpool && { TEXPOOL="`pwd`:$TEXPOOL"; export TEXPOOL; }
    verbose $engine -ini $tcxflag $jobswitch $prgswitch $texargs
) </dev/null
--- end quote

I realized that "verboseMsg" is to print out what is going on to the
log.
and somehow user-defined "verbose" command was used to invoke the
command, "$engine -ini $tcxflag $jobswitch $prgswitch $texargs".

Now, I checked what could go wrong with this small code snippet
by creating a very simplified script as follows.

I traced the function of verbose by running failing command (in this
case, "cp /dev/null /etc" that should fail under ordinary user) and
tested the operation in the following manner.

# /tmp/t-buggy.sh
---- begin quote of /tmp/t-buggy.sh
#!/bin/sh
#

# This script is to show that a failure of
# a command executed in verbose may be executed twice.

# false is not a good failure command sample

set -e

rc=0

verbose() # original. This is buggy!
{
$mktexfmtMode && ${1+"$@"} >&2 || ${1+"$@"}
}

#
run_initex()
{
# run in a subshell to see if this changes anything.
(
      echo "run_initex called"
      # DO SOMETHING THAT SHOULD FAIL
      cp /dev/null /etc
) </dev/null
}

# should succeed
verbose echo "hello, world"
echo "rc = $?"

echo before cp /dev/null /etc
# should fail
verbose cp /dev/null /etc
echo "rc = $?"

echo before subshell execution
# should fail
# run in a subshell ...
(
    verbose cp /dev/null /etc
) </dev/null
echo "rc = $?"

echo before run_initex

mktexfmtMode=true
rc=1
# should fail since run_initex invokes false inside.
verbose run_initex $rc
echo "rc = $?"

echo before cp /dev/null /etc
# should fail under ordinary user account.
verbose cp /dev/null /etc
echo "rc = $?"

exit 0
--- end quote ---

The above is the content of the script.
Now let us run it.

$ /tmp/t-buggy.sh || echo failure
hello, world
rc = 0
before cp /dev/null /etc
cp: cannot create regular file '/etc/null': Permission denied
cp: cannot create regular file '/etc/null': Permission denied
failure
$

Please notice the repeated execution of the failed command by "verbose()".
That is because when the $mktexfmtMode is true the passed command is
executed with redirection.
In this case, the passed command "cp /dev/null /etc" should fail for
ordinary user.
But it is then reexecited because of ||. Shell figured that Left-Hand
Side (LHS) failed and so tried to execute Right-Hand Side (RHS), too.

Now, when I rewrite verbose() in the suggested manner, what happens?
With fixed verbose (as in correction-1 above):

$ /tmp/t-OK.sh || echo fail
hello, world
rc = 0
before cp /dev/null /etc
cp: cannot create regular file '/etc/null': Permission denied
fail
$

Great. It is executed only once and I think this is the intended behavior.

BTW, suppose the intention of "verbose" was to capture whatever error
message (to file descriptor 2) to a file associated with STDOU and
later check error condition by searching for a certain string pattern, we may encounter a subtle problem *IF and ONLY IF* the command fails during an almost full file system condition when stderr is redirected to standard output, AND IF it succeeds without such redirection.

(If the file system was almost full, then the LHS of the original "||"
in "verbose" may have failed due to redirection, but somehow RHS may
have succeeded since there was no re-direction of error message to
almost full system. This may cause a very perplexing situation, indeed.)

Near line 765, we have the following code snippet in fmtutil.sh:

--- quote
if test -f "$fmtfile"; then
    grep '^! ' $format.log >/dev/null 2>&1 &&
      log_warning "\`$engine -ini $tcxflag $jobswitch $prgswitch $texargs'
possibly failed."
--- end quote

Like I said, format.log may have failed to capture the error message
under a very space-tight condition in "verbose()".
I would love to see the "log_warning" to be changed to a
failing "log_failure" instead. (correction-2)

There is another usage of "log_warning" near line 796.

--- quote
          if cp "$destfile" "$mplib_mem_file" </dev/null; then
            mktexupd "$fulldestdir" "$mplib_mem_name"
          else
            log_warning "cp $destfile $mplib_mem_file failed."
          fi
--- end quote

The warning is indeed produced when the file system is full and "cp"
can fail then! So, for obvious reasons, I would like to see this
usage of "log_warning" changed into "log_failure", too. (cprrectopm-3)

To wrap up, I am attaching a patch.
Please find below the diff of modified fmtutil.sh

fmtutil is actually /usr/share/texlive/texmf-dist/scripts/texlive/fmtutil.sh
diff of modified fmtutil in /tmp/fmtutil.sh
and
/usr/bin/fmtutil which is a symlink to the script under
/usr/share/texlive/...
was produced and attached.

Thank you in advance for your attention.

PS: This bug report was created by Debian's reportbug under a PC (32-bit Debian GNU/Linux)
and is not the same PC where the previous bug was reported, but
the shell script should be the same on 32-bit and 64-bit, and the script certainly
has a subtle problem.

-- Package-specific info:
IMPORTANT INFORMATION: We will only consider bug reports concerning
the packaging of TeX Live as relevant. If you have problems with
combination of packages in a LaTeX document, please consult your
local TeX User Group, the comp.text.tex user group, the author of
the original .sty file, or any other help resource.

In particular, bugs that are related to up-upstream, i.e., neither
Debian nor TeX Live (upstream), but the original package authors,
will be closed immediately.

   *** The Debian TeX Team is *not* a LaTeX Help Desk ***

If you report an error when running one of the TeX-related binaries
(latex, pdftex, metafont,...), or if the bug is related to bad or wrong
output, please include a MINIMAL example input file that produces the
error in your report.

Please run your example with
    (pdf)latex -recorder ...
(or any other program that supports -recorder) and send us the generated
file with the extension .fls, it lists all the files loaded during
the run and can easily explain problems induced by outdated files in
your home directory.

Don't forget to also include minimal examples of other files that are
needed, e.g. bibtex databases. Often it also helps
to include the logfile. Please, never send included pictures!

If your example file isn't short or produces more than one page of
output (except when multiple pages are needed to show the problem),
you can probably minimize it further. Instructions on how to do that
can be found at

http://www.minimalbeispiel.de/mini-en.html (english)

or

http://www.minimalbeispiel.de/mini.html (german)

##################################
minimal input file

##################################
other files

######################################
List of ls-R files

-rw-r--r-- 1 root root 1047 May 13 17:52 /var/lib/texmf/ls-R
-rw-rw-r-- 1 root staff 80 May 13 16:05 /usr/local/share/texmf/ls-R
lrwxrwxrwx 1 root root 29 Jun 15 2013 /usr/share/texmf/ls-R -> /var/lib/texmf/ls-R-TEXMFMAIN
lrwxrwxrwx 1 root root 31 Apr 8 11:51 /usr/share/texlive/texmf-dist/ls-R -> /var/lib/texmf/ls-R-TEXLIVEDIST
lrwxrwxrwx 1 root root 31 Apr 8 11:51 /usr/share/texlive/texmf-dist/ls-R -> /var/lib/texmf/ls-R-TEXLIVEDIST
######################################
Config files
-rw-r--r-- 1 root root 838 May 13 17:50 /etc/texmf/web2c/texmf.cnf
-rw-r--r-- 1 root root 4589 May 13 17:52 /var/lib/texmf/web2c/fmtutil.cnf
lrwxrwxrwx 1 root root 32 Apr 8 11:51 /usr/share/texmf/web2c/updmap.cfg -> /var/lib/texmf/updmap.cfg-DEBIAN
-rw-r--r-- 1 root root 3497 May 13 17:52 /var/lib/texmf/tex/generic/config/language.dat
######################################
Files in /etc/texmf/web2c/
total 2
-rw-r--r-- 1 root root 283 Nov 10 2008 mktex.cnf
-rw-r--r-- 1 root root 838 May 13 17:50 texmf.cnf
######################################
md5sums of texmf.d
ca40c66f144b4bafc3e59a2dd32ecb9c /etc/texmf/texmf.d/00debian.cnf
d41d8cd98f00b204e9800998ecf8427e /etc/texmf/texmf.d/20ptexjtex.bak
1df66bc319cec731e202eaf39f5d85e1 /etc/texmf/texmf.d/96JadeTeX.cnf

-- System Information:
Debian Release: jessie/sid
APT prefers testing
APT policy: (500, 'testing'), (500, 'stable')
Architecture: i386 (i686)

Kernel: Linux 3.2.0-4-686-pae (SMP w/2 CPU cores)
Locale: LANG=C, LC_CTYPE=C (charmap=ANSI_X3.4-1968) (ignored: LC_ALL set to C)
Shell: /bin/sh linked to /bin/dash

Versions of packages texlive-base depends on:
ii debconf [debconf-2.0] 1.5.52
ii dpkg                   1.17.6
ii libpaper-utils         1.1.24+nmu3
ii luatex                 0.76.0-3
ii tex-common             4.04
ii texlive-binaries       2013.20130729.30972-2+b3
ii ucf                    3.0027+nmu1
ii xdg-utils              1.1.0~rc1+git20111210-7

Versions of packages texlive-base recommends:
ii lmodern 2.004.4-3

Versions of packages texlive-base suggests:
ii evince [postscript-viewer]       3.4.0-3.1+b1
ii ghostscript [postscript-viewer] 9.05~dfsg-8+b1
pn perl-tk                          <none>
pn xpdf-reader | pdf-viewer         <none>

Versions of packages tex-common depends on:
ii debconf [debconf-2.0] 1.5.52
ii dpkg                   1.17.6
ii ucf                    3.0027+nmu1

Versions of packages tex-common suggests:
ii debhelper 9.20140228

Versions of packages texlive-base is related to:
ii tex-common        4.04
ii texlive-binaries 2013.20130729.30972-2+b3

-- debconf information:
texlive-base/texconfig_ignorant:
tex-common/check_texmf_wrong:
texlive-base/binary_chooser: pdftex, dvips, dvipdfmx, xdvi
tex-common/check_texmf_missing: