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

Observed durations of \setmainfont et al. feel big #528

Open
2 of 4 tasks
jfbu opened this issue Jul 30, 2024 · 4 comments
Open
2 of 4 tasks

Observed durations of \setmainfont et al. feel big #528

jfbu opened this issue Jul 30, 2024 · 4 comments

Comments

@jfbu
Copy link
Contributor

jfbu commented Jul 30, 2024

Description

Recently I worked on some project using lualatex and noticed during each build a systematic apparent "freeze" of one to two seconds right after having loaded unicode-math-table.tex. For a long time I blamed (this was silly) that file but now I understand it is \setmainfont et al. which were responsible for it all:

\setmainfont{DejaVu Serif}[
%  RawFeature={fallback=faqfallback}
]
\setsansfont{DejaVu Sans}[
%  RawFeature={fallback=faqfallback}
]
\setmonofont{DejaVu Sans Mono}[
%  RawFeature={fallback=faqfallback}
]

I have commented out here the fallback business (which exacerbates the situation but does not cause it) to focus on simpler configuration. I tested with TeX Gyre Termes too and found faster times but in my view "problem" persists.

fontspec is definitely not responsible for my lack of upgrade to my hardware, which I admit is currently quite outdated (2Ghz single core CPU at this time), and the timings would certainly be divided by at least 2, probably 5 on current CPUs.

Still a single \setmainfont or cousin costs an amount of time similar to loading all of unicode-math for example (from half as much to twice as much, with lualatex).

Check/indicate

  • Relevant for XeTeX
  • Relevant for LuaTeX
  • Issue tracker has been searched for similar issues?
  • Links to <tex.stackexchange.com> discussion if appropriate

Minimal example demonstrating the issue

Here is my test file

\documentclass{article}
\usepackage{pdftexcmds}
\usepackage{iftex}
\makeatletter
\let\pdfresettimer\pdf@resettimer
\let\pdfelapsedtime\pdf@elapsedtime
\makeatother

\usepackage{fontspec}

\pdfresettimer

\setmainfont{DejaVu Serif}

\typeout{(\ifxetex xelatex \else lualatex \fi 1)\the\dimexpr \pdfelapsedtime sp\relax}

\pdfresettimer

\setsansfont{DejaVu Sans}

\typeout{(\ifxetex xelatex \else lualatex \fi 2)\the\dimexpr \pdfelapsedtime sp\relax}

\pdfresettimer

\setmonofont{DejaVu Sans Mono}

\typeout{(\ifxetex xelatex \else lualatex \fi 3)\the\dimexpr \pdfelapsedtime sp\relax}


\pdfresettimer
\usepackage{unicode-math}
\typeout{UNICODE-MATH: \the\dimexpr\pdfelapsedtime sp\relax}

\begin{document}
nothing to worry \textsf{about}? \texttt{mono}
\end{document}

Typical console output with lualatex (pt is to be read as second)

