Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Allow for parallel format creation #1

Open
wants to merge 4 commits into
base: master
Choose a base branch
from
Open

Conversation

norbusan
Copy link
Member

@norbusan norbusan commented May 8, 2024

No description provided.

norbusan added 2 commits May 8, 2024 09:53
- make forking optional
- test for availability of ForkManager
- add command line option to disable forking
- when running with forkmanager, dump output of compile logs to $nul
- if --quiet is given, also hide the compile logs
@@ -128,6 +130,7 @@ BEGIN
"no-engine-subdir",
"no-error-if-no-engine=s",
"no-error-if-no-format",
"no-fork",
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Add a command line argument to disable forking even in presence of ForkManager module.

} else {
$USE_FORKMANAGER = 1;
}
}
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Dynamically check for presence of the forking module

# in mktexfmtMode we must redirect *all* output to stderr
$cmdline .= " >&2" if $mktexfmtMode;
if ($opts{'quiet'} || $USE_FORKMANAGER) {
$cmdline .= " >$nul 2>$nul";
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we run in quiet mode, or under fork manager, we do NOT show the output of the format creation run.
This complete log is still in the log file.

@norbusan
Copy link
Member Author

norbusan commented May 8, 2024

with forkmanager

$ time fmtutil-sys --byengine=euptex
fmtutil: fmtutil is using the following fmtutil.cnf files (in precedence order):
fmtutil:   /home/norbert/tl/2024/texmf-dist/web2c/fmtutil.cnf
fmtutil: fmtutil is using the following fmtutil.cnf file for writing changes:
fmtutil:   /home/norbert/tl/2024/texmf-config/web2c/fmtutil.cnf
fmtutil [INFO]: writing formats under /home/norbert/tl/2024/texmf-var/web2c
fmtutil [INFO]: --- remaking euptex with euptex
fmtutil: running `euptex -ini   -jobname=euptex -progname=euptex *euptex.ini' ...
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/euptex/euptex.log
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/euptex/euptex.fmt installed.
fmtutil [INFO]: --- remaking platex with euptex
fmtutil [INFO]: --- remaking uptex with euptex
fmtutil [INFO]: --- remaking uplatex with euptex
fmtutil [INFO]: --- remaking platex-dev with euptex
fmtutil [INFO]: --- remaking eptex with euptex
fmtutil [INFO]: --- remaking uplatex-dev with euptex
fmtutil [INFO]: --- remaking ptex with euptex
fmtutil: running `euptex -ini   -jobname=uptex -progname=uptex uptex.ini' ...
fmtutil: running `euptex -ini   -jobname=platex -progname=platex -kanji-internal=euc *platex.ini' ...
fmtutil: running `euptex -ini   -jobname=uplatex -progname=uplatex *uplatex.ini' ...
fmtutil: running `euptex -ini   -jobname=uplatex-dev -progname=uplatex-dev *uplatex.ini' ...
fmtutil: running `euptex -ini   -jobname=platex-dev -progname=platex-dev -kanji-internal=euc *platex.ini' ...
fmtutil: running `euptex -ini   -jobname=ptex -progname=ptex -kanji-internal=euc ptex.ini' ...
fmtutil: running `euptex -ini   -jobname=eptex -progname=eptex -kanji-internal=euc *eptex.ini' ...
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/euptex/uptex.log
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/euptex/uptex.fmt installed.
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/euptex/ptex.log
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/euptex/ptex.fmt installed.
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/euptex/eptex.log
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/euptex/eptex.fmt installed.
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/euptex/platex.log
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/euptex/platex.fmt installed.
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/euptex/uplatex.log
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/euptex/platex-dev.log
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/euptex/uplatex.fmt installed.
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/euptex/platex-dev.fmt installed.
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/euptex/uplatex-dev.log
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/euptex/uplatex-dev.fmt installed.
fmtutil [INFO]: disabled formats: 3
fmtutil [INFO]: successfully rebuilt formats: 8
fmtutil [INFO]: not selected formats: 46
fmtutil [INFO]: total formats: 57
fmtutil [INFO]: exiting with status 0

real    0m7.787s
user    0m22.445s
sys     0m0.888s

@norbusan
Copy link
Member Author

norbusan commented May 8, 2024

without forking

$ time fmtutil-sys --no-fork --byengine=euptex
fmtutil: fmtutil is using the following fmtutil.cnf files (in precedence order):
fmtutil:   /home/norbert/tl/2024/texmf-dist/web2c/fmtutil.cnf
fmtutil: fmtutil is using the following fmtutil.cnf file for writing changes:
fmtutil:   /home/norbert/tl/2024/texmf-config/web2c/fmtutil.cnf
fmtutil [INFO]: writing formats under /home/norbert/tl/2024/texmf-var/web2c
fmtutil [INFO]: --- remaking euptex with euptex
fmtutil: running `euptex -ini   -jobname=euptex -progname=euptex *euptex.ini' ...
This is e-upTeX, Version 3.141592653-p4.1.1-u1.30-230214-2.6 (utf8.uptex) (TeX Live 2024) (INITEX)
 restricted \write18 enabled.
entering extended mode
(/home/norbert/tl/2024/texmf-dist/tex/uptex/uptex-base/euptex.ini
...
... lots of lines removed
...
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/euptex/uplatex.log
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/euptex/uplatex.fmt installed.
fmtutil [INFO]: disabled formats: 3
fmtutil [INFO]: successfully rebuilt formats: 8
fmtutil [INFO]: not selected formats: 46
fmtutil [INFO]: total formats: 57
fmtutil [INFO]: exiting with status 0

real    0m18.710s
user    0m18.010s
sys     0m0.686s

@norbusan
Copy link
Member Author

norbusan commented May 8, 2024

with forkmanager and --quiet

$ time fmtutil-sys --byengine=euptex --quiet
fmtutil: running `euptex -ini   -jobname=euptex -progname=euptex *euptex.ini' ...
fmtutil: running `euptex -ini   -jobname=uplatex -progname=uplatex *uplatex.ini' ...
fmtutil: running `euptex -ini   -jobname=uptex -progname=uptex uptex.ini' ...
fmtutil: running `euptex -ini   -jobname=ptex -progname=ptex -kanji-internal=euc ptex.ini' ...
fmtutil: running `euptex -ini   -jobname=platex-dev -progname=platex-dev -kanji-internal=euc *platex.ini' ...
fmtutil: running `euptex -ini   -jobname=platex -progname=platex -kanji-internal=euc *platex.ini' ...
fmtutil: running `euptex -ini   -jobname=eptex -progname=eptex -kanji-internal=euc *eptex.ini' ...
fmtutil: running `euptex -ini   -jobname=uplatex-dev -progname=uplatex-dev *uplatex.ini' ...

real    0m7.771s
user    0m22.988s
sys     0m0.927s

@norbusan
Copy link
Member Author

norbusan commented May 8, 2024

without forkmanager and --quiet

$ time fmtutil-sys --no-fork --byengine=euptex --quiet
fmtutil: running `euptex -ini   -jobname=euptex -progname=euptex *euptex.ini' ...
fmtutil: running `euptex -ini   -jobname=uplatex-dev -progname=uplatex-dev *uplatex.ini' ...
fmtutil: running `euptex -ini   -jobname=uplatex -progname=uplatex *uplatex.ini' ...
fmtutil: running `euptex -ini   -jobname=platex -progname=platex -kanji-internal=euc *platex.ini' ...
fmtutil: running `euptex -ini   -jobname=uptex -progname=uptex uptex.ini' ...
fmtutil: running `euptex -ini   -jobname=eptex -progname=eptex -kanji-internal=euc *eptex.ini' ...
fmtutil: running `euptex -ini   -jobname=platex-dev -progname=platex-dev -kanji-internal=euc *platex.ini' ...
fmtutil: running `euptex -ini   -jobname=ptex -progname=ptex -kanji-internal=euc ptex.ini' ...

real    0m17.774s
user    0m17.131s
sys     0m0.582s

@norbusan
Copy link
Member Author

norbusan commented May 8, 2024

Timing for fmtutil-sys --all

Without forkmanager:

real    1m37.315s
user    1m33.175s
sys     0m3.799s

With forkmanager:

real    0m31.936s
user    7m54.376s
sys     0m15.308s

@kberry
Copy link

kberry commented May 8, 2024

As your TODO implies, $nproc = 24 needs to be changed before release. I don't know how to easily determine a value, though. how portable is the nproc program? What about Windows? Just disable on Windows?

@kberry
Copy link

kberry commented May 8, 2024

Anyway, nproc is not so important. What's important to me is the (lack of) output. If I'm understanding right, I don't like the fact that forking implies --quiet. The result will be that nothing shows up in install-tl.log / tlmgr-commands.log. I.e., debugging becomes impossible. The .log files from TeX are not sufficient to figure out what's going on when it fails, in my experience. I don't have an easy solution. Sorry.

@marmitar
Copy link

marmitar commented May 9, 2024

Yes, there still need some work with the output, I'll try to implement per-process output buffer, like I discussed on TeX-Live/texlive-source#69. There's also the problem with print_deferred_* functions being ignored.

@norbusan
Copy link
Member Author

norbusan commented May 9, 2024

As your TODO implies, $nproc = 24 needs to be changed before release. I don't know how to easily determine a value, though. how portable is the nproc program?

Good point. Maybe set it to something conservative like 8 or so?
Or rad /proc/cpuinfo on linux, something similar on Mac, and some env var on Windows, ...

What about Windows? Just disable on Windows?

Probably better to, I don't trust forks on Windows.

@norbusan
Copy link
Member Author

norbusan commented May 9, 2024

What's important to me is the (lack of) output.

What about the following, which we are already doing in tlmgr, namely use TLUtils::run_cmd which catches stdout and returns the return value and the stdout output.

If all went well, just drop the stdout, but if something fails, dump everything to stdout.

Would that work?

@norbusan
Copy link
Member Author

norbusan commented May 9, 2024

There's also the problem with print_deferred_* functions being ignored.

Indeed, the reason for the print_deferred_* is that at the moment we have all the voluminous stdout output, and giving advice/error messages in the middle of the logs is not helpful, nobody will see them.

Maybe the best is:

  • every forked run has its't own temp directory
  • write stdout and stderr to that temp dir
  • writes deferred print statements to a separate file

and after we have returned control to the main program:

  • check the exit codes
  • if none-success, dump stdout/stderr of the process
  • dump defererred print statements from the tmp dirs

WDYT?

@kberry
Copy link

kberry commented May 9, 2024 via email

@kberry
Copy link

kberry commented May 9, 2024

Dick Koch confirms sysctl -n hw.ncpu for Macs.

@norbusan
Copy link
Member Author

I changed the code to:

  • disable forkmanager on Windows
  • get the number of cpus via the suggestion from Karl
  • reset nproc to 0 if the value get is not a number

@norbusan
Copy link
Member Author

I also have tried now to deal with the deferred prints and the mixed up printing.
It is not completely disentangled, but at least only logs for failed formats will be printed.

@@ -203,6 +206,18 @@ sub main {
die "$0: Unexpected non-option argument(s): @ARGV\n"
. "Try \"$prg --help\" for more information.\n";
}
# for full fmtutil, let us try to use ForkManager if available
# do not try this on Windows
if (wndws() || $opts{"no-fork"}) {
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We disable forking on windows

@kberry
Copy link

kberry commented May 10, 2024 via email

@norbusan
Copy link
Member Author

norbusan commented May 10, 2024

With the current code and an error happening, we get the following output.
I have edited csplain.ini to contain some dummy code, and then run

``` fmtutil-sys --byengine xetex
fmtutil: fmtutil is using the following fmtutil.cnf files (in precedence order):
fmtutil:   /home/norbert/tl/2024/texmf-dist/web2c/fmtutil.cnf
fmtutil: fmtutil is using the following fmtutil.cnf file for writing changes:
fmtutil:   /home/norbert/tl/2024/texmf-config/web2c/fmtutil.cnf
fmtutil [INFO]: writing formats under /home/norbert/tl/2024/texmf-var/web2c
fmtutil [INFO]: --- remaking xetex with xetex
fmtutil: running `xetex -ini   -jobname=xetex -progname=xetex -etex xetex.ini' ...
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/xetex/xetex.log
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/xetex/xetex.fmt installed.
fmtutil [INFO]: --- remaking cont-en with xetex
fmtutil [INFO]: --- remaking xelatex with xetex
fmtutil [INFO]: --- remaking pdfcsplain with xetex
fmtutil [INFO]: --- remaking xelatex-dev with xetex
fmtutil: running `xetex -ini   -jobname=cont-en -progname=context -8bit *cont-en.mkii' ...
fmtutil: running `xetex -ini   -jobname=xelatex -progname=xelatex -etex xelatex.ini' ...
fmtutil: running `xetex -ini   -jobname=pdfcsplain -progname=pdfcsplain -etex csplain.ini' ...
fmtutil: running `xetex -ini   -jobname=xelatex-dev -progname=xelatex-dev -etex xelatex.ini' ...
This is XeTeX, Version 3.141592653-2.6-0.999996 (TeX Live 2024) (INITEX)
 restricted \write18 enabled.
entering extended mode
(/home/norbert/tl/2024/texmf-dist/tex/csplain/base/csplain.ini
! Undefined control sequence.
l.2 \foobar
           
? 
! Emergency stop.
l.2 
    
No pages of output.
Transcript written on pdfcsplain.log.fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/xetex/pdfcsplain.log
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/xetex/cont-en.log
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/xetex/cont-en.fmt installed.
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/xetex/xelatex.log
fmtutil [INFO]: log file copied to: /home/norbert/tl/2024/texmf-var/web2c/xetex/xelatex-dev.log
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/xetex/xelatex.fmt installed.
fmtutil [INFO]: /home/norbert/tl/2024/texmf-var/web2c/xetex/xelatex-dev.fmt installed.
fmtutil [ERROR]: running `xetex -ini   -jobname=pdfcsplain -progname=pdfcsplain -etex csplain.ini </dev/null' return status: 0.00390625
fmtutil [ERROR]: returning error due to option --strict
fmtutil [INFO]: disabled formats: 3
fmtutil [INFO]: successfully rebuilt formats: 4
fmtutil [INFO]: not selected formats: 49
fmtutil [INFO]: failed to build: 1 (xetex/pdfcsplain)
fmtutil [INFO]: total formats: 57
fmtutil [INFO]: exiting with status 1

That shows that the deferred printing is working and output is shown.

@norbusan
Copy link
Member Author

norbusan commented May 10, 2024 via email

@kberry
Copy link

kberry commented May 11, 2024 via email

@marmitar
Copy link

marmitar commented May 11, 2024

Really nice work @norbusan!

I was thinking about something like the following for the output. Store each line that would be printed in a variable and print it all at once in when the process is exiting. This would print the output of each format close together. What do you say?

diff --git a/texlive-scripts/fmtutil.pl b/texlive-scripts/fmtutil.pl
index cc304a0..ce46c20 100755
--- a/texlive-scripts/fmtutil.pl
+++ b/texlive-scripts/fmtutil.pl
@@ -58,6 +58,13 @@ my $FMT_NOTAVAIL    = 4;
 my $nul = (wndws() ? 'nul' : '/dev/null');
 my $sep = (wndws() ? ';' : ':');
 
+my $print_stderr = sub {
+  print STDERR @_;
+};
+my $print_stdout = sub {
+  print STDOUT @_;
+};
+
 my @deferred_stderr;
 my @deferred_stdout;
 # $::opt_verbosity = 3; # manually enable debugging
@@ -533,11 +540,21 @@ sub callback_build_formats {
         next if ($swi eq "format=engine" && $fmt ne $eng);
         next if ($swi eq "format!=engine" && $fmt eq $eng);
         $total++;
+        my $collected_stderr = "";
+        my $collected_stdout = "";
         if ($USE_FORKMANAGER) {
           $pm->start("select_and_rebuild_format($fmt, $eng, $what, $whatarg)") and next;
+          $print_stderr = sub {
+            $collected_stderr = $collected_stderr . join "", @_;
+          };
+          $print_stdout = sub {
+            $collected_stdout = $collected_stdout . join "", @_;
+          };
         }
         my $val = select_and_rebuild_format($fmt, $eng, $what, $whatarg);
         if ($USE_FORKMANAGER) {
+          print STDERR $collected_stderr;
+          print STDOUT $collected_stdout;
           my @array = ($fmt, $eng, \@deferred_stdout, \@deferred_stderr);
           $pm->finish($val, \@array);
         } else {
@@ -1452,23 +1469,23 @@ sub reset_root_home {
 #
 sub print_info {
   if ($mktexfmtMode) {
-    print STDERR "$prg [INFO]: ", @_ if (!$opts{'quiet'});
+    $print_stderr->("$prg [INFO]: ", @_) if (!$opts{'quiet'});
   } else {
-    print STDOUT "$prg [INFO]: ", @_ if (!$opts{'quiet'});
+    $print_stdout->("$prg [INFO]: ", @_) if (!$opts{'quiet'});
   }
 }
 sub print_verbose {
   if ($mktexfmtMode) {
-    print STDERR "$prg: ", @_;
+    $print_stderr->("$prg: ", @_);
   } else {
-    print STDOUT "$prg: ", @_;
+    $print_stdout->("$prg: ", @_);
   }
 }
 sub print_warning {
-  print STDERR "$prg [WARNING]: ", @_ if (!$opts{'quiet'}) 
+  $print_stderr->("$prg [WARNING]: ", @_) if (!$opts{'quiet'})
 }
 sub print_error {
-  print STDERR "$prg [ERROR]: ", @_;
+  $print_stderr->("$prg [ERROR]: ", @_);
 }
 #
 # same with deferred

We could also collect the output into an array, and it may be more performant actually.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants