Am 16.12.22 um 18:10 schrieb Hans Hagen via ntg-context:
So the challenge is how to determine bottlenecks. Are there users on
this list that have document runs of more than 10 seconds (as reference:
the luametatex manual takes < 9 seconds for 350 pages and loads plenty
fonts and has many tables) or have many (small) runs and are annoyed by
the runtime? And if so, what does one guess are the bottlenecks?
(1)
This is my 366 page ConTeXt book:
mkiv lua stats > used config file:
home:texmf/web2c/texmfcnf.lua;selfautoparent:/texmf/web2c/texmfcnf.lua
mkiv lua stats > used cache path:
/Users/hraban/lmtx/tex/texmf-cache/luametatex-cache/context/c821363a6b068765c2a3bbfe3917fcf5
mkiv lua stats > resource resolver: loadtime 0.046 seconds, 1 scans
with scantime 0.037 seconds, 0 shared scans, 165 found files, scanned
paths: /Users/hraban/texmf
mkiv lua stats > stored bytecode data: 507 modules (0.378 sec), 106
tables (0.017 sec), 613 chunks (0.395 sec)
mkiv lua stats > traced context: maxstack: 3112, freed: 1448,
unreachable: 1664
mkiv lua stats > cleaned up reserved nodes: 202 nodes, 22 lists of 517
mkiv lua stats > node memory usage: 1137 attribute, 46 dir, 559 glue,
82 gluespec, 177 glyph, 236 hlist, 3 kern, 647 mathspec, 48 penalty, 2
submlist, 2 temp
mkiv lua stats > node list callback tasks: 13 unique task lists, 180
instances (re)created, 216502 calls
mkiv lua stats > h-node processing time: 2.544 seconds including kernel
mkiv lua stats > synctex tracing: 46 referenced files, 22 files
ignored, 41808 objects flushed, logfile: prd_de.synctex
mkiv lua stats > attribute processing time: 0.201 seconds front- and
backend
mkiv lua stats > driver time: 5.265 seconds
mkiv lua stats > used backend: pdf
mkiv lua stats > jobdata time: 0.271 seconds saving, 0.056 seconds loading
mkiv lua stats > callbacks: file: 26780, saved: 405242, direct: 524,
function: 281755, value: 2288, message: 0, bytecode: 613, late 0, total:
717202 (1960 per page)
mkiv lua stats > randomizer: resumed with value 0.57895496379132
mkiv lua stats > v-node processing time: 1.464 seconds
mkiv lua stats > loaded tex modules: 10 requested, all found (*-filter
*-libs-imp-zint *-module-catcodes *-s-fonts-show *-s-symbols-show
*-scite *-syntax-groups *-syntax-highlight *-vim *-visual)
mkiv lua stats > loaded patterns: de::3 en::1, load time: 0.000
mkiv lua stats > xml load time: 0.002 seconds, 1 files, 1 converted
mkiv lua stats > lxml preparation time: 0.000 seconds, 0 nodes, 31
lpath calls, 4 cached calls
mkiv lua stats > interactive elements: 2536 references, 2870 destinations
mkiv lua stats > margin data: 295 entries, 1 pending
mkiv lua stats > loaded fonts: 31 files: latinmodern-math.otf,
lmmono10-italic.otf, lmmono10-regular.otf, lmmonocaps10-regular.otf,
lmmonolt10-bold.otf, lmmonolt10-boldoblique.otf,
lmmonoltcond10-regular.otf, lmmonoslant10-regular.otf,
lmroman10-bold.otf, lmroman10-italic.otf, lmroman10-regular.otf,
lmromancaps10-regular.otf, lmsans10-oblique.otf, lmsans10-regular.otf,
cc-icons.ttf, dejavusansmono.ttf, marvosym.ttf, font awesome 5
brands-regular-400.otf, font awesome 5 free-regular-400.otf, font
awesome 5 free-solid-900.otf, cambria.ttc, cambriab.ttf, cambriai.ttf,
cambriaz.ttf, segoe ui bold italic.ttf, segoe ui bold.ttf, segoe ui
italic.ttf, segoe ui.ttf, segoepr.ttf, symbola.otf,
unifrakturmaguntia.ttf (suspicious x height)
mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 193
instances, 157 shared in backend, 11 common vectors, 146 common hashes,
load time 15.349 seconds
mkiv lua stats > body font sizes: defined: 10pt 11pt 12pt 14.4pt 17.3pt
20.7pt 4pt 5pt 6pt 7pt 8pt 9pt, undefined: 11.2pt 14pt 16.8pt
mkiv lua stats > visualization time: 0.154 seconds
mkiv lua stats > metapost: 0.678 seconds, loading: 0.092, execution:
0.651, n: 528, average: 0.003, instances: 2, luacalls: 37745 (file:
31092, text: 0, script: 3507, log: 3146), memory: 8.825 M
mkiv lua stats > math tweaking time: 8.659 seconds, 116 math goodie tables
mkiv lua stats > math processing time: 0.012 seconds
mkiv lua stats > graphics processing time: 2.885 seconds including tex,
247 processed images, 69 unique asked, 42 bad names
mkiv lua stats > pdf annotations: 2536 links (2535 unique), 0 special
mkiv lua stats > font embedding time: 0.084 seconds, 31 fonts
mkiv lua stats > result saved in file: prd_de.pdf, compresslevel 1,
objectcompresslevel 0
mkiv lua stats > positions: 6786 collected, 3635 deltas, 6678 shared
partials, 46 partial entries
mkiv lua stats > used platform: osx-64, type: unix, binary subtree:
texmf-osx-64
mkiv lua stats > used engine: luametatex version: 2.1004, functionality
level: 20221208, format id: 678, compiler: clang
mkiv lua stats > tex properties: 740852 hash slots used of 2097152,
59643 control sequences, approximate memory usage: 217 MB
mkiv lua stats > lua properties: engine: lua 5.4, used memory: 800 MB,
ctx: 767 MB, max: 767 MB, symbol mask: utf (τεχ)
mkiv lua stats > runtime: 30.592 seconds, 366 processed pages, 366
shipped pages, 11.964 pages/second
system | total runtime: 219.556 seconds of 219.819 seconds
real 3m39,829s
user 3m23,086s
sys 0m12,772s
I guess it needs too much time on calling zint for all the QR codes that
I probably will get rid of anyway. Otherwise it loads nearly all
modules. So it’s an extreme case.
(2)
This is a 720 page novel (first run with this LMTX version, some fonts
were still uncached):
mkiv lua stats > used config file:
home:texmf/web2c/texmfcnf.lua;selfautoparent:/texmf/web2c/texmfcnf.lua
mkiv lua stats > used cache path:
/Users/hraban/lmtx/tex/texmf-cache/luametatex-cache/context/c821363a6b068765c2a3bbfe3917fcf5
mkiv lua stats > resource resolver: loadtime 0.045 seconds, 1 scans
with scantime 0.036 seconds, 0 shared scans, 27 found files, scanned
paths: /Users/hraban/texmf
mkiv lua stats > stored bytecode data: 507 modules (0.388 sec), 106
tables (0.016 sec), 613 chunks (0.404 sec)
mkiv lua stats > traced context: maxstack: 1659, freed: 4, unreachable:
1655
mkiv lua stats > cleaned up reserved nodes: 74 nodes, 8 lists of 435
mkiv lua stats > node memory usage: 14 attribute, 2 glue, 83 gluespec,
3 kern, 647 mathspec, 3 penalty, 2 temp
mkiv lua stats > node list callback tasks: 13 unique task lists, 11
instances (re)created, 64714 calls
mkiv lua stats > h-node processing time: 11.444 seconds including kernel
mkiv lua stats > attribute processing time: 0.433 seconds front- and
backend
mkiv lua stats > driver time: 13.557 seconds
mkiv lua stats > used backend: pdf
mkiv lua stats > jobdata time: 0.018 seconds saving, 0.004 seconds loading
mkiv lua stats > callbacks: file: 6035, saved: 123944, direct: 4,
function: 37443, value: 721, message: 0, bytecode: 613, late 0, total:
168760 (234 per page)
mkiv lua stats > randomizer: resumed with value 0.69074136591922
mkiv lua stats > v-node processing time: 0.273 seconds
mkiv lua stats > loaded patterns: de::3 en::1, load time: 0.000
mkiv lua stats > interactive elements: 2 references, 1 destinations
mkiv lua stats > loaded fonts: 8 files: latinmodern-math.otf,
lmroman10-regular.otf, supernett_cn_light.otf, alegreya-bold.ttf,
alegreya-italic.ttf, alegreya-regular.ttf, alegreyasans-light.ttf,
alegreyasc-regular.ttf
mkiv lua stats > font engine: otf 3.131, afm 1.513, tfm 1.000, 31
instances, 20 shared in backend, 5 common vectors, 15 common hashes,
load time 0.797 seconds
mkiv lua stats > math tweaking time: 0.167 seconds, 12 math goodie tables
mkiv lua stats > graphics processing time: 0.003 seconds including tex,
2 processed images, 1 unique asked, 0 bad names
mkiv lua stats > pdf annotations: 2 links (2 unique), 0 special
mkiv lua stats > font embedding time: 0.017 seconds, 6 fonts
mkiv lua stats > result saved in file: prd_02_pyka.pdf, compresslevel
1, objectcompresslevel 3
mkiv lua stats > positions: 4 collected, 0 deltas, 0 shared partials, 0
partial entries
mkiv lua stats > used platform: osx-64, type: unix, binary subtree:
texmf-osx-64
mkiv lua stats > used engine: luametatex version: 2.1004, functionality
level: 20221208, format id: 678, compiler: clang
mkiv lua stats > tex properties: 740852 hash slots used of 2097152,
55184 control sequences, approximate memory usage: 51 MB
mkiv lua stats > lua properties: engine: lua 5.4, used memory: 124 MB,
ctx: 109 MB, max: 181 MB, symbol mask: utf (τεχ)
mkiv lua stats > runtime: 19.275 seconds, 720 processed pages, 720
shipped pages, 37.355 pages/second
system | total runtime: 59.113 seconds of 59.220 seconds
real 0m59,229s
user 0m57,610s
sys 0m1,379s
Made on a Mac mini from 2012 (2,3 GHz i7, 16 GB RAM), but with SSDs.
Hraban
___________________________________________________________________________________
If your question is of interest to others as well, please add an entry to the
Wiki!
maillist : ntg-context@ntg.nl / https://www.ntg.nl/mailman/listinfo/ntg-context
webpage : https://www.pragma-ade.nl / http://context.aanhet.net
archive : https://bitbucket.org/phg/context-mirror/commits/
wiki : https://contextgarden.net
___________________________________________________________________________________