(/usr/local/texlive/2024/texmf-dist/tex/latex/fontspec/fontspec.cfg)))
(lualatex 1)0.20174pt
(lualatex 2)0.28061pt
(lualatex 3)0.17163pt
(/usr/local/texlive/2024/texmf-dist/tex/latex/unicode-math/unicode-math.sty
(/usr/local/texlive/2024/texmf-dist/tex/latex/unicode-math/unicode-math-luatex.
sty
(/usr/local/texlive/2024/texmf-dist/tex/latex/l3packages/l3keys2e/l3keys2e.sty)
 (/usr/local/texlive/2024/texmf-dist/tex/latex/base/fix-cm.sty
(/usr/local/texlive/2024/texmf-dist/tex/latex/base/ts1enc.def))
(/usr/local/texlive/2024/texmf-dist/tex/latex/amsmath/amsmath.sty
For additional information on amsmath, use the `?' option.
(/usr/local/texlive/2024/texmf-dist/tex/latex/amsmath/amstext.sty
(/usr/local/texlive/2024/texmf-dist/tex/latex/amsmath/amsgen.sty))
(/usr/local/texlive/2024/texmf-dist/tex/latex/amsmath/amsbsy.sty)
(/usr/local/texlive/2024/texmf-dist/tex/latex/amsmath/amsopn.sty))
(/usr/local/texlive/2024/texmf-dist/tex/lualatex/lualatex-math/lualatex-math.st
y (/usr/local/texlive/2024/texmf-dist/tex/latex/etoolbox/etoolbox.sty))
(/usr/local/texlive/2024/texmf-dist/tex/latex/unicode-math/unicode-math-table.t
ex)))
UNICODE-MATH: 0.15425pt
(./testfontspec.aux)
[1{/usr/local/texlive/2024/texmf-var/fonts/map/pdftex/updmap/pdftex.map}]
(./testfontspec.aux))
 484 words of node memory still in use:
   6 hlist, 2 vlist, 2 rule, 2 glue, 4 kern, 1 glyph, 6 attribute, 52 glue_spec
, 6 attribute_list, 1 write nodes
   avail lists: 2:30,3:4,4:1,5:26,6:2,7:86,9:18,11:2
</usr/local/texlive/2024/texmf-dist/fonts/truetype/public/dejavu/DejaVuSansMono
.ttf></usr/local/texlive/2024/texmf-dist/fonts/truetype/public/dejavu/DejaVuSan
s.ttf></usr/local/texlive/2024/texmf-dist/fonts/truetype/public/dejavu/DejaVuSe
rif.ttf>

and with xelatex

(/usr/local/texlive/2024/texmf-dist/tex/latex/fontspec/fontspec.cfg)))
(xelatex 1)0.08669pt
(xelatex 2)0.07364pt
(xelatex 3)0.0464pt
(/usr/local/texlive/2024/texmf-dist/tex/latex/unicode-math/unicode-math.sty
(/usr/local/texlive/2024/texmf-dist/tex/latex/unicode-math/unicode-math-xetex.s
ty
(/usr/local/texlive/2024/texmf-dist/tex/latex/l3packages/l3keys2e/l3keys2e.sty)
 (/usr/local/texlive/2024/texmf-dist/tex/latex/base/fix-cm.sty
(/usr/local/texlive/2024/texmf-dist/tex/latex/base/ts1enc.def))
(/usr/local/texlive/2024/texmf-dist/tex/latex/amsmath/amsmath.sty
For additional information on amsmath, use the `?' option.
(/usr/local/texlive/2024/texmf-dist/tex/latex/amsmath/amstext.sty
(/usr/local/texlive/2024/texmf-dist/tex/latex/amsmath/amsgen.sty))
(/usr/local/texlive/2024/texmf-dist/tex/latex/amsmath/amsbsy.sty)
(/usr/local/texlive/2024/texmf-dist/tex/latex/amsmath/amsopn.sty))
(/usr/local/texlive/2024/texmf-dist/tex/latex/unicode-math/unicode-math-table.t
ex)))
UNICODE-MATH: 0.10739pt
(./testfontspec.aux)
[1] (./testfontspec.aux) )
Output written on testfontspec.pdf (1 page).
Transcript written on testfontspec.log.

Further details

With original context of lualatex with fallback config, the three font definitions ended up costing about 1s to 1.5s.

This is not an issue report but a question to learn if some profiling has been done to identify what causes observed execution times. Is it mostly engine issue, or at macro layer? "One second" is a lot of time when watching console output during preamble execution.

@wspr
Copy link
Collaborator

wspr commented Jul 30, 2024

It's been quite some time since I looked at profiling this code. I did have some l3benchmark hooks here and there at some point to figure out where the problems were (although I suspect unicode-math was where the main issues were found).

fontspec does do some speculative font loading, and I believe there might be some lingering caching issues where loading the same font with the same features shouldn't re-process everything (but actually it does).

My guess is that you might see some speed up if you explicitly specify the italic, bold, etc., shapes — it might be slow to use engine lookups for them. Sadly I don't have free cycles right now to tear apart the code line by line but I'm happy to keep this issue open to look into it in the future.

@jfbu
Copy link
Contributor Author

jfbu commented Jul 30, 2024

I tried specifying the italic, bold and bold-italic explicitly, and it did not change much:

(xelatex 1)0.0996pt
(xelatex 2)0.08202pt
(xelatex 3)0.05931pt
...
UNICODE-MATH: 0.11235pt

and

(lualatex 1)0.2339pt
(lualatex 2)0.28549pt
(lualatex 3)0.18494pt
...
UNICODE-MATH: 0.15825pt

I had to remove spaces from name (with xelatex, and I left it this way for lualatex). Maybe I should have added Extension=.ttf or Path?

Here is test file

\documentclass{article}
\usepackage{pdftexcmds}
\usepackage{iftex}
\makeatletter
\let\pdfresettimer\pdf@resettimer
\let\pdfelapsedtime\pdf@elapsedtime
\makeatother

\usepackage{fontspec}

\pdfresettimer

\setmainfont{DejaVuSerif}[
    RegularFont=*,
    BoldFont=*-Bold,
    ItalicFont=*-Italic,
    BoldItalicFont=*-BoldItalic,
]

\typeout{(\ifxetex xelatex \else lualatex \fi 1)\the\dimexpr \pdfelapsedtime sp\relax}

\pdfresettimer

\setsansfont{DejaVuSans}[
    RegularFont=*,
    BoldFont=*-Bold,
    ItalicFont=*-Oblique,
    BoldItalicFont=*-BoldOblique,
]

\typeout{(\ifxetex xelatex \else lualatex \fi 2)\the\dimexpr \pdfelapsedtime sp\relax}

\pdfresettimer

\setmonofont{DejaVuSansMono}[
    RegularFont=*,
    BoldFont=*-Bold,
    ItalicFont=*-Oblique,
    BoldItalicFont=*-BoldOblique,
]

\typeout{(\ifxetex xelatex \else lualatex \fi 3)\the\dimexpr \pdfelapsedtime sp\relax}


\pdfresettimer
\usepackage{unicode-math}
\typeout{UNICODE-MATH: \the\dimexpr\pdfelapsedtime sp\relax}

\begin{document}
nothing to worry \textsf{about}? \texttt{mono}
\end{document}

luaotfload seems to put strange warnings in log but this is probably some other problem

(lualatex 1)0.16559pt
luaotfload | aux : font no 26 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 26 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 26 (nil) does not define feature smcp for script dflt
 with language dflt
luaotfload | aux : font no 26 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 26 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 26 (nil) does not define feature smcp for script dflt
 with language dflt
luaotfload | aux : font no 27 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 27 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 27 (nil) does not define feature smcp for script dflt
 with language dflt
luaotfload | aux : font no 27 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 27 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 27 (nil) does not define feature smcp for script dflt
 with language dflt
luaotfload | aux : font no 28 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 28 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 28 (nil) does not define feature smcp for script dflt
 with language dflt
luaotfload | aux : font no 28 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 28 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 28 (nil) does not define feature smcp for script dflt
 with language dflt
luaotfload | aux : font no 29 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 29 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 29 (nil) does not define feature smcp for script dflt
 with language dflt
luaotfload | aux : font no 29 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 29 (nil) does not define feature smcp for script latn
 with language dflt
luaotfload | aux : font no 29 (nil) does not define feature smcp for script dflt
 with language dflt

@wspr
Copy link
Collaborator

wspr commented Jul 31, 2024

I said I didn't have time to profile this, and I don't, but I tried this and found that there is a small part of the code which appears to be responsible for 50% of the font loading time:

\documentclass{article}
\usepackage{fontspec,l3benchmark}
\ExplSyntaxOn
\cs_set_protected:Nn \__fontspec_select_font_family:nn
  {
    \group_begin:
\benchmark_tic:
\benchmark_tic:
    \__fontspec_font_suppress_not_found_error:
    \__fontspec_init:
    \__fontspec_sanitise_fontname:Nn \l_fontspec_fontname_tl {#2}
    \tl_set_eq:NN \l__fontspec_fontname_up_tl \l_fontspec_fontname_tl
    \tl_set_eq:NN \l__fontspec_basename_tl    \l_fontspec_fontname_tl
    \__fontspec_if_detect_external:nT {#2}
     { \keys_set:nn {fontspec-preparse-external} {Path} }
    \keys_set_known:nn {fontspec-preparse-cfg} {#1}
    \__fontspec_init_ttc:n {#2}
    \__fontspec_load_external_fontoptions:N \l_fontspec_fontname_tl
    \__fontspec_extract_all_features:n {#1}
    \tl_set:Nx \l__fontspec_fontid_tl { \tl_to_str:N \l_fontspec_fontname_tl-:-\tl_to_str:N \l__fontspec_all_features_clist }
    \__fontspec_preparse_features:
    \__fontspec_load_font:
    \__fontspec_set_scriptlang:
    \__fontspec_get_features:n {}
    \bool_set_false:N \l__fontspec_firsttime_bool
\benchmark_toc:
    \__fontspec_save_family_needed:nTF {#2}
      {
        \__fontspec_save_family:nn {#1} {#2}
      }
      {
      }
\benchmark_toc:\pausenow
    \group_end:
    \tl_set_eq:NN \l_fontspec_family_tl \g__fontspec_nfss_family_tl
  }
\setmainfont{Times}
\begin{document}
hello
\end{document}

On my new-ish Mac mini, this gives:

(l3benchmark) + TIC
(l3benchmark) +-+ TIC
(l3benchmark) +-+ TOC: 0.0114 s
(l3benchmark) + TOC: 0.0205 s

Do you see a similar performance hit for the save_family block of code? I suspect this could be optimised as not a huge amount of information is needed to be stored per font.

@jfbu
Copy link
Contributor Author

jfbu commented Jul 31, 2024

Here is typical output on my very old hardware. It appears my estimate current PCs would be about 4X faster was not that far off!

... and yes, sorry, I do obtain similar findings on my equipment, with some interesting difference between xelatex and lualatex. (inclusive of a blank line in output which I have not tried to understand).

For xelatex:

(l3benchmark) + TIC
(l3benchmark) +-+ TIC
(l3benchmark) +-+ TOC: 0.0446 s
(l3benchmark) + TOC: 0.0728 s

For lualatex:

(l3benchmark) + TIC
(l3benchmark) +-+ TIC

(l3benchmark) +-+ TOC: 0.0226 s
(l3benchmark) + TOC: 0.102 s

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

No branches or pull requests

2 participants